From 7d3a5a0252db1cc84abd7d3de3b922d04ec66dcc Mon Sep 17 00:00:00 2001 From: Simon Vrouwe Date: Tue, 20 Aug 2019 07:13:39 +0300 Subject: [PATCH 1/5] lightningd/plugin: wait for static plugins to initialize at lightningd startup When a static (dynamic=false) plugin initializes, it can now make assumptions about lightningd's state, and safely abort when needed (next commits). Static plugins cannot make RPC calls from init anymore. --- lightningd/plugin.c | 31 +++++++++++++++++++++++++++++++ lightningd/plugin.h | 7 +++++-- 2 files changed, 36 insertions(+), 2 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 8367b604d2ff..ece2846f6fb6 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -31,6 +31,7 @@ * willing to wait. Plugins shouldn't do any initialization in the * `getmanifest` call anyway, that's what `init `is for. */ #define PLUGIN_MANIFEST_TIMEOUT 60 +#define PLUGIN_SYNC_INIT_TIMEOUT 10 struct plugins *plugins_new(const tal_t *ctx, struct log_book *log_book, struct lightningd *ld) @@ -801,6 +802,12 @@ static void plugin_manifest_timeout(struct plugin *plugin) fatal("Can't recover from plugin failure, terminating."); } +static void plugin_sync_init_timeout(struct plugin *plugin) +{ + log_broken(plugin->log, "The non-dynamic plugin failed to respond to \"init\" in time, terminating."); + fatal("Can't recover from plugin failure, terminating."); +} + /** * Callback for the plugin_manifest request. */ @@ -1027,6 +1034,14 @@ static void plugin_config_cb(const char *buffer, struct plugin *plugin) { plugin->plugin_state = CONFIGURED; + /*FIXME: test for startup=True here also ? */ + if (!plugin->dynamic) { + plugin->plugins->pending_sync_configs--; + tal_free(plugin->timeout_timer); + /* When all non-dynamic plugins are initialized, continue start-up */ + if (plugin->plugins->pending_sync_configs == 0) + io_break(plugin->plugins); + } } /* FIXME(cdecker) This just builds a string for the request because @@ -1061,10 +1076,22 @@ static void plugin_config(struct plugin *plugin) jsonrpc_request_end(req); plugin_request_send(plugin, req); + + /* Wait for static plugin's `init` response during startup, so they can do + * their thing or abort at an early stage */ + if (!plugin->dynamic && plugin->plugins->startup) { + plugin->plugins->pending_sync_configs++; + /* FIXME assert plugin->timeout_timer == NULL here ? */ + plugin->timeout_timer = new_reltimer(plugin->plugins->ld->timers, + plugin, time_from_sec(PLUGIN_SYNC_INIT_TIMEOUT), + plugin_sync_init_timeout, plugin); + } } void plugins_config(struct plugins *plugins) { + plugins->pending_sync_configs = 0; + struct plugin *p; list_for_each(&plugins->plugins, p, list) { if (p->plugin_state == UNCONFIGURED) { @@ -1072,6 +1099,10 @@ void plugins_config(struct plugins *plugins) plugin_config(p); } } + + /* At start-up, wait for non-dynamic plugins to initialize */ + if (plugins->pending_sync_configs > 0) + io_loop_with_timers(plugins->ld); } void json_add_opt_plugins(struct json_stream *response, diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 8787b62379f5..c5ab7257159c 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -29,7 +29,8 @@ struct plugin { enum plugin_state plugin_state; - /* If this plugin can be restarted without restarting lightningd */ + /* If this plugin can be restarted without restarting lightningd and don't + * wait for their initialization */ bool dynamic; bool signal_startup; @@ -50,7 +51,8 @@ struct plugin { const char **methods; /* Timer to add a timeout to some plugin RPC calls. Used to - * guarantee that `getmanifest` doesn't block indefinitely. */ + * guarantee that `getmanifest` and some `init` (for non-dynamic plugins) + * doesn't block indefinitely */ const struct oneshot *timeout_timer; /* An array of subscribed topics */ @@ -65,6 +67,7 @@ struct plugin { struct plugins { struct list_head plugins; size_t pending_manifests; + size_t pending_sync_configs; bool startup; /* Currently pending requests by their request ID */ From e9abddf0135d8e11d9cafcef9f66ed6423e01d9a Mon Sep 17 00:00:00 2001 From: Simon Vrouwe Date: Sat, 24 Aug 2019 11:51:58 +0300 Subject: [PATCH 2/5] lightningd\plugin: extend plugins->startup window to include plugins_config Also fixes issue of configuration[`startup`] always being False in plugins `init` --- lightningd/plugin.c | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index ece2846f6fb6..bc9400cfb279 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -1024,8 +1024,6 @@ void plugins_init(struct plugins *plugins, const char *dev_plugin_debug) if (plugins->pending_manifests > 0) io_loop_with_timers(plugins->ld); - // There won't be io_loop anymore to wait for plugins - plugins->startup = false; } static void plugin_config_cb(const char *buffer, @@ -1100,9 +1098,12 @@ void plugins_config(struct plugins *plugins) } } - /* At start-up, wait for non-dynamic plugins to initialize */ + /* Wait here for any static plugins to initialize, which implies startup.*/ if (plugins->pending_sync_configs > 0) io_loop_with_timers(plugins->ld); + + /* Close the startup window (if any) */ + plugins->startup = false; } void json_add_opt_plugins(struct json_stream *response, From 85df1135ca739d1d9ea6db0f7965d1fca6808372 Mon Sep 17 00:00:00 2001 From: Simon Vrouwe Date: Sat, 24 Aug 2019 11:53:46 +0300 Subject: [PATCH 3/5] lightningd/plugin: handle plugin's init result When plugin's `init` response contains an `error` field and: - plugin is static and lightingd is starting up, then lightningd is killed - otherwise the plugin (only) is killed This allows a static plugin to safely abort the lightningd startup or have itself killed when (freshly) started via rpc at run-time. Dynamic plugins, which can be started anytime, can use rpc.stop() to shutdown when needed. --- lightningd/plugin.c | 41 ++++++++++++++++++++++++++++++++++++----- lightningd/plugin.h | 10 ++++++++-- 2 files changed, 44 insertions(+), 7 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index bc9400cfb279..e24bb94e5e91 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -804,7 +804,7 @@ static void plugin_manifest_timeout(struct plugin *plugin) static void plugin_sync_init_timeout(struct plugin *plugin) { - log_broken(plugin->log, "The non-dynamic plugin failed to respond to \"init\" in time, terminating."); + log_broken(plugin->log, "The static plugin failed to respond to \"init\" in time, terminating."); fatal("Can't recover from plugin failure, terminating."); } @@ -1031,15 +1031,46 @@ static void plugin_config_cb(const char *buffer, const jsmntok_t *idtok, struct plugin *plugin) { - plugin->plugin_state = CONFIGURED; - /*FIXME: test for startup=True here also ? */ - if (!plugin->dynamic) { + const jsmntok_t *errortok; + + /* An init-error from a static plugin during lightningd startup will crash + * lightningd. An init-error outside startup will kill the (static or + * dynamic) plugin only. */ + errortok = json_get_member(buffer, toks, "error"); + if (errortok && errortok->type != JSMN_STRING) { + if (!plugin->dynamic && plugin->plugins->startup) + fatal("init-error of static plugin at ld startup '%s':" + " \"error\" result is not an object: %.*s", plugin->cmd, + toks[0].end - toks[0].start, + buffer + toks[0].start); + + /* Any plugin that doesn't want to be started via RPC at run-time, can + * return an init-error, so it is killed cleanly. */ + plugin_kill(plugin, + "\"error\" result is not an object: %.*s", + toks[0].end - toks[0].start, + buffer + toks[0].start); + } + + /* TODO: add error code + message + * TODO: check json `id` */ + if (!plugin->dynamic && plugin->plugins->startup) { + if (errortok) + fatal("init-error of static plugin at ld startup '%s'", plugin->cmd); plugin->plugins->pending_sync_configs--; tal_free(plugin->timeout_timer); - /* When all non-dynamic plugins are initialized, continue start-up */ + + /* When all static plugins are initialized, break the io_loop in + * plugins_config, which also unsets plugins->startup */ if (plugin->plugins->pending_sync_configs == 0) io_break(plugin->plugins); } + + if (errortok) { + plugin_kill(plugin, "error initializing plugin"); + return; + } + plugin->plugin_state = CONFIGURED; } /* FIXME(cdecker) This just builds a string for the request because diff --git a/lightningd/plugin.h b/lightningd/plugin.h index c5ab7257159c..b7075efdce47 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -29,8 +29,14 @@ struct plugin { enum plugin_state plugin_state; - /* If this plugin can be restarted without restarting lightningd and don't - * wait for their initialization */ + /* dynamic=True: plugin can be stopped/started via RPC at runtime and it + * expects lightningd to be up-and-running during init. + * + * dynamic=False: when lightningd starts up, it will wait for the plugin's + * init-result and will shutdown when that is an error. A static plugin + * cannot be stopped but *can* be started via RPC. It should check the + * `startup` field in its init call, which may return an error to kill the + * plugin. Static plugins shouldn't make RPC calls during init. */ bool dynamic; bool signal_startup; From 665e23970ae8616324eeb53668c3bc06d0b09197 Mon Sep 17 00:00:00 2001 From: Simon Vrouwe Date: Sat, 24 Aug 2019 16:12:52 +0300 Subject: [PATCH 4/5] pytest: fix test_plugin_command for new dynamic/static policy Some refactoring n->l1, ipdb (debugger) reserves n for `next` --- tests/plugins/static.py | 6 ++--- tests/plugins/static_2.py | 29 ++++++++++++++++++++++++ tests/test_plugin.py | 47 +++++++++++++++++++++------------------ 3 files changed, 57 insertions(+), 25 deletions(-) create mode 100755 tests/plugins/static_2.py diff --git a/tests/plugins/static.py b/tests/plugins/static.py index ff89eeffc106..153dc663e579 100755 --- a/tests/plugins/static.py +++ b/tests/plugins/static.py @@ -12,14 +12,14 @@ @plugin.init() def init(configuration, options, plugin): - plugin.log("Static plugin initialized.") + plugin.log("init startup={}".format(configuration['startup'])) -@plugin.method('hello') +@plugin.method('world') def reject(plugin): """Mark a given node_id as reject for future connections. """ - return "Hello, you cannot stop me without stopping lightningd" + return "World, you cannot stop me without stopping lightningd" plugin.run() diff --git a/tests/plugins/static_2.py b/tests/plugins/static_2.py new file mode 100755 index 000000000000..c2949d7aae53 --- /dev/null +++ b/tests/plugins/static_2.py @@ -0,0 +1,29 @@ +#!/usr/bin/env python3 +"""Simple plugin to test the dynamic behavior. + +A plugin started with dynamic to False cannot be controlled after lightningd +has been started. +""" + +from lightning import Plugin + +plugin = Plugin(dynamic=False) + + +@plugin.init() +def init(configuration, options, plugin): + plugin.log("init startup={}".format(configuration['startup'])) + + # we don't like to be started at run-time + if not configuration['startup']: + raise Exception + + +@plugin.method('static_2') +def reject(plugin): + """Mark a given node_id as reject for future connections. + """ + return "World, you cannot stop me without stopping lightningd" + + +plugin.run() diff --git a/tests/test_plugin.py b/tests/test_plugin.py index c655d8027ee8..3739ab8a3a2f 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -108,51 +108,54 @@ def test_plugin_slowinit(node_factory): def test_plugin_command(node_factory): """Tests the 'plugin' RPC command""" - n = node_factory.get_node() + opts = {"plugin": os.path.join(os.getcwd(), "tests/plugins/static.py")} + l1 = node_factory.get_node(options=opts) + + # Test that we cannot stop a plugin with 'dynamic' set to False in + # getmanifest + with pytest.raises(RpcError, match=r"plugin cannot be managed when lightningd is up"): + l1.rpc.plugin_stop(plugin="static.py") + + # A static plugin started via RPC that returns an init-error is killed + l1.rpc.plugin_start(plugin=os.path.join(os.getcwd(), "tests/plugins/static_2.py")) + l1.daemon.wait_for_log(r"plugin-static_2.py Killing plugin: error initializing plugin") # Make sure that the 'hello' command from the helloworld.py plugin # is not available. - cmd = [hlp for hlp in n.rpc.help()["help"] if "hello" in hlp["command"]] + cmd = [hlp for hlp in l1.rpc.help()["help"] if "hello" in hlp["command"]] assert(len(cmd) == 0) # Add the 'contrib/plugins' test dir time.sleep(2) - n.rpc.plugin_startdir(directory=os.path.join(os.getcwd(), "contrib/plugins")) - n.daemon.wait_for_log(r"Plugin helloworld.py initialized") + l1.rpc.plugin_startdir(directory=os.path.join(os.getcwd(), "contrib/plugins")) + l1.daemon.wait_for_log(r"Plugin helloworld.py initialized") # Make sure that the 'hello' command from the helloworld.py plugin # is now available. - cmd = [hlp for hlp in n.rpc.help()["help"] if "hello" in hlp["command"]] + cmd = [hlp for hlp in l1.rpc.help()["help"] if "hello" in hlp["command"]] assert(len(cmd) == 1) # Make sure 'rescan' and 'list' controls dont crash - n.rpc.plugin_rescan() - n.rpc.plugin_list() + l1.rpc.plugin_rescan() + l1.rpc.plugin_list() time.sleep(1) # Make sure the plugin behaves normally after stop and restart - n.rpc.plugin_stop(plugin="helloworld.py") - n.daemon.wait_for_log(r"Killing plugin: helloworld.py") + l1.rpc.plugin_stop(plugin="helloworld.py") + l1.daemon.wait_for_log(r"Killing plugin: helloworld.py") time.sleep(1) - n.rpc.plugin_start(plugin=os.path.join(os.getcwd(), "contrib/plugins/helloworld.py")) - n.daemon.wait_for_log(r"Plugin helloworld.py initialized") - assert("Hello world" == n.rpc.call(method="hello")) + l1.rpc.plugin_start(plugin=os.path.join(os.getcwd(), "contrib/plugins/helloworld.py")) + l1.daemon.wait_for_log(r"Plugin helloworld.py initialized") + assert("Hello world" == l1.rpc.call(method="hello")) # Now stop the helloworld plugin - n.rpc.plugin_stop(plugin="helloworld.py") - n.daemon.wait_for_log(r"Killing plugin: helloworld.py") + l1.rpc.plugin_stop(plugin="helloworld.py") + l1.daemon.wait_for_log(r"Killing plugin: helloworld.py") time.sleep(1) # Make sure that the 'hello' command from the helloworld.py plugin # is not available anymore. - cmd = [hlp for hlp in n.rpc.help()["help"] if "hello" in hlp["command"]] + cmd = [hlp for hlp in l1.rpc.help()["help"] if "hello" in hlp["command"]] assert(len(cmd) == 0) - # Test that we cannot stop a plugin with 'dynamic' set to False in - # getmanifest - n.rpc.plugin_start(plugin=os.path.join(os.getcwd(), "tests/plugins/static.py")) - n.daemon.wait_for_log(r"Static plugin initialized.") - with pytest.raises(RpcError, match=r"plugin cannot be managed when lightningd is up"): - n.rpc.plugin_stop(plugin="static.py") - def test_plugin_disable(node_factory): """--disable-plugin works""" From 66db9e83d6a7cdcd0123785dc6692b94f678913b Mon Sep 17 00:00:00 2001 From: Simon Vrouwe Date: Mon, 26 Aug 2019 08:49:49 +0300 Subject: [PATCH 5/5] fixup: the default is dynamic=false --- lightningd/plugin.c | 2 ++ 1 file changed, 2 insertions(+) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index e24bb94e5e91..d6dc17e20e6f 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -837,6 +837,8 @@ static void plugin_manifest_cb(const char *buffer, dynamictok = json_get_member(buffer, resulttok, "dynamic"); if (dynamictok && json_to_bool(buffer, dynamictok, &dynamic_plugin)) plugin->dynamic = dynamic_plugin; + else + plugin->dynamic = false; if (!plugin_opts_add(plugin, buffer, resulttok) || !plugin_rpcmethods_add(plugin, buffer, resulttok) ||