From e42f24e25662e70a2c13bb110974b5555708844b Mon Sep 17 00:00:00 2001 From: Vincenzo Palazzo Date: Thu, 11 Jan 2024 16:05:46 +0100 Subject: [PATCH 1/2] core: notify plugins when a log line is emitted. Currently make a plugin that do reportings of logs on a services like graphana is not possible. So this commit include the possibility to write a plugin that do the report of this analisys. Changelog-Added: core: notify plugins when a log line is emitted. Signed-off-by: Vincenzo Palazzo --- common/Makefile | 1 + common/plugin.c | 15 +++++++++++++++ common/plugin.h | 13 +++++++++++++ lightningd/Makefile | 3 ++- lightningd/log.c | 8 ++++++++ lightningd/notification.c | 24 ++++++++++++++++++++++-- lightningd/notification.h | 2 ++ lightningd/plugin.c | 6 +++--- lightningd/test/run-log-pruning.c | 6 ++++++ lightningd/test/run-log_filter.c | 4 ++++ plugins/Makefile | 1 + plugins/bkpr/test/run-bkpr_db.c | 4 ++++ plugins/bkpr/test/run-recorder.c | 4 ++++ plugins/libplugin.c | 4 +++- 14 files changed, 88 insertions(+), 7 deletions(-) create mode 100644 common/plugin.c create mode 100644 common/plugin.h diff --git a/common/Makefile b/common/Makefile index 4c8c946f6418..20ece55680a8 100644 --- a/common/Makefile +++ b/common/Makefile @@ -77,6 +77,7 @@ COMMON_SRC_NOGEN := \ common/per_peer_state.c \ common/permute_tx.c \ common/ping.c \ + common/plugin.c \ common/psbt_internal.c \ common/psbt_keypath.c \ common/psbt_open.c \ diff --git a/common/plugin.c b/common/plugin.c new file mode 100644 index 000000000000..ae65e0a39f3e --- /dev/null +++ b/common/plugin.c @@ -0,0 +1,15 @@ +#include "config.h" +#include +#include + +bool is_asterix_notification(const char *notification_name, const char *subscription) +{ + bool is_special; + /* Asterisk is magic "all", and log notification + * is a special notification that must be turn on + * only if requested. */ + is_special = streq(subscription, "*") && !streq(notification_name, "log"); + if (is_special) + return true; + return false; +} diff --git a/common/plugin.h b/common/plugin.h new file mode 100644 index 000000000000..df6e7e169b62 --- /dev/null +++ b/common/plugin.h @@ -0,0 +1,13 @@ +#ifndef LIGHTNING_COMMON_PLUGIN_H +#define LIGHTNING_COMMON_PLUGIN_H + +#include "config.h" +#include + +/* is_magic_notification - check if the notification name + * is a special notification and need to be handled in a + * special way. */ +bool is_asterix_notification(const char *notification_name, + const char *subscriptions); + +#endif /* LIGHTNING_COMMON_PLUGIN_H */ diff --git a/lightningd/Makefile b/lightningd/Makefile index d7243855f670..0c8aa0ba5a68 100644 --- a/lightningd/Makefile +++ b/lightningd/Makefile @@ -131,9 +131,10 @@ LIGHTNINGD_COMMON_OBJS := \ common/penalty_base.o \ common/per_peer_state.o \ common/permute_tx.o \ - common/psbt_keypath.o \ + common/psbt_keypath.o \ common/psbt_open.o \ common/pseudorand.o \ + common/plugin.o \ common/random_select.o \ common/setup.o \ common/shutdown_scriptpubkey.o \ diff --git a/lightningd/log.c b/lightningd/log.c index 316890115fde..0d7592d74101 100644 --- a/lightningd/log.c +++ b/lightningd/log.c @@ -540,6 +540,13 @@ static void maybe_print(struct logger *log, const struct log_entry *l) log->log_book->log_files); } +static void maybe_notify_log(struct logger *log, + const struct log_entry *l) +{ + if (l->level >= log->print_level) + notify_log(log->log_book->ld, l); +} + void logv(struct logger *log, enum log_level level, const struct node_id *node_id, bool call_notifier, @@ -561,6 +568,7 @@ void logv(struct logger *log, enum log_level level, l->log[i] = '?'; maybe_print(log, l); + maybe_notify_log(log, l); add_entry(log, &l); diff --git a/lightningd/notification.c b/lightningd/notification.c index 09dddf3106f3..cdaa24c9ab59 100644 --- a/lightningd/notification.c +++ b/lightningd/notification.c @@ -3,6 +3,7 @@ #include #include #include +#include #include bool notifications_topic_is_native(const char *topic) @@ -135,8 +136,7 @@ static void warning_notification_serialize(struct json_stream *stream, /* Choose "BROKEN"/"UNUSUAL" to keep consistent with the habit * of plugin. But this may confuses the users who want to 'getlog' * with the level indicated by notifications. It is the duty of a - * plugin to eliminate this misunderstanding. - */ + * plugin to eliminate this misunderstanding. */ json_add_string(stream, "level", l->level == LOG_BROKEN ? "error" : "warn"); @@ -618,3 +618,23 @@ bool notify_deprecated_oneshot(struct lightningd *ld, return plugin_single_notify(p, take(n)); } REGISTER_NOTIFICATION(deprecated_oneshot); + +static void log_notification_serialize(struct json_stream *stream, + const struct log_entry *l) +{ + json_add_string(stream, "level", log_level_name(l->level)); + json_add_timestr(stream, "time", l->time.ts); + json_add_timeiso(stream, "timestamp", l->time); + json_add_string(stream, "source", l->prefix->prefix); + json_add_string(stream, "log", l->log); +} + + +REGISTER_NOTIFICATION(log); + +void notify_log(struct lightningd *ld, const struct log_entry *l) +{ + struct jsonrpc_notification *n = notify_start("log"); + log_notification_serialize(n->stream, l); + notify_send(ld, n); +} diff --git a/lightningd/notification.h b/lightningd/notification.h index 0fff00c989ff..1c676f7eb0d6 100644 --- a/lightningd/notification.h +++ b/lightningd/notification.h @@ -107,4 +107,6 @@ bool notify_deprecated_oneshot(struct lightningd *ld, /* Tell this plugin to shutdown: returns true if it was subscribed. */ bool notify_plugin_shutdown(struct lightningd *ld, struct plugin *p); +/* Inform the plugin when a log line is emitted */ +void notify_log(struct lightningd *ld, const struct log_entry *l); #endif /* LIGHTNING_LIGHTNINGD_NOTIFICATION_H */ diff --git a/lightningd/plugin.c b/lightningd/plugin.c index 2110d86be957..bcc4224d0513 100644 --- a/lightningd/plugin.c +++ b/lightningd/plugin.c @@ -15,6 +15,7 @@ #include #include #include +#include #include #include #include @@ -2402,10 +2403,9 @@ static bool plugin_subscriptions_contains(struct plugin *plugin, { for (size_t i = 0; i < tal_count(plugin->subscriptions); i++) { if (streq(method, plugin->subscriptions[i]) - /* Asterisk is magic "all" */ - || streq(plugin->subscriptions[i], "*")) { + || is_asterix_notification(method, + plugin->subscriptions[i])) return true; - } } return false; diff --git a/lightningd/test/run-log-pruning.c b/lightningd/test/run-log-pruning.c index e6dfd00c1465..795f50025c54 100644 --- a/lightningd/test/run-log-pruning.c +++ b/lightningd/test/run-log-pruning.c @@ -84,6 +84,12 @@ const char *log_level_name(enum log_level level UNNEEDED) bool log_level_parse(const char *levelstr UNNEEDED, size_t len UNNEEDED, enum log_level *level UNNEEDED) { fprintf(stderr, "log_level_parse called!\n"); abort(); } +/* Generated stub for node_id_to_hexstr */ +char *node_id_to_hexstr(const tal_t *ctx UNNEEDED, const struct node_id *id UNNEEDED) +{ fprintf(stderr, "node_id_to_hexstr called!\n"); abort(); } +/* Generated stub for notify_log */ +void notify_log(struct lightningd *ld UNNEEDED, const struct log_entry *l UNNEEDED) +{ fprintf(stderr, "notify_log called!\n"); abort(); } /* Generated stub for notify_warning */ void notify_warning(struct lightningd *ld UNNEEDED, struct log_entry *l UNNEEDED) { fprintf(stderr, "notify_warning called!\n"); abort(); } diff --git a/lightningd/test/run-log_filter.c b/lightningd/test/run-log_filter.c index f2d12494f693..bbf340f02fec 100644 --- a/lightningd/test/run-log_filter.c +++ b/lightningd/test/run-log_filter.c @@ -7,8 +7,12 @@ #define fwrite test_fwrite static size_t test_fwrite(const void *ptr, size_t size, size_t nmemb, FILE *stream); + #include "../log.c" +void notify_log(struct lightningd *ld UNNEEDED, const struct log_entry *l UNNEEDED) +{ } + /* AUTOGENERATED MOCKS START */ /* Generated stub for command_fail */ struct command_result *command_fail(struct command *cmd UNNEEDED, enum jsonrpc_errcode code UNNEEDED, diff --git a/plugins/Makefile b/plugins/Makefile index e9c067674ac1..faafac18ade3 100644 --- a/plugins/Makefile +++ b/plugins/Makefile @@ -166,6 +166,7 @@ PLUGIN_COMMON_OBJS := \ common/lease_rates.o \ common/memleak.o \ common/node_id.o \ + common/plugin.o \ common/psbt_open.o \ common/pseudorand.o \ common/random_select.o \ diff --git a/plugins/bkpr/test/run-bkpr_db.c b/plugins/bkpr/test/run-bkpr_db.c index 04ffe463f916..d9ee7bda45d6 100644 --- a/plugins/bkpr/test/run-bkpr_db.c +++ b/plugins/bkpr/test/run-bkpr_db.c @@ -94,6 +94,10 @@ int htlc_state_flags(enum htlc_state state UNNEEDED) /* Generated stub for htlc_state_name */ const char *htlc_state_name(enum htlc_state s UNNEEDED) { fprintf(stderr, "htlc_state_name called!\n"); abort(); } +/* Generated stub for is_asterix_notification */ +bool is_asterix_notification(const char *notification_name UNNEEDED, + const char *subscriptions UNNEEDED) +{ fprintf(stderr, "is_asterix_notification called!\n"); abort(); } /* Generated stub for json_get_id */ const char *json_get_id(const tal_t *ctx UNNEEDED, const char *buffer UNNEEDED, const jsmntok_t *obj UNNEEDED) diff --git a/plugins/bkpr/test/run-recorder.c b/plugins/bkpr/test/run-recorder.c index 73fcf54a88fd..f38391cfbd2d 100644 --- a/plugins/bkpr/test/run-recorder.c +++ b/plugins/bkpr/test/run-recorder.c @@ -100,6 +100,10 @@ int htlc_state_flags(enum htlc_state state UNNEEDED) /* Generated stub for htlc_state_name */ const char *htlc_state_name(enum htlc_state s UNNEEDED) { fprintf(stderr, "htlc_state_name called!\n"); abort(); } +/* Generated stub for is_asterix_notification */ +bool is_asterix_notification(const char *notification_name UNNEEDED, + const char *subscriptions UNNEEDED) +{ fprintf(stderr, "is_asterix_notification called!\n"); abort(); } /* Generated stub for json_get_id */ const char *json_get_id(const tal_t *ctx UNNEEDED, const char *buffer UNNEEDED, const jsmntok_t *obj UNNEEDED) diff --git a/plugins/libplugin.c b/plugins/libplugin.c index a2acab60485c..a79b3038c6d1 100644 --- a/plugins/libplugin.c +++ b/plugins/libplugin.c @@ -12,6 +12,7 @@ #include #include #include +#include #include #include #include @@ -1740,7 +1741,8 @@ static void ld_command_handle(struct plugin *plugin, for (size_t i = 0; i < plugin->num_notif_subs; i++) { if (streq(cmd->methodname, plugin->notif_subs[i].name) - || streq(plugin->notif_subs[i].name, "*")) { + || is_asterix_notification(cmd->methodname, + plugin->notif_subs[i].name)) { plugin->notif_subs[i].handle(cmd, plugin->buffer, paramstok); From 6c67b7bbd56699949f39f4cd0aa91bfd76a6272b Mon Sep 17 00:00:00 2001 From: Vincenzo Palazzo Date: Thu, 11 Jan 2024 18:34:03 +0100 Subject: [PATCH 2/2] docs: adds documentation about the log notification Changelog-None: docs: adds documentation about the log notification Signed-off-by: Vincenzo Palazzo --- doc/developers-guide/plugin-development/event-notifications.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/doc/developers-guide/plugin-development/event-notifications.md b/doc/developers-guide/plugin-development/event-notifications.md index 3e24ee0c7ef9..7d3aeba994af 100644 --- a/doc/developers-guide/plugin-development/event-notifications.md +++ b/doc/developers-guide/plugin-development/event-notifications.md @@ -207,6 +207,8 @@ A notification for topic `warning` is sent every time a new `BROKEN`/`UNUSUAL` l `jcon fd :`, `plugin-manager`; 4. `log` is the context of the original log entry. +There is also a more general version of this notification called `log`, which has the same payload. This needs to be used with caution, but it is useful for plugins that report logs remotely. For example: using OpenTelemetry. + ### `forward_event` A notification for topic `forward_event` is sent every time the status of a forward payment is set. The json format is same as the API `listforwards`.