common: don't send trace messages by default, don't ratelimit at all.

common/status.c

@@ -15,12 +15,9 @@
 static int status_fd = -1;
 static struct daemon_conn *status_conn;
 volatile bool logging_io = false;
+bool logging_trace = false;
 static bool was_logging_io;
 
-/* If we're more than this many msgs deep, don't add debug messages. */
-#define TRACE_QUEUE_LIMIT 20
-static size_t traces_suppressed;
-
 static void got_sigusr1(int signal UNUSED)
 {
 	logging_io = !logging_io;
@@ -149,22 +146,10 @@ void status_vfmt(enum log_level level,
 {
 	char *str;
 
-	/* We only suppress async debug msgs.  IO messages are even spammier
-	 * but they only occur when explicitly asked for */
-	if ((level == LOG_DBG || level == LOG_TRACE) && status_conn) {
-		size_t qlen = daemon_conn_queue_length(status_conn);
-
-		/* Once suppressing, we keep suppressing until we're empty */
-		if (traces_suppressed && qlen == 0) {
-			size_t n = traces_suppressed;
-			traces_suppressed = 0;
-			/* Careful: recursion! */
-			status_trace("...[%zu debug/trace messages suppressed]...", n);
-		} else if (traces_suppressed || qlen > TRACE_QUEUE_LIMIT) {
-			traces_suppressed++;
-			return;
-		}
-	}
+	/* These are spammy, so only log if requested (or IO logging)*/
+	if (level == LOG_TRACE && (!logging_trace && !logging_io))
+		return;
+
 	str = tal_vfmt(NULL, fmt, ap);
 	status_send(take(towire_status_log(NULL, level, peer, str)));
 	tal_free(str);

common/status.h

@@ -26,6 +26,8 @@ void status_vfmt(enum log_level level,
 
 /* Usually we only log the packet names, not contents. */
 extern volatile bool logging_io;
+/* Usually we don't bother with TRACE spam */
+extern bool logging_trace;
 
 /* This logs a debug summary if IO logging not enabled. */
 void status_peer_io(enum log_level iodir,

common/subdaemon.c

@@ -30,6 +30,8 @@ bool subdaemon_setup(int argc, char *argv[])
 	for (int i = 1; i < argc; i++) {
 		if (streq(argv[i], "--log-io"))
 			logging_io = true;
+		if (streq(argv[i], "--log-trace"))
+			logging_trace = true;
 	}
 
 	developer = daemon_developer_mode(argv);

connectd/test/run-netaddress.c

@@ -53,9 +53,6 @@ u8 *b32_decode(const tal_t *ctx UNNEEDED, const char *str UNNEEDED, size_t len U
 /* Generated stub for b32_encode */
 char *b32_encode(const tal_t *ctx UNNEEDED, const void *data UNNEEDED, size_t len UNNEEDED)
 { fprintf(stderr, "b32_encode called!\n"); abort(); }
-/* Generated stub for daemon_conn_queue_length */
-size_t daemon_conn_queue_length(const struct daemon_conn *dc UNNEEDED)
-{ fprintf(stderr, "daemon_conn_queue_length called!\n"); abort(); }
 /* Generated stub for daemon_conn_send */
 void daemon_conn_send(struct daemon_conn *dc UNNEEDED, const u8 *msg UNNEEDED)
 { fprintf(stderr, "daemon_conn_send called!\n"); abort(); }

lightningd/log.c

@@ -478,6 +478,11 @@ bool log_has_io_logging(const struct logger *log)
 	return print_level(log->log_book, log->prefix, log->default_node_id, NULL) < LOG_TRACE;
 }
 
+bool log_has_trace_logging(const struct logger *log)
+{
+	return print_level(log->log_book, log->prefix, log->default_node_id, NULL) < LOG_DBG;
+}
+
 /* This may move entry! */
 static void add_entry(struct logger *log, struct log_entry **l)
 {

lightningd/log.h

@@ -48,6 +48,8 @@ void logv(struct logger *logger, enum log_level level, const struct node_id *nod
 const char *log_prefix(const struct logger *logger);
 /* Is there any chance we do io-level logging for this node_id in log? */
 bool log_has_io_logging(const struct logger *log);
+/* How about trace logging? */
+bool log_has_trace_logging(const struct logger *log);
 
 void opt_register_logging(struct lightningd *ld);
 

lightningd/subd.c

@@ -205,6 +205,7 @@ static int subd(const char *path, const char *name,
 		bool debugging,
 		int *msgfd,
 		bool io_logging,
+		bool trace_logging,
 		bool developer,
 		va_list *ap)
 {
@@ -228,7 +229,7 @@ static int subd(const char *path, const char *name,
 
 	if (childpid == 0) {
 		size_t num_args;
-		char *args[] = { NULL, NULL, NULL, NULL, NULL };
+		char *args[] = { NULL, NULL, NULL, NULL, NULL, NULL };
 		int **fds = tal_arr(tmpctx, int *, 3);
 		int stdoutfd = STDOUT_FILENO, stderrfd = STDERR_FILENO;
 
@@ -259,6 +260,8 @@ static int subd(const char *path, const char *name,
 		args[num_args++] = tal_strdup(NULL, path);
 		if (io_logging)
 			args[num_args++] = "--log-io";
+		if (trace_logging)
+			args[num_args++] = "--log-trace";
 		if (debugging)
 			args[num_args++] = "--dev-debug-self";
 		if (developer)
@@ -742,9 +745,10 @@ static struct subd *new_subd(const tal_t *ctx,
 
 	sd->pid = subd(path, name, debugging(ld, name),
 		       &msg_fd,
-		       /* We only turn on subdaemon io logging if we're going
+		       /* We only turn on subdaemon io/trace logging if we're going
 			* to print it: too stressful otherwise! */
 		       log_has_io_logging(sd->log),
+		       log_has_trace_logging(sd->log),
 		       ld->developer,
 		       ap);
 	if (sd->pid == (pid_t)-1) {

lightningd/test/run-find_my_abspath.c

@@ -173,6 +173,9 @@ void log_backtrace_print(const char *fmt UNNEEDED, ...)
 /* Generated stub for log_has_io_logging */
 bool log_has_io_logging(const struct logger *log UNNEEDED)
 { fprintf(stderr, "log_has_io_logging called!\n"); abort(); }
+/* Generated stub for log_has_trace_logging */
+bool log_has_trace_logging(const struct logger *log UNNEEDED)
+{ fprintf(stderr, "log_has_trace_logging called!\n"); abort(); }
 /* Generated stub for log_prefix */
 const char *log_prefix(const struct logger *logger UNNEEDED)
 { fprintf(stderr, "log_prefix called!\n"); abort(); }

lightningd/test/run-shuffle_fds.c

@@ -86,6 +86,9 @@ void log_(struct logger *logger UNNEEDED, enum log_level level UNNEEDED,
 /* Generated stub for log_has_io_logging */
 bool log_has_io_logging(const struct logger *log UNNEEDED)
 { fprintf(stderr, "log_has_io_logging called!\n"); abort(); }
+/* Generated stub for log_has_trace_logging */
+bool log_has_trace_logging(const struct logger *log UNNEEDED)
+{ fprintf(stderr, "log_has_trace_logging called!\n"); abort(); }
 /* Generated stub for log_prefix */
 const char *log_prefix(const struct logger *logger UNNEEDED)
 { fprintf(stderr, "log_prefix called!\n"); abort(); }