[RFC] core: notify plugins when a log line is emitted

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			\

common/plugin.c

@@ -0,0 +1,15 @@
+#include "config.h"
+#include <ccan/tal/str/str.h>
+#include <common/plugin.h>
+
+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;
+}

common/plugin.h

@@ -0,0 +1,13 @@
+#ifndef LIGHTNING_COMMON_PLUGIN_H
+#define LIGHTNING_COMMON_PLUGIN_H
+
+#include "config.h"
+#include <stdbool.h>
+
+/* 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 */

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 <error_fd_to_jsonrpc>:`, `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`.

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		\

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);
 

lightningd/notification.c

@@ -3,6 +3,7 @@
 #include <common/configdir.h>
 #include <lightningd/channel.h>
 #include <lightningd/coin_mvts.h>
+#include <lightningd/log.h>
 #include <lightningd/notification.h>
 
 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);
+}

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 */

lightningd/plugin.c

@@ -15,6 +15,7 @@
 #include <common/features.h>
 #include <common/json_command.h>
 #include <common/memleak.h>
+#include <common/plugin.h>
 #include <common/timeout.h>
 #include <common/version.h>
 #include <connectd/connectd_wiregen.h>
@@ -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;

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(); }

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,

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			\

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)

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)

plugins/libplugin.c

@@ -12,6 +12,7 @@
 #include <common/json_parse_simple.h>
 #include <common/json_stream.h>
 #include <common/memleak.h>
+#include <common/plugin.h>
 #include <common/route.h>
 #include <errno.h>
 #include <plugins/libplugin.h>
@@ -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);