diff --git a/doc/PLUGINS.md b/doc/PLUGINS.md index 40d316b457e3..f4a422efa9fb 100644 --- a/doc/PLUGINS.md +++ b/doc/PLUGINS.md @@ -791,6 +791,16 @@ here, with the peer's signatures attached. } ``` +### `shutdown` + +Called when lightningd is shutting down, or this plugin has been +shutdown by the plugin stop command. The plugin has 30 seconds to +exit itself, otherwise it's killed. + +Because lightningd can crash or be killed, a plugin cannot rely on +this function always called. + + ## Hooks Hooks allow a plugin to define custom behavior for `lightningd` diff --git a/lightningd/bitcoind.h b/lightningd/bitcoind.h index 8fb275e342cf..d17a28605cd2 100644 --- a/lightningd/bitcoind.h +++ b/lightningd/bitcoind.h @@ -32,6 +32,9 @@ struct bitcoind { /* Ignore results, we're shutting down. */ bool shutdown; + /* Timer if we're waiting for it to warm up. */ + struct oneshot *checkchain_timer; + struct list_head pending_getfilteredblock; /* Map each method to a plugin, so we can have multiple plugins diff --git a/lightningd/chaintopology.c b/lightningd/chaintopology.c index a7d5463ba4d2..9b3b7a6574ab 100644 --- a/lightningd/chaintopology.c +++ b/lightningd/chaintopology.c @@ -46,10 +46,10 @@ static void maybe_completed_init(struct chain_topology *topo) static void next_topology_timer(struct chain_topology *topo) { - /* This takes care of its own lifetime. */ - notleak(new_reltimer(topo->timers, topo, - time_from_sec(topo->poll_seconds), - try_extend_tip, topo)); + assert(!topo->extend_timer); + topo->extend_timer = new_reltimer(topo->ld->timers, topo, + time_from_sec(topo->poll_seconds), + try_extend_tip, topo); } static bool we_broadcast(const struct chain_topology *topo, @@ -437,6 +437,7 @@ static void update_feerates(struct bitcoind *bitcoind, static void start_fee_estimate(struct chain_topology *topo) { + topo->updatefee_timer = NULL; /* Once per new block head, update fee estimates. */ bitcoind_estimate_fees(topo->bitcoind, NUM_FEERATES, update_feerates, topo); @@ -582,10 +583,10 @@ AUTODATA(json_command, &parse_feerate_command); static void next_updatefee_timer(struct chain_topology *topo) { - /* This takes care of its own lifetime. */ - notleak(new_reltimer(topo->timers, topo, - time_from_sec(topo->poll_seconds), - start_fee_estimate, topo)); + assert(!topo->updatefee_timer); + topo->updatefee_timer = new_reltimer(topo->ld->timers, topo, + time_from_sec(topo->poll_seconds), + start_fee_estimate, topo); } struct sync_waiter { @@ -935,6 +936,7 @@ static void get_new_block(struct bitcoind *bitcoind, static void try_extend_tip(struct chain_topology *topo) { + topo->extend_timer = NULL; bitcoind_getrawblockbyheight(topo->bitcoind, topo->tip->height + 1, get_new_block, topo); } @@ -1144,24 +1146,25 @@ check_chain(struct bitcoind *bitcoind, const char *chain, return; } - notleak(new_reltimer(bitcoind->ld->timers, bitcoind, - /* Be 4x more aggressive in this case. */ - time_divide(time_from_sec(bitcoind->ld->topology - ->poll_seconds), 4), - retry_check_chain, bitcoind->ld->topology)); - } + assert(!bitcoind->checkchain_timer); + bitcoind->checkchain_timer + = new_reltimer(bitcoind->ld->timers, bitcoind, + /* Be 4x more aggressive in this case. */ + time_divide(time_from_sec(bitcoind->ld->topology + ->poll_seconds), 4), + retry_check_chain, bitcoind->ld->topology); +} static void retry_check_chain(struct chain_topology *topo) { + topo->bitcoind->checkchain_timer = NULL; bitcoind_getchaininfo(topo->bitcoind, false, check_chain, topo); } void setup_topology(struct chain_topology *topo, - struct timers *timers, u32 min_blockheight, u32 max_blockheight) { memset(&topo->feerate, 0, sizeof(topo->feerate)); - topo->timers = timers; topo->min_blockheight = min_blockheight; topo->max_blockheight = max_blockheight; @@ -1173,6 +1176,7 @@ void setup_topology(struct chain_topology *topo, log_debug(topo->ld->log, "All Bitcoin plugin commands registered"); /* Sanity checks, then topology initialization. */ + topo->bitcoind->checkchain_timer = NULL; bitcoind_getchaininfo(topo->bitcoind, true, check_chain, topo); tal_add_destructor(topo, destroy_chain_topology); @@ -1187,3 +1191,12 @@ void begin_topology(struct chain_topology *topo) { try_extend_tip(topo); } + +void stop_topology(struct chain_topology *topo) +{ + /* Remove timers while we're cleaning up plugins. */ + tal_free(topo->bitcoind->checkchain_timer); + tal_free(topo->extend_timer); + tal_free(topo->updatefee_timer); +} + diff --git a/lightningd/chaintopology.h b/lightningd/chaintopology.h index 0b6a5e0203dc..e824eb85e850 100644 --- a/lightningd/chaintopology.h +++ b/lightningd/chaintopology.h @@ -113,8 +113,8 @@ struct chain_topology { /* The bitcoind. */ struct bitcoind *bitcoind; - /* Our timer list. */ - struct timers *timers; + /* Timers we're running. */ + struct oneshot *extend_timer, *updatefee_timer; /* Bitcoin transactions we're broadcasting */ struct list_head outgoing_txs; @@ -193,11 +193,13 @@ void broadcast_tx_ahf(struct chain_topology *topo, const char *err)); struct chain_topology *new_topology(struct lightningd *ld, struct log *log); -void setup_topology(struct chain_topology *topology, struct timers *timers, +void setup_topology(struct chain_topology *topology, u32 min_blockheight, u32 max_blockheight); void begin_topology(struct chain_topology *topo); +void stop_topology(struct chain_topology *topo); + struct txlocator *locate_tx(const void *ctx, const struct chain_topology *topo, const struct bitcoin_txid *txid); static inline bool topology_synced(const struct chain_topology *topo) diff --git a/lightningd/lightningd.c b/lightningd/lightningd.c index 38ce1f574b02..83d6ed44bb98 100644 --- a/lightningd/lightningd.c +++ b/lightningd/lightningd.c @@ -1035,8 +1035,7 @@ int main(int argc, char *argv[]) /*~ Initialize block topology. This does its own io_loop to * talk to bitcoind, so does its own db transactions. */ - setup_topology(ld->topology, ld->timers, - min_blockheight, max_blockheight); + setup_topology(ld->topology, min_blockheight, max_blockheight); db_begin_transaction(ld->wallet->db); @@ -1142,12 +1141,15 @@ int main(int argc, char *argv[]) stop_response = tal_steal(NULL, ld->stop_response); } + /* Stop topology callbacks. */ + stop_topology(ld->topology); + /* We're not going to collect our children. */ remove_sigchild_handler(); - shutdown_subdaemons(ld); - /* Remove plugins. */ - plugins_free(ld->plugins); + /* Tell plugins we're shutting down. */ + shutdown_plugins(ld); + shutdown_subdaemons(ld); /* Clean up the JSON-RPC. This needs to happen in a DB transaction since * it might actually be touching the DB in some destructors, e.g., diff --git a/lightningd/notification.c b/lightningd/notification.c index df9b6deaebb7..7f3ea216f2ce 100644 --- a/lightningd/notification.c +++ b/lightningd/notification.c @@ -554,3 +554,14 @@ void notify_channel_open_failed(struct lightningd *ld, jsonrpc_notification_end(n); plugins_notify(ld->plugins, take(n)); } + +REGISTER_NOTIFICATION(plugin_shutdown, NULL); + +bool notify_plugin_shutdown(struct lightningd *ld, struct plugin *p) +{ + struct jsonrpc_notification *n = + jsonrpc_notification_start(NULL, "shutdown"); + + jsonrpc_notification_end(n); + return plugin_single_notify(p, take(n)); +} diff --git a/lightningd/notification.h b/lightningd/notification.h index 452926a37dff..ac27c8c14541 100644 --- a/lightningd/notification.h +++ b/lightningd/notification.h @@ -104,4 +104,7 @@ void notify_openchannel_peer_sigs(struct lightningd *ld, void notify_channel_open_failed(struct lightningd *ld, const struct channel_id *cid); + +/* Tell this plugin to shutdown: returns true if it was subscribed. */ +bool notify_plugin_shutdown(struct lightningd *ld, struct plugin *p); #endif /* LIGHTNING_LIGHTNINGD_NOTIFICATION_H */ diff --git a/lightningd/plugin.c b/lightningd/plugin.c index fa1dfcf5e727..e983ddb36960 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -89,22 +89,6 @@ struct plugins *plugins_new(const tal_t *ctx, struct log_book *log_book, return p; } -void plugins_free(struct plugins *plugins) -{ - struct plugin *p; - - plugins->shutdown = true; - - /* Plugins are usually the unit of allocation, and they are internally - * consistent, so let's free each plugin first. */ - while (!list_empty(&plugins->plugins)) { - p = list_pop(&plugins->plugins, struct plugin, list); - tal_free(p); - } - - tal_free(plugins); -} - /* Check that all the plugin's subscriptions are actually for known * notification topics. Emit a warning if that's not the case, but * don't kill the plugin. */ @@ -205,8 +189,12 @@ static void destroy_plugin(struct plugin *p) /* If we are shutting down, do not continue to checking if * the dying plugin is important. */ - if (p->plugins->shutdown) + if (p->plugins->shutdown) { + /* But return if this was the last plugin! */ + if (list_empty(&p->plugins->plugins)) + io_break(p->plugins); return; + } /* Now check if the dying plugin is important. */ if (p->important) { @@ -1958,21 +1946,36 @@ static bool plugin_subscriptions_contains(struct plugin *plugin, return false; } +bool plugin_single_notify(struct plugin *p, + const struct jsonrpc_notification *n TAKES) +{ + bool interested; + if (plugin_subscriptions_contains(p, n->method)) { + plugin_send(p, json_stream_dup(p, n->stream, p->log)); + interested = true; + } else + interested = false; + + if (taken(n)) + tal_free(n); + + return interested; +} + void plugins_notify(struct plugins *plugins, const struct jsonrpc_notification *n TAKES) { struct plugin *p; + if (taken(n)) + tal_steal(tmpctx, n); + /* If we're shutting down, ld->plugins will be NULL */ if (plugins) { list_for_each(&plugins->plugins, p, list) { - if (plugin_subscriptions_contains(p, n->method)) - plugin_send(p, json_stream_dup(p, n->stream, - p->log)); + plugin_single_notify(p, n); } } - if (taken(n)) - tal_free(n); } static void destroy_request(struct jsonrpc_request *req, @@ -2067,3 +2070,49 @@ bool was_plugin_destroyed(struct plugin_destroyed *pd) tal_free(pd); return true; } + +static void plugin_shutdown_timeout(struct lightningd *ld) +{ + io_break(ld->plugins); +} + +void shutdown_plugins(struct lightningd *ld) +{ + struct plugin *p, *next; + + /* This makes sure we don't complain about important plugins + * vanishing! */ + ld->plugins->shutdown = true; + + /* Tell them all to shutdown; if they care. */ + list_for_each_safe(&ld->plugins->plugins, p, next, list) { + /* Kill immediately, deletes self from list. */ + if (!notify_plugin_shutdown(ld, p)) + tal_free(p); + } + + /* If anyone was interested in shutdown, give them time. */ + if (!list_empty(&ld->plugins->plugins)) { + struct oneshot *t; + + /* 30 seconds should do it. */ + t = new_reltimer(ld->timers, ld, + time_from_sec(30), + plugin_shutdown_timeout, ld); + + io_loop_with_timers(ld); + tal_free(t); + + /* Report and free remaining plugins. */ + while (!list_empty(&ld->plugins->plugins)) { + p = list_pop(&ld->plugins->plugins, struct plugin, list); + log_debug(ld->log, + "%s: failed to shutdown, killing.", + p->shortname); + tal_free(p); + } + } + + /* NULL stops notifications trying to access plugins. */ + ld->plugins = tal_free(ld->plugins); +} diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 57c6a3f5dbf3..99ab5422da33 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -189,26 +189,6 @@ void plugins_add_default_dir(struct plugins *plugins); */ void plugins_init(struct plugins *plugins); -/** - * Free all resources that are held by plugins in the correct order. - * - * This function ensures that the resources dangling off of the plugins struct - * are freed in the correct order. This is necessary since the struct manages - * two orthogonal sets of resources: - * - * - Plugins - * - Hook calls and notifications - * - * The tal hierarchy is organized in a plugin centric way, i.e., the plugins - * may exit in an arbitrary order and they'll unregister pointers in the other - * resources. However this will fail if `tal_free` decides to free one of the - * non-plugin resources (technically a sibling in the allocation tree) before - * the plugins we will get a use-after-free. This function fixes this by - * freeing in the correct order without adding additional child-relationships - * in the allocation structure and without adding destructors. - */ -void plugins_free(struct plugins *plugins); - /** * Register a plugin for initialization and execution. * @@ -271,6 +251,11 @@ bool plugins_send_getmanifest(struct plugins *plugins); void plugin_kill(struct plugin *plugin, enum log_level loglevel, const char *fmt, ...); +/** + * Tell all the plugins we're shutting down, and free them. + */ +void shutdown_plugins(struct lightningd *ld); + /** * Returns the plugin which registers the command with name {cmd_name} */ @@ -351,6 +336,17 @@ char *add_plugin_dir(struct plugins *plugins, const char *dir, */ void clear_plugins(struct plugins *plugins); +/** + * Send notification to this single plugin, if interested. + * + * Returns true if it was subscribed to the notification. + */ +bool plugin_single_notify(struct plugin *p, + const struct jsonrpc_notification *n TAKES); + +/** + * Send notification to all interested plugins. + */ void plugins_notify(struct plugins *plugins, const struct jsonrpc_notification *n TAKES); diff --git a/lightningd/plugin_control.c b/lightningd/plugin_control.c index 06aaf3f42570..db8836c2bc93 100644 --- a/lightningd/plugin_control.c +++ b/lightningd/plugin_control.c @@ -1,4 +1,5 @@ #include +#include #include #include #include @@ -101,11 +102,44 @@ plugin_dynamic_startdir(struct plugin_command *pcmd, const char *dir_path) return command_still_pending(pcmd->cmd); } +static struct command_result *plugin_stop(struct command *cmd, struct plugin *p, + bool kill) +{ + struct json_stream *response; + const char *stopmsg = tal_fmt(NULL, "Successfully stopped %s.", + p->shortname); + + if (kill) + plugin_kill(p, LOG_INFORM, "stopped by lightningd via RPC"); + + response = json_stream_success(cmd); + json_add_string(response, "command", "stop"); + json_add_string(response, "result", take(stopmsg)); + return command_success(cmd, response); +} + +/* If plugin stops itself, we end up here. */ +static void plugin_stopped(struct plugin *p, struct command *cmd) +{ + plugin_stop(cmd, p, false); +} + +struct plugin_stop_timeout { + struct command *cmd; + struct plugin *p; +}; + +static void plugin_stop_timeout(struct plugin_stop_timeout *pst) +{ + log_unusual(pst->p->log, "Timeout on shutdown: killing anyway"); + tal_del_destructor2(pst->p, plugin_stopped, pst->cmd); + plugin_stop(pst->cmd, pst->p, true); +} + static struct command_result * plugin_dynamic_stop(struct command *cmd, const char *plugin_name) { struct plugin *p; - struct json_stream *response; list_for_each(&cmd->ld->plugins->plugins, p, list) { if (plugin_paths_match(p->cmd, plugin_name)) { @@ -114,14 +148,24 @@ plugin_dynamic_stop(struct command *cmd, const char *plugin_name) "%s cannot be managed when " "lightningd is up", plugin_name); - plugin_kill(p, LOG_INFORM, - "stopped by lightningd via RPC"); - response = json_stream_success(cmd); - json_add_string(response, "command", "stop"); - json_add_string(response, "result", - take(tal_fmt(NULL, "Successfully stopped %s.", - plugin_name))); - return command_success(cmd, response); + + /* If it's interested in clean shutdown, tell it. */ + if (notify_plugin_shutdown(cmd->ld, p)) { + struct plugin_stop_timeout *pst; + + /* Kill in 30 seconds if it doesn't exit. */ + pst = tal(p, struct plugin_stop_timeout); + pst->p = p; + pst->cmd = cmd; + notleak(new_reltimer(cmd->ld->timers, pst, + time_from_sec(30), + plugin_stop_timeout, + pst)); + + tal_add_destructor2(p, plugin_stopped, cmd); + return command_still_pending(cmd); + } + return plugin_stop(cmd, p, true); } } diff --git a/lightningd/test/run-find_my_abspath.c b/lightningd/test/run-find_my_abspath.c index 946f38e27788..3eb28f7fa311 100644 --- a/lightningd/test/run-find_my_abspath.c +++ b/lightningd/test/run-find_my_abspath.c @@ -184,9 +184,6 @@ void per_peer_state_set_fds_arr(struct per_peer_state *pps UNNEEDED, const int * /* Generated stub for plugins_config */ void plugins_config(struct plugins *plugins UNNEEDED) { fprintf(stderr, "plugins_config called!\n"); abort(); } -/* Generated stub for plugins_free */ -void plugins_free(struct plugins *plugins UNNEEDED) -{ fprintf(stderr, "plugins_free called!\n"); abort(); } /* Generated stub for plugins_init */ void plugins_init(struct plugins *plugins UNNEEDED) { fprintf(stderr, "plugins_init called!\n"); abort(); } @@ -202,9 +199,15 @@ void plugins_set_builtin_plugins_dir(struct plugins *plugins UNNEEDED, void setup_color_and_alias(struct lightningd *ld UNNEEDED) { fprintf(stderr, "setup_color_and_alias called!\n"); abort(); } /* Generated stub for setup_topology */ -void setup_topology(struct chain_topology *topology UNNEEDED, struct timers *timers UNNEEDED, +void setup_topology(struct chain_topology *topology UNNEEDED, u32 min_blockheight UNNEEDED, u32 max_blockheight UNNEEDED) { fprintf(stderr, "setup_topology called!\n"); abort(); } +/* Generated stub for shutdown_plugins */ +void shutdown_plugins(struct lightningd *ld UNNEEDED) +{ fprintf(stderr, "shutdown_plugins called!\n"); abort(); } +/* Generated stub for stop_topology */ +void stop_topology(struct chain_topology *topo UNNEEDED) +{ fprintf(stderr, "stop_topology called!\n"); abort(); } /* Generated stub for timer_expired */ void timer_expired(tal_t *ctx UNNEEDED, struct timer *timer UNNEEDED) { fprintf(stderr, "timer_expired called!\n"); abort(); } diff --git a/plugins/libplugin.c b/plugins/libplugin.c index 43216f3359e9..63d56c21dc0e 100644 --- a/plugins/libplugin.c +++ b/plugins/libplugin.c @@ -12,6 +12,7 @@ #include #include #include +#include #include #include #include @@ -78,6 +79,8 @@ struct plugin { bool manifested; /* Has init been received ? */ bool initialized; + /* Are we exiting? */ + bool exiting; /* Map from json command names to usage strings: we don't put this inside * struct json_command as it's good practice to have those const. */ @@ -1123,6 +1126,15 @@ void plugin_notify_progress(struct command *cmd, plugin_notify_end(cmd, js); } +void NORETURN plugin_exit(struct plugin *p, int exitcode) +{ + p->exiting = true; + io_conn_out_exclusive(p->stdout_conn, true); + io_wake(p); + io_loop(NULL, NULL); + exit(exitcode); +} + void NORETURN plugin_err(struct plugin *p, const char *fmt, ...) { va_list ap; @@ -1131,8 +1143,10 @@ void NORETURN plugin_err(struct plugin *p, const char *fmt, ...) plugin_logv(p, LOG_BROKEN, fmt, ap); va_end(ap); va_start(ap, fmt); - errx(1, "%s", tal_vfmt(NULL, fmt, ap)); + vfprintf(stderr, fmt, ap); + fprintf(stderr, "\n"); va_end(ap); + plugin_exit(p, 1); } void plugin_log(struct plugin *p, enum log_level l, const char *fmt, ...) @@ -1315,6 +1329,9 @@ static struct io_plan *ld_write_json(struct io_conn *conn, return json_stream_output(plugin->js_arr[0], plugin->stdout_conn, ld_stream_complete, plugin); + /* If we were simply flushing final output, stop now. */ + if (plugin->exiting) + io_break(plugin); return io_out_wait(conn, plugin, ld_write_json, plugin); } @@ -1391,7 +1408,7 @@ static struct plugin *new_plugin(const tal_t *ctx, } p->init = init; - p->manifested = p->initialized = false; + p->manifested = p->initialized = p->exiting = false; p->restartability = restartability; strmap_init(&p->usagemap); p->in_timer = 0; diff --git a/plugins/libplugin.h b/plugins/libplugin.h index e480ed50da32..e79b4a0a079f 100644 --- a/plugins/libplugin.h +++ b/plugins/libplugin.h @@ -164,6 +164,9 @@ struct command_result *command_param_failed(void); /* Call this on fatal error. */ void NORETURN plugin_err(struct plugin *p, const char *fmt, ...); +/* Normal exit (makes sure to flush output!). */ +void NORETURN plugin_exit(struct plugin *p, int exitcode); + /* This command is finished, here's a detailed error; @cmd cannot be * NULL, data can be NULL; otherwise it must be a JSON object. */ struct command_result *WARN_UNUSED_RESULT diff --git a/tests/plugins/test_libplugin.c b/tests/plugins/test_libplugin.c index ef62ab96311b..39774e64d374 100644 --- a/tests/plugins/test_libplugin.c +++ b/tests/plugins/test_libplugin.c @@ -6,6 +6,7 @@ const char *name_option; static bool self_disable = false; +static bool dont_shutdown = false; static struct command_result *json_helloworld(struct command *cmd, const char *buf, @@ -56,6 +57,18 @@ static void json_connected(struct command *cmd, json_strdup(tmpctx, buf, idtok)); } +static void json_shutdown(struct command *cmd, + const char *buf, + const jsmntok_t *params) +{ + plugin_log(cmd->plugin, LOG_DBG, "shutdown called"); + + if (dont_shutdown) + return; + + plugin_exit(cmd->plugin, 0); +} + static struct command_result *testrpc_cb(struct command *cmd, const char *buf, const jsmntok_t *params, @@ -137,6 +150,9 @@ static const struct plugin_hook hooks[] = { { static const struct plugin_notification notifs[] = { { "connect", json_connected, + }, { + "shutdown", + json_shutdown } }; @@ -159,5 +175,9 @@ int main(int argc, char *argv[]) "flag", "Whether to disable.", flag_option, &self_disable), + plugin_option("dont_shutdown", + "flag", + "Whether to timeout when asked to shutdown.", + flag_option, &dont_shutdown), NULL); } diff --git a/tests/test_misc.py b/tests/test_misc.py index e6277716e4eb..4ba6060998ea 100644 --- a/tests/test_misc.py +++ b/tests/test_misc.py @@ -134,11 +134,16 @@ def crash_bitcoincli(r): bitcoind.cmd_line += ["-blocksonly"] bitcoind.start() - l2 = node_factory.get_node(start=False, expect_fail=True) + # Ignore BROKEN log message about blocksonly mode. + l2 = node_factory.get_node(start=False, expect_fail=True, + allow_broken_log=True) with pytest.raises(ValueError): l2.start(stderr=subprocess.PIPE) assert l2.daemon.is_in_stderr(r".*deactivating transaction relay is not" " supported.") is not None + # wait_for_log gets upset since daemon is not running. + wait_for(lambda: l2.daemon.is_in_log('deactivating transaction' + ' relay is not supported')) def test_bitcoin_ibd(node_factory, bitcoind): diff --git a/tests/test_plugin.py b/tests/test_plugin.py index e8f830ac48ff..34f99e803bf2 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -2545,3 +2545,25 @@ def init(options, configuration, plugin): n.daemon.wait_for_log(r"Plugin changed, needs restart.") n.daemon.wait_for_log(r"test_restart_on_update 2") n.stop() + + +def test_plugin_shutdown(node_factory): + """test 'shutdown' notification""" + p = os.path.join(os.getcwd(), "tests/plugins/test_libplugin") + l1 = node_factory.get_node(options={'plugin': p}) + + l1.rpc.plugin_stop(p) + l1.daemon.wait_for_log(r"test_libplugin: shutdown called") + # FIXME: clean this up! + l1.daemon.wait_for_log(r"test_libplugin: Killing plugin: exited during normal operation") + + # Now try timeout. + l1.rpc.plugin_start(p, dont_shutdown=True) + l1.rpc.plugin_stop(p) + l1.daemon.wait_for_log(r"test_libplugin: shutdown called") + l1.daemon.wait_for_log(r"test_libplugin: Timeout on shutdown: killing anyway") + + # Now, should also shutdown on finish. + l1.rpc.plugin_start(p) + l1.rpc.stop() + l1.daemon.wait_for_log(r"test_libplugin: shutdown called")