From 020bdd1c83f873cac8a5f21061c3bd356ad4ad94 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 02:49:05 +0930 Subject: [PATCH 01/24] lightningd: fix race where we do rescan before all plugins finish init. The symptom (under heavy load and valgrind) in test_plugin_command: lightningd: common/json_stream.c:237: json_stream_output_: Assertion `!js->reader' failed. This is because we try to call `getmanifest` again on `pay` which has not yet responded to init. The minimal fix for this is to keep proper state, so we can tell the difference between "not yet called getmanifest" and "not yet finished init". Signed-off-by: Rusty Russell --- lightningd/bitcoind.c | 5 +++-- lightningd/plugin.c | 5 +++-- lightningd/plugin.h | 8 +++++++- lightningd/plugin_control.c | 6 +++--- 4 files changed, 16 insertions(+), 8 deletions(-) diff --git a/lightningd/bitcoind.c b/lightningd/bitcoind.c index 89a9e22d936c..2a4b28a1887b 100644 --- a/lightningd/bitcoind.c +++ b/lightningd/bitcoind.c @@ -47,7 +47,7 @@ static void plugin_config_cb(const char *buffer, const jsmntok_t *idtok, struct plugin *plugin) { - plugin->plugin_state = CONFIGURED; + plugin->plugin_state = INIT_COMPLETE; io_break(plugin); } @@ -77,8 +77,9 @@ static void wait_plugin(struct bitcoind *bitcoind, const char *method, * before responding to `init`). * Note that lightningd/plugin will not send `init` to an already * configured plugin. */ - if (p->plugin_state != CONFIGURED) + if (p->plugin_state == NEEDS_INIT) config_plugin(p); + strmap_add(&bitcoind->pluginsmap, method, p); } diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 01e5e4d6709c..ef1b81741a30 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -969,6 +969,7 @@ bool plugin_parse_getmanifest_response(const char *buffer, !plugin_hooks_add(plugin, buffer, resulttok)) return false; + plugin->plugin_state = NEEDS_INIT; return true; } @@ -1167,7 +1168,7 @@ static void plugin_config_cb(const char *buffer, const jsmntok_t *idtok, struct plugin *plugin) { - plugin->plugin_state = CONFIGURED; + plugin->plugin_state = INIT_COMPLETE; } void @@ -1240,7 +1241,7 @@ void plugins_config(struct plugins *plugins) { struct plugin *p; list_for_each(&plugins->plugins, p, list) { - if (p->plugin_state == UNCONFIGURED) + if (p->plugin_state == NEEDS_INIT) plugin_config(p); } diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 1a47232dd2e9..0d26325e916a 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -22,8 +22,14 @@ enum plugin_state { + /* We have to ask getmanifest */ UNCONFIGURED, - CONFIGURED + /* Got `getmanifest` reply, now we need to send `init`. */ + NEEDS_INIT, + /* We have to get `init` response */ + AWAITING_INIT_RESPONSE, + /* We have `init` response. */ + INIT_COMPLETE }; /** diff --git a/lightningd/plugin_control.c b/lightningd/plugin_control.c index 0ed7f951e487..c0fdad82d496 100644 --- a/lightningd/plugin_control.c +++ b/lightningd/plugin_control.c @@ -25,7 +25,7 @@ static struct command_result *plugin_dynamic_list_plugins(struct command *cmd) json_object_start(response, NULL); json_add_string(response, "name", p->cmd); json_add_bool(response, "active", - p->plugin_state == CONFIGURED); + p->plugin_state == INIT_COMPLETE); json_object_end(response); } json_array_end(response); @@ -69,14 +69,14 @@ static void plugin_dynamic_config_callback(const char *buffer, { struct plugin *p; - dp->plugin->plugin_state = CONFIGURED; + dp->plugin->plugin_state = INIT_COMPLETE; /* Reset the timer only now so that we are either configured, or * killed. */ tal_free(dp->plugin->timeout_timer); tal_del_destructor2(dp->plugin, plugin_dynamic_crash, dp); list_for_each(&dp->plugin->plugins->plugins, p, list) { - if (p->plugin_state != CONFIGURED) + if (p->plugin_state != INIT_COMPLETE) return; } From 02e169851684734c3b34fef7e3e804129c514713 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:41:59 +0930 Subject: [PATCH 02/24] plugin_hook_call: return indication whether we called the callback or not. This will allow us to simplify the caller's command handling. Signed-off-by: Rusty Russell --- lightningd/plugin_hook.c | 4 +++- lightningd/plugin_hook.h | 9 ++++++--- lightningd/test/run-invoice-select-inchan.c | 2 +- lightningd/test/run-jsonrpc.c | 2 +- wallet/test/run-wallet.c | 2 +- 5 files changed, 12 insertions(+), 7 deletions(-) diff --git a/lightningd/plugin_hook.c b/lightningd/plugin_hook.c index 97b8fc248d2f..2d32d9f6fe2a 100644 --- a/lightningd/plugin_hook.c +++ b/lightningd/plugin_hook.c @@ -238,7 +238,7 @@ static void plugin_hook_call_next(struct plugin_hook_request *ph_req) plugin_request_send(ph_req->plugin, req); } -void plugin_hook_call_(struct lightningd *ld, const struct plugin_hook *hook, +bool plugin_hook_call_(struct lightningd *ld, const struct plugin_hook *hook, tal_t *cb_arg STEALS) { struct plugin_hook_request *ph_req; @@ -265,6 +265,7 @@ void plugin_hook_call_(struct lightningd *ld, const struct plugin_hook *hook, list_add_tail(&ph_req->call_chain, &link->list); } plugin_hook_call_next(ph_req); + return false; } else { /* If no plugin has registered for this hook, just * call the callback with a NULL result. Saves us the @@ -275,6 +276,7 @@ void plugin_hook_call_(struct lightningd *ld, const struct plugin_hook *hook, hook->final_cb(cb_arg); else hook->single_response_cb(cb_arg, NULL, NULL); + return true; } } diff --git a/lightningd/plugin_hook.h b/lightningd/plugin_hook.h index e2be6277c4e6..272659336f97 100644 --- a/lightningd/plugin_hook.h +++ b/lightningd/plugin_hook.h @@ -83,8 +83,11 @@ AUTODATA_TYPE(hooks, struct plugin_hook); /* Do not call this directly, rather use the `plugin_hook_call_name` * wrappers generated by the `PLUGIN_HOOK_REGISTER` macro. + * + * Returns true if callback called immediately, otherwise false if it's + * still waiting on a plugin response. */ -void plugin_hook_call_(struct lightningd *ld, const struct plugin_hook *hook, +bool plugin_hook_call_(struct lightningd *ld, const struct plugin_hook *hook, tal_t *cb_arg STEALS); /* Generic deserialize_cb: returns true iff 'result': 'continue' */ @@ -97,10 +100,10 @@ bool plugin_hook_continue(void *arg, const char *buffer, const jsmntok_t *toks); */ /* FIXME: Find a way to avoid back-to-back declaration and definition */ #define PLUGIN_HOOK_CALL_DEF(name, cb_arg_type) \ - UNNEEDED static inline void plugin_hook_call_##name( \ + UNNEEDED static inline bool plugin_hook_call_##name( \ struct lightningd *ld, cb_arg_type cb_arg STEALS) \ { \ - plugin_hook_call_(ld, &name##_hook_gen, cb_arg); \ + return plugin_hook_call_(ld, &name##_hook_gen, cb_arg); \ } /* Typechecked registration of a plugin hook. We check that the diff --git a/lightningd/test/run-invoice-select-inchan.c b/lightningd/test/run-invoice-select-inchan.c index 839df1603cf9..49d0d00436d0 100644 --- a/lightningd/test/run-invoice-select-inchan.c +++ b/lightningd/test/run-invoice-select-inchan.c @@ -378,7 +378,7 @@ void per_peer_state_set_fds(struct per_peer_state *pps UNNEEDED, int peer_fd UNNEEDED, int gossip_fd UNNEEDED, int gossip_store_fd UNNEEDED) { fprintf(stderr, "per_peer_state_set_fds called!\n"); abort(); } /* Generated stub for plugin_hook_call_ */ -void plugin_hook_call_(struct lightningd *ld UNNEEDED, const struct plugin_hook *hook UNNEEDED, +bool plugin_hook_call_(struct lightningd *ld UNNEEDED, const struct plugin_hook *hook UNNEEDED, tal_t *cb_arg STEALS UNNEEDED) { fprintf(stderr, "plugin_hook_call_ called!\n"); abort(); } /* Generated stub for subd_release_channel */ diff --git a/lightningd/test/run-jsonrpc.c b/lightningd/test/run-jsonrpc.c index 5bb185784aba..111c2f7bf5ce 100644 --- a/lightningd/test/run-jsonrpc.c +++ b/lightningd/test/run-jsonrpc.c @@ -95,7 +95,7 @@ struct command_result *param_tok(struct command *cmd UNNEEDED, const char *name const jsmntok_t **out UNNEEDED) { fprintf(stderr, "param_tok called!\n"); abort(); } /* Generated stub for plugin_hook_call_ */ -void plugin_hook_call_(struct lightningd *ld UNNEEDED, const struct plugin_hook *hook UNNEEDED, +bool plugin_hook_call_(struct lightningd *ld UNNEEDED, const struct plugin_hook *hook UNNEEDED, tal_t *cb_arg STEALS UNNEEDED) { fprintf(stderr, "plugin_hook_call_ called!\n"); abort(); } /* AUTOGENERATED MOCKS END */ diff --git a/wallet/test/run-wallet.c b/wallet/test/run-wallet.c index a1fbcbf497ba..e101327500cb 100644 --- a/wallet/test/run-wallet.c +++ b/wallet/test/run-wallet.c @@ -546,7 +546,7 @@ void per_peer_state_set_fds(struct per_peer_state *pps UNNEEDED, int peer_fd UNNEEDED, int gossip_fd UNNEEDED, int gossip_store_fd UNNEEDED) { fprintf(stderr, "per_peer_state_set_fds called!\n"); abort(); } /* Generated stub for plugin_hook_call_ */ -void plugin_hook_call_(struct lightningd *ld UNNEEDED, const struct plugin_hook *hook UNNEEDED, +bool plugin_hook_call_(struct lightningd *ld UNNEEDED, const struct plugin_hook *hook UNNEEDED, tal_t *cb_arg STEALS UNNEEDED) { fprintf(stderr, "plugin_hook_call_ called!\n"); abort(); } /* Generated stub for process_onionpacket */ From 7387f22195aebcc627c92329a102b79ca9823a9b Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:42:19 +0930 Subject: [PATCH 03/24] lightningd: avoid plugin timer indirection. Now we know whether the command completed or not, we can correctly call command_still_pending() if it didn't complete. Signed-off-by: Rusty Russell --- lightningd/jsonrpc.c | 18 +++++++++--------- lightningd/test/run-jsonrpc.c | 6 ++++++ 2 files changed, 15 insertions(+), 9 deletions(-) diff --git a/lightningd/jsonrpc.c b/lightningd/jsonrpc.c index d86e3bb051fb..4961b2dc477a 100644 --- a/lightningd/jsonrpc.c +++ b/lightningd/jsonrpc.c @@ -774,11 +774,6 @@ REGISTER_SINGLE_PLUGIN_HOOK(rpc_command, rpc_command_hook_serialize, struct rpc_command_hook_payload *); -static void call_rpc_command_hook(struct rpc_command_hook_payload *p) -{ - plugin_hook_call_rpc_command(p->cmd->ld, p); -} - /* We return struct command_result so command_fail return value has a natural * sink; we don't actually use the result. */ static struct command_result * @@ -787,6 +782,7 @@ parse_request(struct json_connection *jcon, const jsmntok_t tok[]) const jsmntok_t *method, *id, *params; struct command *c; struct rpc_command_hook_payload *rpc_hook; + bool completed; if (tok[0].type != JSMN_OBJECT) { json_command_malformed(jcon, "null", @@ -850,11 +846,15 @@ parse_request(struct json_connection *jcon, const jsmntok_t tok[]) /* Duplicate since we might outlive the connection */ rpc_hook->buffer = tal_dup_talarr(rpc_hook, char, jcon->buffer); rpc_hook->request = tal_dup_talarr(rpc_hook, jsmntok_t, tok); - /* Prevent a race between was_pending and still_pending */ - new_reltimer(c->ld->timers, rpc_hook, time_from_msec(1), - call_rpc_command_hook, rpc_hook); - return command_still_pending(c); + db_begin_transaction(jcon->ld->wallet->db); + completed = plugin_hook_call_rpc_command(jcon->ld, rpc_hook); + db_commit_transaction(jcon->ld->wallet->db); + + /* If it's deferred, mark it (otherwise, it's completed) */ + if (!completed) + return command_still_pending(c); + return NULL; } /* Mutual recursion */ diff --git a/lightningd/test/run-jsonrpc.c b/lightningd/test/run-jsonrpc.c index 111c2f7bf5ce..8f296aeb8064 100644 --- a/lightningd/test/run-jsonrpc.c +++ b/lightningd/test/run-jsonrpc.c @@ -9,6 +9,12 @@ size_t bigsize_get(const u8 *p UNNEEDED, size_t max UNNEEDED, bigsize_t *val UNN /* Generated stub for bigsize_put */ size_t bigsize_put(u8 buf[BIGSIZE_MAX_LEN] UNNEEDED, bigsize_t v UNNEEDED) { fprintf(stderr, "bigsize_put called!\n"); abort(); } +/* Generated stub for db_begin_transaction_ */ +void db_begin_transaction_(struct db *db UNNEEDED, const char *location UNNEEDED) +{ fprintf(stderr, "db_begin_transaction_ called!\n"); abort(); } +/* Generated stub for db_commit_transaction */ +void db_commit_transaction(struct db *db UNNEEDED) +{ fprintf(stderr, "db_commit_transaction called!\n"); abort(); } /* Generated stub for fatal */ void fatal(const char *fmt UNNEEDED, ...) { fprintf(stderr, "fatal called!\n"); abort(); } From 6cbb44c27c4504d753334b78a35189790864109d Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:42:24 +0930 Subject: [PATCH 04/24] lightningd: remove obsolete FIXME comment. We have this now. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 3 --- 1 file changed, 3 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index ef1b81741a30..9561e2bb07b7 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -1222,9 +1222,6 @@ plugin_populate_init_request(struct plugin *plugin, struct jsonrpc_request *req) json_object_end(req->stream); } -/* FIXME(cdecker) This just builds a string for the request because - * the json_stream is tightly bound to the command interface. It - * should probably be generalized and fixed up. */ static void plugin_config(struct plugin *plugin) { From c183b06bd4cb5a6bed8da378a622373a82b6d36b Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:42:29 +0930 Subject: [PATCH 05/24] lightningd: complete plugin state machine. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 2 ++ lightningd/plugin.h | 2 ++ lightningd/plugin_control.c | 3 +++ 3 files changed, 7 insertions(+) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 9561e2bb07b7..789a0632e15a 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -1145,6 +1145,7 @@ void plugins_init(struct plugins *plugins, const char *dev_plugin_debug) plugin_manifest_cb, p); jsonrpc_request_end(req); plugin_request_send(p, req); + p->plugin_state = AWAITING_GETMANIFEST_RESPONSE; plugins->pending_manifests++; /* Don't timeout if they're running a debugger. */ @@ -1232,6 +1233,7 @@ plugin_config(struct plugin *plugin) plugin_populate_init_request(plugin, req); jsonrpc_request_end(req); plugin_request_send(plugin, req); + plugin->plugin_state = AWAITING_INIT_RESPONSE; } void plugins_config(struct plugins *plugins) diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 0d26325e916a..4120f91ee5e7 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -24,6 +24,8 @@ enum plugin_state { /* We have to ask getmanifest */ UNCONFIGURED, + /* We sent getmanifest, need response. */ + AWAITING_GETMANIFEST_RESPONSE, /* Got `getmanifest` reply, now we need to send `init`. */ NEEDS_INIT, /* We have to get `init` response */ diff --git a/lightningd/plugin_control.c b/lightningd/plugin_control.c index c0fdad82d496..d2ab2b3ca28f 100644 --- a/lightningd/plugin_control.c +++ b/lightningd/plugin_control.c @@ -97,6 +97,7 @@ static void plugin_dynamic_config(struct dynamic_plugin *dp) plugin_dynamic_config_callback, dp); plugin_populate_init_request(dp->plugin, req); jsonrpc_request_end(req); + dp->plugin->plugin_state = AWAITING_INIT_RESPONSE; plugin_request_send(dp->plugin, req); } @@ -112,6 +113,7 @@ static void plugin_dynamic_manifest_callback(const char *buffer, return was_pending(plugin_dynamic_error(dp, "Not a dynamic plugin")); /* We got the manifest, now send the init message */ + dp->plugin->plugin_state = NEEDS_INIT; plugin_dynamic_config(dp); } @@ -167,6 +169,7 @@ static struct command_result *plugin_start(struct dynamic_plugin *dp) plugin_dynamic_manifest_callback, dp); jsonrpc_request_end(req); plugin_request_send(p, req); + p->plugin_state = AWAITING_GETMANIFEST_RESPONSE; return command_still_pending(dp->cmd); } From b9b86ed39ba9436d735caada0c36969ae28aff8d Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:42:46 +0930 Subject: [PATCH 06/24] lightningd: plugins_any_in_state and plugins_all_in_state helpers. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 22 ++++++++++++++++++++++ lightningd/plugin.h | 10 ++++++++++ 2 files changed, 32 insertions(+) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 789a0632e15a..d3c9aaf13237 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -973,6 +973,28 @@ bool plugin_parse_getmanifest_response(const char *buffer, return true; } +bool plugins_any_in_state(const struct plugins *plugins, enum plugin_state state) +{ + const struct plugin *p; + + list_for_each(&plugins->plugins, p, list) { + if (p->plugin_state == state) + return true; + } + return false; +} + +bool plugins_all_in_state(const struct plugins *plugins, enum plugin_state state) +{ + const struct plugin *p; + + list_for_each(&plugins->plugins, p, list) { + if (p->plugin_state != state) + return false; + } + return true; +} + /** * Callback for the plugin_manifest request. */ diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 4120f91ee5e7..7bd687a5f804 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -208,6 +208,16 @@ struct plugin *find_plugin_for_command(struct lightningd *ld, */ void plugins_config(struct plugins *plugins); +/** + * Are any plugins at this state still? + */ +bool plugins_any_in_state(const struct plugins *plugins, enum plugin_state state); + +/** + * Are all plugins at this state? + */ +bool plugins_all_in_state(const struct plugins *plugins, enum plugin_state state); + /** * Read and treat (populate options, methods, ...) the `getmanifest` response. */ From 4631ed53a9593872f0707154dc9652619eb0cde9 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:42:59 +0930 Subject: [PATCH 07/24] lightningd: remove counter for pending_manifests in favor of checking for state. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 15 ++++++--------- lightningd/plugin.h | 1 - 2 files changed, 6 insertions(+), 10 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index d3c9aaf13237..2002ae1387e1 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -1003,17 +1003,16 @@ static void plugin_manifest_cb(const char *buffer, const jsmntok_t *idtok, struct plugin *plugin) { - /* Check if all plugins have replied to getmanifest, and break - * if they have */ - plugin->plugins->pending_manifests--; - if (plugin->plugins->pending_manifests == 0) - io_break(plugin->plugins); - if (!plugin_parse_getmanifest_response(buffer, toks, idtok, plugin)) plugin_kill(plugin, "%s: Bad response to getmanifest.", plugin->cmd); /* Reset timer, it'd kill us otherwise. */ tal_free(plugin->timeout_timer); + + /* Check if all plugins have replied to getmanifest, and break + * if they have */ + if (!plugins_any_in_state(plugin->plugins, AWAITING_GETMANIFEST_RESPONSE)) + io_break(plugin->plugins); } /* If this is a valid plugin return full path name, otherwise NULL */ @@ -1134,7 +1133,6 @@ void plugins_init(struct plugins *plugins, const char *dev_plugin_debug) int stdin, stdout; struct jsonrpc_request *req; - plugins->pending_manifests = 0; plugins->default_dir = path_join(plugins, plugins->ld->config_basedir, "plugins"); plugins_add_default_dir(plugins); @@ -1169,7 +1167,6 @@ void plugins_init(struct plugins *plugins, const char *dev_plugin_debug) plugin_request_send(p, req); p->plugin_state = AWAITING_GETMANIFEST_RESPONSE; - plugins->pending_manifests++; /* Don't timeout if they're running a debugger. */ if (debug) p->timeout_timer = NULL; @@ -1182,7 +1179,7 @@ void plugins_init(struct plugins *plugins, const char *dev_plugin_debug) tal_free(cmd); } - if (plugins->pending_manifests > 0) + if (plugins_any_in_state(plugins, AWAITING_GETMANIFEST_RESPONSE)) io_loop_with_timers(plugins->ld); } diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 7bd687a5f804..175c32869ed9 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -87,7 +87,6 @@ struct plugin { */ struct plugins { struct list_head plugins; - size_t pending_manifests; bool startup; /* Currently pending requests by their request ID */ From 140e0b82b90b4a458460f4a2ce1bc33a9dbdb095 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:43:14 +0930 Subject: [PATCH 08/24] lightningd: attach plugins natively to the command which started it. This will let us unify the startup and runtime-started infrastructure. Note that there are two kinds of notifications: 1. Starting a single plugin (i.e. `plugin start`) 2. Starting multiple plugins (i.e. `plugin rescan` or `plugin startdir`). In the latter case, we want the command to complete only once *all* the plugins are dead/finished. We also call plugin_kill() in all cases, and correctly return afterwards (it matters once we use the same paths for dynamic plugins, which don't cause a fatal error if they don't startup). Signed-off-by: Rusty Russell --- lightningd/options.c | 2 +- lightningd/plugin.c | 92 ++++++++++++++++++++++++++++++++----- lightningd/plugin.h | 22 ++++++++- lightningd/plugin_control.c | 35 ++++++++++---- lightningd/plugin_control.h | 11 +++++ 5 files changed, 140 insertions(+), 22 deletions(-) diff --git a/lightningd/options.c b/lightningd/options.c index 1cc9bd9d72b6..ca08154f6306 100644 --- a/lightningd/options.c +++ b/lightningd/options.c @@ -343,7 +343,7 @@ static char *opt_add_proxy_addr(const char *arg, struct lightningd *ld) static char *opt_add_plugin(const char *arg, struct lightningd *ld) { - plugin_register(ld->plugins, arg); + plugin_register(ld->plugins, arg, NULL); return NULL; } diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 2002ae1387e1..a833c401bf5f 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -10,6 +10,7 @@ #include #include #include +#include #include #include #include @@ -50,6 +51,7 @@ struct plugins *plugins_new(const tal_t *ctx, struct log_book *log_book, p->log = new_log(p, log_book, NULL, "plugin-manager"); p->ld = ld; p->startup = true; + p->json_cmds = tal_arr(p, struct command *, 0); uintmap_init(&p->pending_requests); memleak_add_helper(p, memleak_help_pending_requests); @@ -69,6 +71,36 @@ void plugins_free(struct plugins *plugins) tal_free(plugins); } +static void check_plugins_resolved(struct plugins *plugins) +{ + /* As startup, we break out once all getmanifest are returned */ + if (plugins->startup) { + if (!plugins_any_in_state(plugins, AWAITING_GETMANIFEST_RESPONSE)) + io_break(plugins); + /* Otherwise we wait until all finished. */ + } else if (plugins_all_in_state(plugins, INIT_COMPLETE)) { + struct command **json_cmds; + + /* Clear commands first, in case callbacks add new ones. + * Paranoia, but wouldn't that be a nasty bug to find? */ + json_cmds = plugins->json_cmds; + plugins->json_cmds = tal_arr(plugins, struct command *, 0); + for (size_t i = 0; i < tal_count(json_cmds); i++) + plugin_cmd_all_complete(plugins, json_cmds[i]); + tal_free(json_cmds); + } +} + +struct command_result *plugin_register_all_complete(struct lightningd *ld, + struct command *cmd) +{ + if (plugins_all_in_state(ld->plugins, INIT_COMPLETE)) + return plugin_cmd_all_complete(ld->plugins, cmd); + + tal_arr_expand(&ld->plugins->json_cmds, cmd); + return NULL; +} + static void destroy_plugin(struct plugin *p) { struct plugin_rpccall *call; @@ -83,7 +115,8 @@ static void destroy_plugin(struct plugin *p) } } -struct plugin *plugin_register(struct plugins *plugins, const char* path TAKES) +struct plugin *plugin_register(struct plugins *plugins, const char* path TAKES, + struct command *start_cmd) { struct plugin *p, *p_temp; @@ -99,6 +132,7 @@ struct plugin *plugin_register(struct plugins *plugins, const char* path TAKES) p = tal(plugins, struct plugin); p->plugins = plugins; p->cmd = tal_strdup(p, path); + p->start_cmd = start_cmd; p->plugin_state = UNCONFIGURED; p->js_arr = tal_arr(p, struct json_stream *, 0); @@ -166,6 +200,11 @@ void plugin_kill(struct plugin *plugin, char *fmt, ...) io_wake(plugin); kill(plugin->pid, SIGKILL); list_del(&plugin->list); + + if (plugin->start_cmd) + plugin_cmd_killed(plugin->start_cmd, plugin, msg); + + check_plugins_resolved(plugin->plugins); } /** @@ -456,7 +495,12 @@ static struct io_plan *plugin_write_json(struct io_conn *conn, static void plugin_conn_finish(struct io_conn *conn, struct plugin *plugin) { plugin->stdout_conn = NULL; + if (plugin->start_cmd) { + plugin_cmd_succeeded(plugin->start_cmd, plugin); + plugin->start_cmd = NULL; + } tal_free(plugin); + check_plugins_resolved(plugin->plugins); } struct io_plan *plugin_stdin_conn_init(struct io_conn *conn, @@ -892,8 +936,12 @@ static bool plugin_hooks_add(struct plugin *plugin, const char *buffer, static void plugin_manifest_timeout(struct plugin *plugin) { - log_broken(plugin->log, "The plugin failed to respond to \"getmanifest\" in time, terminating."); - fatal("Can't recover from plugin failure, terminating."); + plugin_kill(plugin, + "failed to respond to \"%s\" in time, terminating.", + plugin->plugin_state == AWAITING_GETMANIFEST_RESPONSE + ? "getmanifest" : "init"); + if (plugin->plugins->startup) + fatal("Can't recover from plugin failure, terminating."); } bool plugin_parse_getmanifest_response(const char *buffer, @@ -908,10 +956,12 @@ bool plugin_parse_getmanifest_response(const char *buffer, return false; dynamictok = json_get_member(buffer, resulttok, "dynamic"); - if (dynamictok && !json_to_bool(buffer, dynamictok, &plugin->dynamic)) + if (dynamictok && !json_to_bool(buffer, dynamictok, &plugin->dynamic)) { plugin_kill(plugin, "Bad 'dynamic' field ('%.*s')", json_tok_full_len(dynamictok), json_tok_full(buffer, dynamictok)); + return false; + } featurestok = json_get_member(buffer, resulttok, "featurebits"); @@ -995,6 +1045,9 @@ bool plugins_all_in_state(const struct plugins *plugins, enum plugin_state state return true; } +/* FIXME: Forward declaration to reduce patch noise */ +static void plugin_config(struct plugin *plugin); + /** * Callback for the plugin_manifest request. */ @@ -1003,16 +1056,25 @@ static void plugin_manifest_cb(const char *buffer, const jsmntok_t *idtok, struct plugin *plugin) { - if (!plugin_parse_getmanifest_response(buffer, toks, idtok, plugin)) + if (!plugin_parse_getmanifest_response(buffer, toks, idtok, plugin)) { plugin_kill(plugin, "%s: Bad response to getmanifest.", plugin->cmd); + return; + } - /* Reset timer, it'd kill us otherwise. */ - tal_free(plugin->timeout_timer); + /* At startup, we want to io_break once all getmanifests are done */ + check_plugins_resolved(plugin->plugins); - /* Check if all plugins have replied to getmanifest, and break - * if they have */ - if (!plugins_any_in_state(plugin->plugins, AWAITING_GETMANIFEST_RESPONSE)) - io_break(plugin->plugins); + if (plugin->plugins->startup) { + /* Reset timer, it'd kill us otherwise. */ + plugin->timeout_timer = tal_free(plugin->timeout_timer); + } else { + /* Note: here 60 second timer continues through init */ + /* After startup, automatically call init after getmanifest */ + if (!plugin->dynamic) + plugin_kill(plugin, "Not a dynamic plugin"); + else + plugin_config(plugin); + } } /* If this is a valid plugin return full path name, otherwise NULL */ @@ -1089,7 +1151,7 @@ char *add_plugin_dir(struct plugins *plugins, const char *dir, bool error_ok) continue; fullpath = plugin_fullpath(tmpctx, dir, di->d_name); if (fullpath) { - p = plugin_register(plugins, fullpath); + p = plugin_register(plugins, fullpath, NULL); if (!p && !error_ok) return tal_fmt(NULL, "Failed to register %s: %s", fullpath, strerror(errno)); @@ -1189,6 +1251,12 @@ static void plugin_config_cb(const char *buffer, struct plugin *plugin) { plugin->plugin_state = INIT_COMPLETE; + plugin->timeout_timer = tal_free(plugin->timeout_timer); + if (plugin->start_cmd) { + plugin_cmd_succeeded(plugin->start_cmd, plugin); + plugin->start_cmd = NULL; + } + check_plugins_resolved(plugin->plugins); } void diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 175c32869ed9..753ec2b0fecc 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -46,6 +46,8 @@ struct plugin { bool stop; struct plugins *plugins; const char **plugin_path; + /* If there's a json command which ordered this to start */ + struct command *start_cmd; enum plugin_state plugin_state; @@ -96,6 +98,9 @@ struct plugins { struct lightningd *ld; const char *default_dir; + + /* If there are json commands waiting for plugin resolutions. */ + struct command **json_cmds; }; /* The value of a plugin option, which can have different types. @@ -169,8 +174,14 @@ void plugins_free(struct plugins *plugins); * * @param plugins: Plugin context * @param path: The path of the executable for this plugin + * @param start_cmd: The optional JSON command which caused this. + * + * If @start_cmd, then plugin_cmd_killed or plugin_cmd_succeeded will be called + * on it eventually. */ -struct plugin *plugin_register(struct plugins *plugins, const char* path TAKES); +struct plugin *plugin_register(struct plugins *plugins, + const char* path TAKES, + struct command *start_cmd); /** * Returns true if the provided name matches a plugin command @@ -197,6 +208,15 @@ struct plugin *find_plugin_for_command(struct lightningd *ld, const char *cmd_name); +/** + * Call plugin_cmd_all_complete once all plugins are init or killed. + * + * Returns NULL if it's still pending. otherwise, returns + * plugin_cmd_all_complete(). + */ +struct command_result *plugin_register_all_complete(struct lightningd *ld, + struct command *cmd); + /** * Send the configure message to all plugins. * diff --git a/lightningd/plugin_control.c b/lightningd/plugin_control.c index d2ab2b3ca28f..d0ce18cd01d7 100644 --- a/lightningd/plugin_control.c +++ b/lightningd/plugin_control.c @@ -14,14 +14,15 @@ struct dynamic_plugin { /** * Returned by all subcommands on success. */ -static struct command_result *plugin_dynamic_list_plugins(struct command *cmd) +static struct command_result *plugin_dynamic_list_plugins(struct command *cmd, + const struct plugins *plugins) { struct json_stream *response; - struct plugin *p; + const struct plugin *p; response = json_stream_success(cmd); json_array_start(response, "plugins"); - list_for_each(&cmd->ld->plugins->plugins, p, list) { + list_for_each(&plugins->plugins, p, list) { json_object_start(response, NULL); json_add_string(response, "name", p->cmd); json_add_bool(response, "active", @@ -52,6 +53,24 @@ plugin_dynamic_error(struct dynamic_plugin *dp, const char *error) error); } +struct command_result *plugin_cmd_killed(struct command *cmd, + struct plugin *plugin, const char *msg) +{ + return command_fail(cmd, PLUGIN_ERROR, "%s: %s", plugin->cmd, msg); +} + +struct command_result *plugin_cmd_succeeded(struct command *cmd, + struct plugin *plugin) +{ + return plugin_dynamic_list_plugins(cmd, plugin->plugins); +} + +struct command_result *plugin_cmd_all_complete(struct plugins *plugins, + struct command *cmd) +{ + return plugin_dynamic_list_plugins(cmd, plugins); +} + static void plugin_dynamic_timeout(struct dynamic_plugin *dp) { plugin_dynamic_error(dp, "Timed out while waiting for plugin response"); @@ -81,7 +100,7 @@ static void plugin_dynamic_config_callback(const char *buffer, } /* No plugin unconfigured left, return the plugin list */ - was_pending(plugin_dynamic_list_plugins(dp->cmd)); + was_pending(plugin_dynamic_list_plugins(dp->cmd, dp->plugin->plugins)); } /** @@ -184,7 +203,7 @@ plugin_dynamic_start(struct command *cmd, const char *plugin_path) dp = tal(cmd, struct dynamic_plugin); dp->cmd = cmd; - dp->plugin = plugin_register(cmd->ld->plugins, plugin_path); + dp->plugin = plugin_register(cmd->ld->plugins, plugin_path, NULL); if (!dp->plugin) return plugin_dynamic_error(dp, "Is already registered"); @@ -218,7 +237,7 @@ plugin_dynamic_startdir(struct command *cmd, const char *dir_path) } } if (!found) - plugin_dynamic_list_plugins(cmd); + plugin_dynamic_list_plugins(cmd, cmd->ld->plugins); return command_still_pending(cmd); } @@ -289,7 +308,7 @@ plugin_dynamic_rescan_plugins(struct command *cmd) } if (!found) - return plugin_dynamic_list_plugins(cmd); + return plugin_dynamic_list_plugins(cmd, cmd->ld->plugins); return command_still_pending(cmd); } @@ -361,7 +380,7 @@ static struct command_result *json_plugin_control(struct command *cmd, NULL)) return command_param_failed(); - return plugin_dynamic_list_plugins(cmd); + return plugin_dynamic_list_plugins(cmd, cmd->ld->plugins); } /* subcmd must be one of the above: param_subcommand checked it! */ diff --git a/lightningd/plugin_control.h b/lightningd/plugin_control.h index f63bdd552123..8d1e6ffbf9a8 100644 --- a/lightningd/plugin_control.h +++ b/lightningd/plugin_control.h @@ -3,5 +3,16 @@ #include "config.h" #include +/* Plugin startup failed */ +struct command_result *plugin_cmd_killed(struct command *cmd, + struct plugin *plugin, const char *msg); + +/* Plugin startup succeeded */ +struct command_result *plugin_cmd_succeeded(struct command *cmd, + struct plugin *plugin); + +/* All plugins succeeded/failed */ +struct command_result *plugin_cmd_all_complete(struct plugins *plugins, + struct command *cmd); #endif /* LIGHTNING_LIGHTNINGD_PLUGIN_CONTROL_H */ From 981c1529f9dccf1260eef577f450f800090501a3 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:43:28 +0930 Subject: [PATCH 09/24] pytest: add test for a plugin which falls over outside a command. This actually passes fine, but it's an interesting case to test. Fixed-by: Darosior Signed-off-by: Rusty Russell --- tests/plugins/fail_by_itself.py | 31 +++++++++++++++++++++++++++++++ tests/test_plugin.py | 15 +++++++++++++++ 2 files changed, 46 insertions(+) create mode 100755 tests/plugins/fail_by_itself.py diff --git a/tests/plugins/fail_by_itself.py b/tests/plugins/fail_by_itself.py new file mode 100755 index 000000000000..5023ee7256a5 --- /dev/null +++ b/tests/plugins/fail_by_itself.py @@ -0,0 +1,31 @@ +#!/usr/bin/env python3 +from pyln.client import Plugin +import os +import threading +import time + +plugin = Plugin() + + +class FailThread(threading.Thread): + def __init__(self): + super().__init__() + self.start() + + def run(self): + time.sleep(1) + print("Exiting!") + os._exit(1) + + +@plugin.init() +def init(options, configuration, plugin): + FailThread() + + +@plugin.method('failcmd') +def failcmd(plugin): + pass + + +plugin.run() diff --git a/tests/test_plugin.py b/tests/test_plugin.py index acb6b5f1482d..16e45f94ce0d 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -1218,3 +1218,18 @@ def test_replacement_payload(node_factory): l1.rpc.pay(inv) assert l2.daemon.wait_for_log("Attept to pay.*with wrong secret") + + +def test_plugin_fail(node_factory): + """Test that a plugin which fails (not during a command)""" + plugin = os.path.join(os.path.dirname(__file__), 'plugins/fail_by_itself.py') + l1 = node_factory.get_node(options={"plugin": plugin}) + + time.sleep(2) + # It should clean up! + assert 'failcmd' not in [h['command'] for h in l1.rpc.help()['help']] + + l1.rpc.plugin_start(plugin) + time.sleep(2) + # It should clean up! + assert 'failcmd' not in [h['command'] for h in l1.rpc.help()['help']] From ded2eaa1f1eb67469a9d00cfdfd585f5a9151301 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:43:34 +0930 Subject: [PATCH 10/24] lightningd: refactor to extract getmanifest paths. This will allow the dynamic starting code to use them too. Also lets us move dev_debug_subprocess under #if DEVELOPER. Signed-off-by: Rusty Russell --- lightningd/lightningd.c | 4 +- lightningd/lightningd.h | 6 +- lightningd/plugin.c | 109 ++++++++++++++++---------- lightningd/plugin.h | 16 +++- lightningd/test/run-find_my_abspath.c | 2 +- 5 files changed, 86 insertions(+), 51 deletions(-) diff --git a/lightningd/lightningd.c b/lightningd/lightningd.c index 2b0ded7e7ae3..2013501bedcc 100644 --- a/lightningd/lightningd.c +++ b/lightningd/lightningd.c @@ -123,8 +123,8 @@ static struct lightningd *new_lightningd(const tal_t *ctx) * is a nod to keeping it minimal and explicit: we need this code for * testing, but its existence means we're not actually testing the * same exact code users will be running. */ - ld->dev_debug_subprocess = NULL; #if DEVELOPER + ld->dev_debug_subprocess = NULL; ld->dev_disconnect_fd = -1; ld->dev_subdaemon_fail = false; ld->dev_allow_localhost = false; @@ -808,7 +808,7 @@ int main(int argc, char *argv[]) /*~ Initialize all the plugins we just registered, so they can * do their thing and tell us about themselves (including * options registration). */ - plugins_init(ld->plugins, ld->dev_debug_subprocess); + plugins_init(ld->plugins); /*~ Handle options and config. */ handle_opts(ld, argc, argv); diff --git a/lightningd/lightningd.h b/lightningd/lightningd.h index 2a9f9ad1e287..d33b49d1aa81 100644 --- a/lightningd/lightningd.h +++ b/lightningd/lightningd.h @@ -200,15 +200,15 @@ struct lightningd { * if we are the fundee. */ u32 max_funding_unconfirmed; - /* If we want to debug a subdaemon/plugin. */ - const char *dev_debug_subprocess; - /* RPC which asked us to shutdown, if non-NULL */ struct io_conn *stop_conn; /* RPC response to send once we've shut down. */ const char *stop_response; #if DEVELOPER + /* If we want to debug a subdaemon/plugin. */ + const char *dev_debug_subprocess; + /* If we have a --dev-disconnect file */ int dev_disconnect_fd; diff --git a/lightningd/plugin.c b/lightningd/plugin.c index a833c401bf5f..23ba4d056a7d 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -1188,60 +1188,85 @@ void plugins_add_default_dir(struct plugins *plugins) } } -void plugins_init(struct plugins *plugins, const char *dev_plugin_debug) +bool plugin_send_getmanifest(struct plugin *p) { - struct plugin *p; char **cmd; int stdin, stdout; struct jsonrpc_request *req; + bool debug = false; - plugins->default_dir = path_join(plugins, plugins->ld->config_basedir, "plugins"); - plugins_add_default_dir(plugins); +#if DEVELOPER + if (p->plugins->ld->dev_debug_subprocess + && strends(p->cmd, p->plugins->ld->dev_debug_subprocess)) + debug = true; +#endif + cmd = tal_arrz(tmpctx, char *, 2 + debug); + cmd[0] = p->cmd; + if (debug) + cmd[1] = "--debugger"; + p->pid = pipecmdarr(&stdin, &stdout, &pipecmd_preserve, cmd); + if (p->pid == -1) + return false; - setenv("LIGHTNINGD_PLUGIN", "1", 1); - setenv("LIGHTNINGD_VERSION", version(), 1); - /* Spawn the plugin processes before entering the io_loop */ - list_for_each(&plugins->plugins, p, list) { - bool debug; + log_debug(p->plugins->log, "started(%u) %s", p->pid, p->cmd); + p->buffer = tal_arr(p, char, 64); + p->stop = false; - debug = dev_plugin_debug && strends(p->cmd, dev_plugin_debug); - cmd = tal_arrz(p, char *, 2 + debug); - cmd[0] = p->cmd; - if (debug) - cmd[1] = "--debugger"; - p->pid = pipecmdarr(&stdin, &stdout, &pipecmd_preserve, cmd); + /* Create two connections, one read-only on top of p->stdout, and one + * write-only on p->stdin */ + io_new_conn(p, stdout, plugin_stdout_conn_init, p); + io_new_conn(p, stdin, plugin_stdin_conn_init, p); + req = jsonrpc_request_start(p, "getmanifest", p->log, + plugin_manifest_cb, p); + jsonrpc_request_end(req); + plugin_request_send(p, req); + p->plugin_state = AWAITING_GETMANIFEST_RESPONSE; + + /* Don't timeout if they're running a debugger. */ + if (debug) + p->timeout_timer = NULL; + else { + p->timeout_timer + = new_reltimer(p->plugins->ld->timers, p, + time_from_sec(PLUGIN_MANIFEST_TIMEOUT), + plugin_manifest_timeout, p); + } + + return true; +} + +bool plugins_send_getmanifest(struct plugins *plugins) +{ + struct plugin *p, *next; + bool sent = false; - if (p->pid == -1) + /* Spawn the plugin processes before entering the io_loop */ + list_for_each_safe(&plugins->plugins, p, next, list) { + if (p->plugin_state != UNCONFIGURED) + continue; + if (plugin_send_getmanifest(p)) { + sent = true; + continue; + } + if (plugins->startup) fatal("error starting plugin '%s': %s", p->cmd, strerror(errno)); - else - log_debug(plugins->log, "started(%u) %s", p->pid, p->cmd); - p->buffer = tal_arr(p, char, 64); - p->stop = false; - - /* Create two connections, one read-only on top of p->stdout, and one - * write-only on p->stdin */ - io_new_conn(p, stdout, plugin_stdout_conn_init, p); - io_new_conn(p, stdin, plugin_stdin_conn_init, p); - req = jsonrpc_request_start(p, "getmanifest", p->log, - plugin_manifest_cb, p); - jsonrpc_request_end(req); - plugin_request_send(p, req); - p->plugin_state = AWAITING_GETMANIFEST_RESPONSE; - - /* Don't timeout if they're running a debugger. */ - if (debug) - p->timeout_timer = NULL; - else { - p->timeout_timer - = new_reltimer(plugins->ld->timers, p, - time_from_sec(PLUGIN_MANIFEST_TIMEOUT), - plugin_manifest_timeout, p); - } - tal_free(cmd); + plugin_kill(p, "error starting: %s", strerror(errno)); + tal_free(p); } - if (plugins_any_in_state(plugins, AWAITING_GETMANIFEST_RESPONSE)) + return sent; +} + +void plugins_init(struct plugins *plugins) +{ + plugins->default_dir = path_join(plugins, plugins->ld->config_basedir, "plugins"); + plugins_add_default_dir(plugins); + + setenv("LIGHTNINGD_PLUGIN", "1", 1); + setenv("LIGHTNINGD_VERSION", version(), 1); + + if (plugins_send_getmanifest(plugins)) io_loop_with_timers(plugins->ld); } diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 753ec2b0fecc..f9dad419f931 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -144,10 +144,8 @@ void plugins_add_default_dir(struct plugins *plugins); * arguments. In order to read the getmanifest reply from the plugins * we spin up our own io_loop that exits once all plugins have * responded. - * - * The dev_plugin_debug arg comes from --dev-debugger if DEVELOPER. */ -void plugins_init(struct plugins *plugins, const char *dev_plugin_debug); +void plugins_init(struct plugins *plugins); /** * Free all resources that are held by plugins in the correct order. @@ -196,6 +194,18 @@ bool plugin_paths_match(const char *cmd, const char *name); */ bool plugin_remove(struct plugins *plugins, const char *name); +/** + * Kick of initialization of a plugin. + */ +bool plugin_send_getmanifest(struct plugin *p); + +/** + * Kick of initialization of all plugins which need it/ + * + * Return true if any were started. + */ +bool plugins_send_getmanifest(struct plugins *plugins); + /** * Kill a plugin process, with an error message. */ diff --git a/lightningd/test/run-find_my_abspath.c b/lightningd/test/run-find_my_abspath.c index 78382bb5443b..f476cc0eadcc 100644 --- a/lightningd/test/run-find_my_abspath.c +++ b/lightningd/test/run-find_my_abspath.c @@ -194,7 +194,7 @@ void plugins_config(struct plugins *plugins UNNEEDED) 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, const char *dev_plugin_debug UNNEEDED) +void plugins_init(struct plugins *plugins UNNEEDED) { fprintf(stderr, "plugins_init called!\n"); abort(); } /* Generated stub for plugins_new */ struct plugins *plugins_new(const tal_t *ctx UNNEEDED, struct log_book *log_book UNNEEDED, From d51514c4f850a960ff465fcf1e5683e75d2e195b Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:43:50 +0930 Subject: [PATCH 11/24] pytest: test loading all plugins at once, including failing ones. We modify the slow_init() so it doesn't go too slowly for this test. This demonstrates a crash, where we currently try to fail a command multiple times. Signed-off-by: Rusty Russell --- tests/plugins/slow_init.py | 3 ++- tests/test_plugin.py | 11 +++++++++++ 2 files changed, 13 insertions(+), 1 deletion(-) diff --git a/tests/plugins/slow_init.py b/tests/plugins/slow_init.py index 82881d7d3d40..546135b22087 100755 --- a/tests/plugins/slow_init.py +++ b/tests/plugins/slow_init.py @@ -1,5 +1,6 @@ #!/usr/bin/env python3 from pyln.client import Plugin +import os import time plugin = Plugin() @@ -8,7 +9,7 @@ @plugin.init() def init(options, configuration, plugin): plugin.log("slow_init.py initializing {}".format(configuration)) - time.sleep(21) + time.sleep(int(os.getenv('SLOWINIT_TIME', "0"))) plugin.run() diff --git a/tests/test_plugin.py b/tests/test_plugin.py index 16e45f94ce0d..6befcfad134d 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -194,6 +194,7 @@ def test_plugin_dir(node_factory): def test_plugin_slowinit(node_factory): """Tests that the 'plugin' RPC command times out if plugin doesnt respond""" + os.environ['SLOWINIT_TIME'] = '21' n = node_factory.get_node() with pytest.raises(RpcError, match="Timed out while waiting for plugin response"): @@ -205,6 +206,7 @@ def test_plugin_slowinit(node_factory): n.rpc.plugin_list() +@pytest.mark.xfail(strict=True) def test_plugin_command(node_factory): """Tests the 'plugin' RPC command""" n = node_factory.get_node() @@ -259,6 +261,15 @@ def test_plugin_command(node_factory): with pytest.raises(RpcError, match=r"Plugin exited before completing handshake."): n2.rpc.plugin_start(plugin=os.path.join(os.getcwd(), "tests/plugins/broken.py")) + # Test that we can add a directory with more than one new plugin in it. + try: + n.rpc.plugin_startdir(os.path.join(os.getcwd(), "tests/plugins")) + except RpcError: + pass + + # Usually, it crashes after the above return. + n.rpc.stop() + def test_plugin_disable(node_factory): """--disable-plugin works""" From 605f76fef7b07a0ed3e0a3833588916a03bcf36f Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:43:56 +0930 Subject: [PATCH 12/24] lightningd: unify dynamic and static plugin initialization. This means we now clean up options in startup plugins (that was only done by dynamic code!), and now they both share the 60 second timeout instead of 20 seconds for dynamic. For the dynamic case though, it's 60 seconds to both complete getmanifest and init, which seems fair. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 19 +++- lightningd/plugin_control.c | 206 ++++-------------------------------- tests/test_plugin.py | 5 +- 3 files changed, 41 insertions(+), 189 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 23ba4d056a7d..8c498e77e482 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -190,6 +190,7 @@ void plugin_kill(struct plugin *plugin, char *fmt, ...) { char *msg; va_list ap; + struct plugin_opt *opt; va_start(ap, fmt); msg = tal_vfmt(plugin, fmt, ap); @@ -201,8 +202,18 @@ void plugin_kill(struct plugin *plugin, char *fmt, ...) kill(plugin->pid, SIGKILL); list_del(&plugin->list); - if (plugin->start_cmd) + /* FIXME: This cleans up as it goes because plugin_kill called twice! */ + while ((opt = list_top(&plugin->plugin_opts, struct plugin_opt, list))) { + if (!opt_unregister(opt->name)) + fatal("Could not unregister %s from plugin %s", + opt->name, plugin->cmd); + list_del_from(&plugin->plugin_opts, &opt->list); + } + + if (plugin->start_cmd) { plugin_cmd_killed(plugin->start_cmd, plugin, msg); + plugin->start_cmd = NULL; + } check_plugins_resolved(plugin->plugins); } @@ -494,13 +505,15 @@ static struct io_plan *plugin_write_json(struct io_conn *conn, */ static void plugin_conn_finish(struct io_conn *conn, struct plugin *plugin) { + struct plugins *plugins = plugin->plugins; plugin->stdout_conn = NULL; if (plugin->start_cmd) { - plugin_cmd_succeeded(plugin->start_cmd, plugin); + plugin_cmd_killed(plugin->start_cmd, plugin, + "Plugin exited before completing handshake."); plugin->start_cmd = NULL; } tal_free(plugin); - check_plugins_resolved(plugin->plugins); + check_plugins_resolved(plugins); } struct io_plan *plugin_stdin_conn_init(struct io_conn *conn, diff --git a/lightningd/plugin_control.c b/lightningd/plugin_control.c index d0ce18cd01d7..115d1b104d9c 100644 --- a/lightningd/plugin_control.c +++ b/lightningd/plugin_control.c @@ -33,26 +33,6 @@ static struct command_result *plugin_dynamic_list_plugins(struct command *cmd, return command_success(cmd, response); } -/* Mutual recursion. */ -static void plugin_dynamic_crash(struct plugin *plugin, struct dynamic_plugin *dp); - -/** - * Returned by all subcommands on error. - */ -static struct command_result * -plugin_dynamic_error(struct dynamic_plugin *dp, const char *error) -{ - if (dp->plugin) - plugin_kill(dp->plugin, "%s", error); - else - log_info(dp->cmd->ld->log, "%s", error); - - tal_del_destructor2(dp->plugin, plugin_dynamic_crash, dp); - return command_fail(dp->cmd, JSONRPC2_INVALID_PARAMS, - "%s: %s", dp->plugin ? dp->plugin->cmd : "unknown plugin", - error); -} - struct command_result *plugin_cmd_killed(struct command *cmd, struct plugin *plugin, const char *msg) { @@ -71,127 +51,6 @@ struct command_result *plugin_cmd_all_complete(struct plugins *plugins, return plugin_dynamic_list_plugins(cmd, plugins); } -static void plugin_dynamic_timeout(struct dynamic_plugin *dp) -{ - plugin_dynamic_error(dp, "Timed out while waiting for plugin response"); -} - -static void plugin_dynamic_crash(struct plugin *p, struct dynamic_plugin *dp) -{ - plugin_dynamic_error(dp, "Plugin exited before completing handshake."); -} - -static void plugin_dynamic_config_callback(const char *buffer, - const jsmntok_t *toks, - const jsmntok_t *idtok, - struct dynamic_plugin *dp) -{ - struct plugin *p; - - dp->plugin->plugin_state = INIT_COMPLETE; - /* Reset the timer only now so that we are either configured, or - * killed. */ - tal_free(dp->plugin->timeout_timer); - tal_del_destructor2(dp->plugin, plugin_dynamic_crash, dp); - - list_for_each(&dp->plugin->plugins->plugins, p, list) { - if (p->plugin_state != INIT_COMPLETE) - return; - } - - /* No plugin unconfigured left, return the plugin list */ - was_pending(plugin_dynamic_list_plugins(dp->cmd, dp->plugin->plugins)); -} - -/** - * Send the init message to the plugin. We don't care about its response, - * but it's considered the last part of the handshake : once it responds - * it is considered configured. - */ -static void plugin_dynamic_config(struct dynamic_plugin *dp) -{ - struct jsonrpc_request *req; - - req = jsonrpc_request_start(dp->plugin, "init", dp->plugin->log, - plugin_dynamic_config_callback, dp); - plugin_populate_init_request(dp->plugin, req); - jsonrpc_request_end(req); - dp->plugin->plugin_state = AWAITING_INIT_RESPONSE; - plugin_request_send(dp->plugin, req); -} - -static void plugin_dynamic_manifest_callback(const char *buffer, - const jsmntok_t *toks, - const jsmntok_t *idtok, - struct dynamic_plugin *dp) -{ - if (!plugin_parse_getmanifest_response(buffer, toks, idtok, dp->plugin)) - return was_pending(plugin_dynamic_error(dp, "Gave a bad response to getmanifest")); - - if (!dp->plugin->dynamic) - return was_pending(plugin_dynamic_error(dp, "Not a dynamic plugin")); - - /* We got the manifest, now send the init message */ - dp->plugin->plugin_state = NEEDS_INIT; - plugin_dynamic_config(dp); -} - -/** - * This starts a plugin : spawns the process, connect its stdout and stdin, - * then sends it a getmanifest request. - */ -static struct command_result *plugin_start(struct dynamic_plugin *dp) -{ - int stdin, stdout; - mode_t prev_mask; - char **p_cmd; - struct jsonrpc_request *req; - struct plugin *p = dp->plugin; - - p->dynamic = false; - p_cmd = tal_arrz(NULL, char *, 2); - p_cmd[0] = p->cmd; - /* In case the plugin create files, this is a better default. */ - prev_mask = umask(dp->cmd->ld->initial_umask); - p->pid = pipecmdarr(&stdin, &stdout, &pipecmd_preserve, p_cmd); - umask(prev_mask); - if (p->pid == -1) - return plugin_dynamic_error(dp, "Error running command"); - else - log_debug(dp->cmd->ld->plugins->log, "started(%u) %s", p->pid, p->cmd); - tal_free(p_cmd); - p->buffer = tal_arr(p, char, 64); - p->stop = false; - /* Give the plugin 20 seconds to respond to `getmanifest`, so we don't hang - * too long on the RPC caller. */ - p->timeout_timer = new_reltimer(dp->cmd->ld->timers, dp, - time_from_sec((20)), - plugin_dynamic_timeout, dp); - - /* Besides the timeout we could also have the plugin crash before - * completing the handshake. In that case we'll get notified and we - * can clean up the `struct dynamic_plugin` and return an appropriate - * error. - * - * The destructor is deregistered in the following places: - * - * - plugin_dynamic_error in case of a timeout or a crash - * - plugin_dynamic_config_callback if the handshake completes - */ - tal_add_destructor2(p, plugin_dynamic_crash, dp); - - /* Create two connections, one read-only on top of the plugin's stdin, and one - * write-only on its stdout. */ - io_new_conn(p, stdout, plugin_stdout_conn_init, p); - io_new_conn(p, stdin, plugin_stdin_conn_init, p); - req = jsonrpc_request_start(p, "getmanifest", p->log, - plugin_dynamic_manifest_callback, dp); - jsonrpc_request_end(req); - plugin_request_send(p, req); - p->plugin_state = AWAITING_GETMANIFEST_RESPONSE; - return command_still_pending(dp->cmd); -} - /** * Called when trying to start a plugin through RPC, it starts the plugin and * will give a result 20 seconds later at the most. @@ -199,15 +58,20 @@ static struct command_result *plugin_start(struct dynamic_plugin *dp) static struct command_result * plugin_dynamic_start(struct command *cmd, const char *plugin_path) { - struct dynamic_plugin *dp; + struct plugin *p = plugin_register(cmd->ld->plugins, plugin_path, cmd); - dp = tal(cmd, struct dynamic_plugin); - dp->cmd = cmd; - dp->plugin = plugin_register(cmd->ld->plugins, plugin_path, NULL); - if (!dp->plugin) - return plugin_dynamic_error(dp, "Is already registered"); + if (!p) + return command_fail(cmd, JSONRPC2_INVALID_PARAMS, + "%s: already registered", + plugin_path); - return plugin_start(dp); + /* This will come back via plugin_cmd_killed or plugin_cmd_succeeded */ + if (!plugin_send_getmanifest(p)) + return command_fail(cmd, PLUGIN_ERROR, + "%s: failed to open: %s", + plugin_path, strerror(errno)); + + return command_still_pending(cmd); } /** @@ -218,38 +82,23 @@ static struct command_result * plugin_dynamic_startdir(struct command *cmd, const char *dir_path) { const char *err; - struct plugin *p; - /* If the directory is empty */ - bool found; + struct command_result *res; err = add_plugin_dir(cmd->ld->plugins, dir_path, false); if (err) return command_fail(cmd, JSONRPC2_INVALID_PARAMS, "%s", err); - found = false; - list_for_each(&cmd->ld->plugins->plugins, p, list) { - if (p->plugin_state == UNCONFIGURED) { - found = true; - struct dynamic_plugin *dp = tal(cmd, struct dynamic_plugin); - dp->plugin = p; - dp->cmd = cmd; - plugin_start(dp); - } - } - if (!found) - plugin_dynamic_list_plugins(cmd, cmd->ld->plugins); + /* If none added, this calls plugin_cmd_all_complete immediately */ + res = plugin_register_all_complete(cmd->ld, cmd); + if (res) + return res; + plugins_send_getmanifest(cmd->ld->plugins); return command_still_pending(cmd); } static void clear_plugin(struct plugin *p, const char *name) { - struct plugin_opt *opt; - - list_for_each(&p->plugin_opts, opt, list) - if (!opt_unregister(opt->name)) - fatal("Could not unregister %s from plugin %s", - opt->name, name); plugin_kill(p, "%s stopped by lightningd via RPC", name); tal_free(p); } @@ -290,25 +139,16 @@ plugin_dynamic_stop(struct command *cmd, const char *plugin_name) static struct command_result * plugin_dynamic_rescan_plugins(struct command *cmd) { - bool found; - struct plugin *p; + struct command_result *res; /* This will not fail on "already registered" error. */ plugins_add_default_dir(cmd->ld->plugins); - found = false; - list_for_each(&cmd->ld->plugins->plugins, p, list) { - if (p->plugin_state == UNCONFIGURED) { - struct dynamic_plugin *dp = tal(cmd, struct dynamic_plugin); - dp->plugin = p; - dp->cmd = cmd; - plugin_start(dp); - found = true; - } - } + /* If none added, this calls plugin_cmd_all_complete immediately */ + res = plugin_register_all_complete(cmd->ld, cmd); + if (res) + return res; - if (!found) - return plugin_dynamic_list_plugins(cmd, cmd->ld->plugins); return command_still_pending(cmd); } diff --git a/tests/test_plugin.py b/tests/test_plugin.py index 6befcfad134d..ceffc491ba50 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -194,10 +194,10 @@ def test_plugin_dir(node_factory): def test_plugin_slowinit(node_factory): """Tests that the 'plugin' RPC command times out if plugin doesnt respond""" - os.environ['SLOWINIT_TIME'] = '21' + os.environ['SLOWINIT_TIME'] = '61' n = node_factory.get_node() - with pytest.raises(RpcError, match="Timed out while waiting for plugin response"): + with pytest.raises(RpcError, match='failed to respond to "init" in time, terminating.'): n.rpc.plugin_start(os.path.join(os.getcwd(), "tests/plugins/slow_init.py")) # It's not actually configured yet, see what happens; @@ -206,7 +206,6 @@ def test_plugin_slowinit(node_factory): n.rpc.plugin_list() -@pytest.mark.xfail(strict=True) def test_plugin_command(node_factory): """Tests the 'plugin' RPC command""" n = node_factory.get_node() From 7d6f09cbd92b30222d095b30c4b06e67e07d468d Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:44:02 +0930 Subject: [PATCH 13/24] lightningd: make plugin response functions return the error. Instead of calling plugin_kill() and returning, have them uniformly return an error string or NULL, and have the top level (plugin_read_json) do the plugin_kill() call. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 122 ++++++++++++++++++++++++++------------------ 1 file changed, 73 insertions(+), 49 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 8c498e77e482..c54c8be8acf7 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -228,7 +228,12 @@ static void plugin_send(struct plugin *plugin, struct json_stream *stream) io_wake(plugin); } -static void plugin_log_handle(struct plugin *plugin, const jsmntok_t *paramstok) +/* Returns the error string, or NULL */ +static const char *plugin_log_handle(struct plugin *plugin, + const jsmntok_t *paramstok) + WARN_UNUSED_RESULT; +static const char *plugin_log_handle(struct plugin *plugin, + const jsmntok_t *paramstok) { const jsmntok_t *msgtok, *leveltok; enum log_level level; @@ -237,9 +242,8 @@ static void plugin_log_handle(struct plugin *plugin, const jsmntok_t *paramstok) leveltok = json_get_member(plugin->buffer, paramstok, "level"); if (!msgtok || msgtok->type != JSMN_STRING) { - plugin_kill(plugin, "Log notification from plugin doesn't have " - "a string \"message\" field"); - return; + return tal_fmt(plugin, "Log notification from plugin doesn't have " + "a string \"message\" field"); } if (!leveltok || json_tok_streq(plugin->buffer, leveltok, "info")) @@ -251,22 +255,27 @@ static void plugin_log_handle(struct plugin *plugin, const jsmntok_t *paramstok) else if (json_tok_streq(plugin->buffer, leveltok, "error")) level = LOG_BROKEN; else { - plugin_kill(plugin, - "Unknown log-level %.*s, valid values are " - "\"debug\", \"info\", \"warn\", or \"error\".", - json_tok_full_len(leveltok), - json_tok_full(plugin->buffer, leveltok)); - return; + return tal_fmt(plugin, + "Unknown log-level %.*s, valid values are " + "\"debug\", \"info\", \"warn\", or \"error\".", + json_tok_full_len(leveltok), + json_tok_full(plugin->buffer, leveltok)); } call_notifier = (level == LOG_BROKEN || level == LOG_UNUSUAL)? true : false; /* FIXME: Let plugin specify node_id? */ log_(plugin->log, level, NULL, call_notifier, "%.*s", msgtok->end - msgtok->start, plugin->buffer + msgtok->start); + return NULL; } -static void plugin_notification_handle(struct plugin *plugin, - const jsmntok_t *toks) +/* Returns the error string, or NULL */ +static const char *plugin_notification_handle(struct plugin *plugin, + const jsmntok_t *toks) + WARN_UNUSED_RESULT; + +static const char *plugin_notification_handle(struct plugin *plugin, + const jsmntok_t *toks) { const jsmntok_t *methtok, *paramstok; @@ -274,12 +283,11 @@ static void plugin_notification_handle(struct plugin *plugin, paramstok = json_get_member(plugin->buffer, toks, "params"); if (!methtok || !paramstok) { - plugin_kill(plugin, - "Malformed JSON-RPC notification missing " - "\"method\" or \"params\": %.*s", - toks->end - toks->start, - plugin->buffer + toks->start); - return; + return tal_fmt(plugin, + "Malformed JSON-RPC notification missing " + "\"method\" or \"params\": %.*s", + toks->end - toks->start, + plugin->buffer + toks->start); } /* Dispatch incoming notifications. This is currently limited @@ -287,17 +295,23 @@ static void plugin_notification_handle(struct plugin *plugin, * unwieldy we can switch to the AUTODATA construction to * register notification handlers in a variety of places. */ if (json_tok_streq(plugin->buffer, methtok, "log")) { - plugin_log_handle(plugin, paramstok); + return plugin_log_handle(plugin, paramstok); } else { - plugin_kill(plugin, "Unknown notification method %.*s", - json_tok_full_len(methtok), - json_tok_full(plugin->buffer, methtok)); + return tal_fmt(plugin, "Unknown notification method %.*s", + json_tok_full_len(methtok), + json_tok_full(plugin->buffer, methtok)); } } -static void plugin_response_handle(struct plugin *plugin, - const jsmntok_t *toks, - const jsmntok_t *idtok) +/* Returns the error string, or NULL */ +static const char *plugin_response_handle(struct plugin *plugin, + const jsmntok_t *toks, + const jsmntok_t *idtok) + WARN_UNUSED_RESULT; + +static const char *plugin_response_handle(struct plugin *plugin, + const jsmntok_t *toks, + const jsmntok_t *idtok) { struct plugin_destroyed *pd; struct jsonrpc_request *request; @@ -305,18 +319,16 @@ static void plugin_response_handle(struct plugin *plugin, /* We only send u64 ids, so if this fails it's a critical error (note * that this also works if id is inside a JSON string!). */ if (!json_to_u64(plugin->buffer, idtok, &id)) { - plugin_kill(plugin, - "JSON-RPC response \"id\"-field is not a u64"); - return; + return tal_fmt(plugin, + "JSON-RPC response \"id\"-field is not a u64"); } request = uintmap_get(&plugin->plugins->pending_requests, id); if (!request) { - plugin_kill( - plugin, - "Received a JSON-RPC response for non-existent request"); - return; + return tal_fmt( + plugin, + "Received a JSON-RPC response for non-existent request"); } /* We expect the request->cb to copy if needed */ @@ -327,19 +339,27 @@ static void plugin_response_handle(struct plugin *plugin, * plugin is parent), so detect that case */ if (!was_plugin_destroyed(pd)) tal_free(request); + + return NULL; } /** * Try to parse a complete message from the plugin's buffer. * - * Internally calls the handler if it was able to fully parse a JSON message, - * and returns true in that case. + * Returns NULL if there was no error. + * If it can parse a JSON message, sets *@complete, and returns any error + * from the callback. + * + * If @destroyed was set, it means the plugin called plugin stop on itself. */ -static bool plugin_read_json_one(struct plugin *plugin, bool *destroyed) +static const char *plugin_read_json_one(struct plugin *plugin, + bool *complete, + bool *destroyed) { bool valid; const jsmntok_t *toks, *jrtok, *idtok; struct plugin_destroyed *pd; + const char *err; *destroyed = false; /* Note that in the case of 'plugin stop' this can free request (since @@ -352,28 +372,31 @@ static bool plugin_read_json_one(struct plugin *plugin, bool *destroyed) &valid); if (!toks) { if (!valid) { - plugin_kill(plugin, "Failed to parse JSON response '%.*s'", - (int)plugin->used, plugin->buffer); - return false; + return tal_fmt(plugin, + "Failed to parse JSON response '%.*s'", + (int)plugin->used, plugin->buffer); } /* We need more. */ - return false; + *complete = false; + return NULL; } /* Empty buffer? (eg. just whitespace). */ if (tal_count(toks) == 1) { plugin->used = 0; - return false; + /* We need more. */ + *complete = false; + return NULL; } + *complete = true; jrtok = json_get_member(plugin->buffer, toks, "jsonrpc"); idtok = json_get_member(plugin->buffer, toks, "id"); if (!jrtok) { - plugin_kill( + return tal_fmt( plugin, "JSON-RPC message does not contain \"jsonrpc\" field"); - return false; } pd = plugin_detect_destruction(plugin); @@ -389,7 +412,7 @@ static bool plugin_read_json_one(struct plugin *plugin, bool *destroyed) * * https://www.jsonrpc.org/specification#notification */ - plugin_notification_handle(plugin, toks); + err = plugin_notification_handle(plugin, toks); } else { /* When a rpc call is made, the Server MUST reply with @@ -419,7 +442,7 @@ static bool plugin_read_json_one(struct plugin *plugin, bool *destroyed) * * https://www.jsonrpc.org/specification#response_object */ - plugin_response_handle(plugin, toks, idtok); + err = plugin_response_handle(plugin, toks, idtok); } /* Corner case: rpc_command hook can destroy plugin for 'plugin @@ -433,7 +456,7 @@ static bool plugin_read_json_one(struct plugin *plugin, bool *destroyed) plugin->used -= toks[0].end; tal_free(toks); } - return true; + return err; } static struct io_plan *plugin_read_json(struct io_conn *conn, @@ -451,16 +474,17 @@ static struct io_plan *plugin_read_json(struct io_conn *conn, /* Read and process all messages from the connection */ do { bool destroyed; - success = plugin_read_json_one(plugin, &destroyed); + const char *err; + err = plugin_read_json_one(plugin, &success, &destroyed); /* If it's destroyed, conn is already freed! */ if (destroyed) return io_close(NULL); - /* Processing the message from the plugin might have - * resulted in it stopping, so let's check. */ - if (plugin->stop) + if (err) { + plugin_kill(plugin, "%s", err); return io_close(plugin->stdout_conn); + } } while (success); /* Now read more from the connection */ From 00fffac50547af282865caec636af56f2490e377 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:44:07 +0930 Subject: [PATCH 14/24] lightningd: plugin init routines return error string or NULL. Once again, this unifies plugin_kill() into the caller. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 173 ++++++++++++++++++++++---------------------- lightningd/plugin.h | 8 -- 2 files changed, 85 insertions(+), 96 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index c54c8be8acf7..8678bf01f435 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -606,8 +606,8 @@ char *plugin_opt_set(const char *arg, struct plugin_opt *popt) /* Add a single plugin option to the plugin as well as registering it with the * command line options. */ -static bool plugin_opt_add(struct plugin *plugin, const char *buffer, - const jsmntok_t *opt) +static const char *plugin_opt_add(struct plugin *plugin, const char *buffer, + const jsmntok_t *opt) { const jsmntok_t *nametok, *typetok, *defaulttok, *desctok; struct plugin_opt *popt; @@ -617,9 +617,8 @@ static bool plugin_opt_add(struct plugin *plugin, const char *buffer, defaulttok = json_get_member(buffer, opt, "default"); if (!typetok || !nametok || !desctok) { - plugin_kill(plugin, + return tal_fmt(plugin, "An option is missing either \"name\", \"description\" or \"type\""); - return false; } popt = tal(plugin, struct plugin_opt); @@ -663,8 +662,8 @@ static bool plugin_opt_add(struct plugin *plugin, const char *buffer, *popt->value->as_bool = false; } else { - plugin_kill(plugin, "Only \"string\", \"int\", \"bool\", and \"flag\" options are supported"); - return false; + return tal_fmt(plugin, + "Only \"string\", \"int\", \"bool\", and \"flag\" options are supported"); } if (!defaulttok) popt->description = json_strdup(popt, buffer, desctok); @@ -678,33 +677,34 @@ static bool plugin_opt_add(struct plugin *plugin, const char *buffer, opt_register_arg(popt->name, plugin_opt_set, NULL, popt, popt->description); - return true; + return NULL; } /* Iterate through the options in the manifest response, and add them * to the plugin and the command line options */ -static bool plugin_opts_add(struct plugin *plugin, - const char *buffer, - const jsmntok_t *resulttok) +static const char *plugin_opts_add(struct plugin *plugin, + const char *buffer, + const jsmntok_t *resulttok) { const jsmntok_t *options = json_get_member(buffer, resulttok, "options"); if (!options) { - plugin_kill(plugin, + return tal_fmt(plugin, "\"result.options\" was not found in the manifest"); - return false; } if (options->type != JSMN_ARRAY) { - plugin_kill(plugin, "\"result.options\" is not an array"); - return false; + return tal_fmt(plugin, "\"result.options\" is not an array"); } - for (size_t i = 0; i < options->size; i++) - if (!plugin_opt_add(plugin, buffer, json_get_arr(options, i))) - return false; + for (size_t i = 0; i < options->size; i++) { + const char *err; + err = plugin_opt_add(plugin, buffer, json_get_arr(options, i)); + if (err) + return err; + } - return true; + return NULL; } static void json_stream_forward_change_id(struct json_stream *stream, @@ -808,9 +808,9 @@ static struct command_result *plugin_rpcmethod_dispatch(struct command *cmd, return command_still_pending(cmd); } -static bool plugin_rpcmethod_add(struct plugin *plugin, - const char *buffer, - const jsmntok_t *meth) +static const char *plugin_rpcmethod_add(struct plugin *plugin, + const char *buffer, + const jsmntok_t *meth) { const jsmntok_t *nametok, *categorytok, *desctok, *longdesctok, *usagetok; struct json_command *cmd; @@ -823,38 +823,34 @@ static bool plugin_rpcmethod_add(struct plugin *plugin, usagetok = json_get_member(buffer, meth, "usage"); if (!nametok || nametok->type != JSMN_STRING) { - plugin_kill(plugin, + return tal_fmt(plugin, "rpcmethod does not have a string \"name\": %.*s", meth->end - meth->start, buffer + meth->start); - return false; } if (!desctok || desctok->type != JSMN_STRING) { - plugin_kill(plugin, + return tal_fmt(plugin, "rpcmethod does not have a string " "\"description\": %.*s", meth->end - meth->start, buffer + meth->start); - return false; } if (longdesctok && longdesctok->type != JSMN_STRING) { - plugin_kill(plugin, + return tal_fmt(plugin, "\"long_description\" is not a string: %.*s", meth->end - meth->start, buffer + meth->start); - return false; } if (usagetok && usagetok->type != JSMN_STRING) { - plugin_kill(plugin, + return tal_fmt(plugin, "\"usage\" is not a string: %.*s", meth->end - meth->start, buffer + meth->start); - return false; } cmd = notleak(tal(plugin, struct json_command)); cmd->name = json_strdup(cmd, buffer, nametok); if (categorytok) - cmd->category = json_strdup(cmd, buffer, categorytok); + cmd->category = json_strdup(cmd, buffer, categorytok); else cmd->category = "plugin"; cmd->description = json_strdup(cmd, buffer, desctok); @@ -865,110 +861,107 @@ static bool plugin_rpcmethod_add(struct plugin *plugin, if (usagetok) usage = json_strdup(tmpctx, buffer, usagetok); else if (!deprecated_apis) { - plugin_kill(plugin, + return tal_fmt(plugin, "\"usage\" not provided by plugin"); - return false; } else usage = "[params]"; cmd->deprecated = false; cmd->dispatch = plugin_rpcmethod_dispatch; if (!jsonrpc_command_add(plugin->plugins->ld->jsonrpc, cmd, usage)) { - log_broken(plugin->log, + return tal_fmt(plugin, "Could not register method \"%s\", a method with " "that name is already registered", cmd->name); - return false; } tal_arr_expand(&plugin->methods, cmd->name); - return true; + return NULL; } -static bool plugin_rpcmethods_add(struct plugin *plugin, - const char *buffer, - const jsmntok_t *resulttok) +static const char *plugin_rpcmethods_add(struct plugin *plugin, + const char *buffer, + const jsmntok_t *resulttok) { const jsmntok_t *methods = json_get_member(buffer, resulttok, "rpcmethods"); if (!methods) - return false; + return tal_fmt(plugin, "\"result.rpcmethods\" missing"); if (methods->type != JSMN_ARRAY) { - plugin_kill(plugin, + return tal_fmt(plugin, "\"result.rpcmethods\" is not an array"); - return false; } - for (size_t i = 0; i < methods->size; i++) - if (!plugin_rpcmethod_add(plugin, buffer, - json_get_arr(methods, i))) - return false; - return true; + for (size_t i = 0; i < methods->size; i++) { + const char *err; + err = plugin_rpcmethod_add(plugin, buffer, + json_get_arr(methods, i)); + if (err) + return err; + } + + return NULL; } -static bool plugin_subscriptions_add(struct plugin *plugin, const char *buffer, - const jsmntok_t *resulttok) +static const char *plugin_subscriptions_add(struct plugin *plugin, + const char *buffer, + const jsmntok_t *resulttok) { const jsmntok_t *subscriptions = json_get_member(buffer, resulttok, "subscriptions"); if (!subscriptions) { plugin->subscriptions = NULL; - return true; + return NULL; } plugin->subscriptions = tal_arr(plugin, char *, 0); if (subscriptions->type != JSMN_ARRAY) { - plugin_kill(plugin, "\"result.subscriptions\" is not an array"); - return false; + return tal_fmt(plugin, "\"result.subscriptions\" is not an array"); } for (int i = 0; i < subscriptions->size; i++) { char *topic; const jsmntok_t *s = json_get_arr(subscriptions, i); if (s->type != JSMN_STRING) { - plugin_kill( - plugin, - "result.subscriptions[%d] is not a string: %s", i, - plugin->buffer); - return false; + return tal_fmt(plugin, + "result.subscriptions[%d] is not a string: '%.*s'", i, + json_tok_full_len(s), + json_tok_full(buffer, s)); } topic = json_strdup(plugin, plugin->buffer, s); if (!notifications_have_topic(topic)) { - plugin_kill( + return tal_fmt( plugin, "topic '%s' is not a known notification topic", topic); - return false; } tal_arr_expand(&plugin->subscriptions, topic); } - return true; + return NULL; } -static bool plugin_hooks_add(struct plugin *plugin, const char *buffer, - const jsmntok_t *resulttok) +static const char *plugin_hooks_add(struct plugin *plugin, const char *buffer, + const jsmntok_t *resulttok) { const jsmntok_t *hookstok = json_get_member(buffer, resulttok, "hooks"); if (!hookstok) - return true; + return NULL; for (int i = 0; i < hookstok->size; i++) { - char *name = json_strdup(NULL, plugin->buffer, + char *name = json_strdup(tmpctx, plugin->buffer, json_get_arr(hookstok, i)); if (!plugin_hook_register(plugin, name)) { - plugin_kill(plugin, + return tal_fmt(plugin, "could not register hook '%s', either the " "name doesn't exist or another plugin " "already registered it.", name); - tal_free(name); - return false; } tal_free(name); } - return true; + return NULL; } static void plugin_manifest_timeout(struct plugin *plugin) @@ -981,23 +974,25 @@ static void plugin_manifest_timeout(struct plugin *plugin) fatal("Can't recover from plugin failure, terminating."); } -bool plugin_parse_getmanifest_response(const char *buffer, - const jsmntok_t *toks, - const jsmntok_t *idtok, - struct plugin *plugin) +static const char *plugin_parse_getmanifest_response(const char *buffer, + const jsmntok_t *toks, + const jsmntok_t *idtok, + struct plugin *plugin) { const jsmntok_t *resulttok, *dynamictok, *featurestok, *tok; + const char *err; resulttok = json_get_member(buffer, toks, "result"); if (!resulttok || resulttok->type != JSMN_OBJECT) - return false; + return tal_fmt(plugin, "Invalid/missing result tok in '%.*s'", + json_tok_full_len(toks), + json_tok_full(buffer, toks)); dynamictok = json_get_member(buffer, resulttok, "dynamic"); if (dynamictok && !json_to_bool(buffer, dynamictok, &plugin->dynamic)) { - plugin_kill(plugin, "Bad 'dynamic' field ('%.*s')", + return tal_fmt(plugin, "Bad 'dynamic' field ('%.*s')", json_tok_full_len(dynamictok), json_tok_full(buffer, dynamictok)); - return false; } featurestok = json_get_member(buffer, resulttok, "featurebits"); @@ -1024,40 +1019,39 @@ bool plugin_parse_getmanifest_response(const char *buffer, have_featurebits |= tal_bytelen(fset->bits[i]) > 0; if (!fset->bits[i]) { - plugin_kill( + return tal_fmt( plugin, "Featurebits returned by plugin is not a " "valid hexadecimal string: %.*s", tok->end - tok->start, buffer + tok->start); - return true; } } if (plugin->dynamic && have_featurebits) { - plugin_kill(plugin, + return tal_fmt(plugin, "Custom featurebits only allows for non-dynamic " "plugins: dynamic=%d, featurebits=%.*s", plugin->dynamic, featurestok->end - featurestok->start, buffer + featurestok->start); - return true; } if (!feature_set_or(plugin->plugins->ld->our_features, fset)) { - plugin_kill(plugin, + return tal_fmt(plugin, "Custom featurebits already present"); - return true; } } - if (!plugin_opts_add(plugin, buffer, resulttok) || - !plugin_rpcmethods_add(plugin, buffer, resulttok) || - !plugin_subscriptions_add(plugin, buffer, resulttok) || - !plugin_hooks_add(plugin, buffer, resulttok)) - return false; + err = plugin_opts_add(plugin, buffer, resulttok); + if (!err) + err = plugin_rpcmethods_add(plugin, buffer, resulttok); + if (!err) + err = plugin_subscriptions_add(plugin, buffer, resulttok); + if (!err) + err = plugin_hooks_add(plugin, buffer, resulttok); plugin->plugin_state = NEEDS_INIT; - return true; + return err; } bool plugins_any_in_state(const struct plugins *plugins, enum plugin_state state) @@ -1093,8 +1087,11 @@ static void plugin_manifest_cb(const char *buffer, const jsmntok_t *idtok, struct plugin *plugin) { - if (!plugin_parse_getmanifest_response(buffer, toks, idtok, plugin)) { - plugin_kill(plugin, "%s: Bad response to getmanifest.", plugin->cmd); + const char *err; + err = plugin_parse_getmanifest_response(buffer, toks, idtok, plugin); + + if (err) { + plugin_kill(plugin, "%s", err); return; } diff --git a/lightningd/plugin.h b/lightningd/plugin.h index f9dad419f931..f1db616cb59c 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -247,14 +247,6 @@ bool plugins_any_in_state(const struct plugins *plugins, enum plugin_state state */ bool plugins_all_in_state(const struct plugins *plugins, enum plugin_state state); -/** - * Read and treat (populate options, methods, ...) the `getmanifest` response. - */ -bool plugin_parse_getmanifest_response(const char *buffer, - const jsmntok_t *toks, - const jsmntok_t *idtok, - struct plugin *plugin); - /** * This populates the jsonrpc request with the plugin/lightningd specifications */ From 8f4a93e657489e6ef4c33a5967c4aac319f9c255 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:44:21 +0930 Subject: [PATCH 15/24] lightningd: make plugin_kill() free the plugin. This is what I expected from plugin_kill, and now all the callers do the equivalent anywat, it's easy. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 8 +++++--- lightningd/plugin_control.c | 8 +------- tests/test_plugin.py | 4 ++-- 3 files changed, 8 insertions(+), 12 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 8678bf01f435..c5c416d4b225 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -216,6 +216,7 @@ void plugin_kill(struct plugin *plugin, char *fmt, ...) } check_plugins_resolved(plugin->plugins); + tal_free(plugin); } /** @@ -483,7 +484,8 @@ static struct io_plan *plugin_read_json(struct io_conn *conn, if (err) { plugin_kill(plugin, "%s", err); - return io_close(plugin->stdout_conn); + /* plugin_kill frees plugin */ + return io_close(NULL); } } while (success); @@ -966,11 +968,12 @@ static const char *plugin_hooks_add(struct plugin *plugin, const char *buffer, static void plugin_manifest_timeout(struct plugin *plugin) { + bool startup = plugin->plugins->startup; plugin_kill(plugin, "failed to respond to \"%s\" in time, terminating.", plugin->plugin_state == AWAITING_GETMANIFEST_RESPONSE ? "getmanifest" : "init"); - if (plugin->plugins->startup) + if (startup) fatal("Can't recover from plugin failure, terminating."); } @@ -1286,7 +1289,6 @@ bool plugins_send_getmanifest(struct plugins *plugins) fatal("error starting plugin '%s': %s", p->cmd, strerror(errno)); plugin_kill(p, "error starting: %s", strerror(errno)); - tal_free(p); } return sent; diff --git a/lightningd/plugin_control.c b/lightningd/plugin_control.c index 115d1b104d9c..96d10daa1082 100644 --- a/lightningd/plugin_control.c +++ b/lightningd/plugin_control.c @@ -97,12 +97,6 @@ plugin_dynamic_startdir(struct command *cmd, const char *dir_path) return command_still_pending(cmd); } -static void clear_plugin(struct plugin *p, const char *name) -{ - plugin_kill(p, "%s stopped by lightningd via RPC", name); - tal_free(p); -} - static struct command_result * plugin_dynamic_stop(struct command *cmd, const char *plugin_name) { @@ -116,7 +110,7 @@ plugin_dynamic_stop(struct command *cmd, const char *plugin_name) "%s cannot be managed when " "lightningd is up", plugin_name); - clear_plugin(p, plugin_name); + plugin_kill(p, "stopped by lightningd via RPC"); response = json_stream_success(cmd); if (deprecated_apis) json_add_string(response, "", diff --git a/tests/test_plugin.py b/tests/test_plugin.py index ceffc491ba50..0e70f9be46e8 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -229,7 +229,7 @@ def test_plugin_command(node_factory): # Make sure the plugin behaves normally after stop and restart assert("Successfully stopped helloworld.py." == n.rpc.plugin_stop(plugin="helloworld.py")["result"]) - n.daemon.wait_for_log(r"Killing plugin: helloworld.py") + n.daemon.wait_for_log(r"Killing plugin: stopped by lightningd via RPC") 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")) @@ -237,7 +237,7 @@ def test_plugin_command(node_factory): # Now stop the helloworld plugin assert("Successfully stopped helloworld.py." == n.rpc.plugin_stop(plugin="helloworld.py")["result"]) - n.daemon.wait_for_log(r"Killing plugin: helloworld.py") + n.daemon.wait_for_log(r"Killing plugin: stopped by lightningd via RPC") # 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"]] From eb94a9a26b4cf613aba8ff01c23b2c7a71b36fd3 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:44:27 +0930 Subject: [PATCH 16/24] lightningd: make plugin opts free themselves. They are children of the plugin, so this Just Works. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 17 ++++++++--------- 1 file changed, 8 insertions(+), 9 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index c5c416d4b225..f55fb2e7658a 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -190,7 +190,6 @@ void plugin_kill(struct plugin *plugin, char *fmt, ...) { char *msg; va_list ap; - struct plugin_opt *opt; va_start(ap, fmt); msg = tal_vfmt(plugin, fmt, ap); @@ -202,14 +201,6 @@ void plugin_kill(struct plugin *plugin, char *fmt, ...) kill(plugin->pid, SIGKILL); list_del(&plugin->list); - /* FIXME: This cleans up as it goes because plugin_kill called twice! */ - while ((opt = list_top(&plugin->plugin_opts, struct plugin_opt, list))) { - if (!opt_unregister(opt->name)) - fatal("Could not unregister %s from plugin %s", - opt->name, plugin->cmd); - list_del_from(&plugin->plugin_opts, &opt->list); - } - if (plugin->start_cmd) { plugin_cmd_killed(plugin->start_cmd, plugin, msg); plugin->start_cmd = NULL; @@ -606,6 +597,13 @@ char *plugin_opt_set(const char *arg, struct plugin_opt *popt) return NULL; } +static void destroy_plugin_opt(struct plugin_opt *opt) +{ + if (!opt_unregister(opt->name)) + fatal("Could not unregister %s", opt->name); + list_del(&opt->list); +} + /* Add a single plugin option to the plugin as well as registering it with the * command line options. */ static const char *plugin_opt_add(struct plugin *plugin, const char *buffer, @@ -679,6 +677,7 @@ static const char *plugin_opt_add(struct plugin *plugin, const char *buffer, opt_register_arg(popt->name, plugin_opt_set, NULL, popt, popt->description); + tal_add_destructor(popt, destroy_plugin_opt); return NULL; } From a0f9ec653c16a0b58736eae3da4a8c625a7dfda9 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:44:32 +0930 Subject: [PATCH 17/24] lightningd: have plugin_send_getmanifest return an error string. This way the caller doesn't have to "know" that it should use strerror(). Signed-off-by: Rusty Russell --- lightningd/plugin.c | 11 +++++++---- lightningd/plugin.h | 4 +++- lightningd/plugin_control.c | 8 +++++--- 3 files changed, 15 insertions(+), 8 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index f55fb2e7658a..f89e278d726f 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -1224,7 +1224,7 @@ void plugins_add_default_dir(struct plugins *plugins) } } -bool plugin_send_getmanifest(struct plugin *p) +const char *plugin_send_getmanifest(struct plugin *p) { char **cmd; int stdin, stdout; @@ -1242,7 +1242,7 @@ bool plugin_send_getmanifest(struct plugin *p) cmd[1] = "--debugger"; p->pid = pipecmdarr(&stdin, &stdout, &pipecmd_preserve, cmd); if (p->pid == -1) - return false; + return tal_fmt(p, "opening pipe: %s", strerror(errno)); log_debug(p->plugins->log, "started(%u) %s", p->pid, p->cmd); p->buffer = tal_arr(p, char, 64); @@ -1268,7 +1268,7 @@ bool plugin_send_getmanifest(struct plugin *p) plugin_manifest_timeout, p); } - return true; + return NULL; } bool plugins_send_getmanifest(struct plugins *plugins) @@ -1278,9 +1278,12 @@ bool plugins_send_getmanifest(struct plugins *plugins) /* Spawn the plugin processes before entering the io_loop */ list_for_each_safe(&plugins->plugins, p, next, list) { + const char *err; + if (p->plugin_state != UNCONFIGURED) continue; - if (plugin_send_getmanifest(p)) { + err = plugin_send_getmanifest(p); + if (!err) { sent = true; continue; } diff --git a/lightningd/plugin.h b/lightningd/plugin.h index f1db616cb59c..1877fd821b32 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -196,8 +196,10 @@ bool plugin_remove(struct plugins *plugins, const char *name); /** * Kick of initialization of a plugin. + * + * Returns error string, or NULL. */ -bool plugin_send_getmanifest(struct plugin *p); +const char *plugin_send_getmanifest(struct plugin *p); /** * Kick of initialization of all plugins which need it/ diff --git a/lightningd/plugin_control.c b/lightningd/plugin_control.c index 96d10daa1082..e78d1b6208a9 100644 --- a/lightningd/plugin_control.c +++ b/lightningd/plugin_control.c @@ -59,6 +59,7 @@ static struct command_result * plugin_dynamic_start(struct command *cmd, const char *plugin_path) { struct plugin *p = plugin_register(cmd->ld->plugins, plugin_path, cmd); + const char *err; if (!p) return command_fail(cmd, JSONRPC2_INVALID_PARAMS, @@ -66,10 +67,11 @@ plugin_dynamic_start(struct command *cmd, const char *plugin_path) plugin_path); /* This will come back via plugin_cmd_killed or plugin_cmd_succeeded */ - if (!plugin_send_getmanifest(p)) + err = plugin_send_getmanifest(p); + if (err) return command_fail(cmd, PLUGIN_ERROR, - "%s: failed to open: %s", - plugin_path, strerror(errno)); + "%s: %s", + plugin_path, err); return command_still_pending(cmd); } From aee927611a1b5714bf5182fb3785ed568ded61f8 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:44:46 +0930 Subject: [PATCH 18/24] lightningd: make plugin_kill take a simple string. That's more convenient for most callers, which don't need a fmt. Fixed-by: Darosior Signed-off-by: Rusty Russell --- lightningd/plugin.c | 29 ++++++++++++----------------- lightningd/plugin.h | 4 ++-- tests/test_plugin.py | 2 +- 3 files changed, 15 insertions(+), 20 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index f89e278d726f..28b84ce8065d 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -186,15 +186,8 @@ bool plugin_remove(struct plugins *plugins, const char *name) return removed; } -void plugin_kill(struct plugin *plugin, char *fmt, ...) +void plugin_kill(struct plugin *plugin, const char *msg) { - char *msg; - va_list ap; - - va_start(ap, fmt); - msg = tal_vfmt(plugin, fmt, ap); - va_end(ap); - log_info(plugin->log, "Killing plugin: %s", msg); plugin->stop = true; io_wake(plugin); @@ -474,7 +467,7 @@ static struct io_plan *plugin_read_json(struct io_conn *conn, return io_close(NULL); if (err) { - plugin_kill(plugin, "%s", err); + plugin_kill(plugin, err); /* plugin_kill frees plugin */ return io_close(NULL); } @@ -968,10 +961,13 @@ static const char *plugin_hooks_add(struct plugin *plugin, const char *buffer, static void plugin_manifest_timeout(struct plugin *plugin) { bool startup = plugin->plugins->startup; - plugin_kill(plugin, - "failed to respond to \"%s\" in time, terminating.", - plugin->plugin_state == AWAITING_GETMANIFEST_RESPONSE - ? "getmanifest" : "init"); + if (plugin->plugin_state == AWAITING_GETMANIFEST_RESPONSE) + plugin_kill(plugin, + "failed to respond to 'getmanifest' in time, terminating."); + else + plugin_kill(plugin, + "failed to respond to 'init' in time, terminating."); + if (startup) fatal("Can't recover from plugin failure, terminating."); } @@ -1093,7 +1089,7 @@ static void plugin_manifest_cb(const char *buffer, err = plugin_parse_getmanifest_response(buffer, toks, idtok, plugin); if (err) { - plugin_kill(plugin, "%s", err); + plugin_kill(plugin, err); return; } @@ -1288,9 +1284,8 @@ bool plugins_send_getmanifest(struct plugins *plugins) continue; } if (plugins->startup) - fatal("error starting plugin '%s': %s", p->cmd, - strerror(errno)); - plugin_kill(p, "error starting: %s", strerror(errno)); + fatal("error starting plugin '%s': %s", p->cmd, err); + plugin_kill(p, err); } return sent; diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 1877fd821b32..51af0817936e 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -209,9 +209,9 @@ const char *plugin_send_getmanifest(struct plugin *p); bool plugins_send_getmanifest(struct plugins *plugins); /** - * Kill a plugin process, with an error message. + * Kill a plugin process and free @plugin, with an error message. */ -void plugin_kill(struct plugin *plugin, char *fmt, ...) PRINTF_FMT(2,3); +void plugin_kill(struct plugin *plugin, const char *msg); /** * Returns the plugin which registers the command with name {cmd_name} diff --git a/tests/test_plugin.py b/tests/test_plugin.py index 0e70f9be46e8..f2359f7d0469 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -197,7 +197,7 @@ def test_plugin_slowinit(node_factory): os.environ['SLOWINIT_TIME'] = '61' n = node_factory.get_node() - with pytest.raises(RpcError, match='failed to respond to "init" in time, terminating.'): + with pytest.raises(RpcError, match='failed to respond to \'init\' in time, terminating.'): n.rpc.plugin_start(os.path.join(os.getcwd(), "tests/plugins/slow_init.py")) # It's not actually configured yet, see what happens; From dd18a458f92b35a940d5a9e4da76675e52524d40 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:45:03 +0930 Subject: [PATCH 19/24] lightningd: remove `stop` member from plugin. It's not needed now that plugin_kill frees the plugin immediately. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 5 ----- lightningd/plugin.h | 1 - 2 files changed, 6 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 28b84ce8065d..83a01618a844 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -189,8 +189,6 @@ bool plugin_remove(struct plugins *plugins, const char *name) void plugin_kill(struct plugin *plugin, const char *msg) { log_info(plugin->log, "Killing plugin: %s", msg); - plugin->stop = true; - io_wake(plugin); kill(plugin->pid, SIGKILL); list_del(&plugin->list); @@ -501,8 +499,6 @@ static struct io_plan *plugin_write_json(struct io_conn *conn, { if (tal_count(plugin->js_arr)) { return json_stream_output(plugin->js_arr[0], plugin->stdin_conn, plugin_stream_complete, plugin); - } else if (plugin->stop) { - return io_close(conn); } return io_out_wait(conn, plugin, plugin_write_json, plugin); @@ -1242,7 +1238,6 @@ const char *plugin_send_getmanifest(struct plugin *p) log_debug(p->plugins->log, "started(%u) %s", p->pid, p->cmd); p->buffer = tal_arr(p, char, 64); - p->stop = false; /* Create two connections, one read-only on top of p->stdout, and one * write-only on p->stdin */ diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 51af0817936e..4460324d62de 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -43,7 +43,6 @@ struct plugin { pid_t pid; char *cmd; struct io_conn *stdin_conn, *stdout_conn; - bool stop; struct plugins *plugins; const char **plugin_path; /* If there's a json command which ordered this to start */ From 4cac01dc9258d02555fc343afa4dde0f718abaea Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:45:16 +0930 Subject: [PATCH 20/24] lightningd: final cleanup for plugins. 1. Make the destructor call check_plugins_resolved(), unless it was uninitialized (`opt_disable_plugin`). 2. Remove redundant list_del (destructor already does it). Signed-off-by: Rusty Russell --- lightningd/plugin.c | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 83a01618a844..3460c89a67d4 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -113,6 +113,10 @@ static void destroy_plugin(struct plugin *p) call->cmd, PLUGIN_TERMINATED, "Plugin terminated before replying to RPC call.")); } + + /* Don't call this if we're still parsing options! */ + if (p->plugin_state != UNCONFIGURED) + check_plugins_resolved(p->plugins); } struct plugin *plugin_register(struct plugins *plugins, const char* path TAKES, @@ -190,14 +194,11 @@ void plugin_kill(struct plugin *plugin, const char *msg) { log_info(plugin->log, "Killing plugin: %s", msg); kill(plugin->pid, SIGKILL); - list_del(&plugin->list); - if (plugin->start_cmd) { plugin_cmd_killed(plugin->start_cmd, plugin, msg); plugin->start_cmd = NULL; } - check_plugins_resolved(plugin->plugins); tal_free(plugin); } From 6050adcecfbbe2f00f0ef35439bf97b480da30df Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:45:21 +0930 Subject: [PATCH 21/24] lightningd: have plugin-disable be more persistent. The previous implementation was a bit lazy: in particular, since we didn't remember the disabled plugins, we would load them on rescan. Changelog-Changed: config: the `plugin-disable` option works even if specified before the plugin is found. --- doc/lightningd-config.5 | 8 +++++--- doc/lightningd-config.5.md | 8 +++++--- lightningd/options.c | 9 ++++++--- lightningd/plugin.c | 27 ++++++++++++++++++++++----- lightningd/plugin.h | 15 +++++++++++++-- tests/test_plugin.py | 36 +++++++++++++++++++++++++++++++++++- 6 files changed, 86 insertions(+), 17 deletions(-) diff --git a/doc/lightningd-config.5 b/doc/lightningd-config.5 index 0bfaa18f53ec..5c7ec02e891c 100644 --- a/doc/lightningd-config.5 +++ b/doc/lightningd-config.5 @@ -528,9 +528,11 @@ normal effect\. \fBdisable-plugin\fR=\fIPLUGIN\fR -If \fIPLUGIN\fR contains a /, plugins with the same path as \fIPLUGIN\fR are -disabled\. Otherwise, any plugin with that base name is disabled, -whatever directory it is in\. +If \fIPLUGIN\fR contains a /, plugins with the same path as \fIPLUGIN\fR will +not be loaded at startup\. Otherwise, no plugin with that base name will +be loaded at startup, whatever directory it is in\. This option is useful for +disabling a single plugin inside a directory\. You can still explicitly +load plugins which have been disabled, using \fBlightning-plugin\fR(7) \fBstart\fR\. .SH BUGS diff --git a/doc/lightningd-config.5.md b/doc/lightningd-config.5.md index 9ddb1bb691cf..e79df85a9327 100644 --- a/doc/lightningd-config.5.md +++ b/doc/lightningd-config.5.md @@ -434,9 +434,11 @@ including the default built-in plugin directory. You can still add normal effect. **disable-plugin**=*PLUGIN* -If *PLUGIN* contains a /, plugins with the same path as *PLUGIN* are -disabled. Otherwise, any plugin with that base name is disabled, -whatever directory it is in. +If *PLUGIN* contains a /, plugins with the same path as *PLUGIN* will +not be loaded at startup. Otherwise, no plugin with that base name will +be loaded at startup, whatever directory it is in. This option is useful for +disabling a single plugin inside a directory. You can still explicitly +load plugins which have been disabled, using lightning-plugin(7) `start`. BUGS ---- diff --git a/lightningd/options.c b/lightningd/options.c index ca08154f6306..83cffbeaacbb 100644 --- a/lightningd/options.c +++ b/lightningd/options.c @@ -343,15 +343,18 @@ static char *opt_add_proxy_addr(const char *arg, struct lightningd *ld) static char *opt_add_plugin(const char *arg, struct lightningd *ld) { + if (plugin_blacklisted(ld->plugins, arg)) { + log_info(ld->log, "%s: disabled via disable-plugin", arg); + return NULL; + } plugin_register(ld->plugins, arg, NULL); return NULL; } static char *opt_disable_plugin(const char *arg, struct lightningd *ld) { - if (plugin_remove(ld->plugins, arg)) - return NULL; - return tal_fmt(NULL, "Could not find plugin %s", arg); + plugin_blacklist(ld->plugins, arg); + return NULL; } static char *opt_add_plugin_dir(const char *arg, struct lightningd *ld) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 3460c89a67d4..b465afd0a72d 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -52,6 +52,7 @@ struct plugins *plugins_new(const tal_t *ctx, struct log_book *log_book, p->ld = ld; p->startup = true; p->json_cmds = tal_arr(p, struct command *, 0); + p->blacklist = tal_arr(p, const char *, 0); uintmap_init(&p->pending_requests); memleak_add_helper(p, memleak_help_pending_requests); @@ -175,19 +176,30 @@ bool plugin_paths_match(const char *cmd, const char *name) } } -bool plugin_remove(struct plugins *plugins, const char *name) +void plugin_blacklist(struct plugins *plugins, const char *name) { struct plugin *p, *next; - bool removed = false; list_for_each_safe(&plugins->plugins, p, next, list) { if (plugin_paths_match(p->cmd, name)) { + log_info(plugins->log, "%s: disabled via disable-plugin", + p->cmd); list_del_from(&plugins->plugins, &p->list); tal_free(p); - removed = true; } } - return removed; + + tal_arr_expand(&plugins->blacklist, + tal_strdup(plugins->blacklist, name)); +} + +bool plugin_blacklisted(struct plugins *plugins, const char *name) +{ + for (size_t i = 0; i < tal_count(plugins->blacklist); i++) + if (plugin_paths_match(name, plugins->blacklist[i])) + return true; + + return false; } void plugin_kill(struct plugin *plugin, const char *msg) @@ -1179,7 +1191,12 @@ char *add_plugin_dir(struct plugins *plugins, const char *dir, bool error_ok) if (streq(di->d_name, ".") || streq(di->d_name, "..")) continue; fullpath = plugin_fullpath(tmpctx, dir, di->d_name); - if (fullpath) { + if (!fullpath) + continue; + if (plugin_blacklisted(plugins, fullpath)) { + log_info(plugins->log, "%s: disabled via disable-plugin", + fullpath); + } else { p = plugin_register(plugins, fullpath, NULL); if (!p && !error_ok) return tal_fmt(NULL, "Failed to register %s: %s", diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 4460324d62de..63062bbf1c9d 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -100,6 +100,9 @@ struct plugins { /* If there are json commands waiting for plugin resolutions. */ struct command **json_cmds; + + /* Blacklist of plugins from --disable-plugin */ + const char **blacklist; }; /* The value of a plugin option, which can have different types. @@ -191,10 +194,18 @@ bool plugin_paths_match(const char *cmd, const char *name); * @param plugins: Plugin context * @param arg: The basename or fullname of the executable for this plugin */ -bool plugin_remove(struct plugins *plugins, const char *name); +void plugin_blacklist(struct plugins *plugins, const char *name); + +/** + * Is a plugin disabled?. + * + * @param plugins: Plugin context + * @param arg: The basename or fullname of the executable for this plugin + */ +bool plugin_blacklisted(struct plugins *plugins, const char *name); /** - * Kick of initialization of a plugin. + * Kick off initialization of a plugin. * * Returns error string, or NULL. */ diff --git a/tests/test_plugin.py b/tests/test_plugin.py index f2359f7d0469..a79674a6ef57 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -273,13 +273,14 @@ def test_plugin_command(node_factory): def test_plugin_disable(node_factory): """--disable-plugin works""" plugin_dir = os.path.join(os.getcwd(), 'contrib/plugins') - # We need plugin-dir before disable-plugin! + # We used to need plugin-dir before disable-plugin! n = node_factory.get_node(options=OrderedDict([('plugin-dir', plugin_dir), ('disable-plugin', '{}/helloworld.py' .format(plugin_dir))])) with pytest.raises(RpcError): n.rpc.hello(name='Sun') + assert n.daemon.is_in_log('helloworld.py: disabled via disable-plugin') # Also works by basename. n = node_factory.get_node(options=OrderedDict([('plugin-dir', plugin_dir), @@ -287,6 +288,39 @@ def test_plugin_disable(node_factory): 'helloworld.py')])) with pytest.raises(RpcError): n.rpc.hello(name='Sun') + assert n.daemon.is_in_log('helloworld.py: disabled via disable-plugin') + + # Other order also works! + n = node_factory.get_node(options=OrderedDict([('disable-plugin', + 'helloworld.py'), + ('plugin-dir', plugin_dir)])) + with pytest.raises(RpcError): + n.rpc.hello(name='Sun') + assert n.daemon.is_in_log('helloworld.py: disabled via disable-plugin') + + # Both orders of explicit specification work. + n = node_factory.get_node(options=OrderedDict([('disable-plugin', + 'helloworld.py'), + ('plugin', + '{}/helloworld.py' + .format(plugin_dir))])) + with pytest.raises(RpcError): + n.rpc.hello(name='Sun') + assert n.daemon.is_in_log('helloworld.py: disabled via disable-plugin') + + # Both orders of explicit specification work. + n = node_factory.get_node(options=OrderedDict([('plugin', + '{}/helloworld.py' + .format(plugin_dir)), + ('disable-plugin', + 'helloworld.py')])) + with pytest.raises(RpcError): + n.rpc.hello(name='Sun') + assert n.daemon.is_in_log('helloworld.py: disabled via disable-plugin') + + # Still disabled if we load directory. + n.rpc.plugin_startdir(directory=os.path.join(os.getcwd(), "contrib/plugins")) + n.daemon.wait_for_log('helloworld.py: disabled via disable-plugin') def test_plugin_hook(node_factory, executor): From 92c51e7acb7ac3888fa4d707f1774991f9c6de54 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:45:34 +0930 Subject: [PATCH 22/24] lightningd: list disabled plugins in listconfig. Signed-off-by: Rusty Russell --- lightningd/options.c | 3 ++- lightningd/plugin.c | 10 ++++++++++ lightningd/plugin.h | 6 ++++++ tests/test_plugin.py | 6 ++++++ 4 files changed, 24 insertions(+), 1 deletion(-) diff --git a/lightningd/options.c b/lightningd/options.c index 83cffbeaacbb..d8c5d9cfa2bc 100644 --- a/lightningd/options.c +++ b/lightningd/options.c @@ -1278,8 +1278,9 @@ static void add_config(struct lightningd *ld, json_add_opt_plugins(response, ld->plugins); } else if (opt->cb_arg == (void *)opt_log_level) { json_add_opt_log_levels(response, ld->log); + } else if (opt->cb_arg == (void *)opt_disable_plugin) { + json_add_opt_disable_plugins(response, ld->plugins); } else if (opt->cb_arg == (void *)opt_add_plugin_dir - || opt->cb_arg == (void *)opt_disable_plugin || opt->cb_arg == (void *)plugin_opt_set || opt->cb_arg == (void *)plugin_opt_flag_set) { /* FIXME: We actually treat it as if they specified diff --git a/lightningd/plugin.c b/lightningd/plugin.c index b465afd0a72d..54e017c834d0 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -180,6 +180,7 @@ void plugin_blacklist(struct plugins *plugins, const char *name) { struct plugin *p, *next; + log_debug(plugins->log, "blacklist for %s", name); list_for_each_safe(&plugins->plugins, p, next, list) { if (plugin_paths_match(p->cmd, name)) { log_info(plugins->log, "%s: disabled via disable-plugin", @@ -1453,6 +1454,15 @@ void json_add_opt_plugins(struct json_stream *response, json_array_end(response); } +void json_add_opt_disable_plugins(struct json_stream *response, + const struct plugins *plugins) +{ + json_array_start(response, "disable-plugin"); + for (size_t i = 0; i < tal_count(plugins->blacklist); i++) + json_add_string(response, NULL, plugins->blacklist[i]); + json_array_end(response); +} + /** * Determine whether a plugin is subscribed to a given topic/method. */ diff --git a/lightningd/plugin.h b/lightningd/plugin.h index 63062bbf1c9d..0b1442ceca86 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -274,6 +274,12 @@ void json_add_opt_plugins(struct json_stream *response, const struct plugins *plugins); +/** + * Add the disable-plugins options to listconfigs. + */ +void json_add_opt_disable_plugins(struct json_stream *response, + const struct plugins *plugins); + /** * Used by db hooks which can't have any other I/O while talking to plugin. * diff --git a/tests/test_plugin.py b/tests/test_plugin.py index a79674a6ef57..65dc9702a298 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -322,6 +322,12 @@ def test_plugin_disable(node_factory): n.rpc.plugin_startdir(directory=os.path.join(os.getcwd(), "contrib/plugins")) n.daemon.wait_for_log('helloworld.py: disabled via disable-plugin') + # Check that list works + n = node_factory.get_node(options={'disable-plugin': + ['something-else.py', 'helloworld.py']}) + + assert n.rpc.listconfigs()['disable-plugin'] == ['something-else.py', 'helloworld.py'] + def test_plugin_hook(node_factory, executor): """The helloworld plugin registers a htlc_accepted hook. From f157ada3dda5342d5c42446c114f8fc06a368b9c Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:45:47 +0930 Subject: [PATCH 23/24] lightningd: simplify plugin stdin/stdout initialization. There's no reason to assign the plugin vars inside the callback, so do that outside, and the tal_steal() is redundant (the plugin is already the conn parent). And reduce duplication by making plugin_conn_finish call plugin_kill: just make sure we don't call plugin_conn_finish again if plugin_kill is called externally. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 29 ++++++++--------------------- 1 file changed, 8 insertions(+), 21 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 54e017c834d0..557ba67a536e 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -212,6 +212,8 @@ void plugin_kill(struct plugin *plugin, const char *msg) plugin->start_cmd = NULL; } + /* Don't come back when we free stdout_conn! */ + io_set_finish(plugin->stdout_conn, NULL, NULL); tal_free(plugin); } @@ -518,22 +520,10 @@ static struct io_plan *plugin_write_json(struct io_conn *conn, return io_out_wait(conn, plugin, plugin_write_json, plugin); } -/** - * Finalizer for both stdin and stdout connections. - * - * Takes care of final cleanup, once the plugin is definitely dead. - */ +/* This catches the case where their stdout closes (usually they're dead). */ static void plugin_conn_finish(struct io_conn *conn, struct plugin *plugin) { - struct plugins *plugins = plugin->plugins; - plugin->stdout_conn = NULL; - if (plugin->start_cmd) { - plugin_cmd_killed(plugin->start_cmd, plugin, - "Plugin exited before completing handshake."); - plugin->start_cmd = NULL; - } - tal_free(plugin); - check_plugins_resolved(plugins); + plugin_kill(plugin, "Plugin exited before completing handshake."); } struct io_plan *plugin_stdin_conn_init(struct io_conn *conn, @@ -541,18 +531,15 @@ struct io_plan *plugin_stdin_conn_init(struct io_conn *conn, { /* We write to their stdin */ /* We don't have anything queued yet, wait for notification */ - plugin->stdin_conn = tal_steal(plugin, conn); - plugin->stdin_conn = conn; - return io_wait(plugin->stdin_conn, plugin, plugin_write_json, plugin); + return io_wait(conn, plugin, plugin_write_json, plugin); } struct io_plan *plugin_stdout_conn_init(struct io_conn *conn, struct plugin *plugin) { /* We read from their stdout */ - plugin->stdout_conn = conn; io_set_finish(conn, plugin_conn_finish, plugin); - return io_read_partial(plugin->stdout_conn, plugin->buffer, + return io_read_partial(conn, plugin->buffer, tal_bytelen(plugin->buffer), &plugin->len_read, plugin_read_json, plugin); } @@ -1260,8 +1247,8 @@ const char *plugin_send_getmanifest(struct plugin *p) /* Create two connections, one read-only on top of p->stdout, and one * write-only on p->stdin */ - io_new_conn(p, stdout, plugin_stdout_conn_init, p); - io_new_conn(p, stdin, plugin_stdin_conn_init, p); + p->stdout_conn = io_new_conn(p, stdout, plugin_stdout_conn_init, p); + p->stdin_conn = io_new_conn(p, stdin, plugin_stdin_conn_init, p); req = jsonrpc_request_start(p, "getmanifest", p->log, plugin_manifest_cb, p); jsonrpc_request_end(req); From b2ec70af0263361e13b1e554c0edb298c33ab049 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Tue, 5 May 2020 10:45:52 +0930 Subject: [PATCH 24/24] lightningd: fix obsolete comment. We unified this timeout with the 60 second startup timeout. Reported-by: @cdecker Signed-off-by: Rusty Russell --- lightningd/plugin_control.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lightningd/plugin_control.c b/lightningd/plugin_control.c index e78d1b6208a9..87ad14bf90db 100644 --- a/lightningd/plugin_control.c +++ b/lightningd/plugin_control.c @@ -53,7 +53,7 @@ struct command_result *plugin_cmd_all_complete(struct plugins *plugins, /** * Called when trying to start a plugin through RPC, it starts the plugin and - * will give a result 20 seconds later at the most. + * will give a result 60 seconds later at the most (once init completes). */ static struct command_result * plugin_dynamic_start(struct command *cmd, const char *plugin_path)