From: Daan De Meyer <daan.j.demeyer@gmail.com>
Date: Mon, 11 Oct 2021 13:05:08 +0000 (+0100)
Subject: journal: Don't discard kmsg messages coming from journald itself
X-Git-Tag: v250-rc1~215
X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=9c4161800898513914f2c99faefe528c1aecbd40;p=thirdparty%2Fsystemd.git

journal: Don't discard kmsg messages coming from journald itself

Previously, we discarded any kmsg messages coming from journald
itself to avoid infinite loops where potentially the processing
of a kmsg message causes journald to log one or more messages to
kmsg which then get read again by the kmsg handler, ...

However, if we completely disable logging whenever we're processing
a kmsg message coming from journald itself, we also prevent any
infinite loops as we can be sure that journald won't accidentally
generate logging messages while processing a kmsg log message.

This change allows us to store all journald logs generated during
the processing of log messages from other services in the system
journal. Previously these could only be found in kmsg which has
low retention, can't be queried using journalctl and whose logs
don't survive reboots.
---

diff --git a/src/basic/log.c b/src/basic/log.c
index 983e5bc69c4..7bc2f280073 100644
--- a/src/basic/log.c
+++ b/src/basic/log.c
@@ -358,7 +358,7 @@ void log_forget_fds(void) {
 }
 
 void log_set_max_level(int level) {
-        assert((level & LOG_PRIMASK) == level);
+        assert(level == LOG_NULL || (level & LOG_PRIMASK) == level);
 
         log_max_level = level;
 }
diff --git a/src/basic/log.h b/src/basic/log.h
index b34bdffd1b8..3bec4131a79 100644
--- a/src/basic/log.h
+++ b/src/basic/log.h
@@ -27,6 +27,10 @@ typedef enum LogTarget{
         _LOG_TARGET_INVALID = -EINVAL,
 } LogTarget;
 
+/* This log level disables logging completely. It can only be passed to log_set_max_level() and cannot be
+ * used a regular log level. */
+#define LOG_NULL (LOG_EMERG - 1)
+
 /* Note to readers: << and >> have lower precedence than & and | */
 #define SYNTHETIC_ERRNO(num)                (1 << 30 | (num))
 #define IS_SYNTHETIC_ERRNO(val)             ((val) >> 30 & 1)
diff --git a/src/journal/journald-kmsg.c b/src/journal/journald-kmsg.c
index c96b84e61f8..a9b745772bb 100644
--- a/src/journal/journald-kmsg.c
+++ b/src/journal/journald-kmsg.c
@@ -19,6 +19,7 @@
 #include "journald-kmsg.h"
 #include "journald-server.h"
 #include "journald-syslog.h"
+#include "log.h"
 #include "parse-util.h"
 #include "process-util.h"
 #include "stdio-util.h"
@@ -106,6 +107,8 @@ void dev_kmsg_record(Server *s, char *p, size_t l) {
         char *e, *f, *k;
         uint64_t serial;
         size_t pl;
+        int saved_log_max_level = INT_MAX;
+        ClientContext *c = NULL;
 
         assert(s);
         assert(p);
@@ -266,10 +269,16 @@ void dev_kmsg_record(Server *s, char *p, size_t l) {
         else {
                 pl -= syslog_parse_identifier((const char**) &p, &identifier, &pid);
 
-                /* Avoid any messages we generated ourselves via
-                 * log_info() and friends. */
-                if (is_us(identifier, pid))
-                        goto finish;
+                /* Avoid logging any new messages when we're processing messages generated by ourselves via
+                 * log_info() and friends to avoid infinite loops. */
+                if (is_us(identifier, pid)) {
+                        if (!ratelimit_below(&s->kmsg_own_ratelimit))
+                                return;
+
+                        saved_log_max_level = log_get_max_level();
+                        c = s->my_context;
+                        log_set_max_level(LOG_NULL);
+                }
 
                 if (identifier) {
                         syslog_identifier = strjoin("SYSLOG_IDENTIFIER=", identifier);
@@ -287,7 +296,11 @@ void dev_kmsg_record(Server *s, char *p, size_t l) {
         if (cunescape_length_with_prefix(p, pl, "MESSAGE=", UNESCAPE_RELAX, &message) >= 0)
                 iovec[n++] = IOVEC_MAKE_STRING(message);
 
-        server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, NULL, priority, 0);
+
+        server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), c, NULL, priority, 0);
+
+        if (saved_log_max_level != INT_MAX)
+                log_set_max_level(saved_log_max_level);
 
 finish:
         for (j = 0; j < z; j++)
diff --git a/src/journal/journald-server.c b/src/journal/journald-server.c
index ed53d320059..8e2990190ba 100644
--- a/src/journal/journald-server.c
+++ b/src/journal/journald-server.c
@@ -65,6 +65,9 @@
 #define DEFAULT_RATE_LIMIT_BURST 10000
 #define DEFAULT_MAX_FILE_USEC USEC_PER_MONTH
 
+#define DEFAULT_KMSG_OWN_INTERVAL (5 * USEC_PER_SEC)
+#define DEFAULT_KMSG_OWN_BURST 50
+
 #define RECHECK_SPACE_USEC (30*USEC_PER_SEC)
 
 #define NOTIFY_SNDBUF_SIZE (8*1024*1024)
@@ -2212,6 +2215,11 @@ int server_init(Server *s, const char *namespace) {
 
                 .runtime_storage.name = "Runtime Journal",
                 .system_storage.name = "System Journal",
+
+                .kmsg_own_ratelimit = {
+                        .interval = DEFAULT_KMSG_OWN_INTERVAL,
+                        .burst = DEFAULT_KMSG_OWN_BURST,
+                },
         };
 
         r = set_namespace(s, namespace);
diff --git a/src/journal/journald-server.h b/src/journal/journald-server.h
index 53e75ff3b0b..2e57905e03b 100644
--- a/src/journal/journald-server.h
+++ b/src/journal/journald-server.h
@@ -16,6 +16,7 @@ typedef struct Server Server;
 #include "journald-stream.h"
 #include "list.h"
 #include "prioq.h"
+#include "ratelimit.h"
 #include "time-util.h"
 #include "varlink.h"
 
@@ -142,6 +143,7 @@ struct Server {
 
         uint64_t *kernel_seqnum;
         bool dev_kmsg_readable:1;
+        RateLimit kmsg_own_ratelimit;
 
         bool send_watchdog:1;
         bool sent_notify_ready:1;