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 983e5bc69c4511cc14705d57e8f6fbfc4b2e2fbf..7bc2f280073b0b64682c679f0ea73beefabba725 100644 (file)
--- 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 b34bdffd1b8fed1811e2bb874520e4d56c9c4b76..3bec4131a79ae527af0ed16236af082138a1eb5f 100644 (file)
--- 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 c96b84e61f841c8d7314d1a61b41a7d70e9a3692..a9b745772bb3590f035731f9526a5b9e8d33e8bc 100644 (file)
--- 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 ed53d320059c6d5884e07278e5b7c1267c10a48a..8e2990190ba2ee29652947e55c32c10ad7965f76 100644 (file)
--- 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 53e75ff3b0b3f5ec8f54295bfb8006b470494068..2e57905e03b847dd44d36021c3d3996568ce7507 100644 (file)
--- 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;