Shutdown tokio runtime gracefully when panic occurs in spawned future #535

fordN · 2018-10-29T20:55:41Z

Resolves #314

This PR replaces tokio::run() with a more custom build of a multi-threaded, Tokio runtime in order to allow panics in spawned futures to shutdown the entire runtime gracefully.

A runtime is instantiated and provided the necessary components to setup a context for running our main function. Default components are setup for the context using the respective <>::with_default() method. Included with the runtime: reactor handle, executor context, and timer instance.
The PR also updates the futures library and replaces its now deprecated deadline() function with timeout().

Issues created in tokio:
Tough to track down issue setting up the Timer: tokio-rs/tokio#727
Errors resulting from the fact that block_on does not set default runtime context components: tokio-rs/tokio#728

leoyvens · 2018-10-30T14:16:32Z

@fordN is this still WIP? I imagine having direct access to the runtime and executor will be crucial to solving #314 but this PR isn't there yet, the only change in behaviour I could observe when testing is that we shutdown the runtime when idle, which never happens in practice.

fordN · 2018-10-30T15:35:59Z

@leodasvacas, I tested this by panicking within a future spawned on the runtime.

My experience testing:

Before the changes: the panic log would be written out (but not always) and the runtime would continue to hobble along.
After the changes: the panic is logged and the application shuts down immediately.

timmclean · 2018-10-30T15:40:58Z

Looks like you need to rebase this onto the new retry helper

fordN · 2018-11-12T16:02:05Z

@leodasvacas I updated the shutdown process to send a shutdown signal to a thread that calls runtime.shutdown_now in order to stop all futures, and shutdown the threadpool and reactor. This update solves several of my test cases, but there are still situations where a future continues to run. I believe this is because tokio workers do not maintain a reference to the future in order to shutdown. I've found several related issues.

Issue with futures holding references: rust-lang/futures-rs#853
Brainstorm about tokio implementing a dedicated worker thread to run a reactor instance which among other things allows a worker to track all futures that it owns and drop incomplete futures when it shuts down: tokio-rs/tokio#424
Open PR for dropping incomplete tasks on shutdown: tokio-rs/tokio#722

leoyvens

Good to see this revisited! The code doesn't quite reflect what we discussed (but it's close), let me know if you have questions, I'm also curious to know how your test cases went after this change.

leoyvens · 2018-11-30T15:04:15Z

graph/src/util/log.rs

-pub fn register_panic_hook(panic_logger: slog::Logger) {
+pub fn register_panic_hook(
+    panic_logger: slog::Logger,
+    shutdown_sender: Mutex<Option<oneshot::Sender<()>>>,


I think you can remove the Mutex and the Option around this, and then construct the mutex inside this function, to simplify the signature.

Another thing, we should probably set the exit code to 1 inside the panic hook, since a panic means we'll terminate the process abnormally.

I moved the sleep and exit into the panic_hook, so that now it sends the shutdown signal to main, sleeps, and then exits the process.

The compiler didn't like constructing the Mutex<Option<>> inside of register_panic_hook()., so I am still passing the it in as an input.

Could be because you did it inside panic::set_hook rather than right before it. But it's fine, this is not important.

Yep, updated.

leoyvens · 2018-11-30T15:06:09Z

graph/src/util/log.rs

@@ -69,5 +74,15 @@ pub fn register_panic_hook(panic_logger: slog::Logger) {
                );
            }
        };
