From a9aad0da982e0383e346c9bcbc8dce0240e22df8 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Thu, 11 Feb 2021 11:39:31 +1030 Subject: [PATCH] plugin: add log-level to plugin_kill, make it take format string. We currently log every kill at INFO level, even if it's during shutdown. Change those to debug, but lift those where we got a malformed response. Signed-off-by: Rusty Russell --- lightningd/plugin.c | 39 ++++++++++++++++++++++++++----------- lightningd/plugin.h | 4 +++- lightningd/plugin_control.c | 3 ++- 3 files changed, 33 insertions(+), 13 deletions(-) diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 0fb91c82b..2ac05de04 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -117,7 +117,7 @@ static void check_plugins_manifests(struct plugins *plugins) /* Only complain and free plugins! */ if (depfail[i]->plugin_state != NEEDS_INIT) continue; - plugin_kill(depfail[i], + plugin_kill(depfail[i], LOG_UNUSUAL, "Cannot meet required hook dependencies"); } @@ -287,9 +287,19 @@ bool plugin_blacklisted(struct plugins *plugins, const char *name) return false; } -void plugin_kill(struct plugin *plugin, const char *msg) +void plugin_kill(struct plugin *plugin, enum log_level loglevel, + const char *fmt, ...) { - log_info(plugin->log, "Killing plugin: %s", msg); + va_list ap; + const char *msg; + + va_start(ap, fmt); + msg = tal_vfmt(tmpctx, fmt, ap); + va_end(ap); + + log_(plugin->log, loglevel, + NULL, loglevel >= LOG_UNUSUAL, + "Killing plugin: %s", msg); kill(plugin->pid, SIGKILL); if (plugin->start_cmd) { plugin_cmd_killed(plugin->start_cmd, plugin, msg); @@ -605,7 +615,8 @@ static struct io_plan *plugin_read_json(struct io_conn *conn, return io_close(NULL); if (err) { - plugin_kill(plugin, err); + plugin_kill(plugin, LOG_UNUSUAL, + "%s", err); /* plugin_kill frees plugin */ return io_close(NULL); } @@ -648,8 +659,11 @@ static struct io_plan *plugin_write_json(struct io_conn *conn, /* This catches the case where their stdout closes (usually they're dead). */ static void plugin_conn_finish(struct io_conn *conn, struct plugin *plugin) { - const char *msg = tal_fmt(tmpctx, "exited %s", state_desc(plugin)); - plugin_kill(plugin, msg); + /* This is expected at shutdown of course. */ + plugin_kill(plugin, + plugin->plugins->shutdown + ? LOG_DBG : LOG_INFORM, + "exited %s", state_desc(plugin)); } struct io_plan *plugin_stdin_conn_init(struct io_conn *conn, @@ -1224,7 +1238,8 @@ static void plugin_manifest_timeout(struct plugin *plugin) { bool startup = plugin->plugins->startup; - plugin_kill(plugin, tal_fmt(tmpctx, "timed out %s", state_desc(plugin))); + plugin_kill(plugin, LOG_UNUSUAL, + "timed out %s", state_desc(plugin)); if (startup) fatal("Can't recover from plugin failure, terminating."); @@ -1356,8 +1371,9 @@ static void plugin_manifest_cb(const char *buffer, const char *err; err = plugin_parse_getmanifest_response(buffer, toks, idtok, plugin); + /* FIXME: log debug if it disabled *itself*! */ if (err) { - plugin_kill(plugin, err); + plugin_kill(plugin, LOG_INFORM, "%s", err); return; } @@ -1365,7 +1381,8 @@ static void plugin_manifest_cb(const char *buffer, plugin->timeout_timer = tal_free(plugin->timeout_timer); if (!plugin->plugins->startup && !plugin->dynamic) - plugin_kill(plugin, "Not a dynamic plugin"); + plugin_kill(plugin, LOG_INFORM, + "Not a dynamic plugin"); else check_plugins_manifests(plugin->plugins); } @@ -1554,7 +1571,7 @@ bool plugins_send_getmanifest(struct plugins *plugins) } if (plugins->startup) fatal("error starting plugin '%s': %s", p->cmd, err); - plugin_kill(p, err); + plugin_kill(p, LOG_UNUSUAL, "%s", err); } return sent; @@ -1607,7 +1624,7 @@ static void plugin_config_cb(const char *buffer, disable); /* Don't get upset if this was a built-in! */ plugin->important = false; - plugin_kill(plugin, disable); + plugin_kill(plugin, LOG_DBG, disable); return; } diff --git a/lightningd/plugin.h b/lightningd/plugin.h index ccba56f0b..f7954e568 100644 --- a/lightningd/plugin.h +++ b/lightningd/plugin.h @@ -18,6 +18,7 @@ #include #include #include +#include #include @@ -256,7 +257,8 @@ bool plugins_send_getmanifest(struct plugins *plugins); /** * Kill a plugin process and free @plugin, with an error message. */ -void plugin_kill(struct plugin *plugin, const char *msg); +void plugin_kill(struct plugin *plugin, enum log_level loglevel, + const char *fmt, ...); /** * Returns the plugin which registers the command with name {cmd_name} diff --git a/lightningd/plugin_control.c b/lightningd/plugin_control.c index d5eadfad4..f70ee7179 100644 --- a/lightningd/plugin_control.c +++ b/lightningd/plugin_control.c @@ -113,7 +113,8 @@ plugin_dynamic_stop(struct command *cmd, const char *plugin_name) "%s cannot be managed when " "lightningd is up", plugin_name); - plugin_kill(p, "stopped by lightningd via RPC"); + plugin_kill(p, LOG_INFORM, + "stopped by lightningd via RPC"); response = json_stream_success(cmd); json_add_string(response, "result", take(tal_fmt(NULL, "Successfully stopped %s.",