+
+        if let Ok(ref mut mutex) = shutdown_sender.lock() {


The mutex may be unwrapped, since it will only error if a panic happens while holding the lock, but in this case that would be a double panic which will abort.

node/src/main.rs

leoyvens · 2018-12-03T20:03:00Z

#620 caused conflicts. The Cargo.lock you'll want to just get the version on master.

leoyvens

This is looking good, just a few extra comments. Sorry for the never-ending review here!

graph/src/util/log.rs

node/src/main.rs

graph/src/util/log.rs

node/src/main.rs

Exit process after running shutdown and waiting for 3 seconds to ensure complete shutdown of all workers.

timmclean · 2018-12-14T19:21:49Z

Adding this to the Hosted Service milestone, as we need this so that nodes don't get stuck in a broken state due to a transient panic

leoyvens · 2018-12-14T19:57:42Z

Needs to be fmt'ed.

leoyvens

Have a comment about dead code and this needs to be rustfmt'ed, otherwise it's good to go!

leoyvens · 2018-12-14T19:59:03Z

node/src/main.rs

+    // Create components for tokio context: multi-threaded runtime, reactor reference,
+    // executor context on the runtime, and Timer handle.
+    let runtime = tokio::runtime::Runtime::new().expect("Failed to create runtime");
+    let reactor = tokio_reactor::Handle::current();


Is this variable unused? Looks like the whole tokio_reactor dependency is unused now.

yep 👍, I've now removed the entire tokio_reactor dependency.

leoyvens

Still some tokio-reactor left standing.

leoyvens · 2018-12-15T12:05:24Z

graph/src/lib.rs

@@ -21,7 +21,10 @@ extern crate slog_envlogger;
 extern crate slog_term;
 extern crate tiny_keccak;
 pub extern crate tokio;
+pub extern crate tokio_executor;
+pub extern crate tokio_reactor;


This is dead code.

leoyvens · 2018-12-15T12:05:35Z

graph/Cargo.toml

@@ -30,5 +30,8 @@ slog-envlogger = "2.1.0"
 slog-term = "2.4.0"
 tiny-keccak = "1.0"
 tokio = "0.1.11"
+tokio-executor = "0.1.5"
+tokio-reactor = "0.1.6"


This dependency is dead.

Removed .expect()s from Shutdown sending instead logging failed or already sent status.

leoyvens

All good now, will be great to have this!

Jannis · 2018-12-17T13:21:24Z

🎉

timmclean · 2018-12-17T17:26:23Z

Nice! So this means that we abort the process now on panics?

By the way, it looks like the two Tokio issues have comments on them

ghost assigned fordN Oct 29, 2018

ghost added pending review review labels Oct 29, 2018

fordN force-pushed the ford/tokio-blockon branch from ddfed8a to b65f741 Compare October 29, 2018 22:56

fordN changed the title ~~Shutdown tokio runtime gracefully when panic occurs in spawned thread~~ Shutdown tokio runtime gracefully when panic occurs in spawned future Oct 29, 2018

fordN force-pushed the ford/tokio-blockon branch from b65f741 to 80e181b Compare October 30, 2018 07:49

fordN force-pushed the ford/tokio-blockon branch 2 times, most recently from 8879d0a to df8c829 Compare November 30, 2018 09:01

fordN requested review from leoyvens, Jannis and timmclean November 30, 2018 09:04

leoyvens requested changes Nov 30, 2018

View reviewed changes

fordN force-pushed the ford/tokio-blockon branch from df8c829 to 8e877eb Compare December 4, 2018 19:23

leoyvens requested changes Dec 5, 2018

View reviewed changes

graph/src/util/log.rs Outdated Show resolved Hide resolved

node/src/main.rs Outdated Show resolved Hide resolved

graph/src/util/log.rs Show resolved Hide resolved

graph/src/util/log.rs Outdated Show resolved Hide resolved

node/src/main.rs Show resolved Hide resolved

fordN added 8 commits December 14, 2018 03:15

graph, node: Upgrade tokio and replace run() with block_on()

f3ad58c

graph, node: Use tokio_executor to set Runtime as default executor

49b893d

graph, node: Set default timer and reactor for Tokio runtime block_on

5a6d659

graph, node: Set default timer and reactor for Tokio runtime block_on

a39dc06

graph: Update tokio deadline() --> timeout() (deadline is deprecated)

a8392a5

node: Add comments to explain tokio runtime setup, use default Timer

863d286

graph, node: Send shutdown signal from panic logger, shutdown runtime

2c7804a

Exit process after running shutdown and waiting for 3 seconds to ensure complete shutdown of all workers.

graph, node: Add descriptive comments, restructure shutdown sending

414ed4e

fordN force-pushed the ford/tokio-blockon branch from 570cc99 to e342396 Compare December 14, 2018 11:20

timmclean added this to the Hosted Service milestone Dec 14, 2018

leoyvens requested changes Dec 14, 2018

View reviewed changes

fordN added 2 commits December 14, 2018 15:28

graph, node: Simplify register panic hook signature, build mutex within

366f814

node: Log successful Runtime shutdown, remove reactor with_default

3d7a87d

fordN force-pushed the ford/tokio-blockon branch from e342396 to 0ab2119 Compare December 14, 2018 23:29

leoyvens requested changes Dec 15, 2018

View reviewed changes

fordN added 2 commits December 17, 2018 00:44

graph: Shutdown sender mutex logs when it has already been used

024c9bf

Removed .expect()s from Shutdown sending instead logging failed or already sent status.

graph: Remove unused dependency tokio_reactor and unused import Instant

108b9c4

fordN force-pushed the ford/tokio-blockon branch from 0ab2119 to 108b9c4 Compare December 17, 2018 08:44

leoyvens approved these changes Dec 17, 2018

View reviewed changes

fordN merged commit e1b2582 into master Dec 17, 2018

ghost removed pending review review labels Dec 17, 2018

fordN deleted the ford/tokio-blockon branch January 17, 2019 00:34

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Shutdown tokio runtime gracefully when panic occurs in spawned future #535

Shutdown tokio runtime gracefully when panic occurs in spawned future #535

fordN commented Oct 29, 2018 •

edited

Loading

leoyvens commented Oct 30, 2018

fordN commented Oct 30, 2018

timmclean commented Oct 30, 2018

fordN commented Nov 12, 2018

leoyvens left a comment •

edited

Loading

leoyvens Nov 30, 2018

leoyvens Nov 30, 2018

fordN Dec 5, 2018

fordN Dec 5, 2018

leoyvens Dec 5, 2018 •

edited

Loading

fordN Dec 14, 2018

leoyvens Nov 30, 2018

leoyvens commented Dec 3, 2018

leoyvens left a comment

timmclean commented Dec 14, 2018

leoyvens commented Dec 14, 2018

leoyvens left a comment

leoyvens Dec 14, 2018

fordN Dec 14, 2018

leoyvens left a comment

leoyvens Dec 15, 2018

leoyvens Dec 15, 2018

leoyvens left a comment

Jannis commented Dec 17, 2018

timmclean commented Dec 17, 2018

Shutdown tokio runtime gracefully when panic occurs in spawned future #535

Shutdown tokio runtime gracefully when panic occurs in spawned future #535

Conversation

fordN commented Oct 29, 2018 • edited Loading

leoyvens commented Oct 30, 2018

fordN commented Oct 30, 2018

timmclean commented Oct 30, 2018

fordN commented Nov 12, 2018

leoyvens left a comment • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

leoyvens Dec 5, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

leoyvens commented Dec 3, 2018

leoyvens left a comment

Choose a reason for hiding this comment

timmclean commented Dec 14, 2018

leoyvens commented Dec 14, 2018

leoyvens left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

leoyvens left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

leoyvens left a comment

Choose a reason for hiding this comment

Jannis commented Dec 17, 2018

timmclean commented Dec 17, 2018

fordN commented Oct 29, 2018 •

edited

Loading

leoyvens left a comment •

edited

Loading

leoyvens Dec 5, 2018 •

edited

Loading