journald: allow additional payload in server_driver_message

The code to format the iovec is shared with log.c. All call sites to
server_driver_message are changed to include the additional "MESSAGE="
part, but the new functionality is not used and change in functionality
is not expected.

iovec is preallocated, so the maximum number of messages is limited.
In server_driver_message N_IOVEC_PAYLOAD_FIELDS is currently set to 1.

New code is not oom safe, it will fail if memory cannot be allocated.
This will be fixed in subsequent commit.

7 files changed, 102 insertions, 55 deletions

diff --git a/src/basic/log.c b/src/basic/log.c
index a2bc0d5be2..18d4b82be2 100644
--- a/src/basic/log.c
+++ b/src/basic/log.c
@@ -805,6 +805,52 @@ int log_oom_internal(const char *file, int line, const char *func) {
         return -ENOMEM;
 }
 
+int log_format_iovec(
+                struct iovec *iovec,
+                unsigned iovec_len,
+                unsigned *n,
+                bool newline_separator,
+                int error,
+                const char *format,
+                va_list ap) {
+
+        static const char nl = '\n';
+
+        while (format && *n + 1 < iovec_len) {
+                va_list aq;
+                char *m;
+                int r;
+
+                /* We need to copy the va_list structure,
+                 * since vasprintf() leaves it afterwards at
+                 * an undefined location */
+
+                if (error != 0)
+                        errno = error;
+
+                va_copy(aq, ap);
+                r = vasprintf(&m, format, aq);
+                va_end(aq);
+                if (r < 0)
+                        return -EINVAL;
+
+                /* Now, jump enough ahead, so that we point to
+                 * the next format string */
+                VA_FORMAT_ADVANCE(format, ap);
+
+                IOVEC_SET_STRING(iovec[(*n)++], m);
+
+                if (newline_separator) {
+                        iovec[*n].iov_base = (char*) &nl;
+                        iovec[*n].iov_len = 1;
+                        (*n)++;
+                }
+
+                format = va_arg(ap, char *);
+        }
+        return 0;
+}
+
 int log_struct_internal(
                 int level,
                 int error,
@@ -837,10 +883,10 @@ int log_struct_internal(
                 char header[LINE_MAX];
                 struct iovec iovec[17] = {};
                 unsigned n = 0, i;
+                int r;
                 struct msghdr mh = {
                         .msg_iov = iovec,
                 };
-                static const char nl = '\n';
                 bool fallback = false;
 
                 /* If the journal is available do structured logging */
@@ -848,43 +894,14 @@ int log_struct_internal(
                 IOVEC_SET_STRING(iovec[n++], header);
 
                 va_start(ap, format);
-                while (format && n + 1 < ELEMENTSOF(iovec)) {
-                        va_list aq;
-                        char *m;
-
-                        /* We need to copy the va_list structure,
-                         * since vasprintf() leaves it afterwards at
-                         * an undefined location */
-
-                        if (error != 0)
-                                errno = error;
-
-                        va_copy(aq, ap);
-                        if (vasprintf(&m, format, aq) < 0) {
-                                va_end(aq);
-                                fallback = true;
-                                goto finish;
-                        }
-                        va_end(aq);
-
-                        /* Now, jump enough ahead, so that we point to
-                         * the next format string */
-                        VA_FORMAT_ADVANCE(format, ap);
-
-                        IOVEC_SET_STRING(iovec[n++], m);
-
-                        iovec[n].iov_base = (char*) &nl;
-                        iovec[n].iov_len = 1;
-                        n++;
-
-                        format = va_arg(ap, char *);
+                r = log_format_iovec(iovec, ELEMENTSOF(iovec), &n, true, error, format, ap);
+                if (r < 0)
+                        fallback = true;
+                else {
+                        mh.msg_iovlen = n;
+                        (void) sendmsg(journal_fd, &mh, MSG_NOSIGNAL);
                 }
 
-                mh.msg_iovlen = n;
-
-                (void) sendmsg(journal_fd, &mh, MSG_NOSIGNAL);
-
-        finish:
                 va_end(ap);
                 for (i = 1; i < n; i += 2)
                         free(iovec[i].iov_base);
diff --git a/src/basic/log.h b/src/basic/log.h
index cda1e45cc8..8c7c5e4598 100644
--- a/src/basic/log.h
+++ b/src/basic/log.h
@@ -26,6 +26,7 @@
 #include <stdbool.h>
 #include <stdlib.h>
 #include <sys/signalfd.h>
+#include <sys/socket.h>
 #include <syslog.h>
 
 #include "sd-id128.h"
@@ -127,6 +128,15 @@ int log_oom_internal(
                 int line,
                 const char *func);
 
+int log_format_iovec(
+                struct iovec *iovec,
+                unsigned iovec_len,
+                unsigned *n,
+                bool newline_separator,
+                int error,
+                const char *format,
+                va_list ap);
+
 /* This modifies the buffer passed! */
 int log_dump_internal(
                 int level,
diff --git a/src/journal/journald-kmsg.c b/src/journal/journald-kmsg.c
index e048e04716..1306ad6974 100644
--- a/src/journal/journald-kmsg.c
+++ b/src/journal/journald-kmsg.c
@@ -158,8 +158,10 @@ static void dev_kmsg_record(Server *s, const char *p, size_t l) {
 
                 /* Did we lose any? */
                 if (serial > *s->kernel_seqnum)
-                        server_driver_message(s, SD_MESSAGE_JOURNAL_MISSED, "Missed %"PRIu64" kernel messages",
-                                              serial - *s->kernel_seqnum);
+                        server_driver_message(s, SD_MESSAGE_JOURNAL_MISSED,
+                                              LOG_MESSAGE("Missed %"PRIu64" kernel messages",
+                                                          serial - *s->kernel_seqnum),
+                                              NULL);
 
                 /* Make sure we never read this one again. Note that
                  * we always store the next message serial we expect
diff --git a/src/journal/journald-server.c b/src/journal/journald-server.c
index cfcc2c4302..6df71953e8 100644
--- a/src/journal/journald-server.c
+++ b/src/journal/journald-server.c
@@ -70,6 +70,7 @@
 #include "string-table.h"
 #include "string-util.h"
 #include "user-util.h"
+#include "log.h"
 
 #define USER_JOURNALS_MAX 1024
 
@@ -142,7 +143,7 @@ static int determine_space_for(
                 sum += (uint64_t) st.st_blocks * 512UL;
         }
 
-        /* If request, then let's bump the min_use limit to the
+        /* If requested, then let's bump the min_use limit to the
          * current usage on disk. We do this when starting up and
          * first opening the journal files. This way sudden spikes in
          * disk usage will not cause journald to vacuum files without
@@ -164,6 +165,7 @@ static int determine_space_for(
                         fb4[FORMAT_BYTES_MAX], fb5[FORMAT_BYTES_MAX], fb6[FORMAT_BYTES_MAX];
 
                 server_driver_message(s, SD_MESSAGE_JOURNAL_USAGE,
+                                      LOG_MESSAGE(
                                       "%s (%s) is currently using %s.\n"
                                       "Maximum allowed usage is set to %s.\n"
                                       "Leaving at least %s free (of currently available %s of space).\n"
@@ -174,7 +176,8 @@ static int determine_space_for(
                                       format_bytes(fb3, sizeof(fb3), metrics->keep_free),
                                       format_bytes(fb4, sizeof(fb4), ss_avail),
                                       format_bytes(fb5, sizeof(fb5), s->cached_space_limit),
-                                      format_bytes(fb6, sizeof(fb6), s->cached_space_available));
+                                      format_bytes(fb6, sizeof(fb6), s->cached_space_available)),
+                                      NULL);
         }
 
         if (available)
@@ -808,9 +811,8 @@ static void dispatch_message_real(
 
 void server_driver_message(Server *s, sd_id128_t message_id, const char *format, ...) {
         char mid[11 + 32 + 1];
-        char buffer[16 + LINE_MAX + 1];
-        struct iovec iovec[N_IOVEC_META_FIELDS + 6];
-        int n = 0;
+        struct iovec iovec[N_IOVEC_META_FIELDS + 5 + N_IOVEC_PAYLOAD_FIELDS];
+        unsigned n = 0, m;
         va_list ap;
         struct ucred ucred = {};
 
@@ -823,22 +825,25 @@ void server_driver_message(Server *s, sd_id128_t message_id, const char *format,
         IOVEC_SET_STRING(iovec[n++], "PRIORITY=6");
         IOVEC_SET_STRING(iovec[n++], "_TRANSPORT=driver");
 
-        memcpy(buffer, "MESSAGE=", 8);
-        va_start(ap, format);
-        vsnprintf(buffer + 8, sizeof(buffer) - 8, format, ap);
-        va_end(ap);
-        IOVEC_SET_STRING(iovec[n++], buffer);
-
         if (!sd_id128_equal(message_id, SD_ID128_NULL)) {
                 snprintf(mid, sizeof(mid), LOG_MESSAGE_ID(message_id));
                 IOVEC_SET_STRING(iovec[n++], mid);
         }
 
+        m = n;
+
+        va_start(ap, format);
+        assert_se(log_format_iovec(iovec, ELEMENTSOF(iovec), &n, false, 0, format, ap) >= 0);
+        va_end(ap);
+
         ucred.pid = getpid();
         ucred.uid = getuid();
         ucred.gid = getgid();
 
         dispatch_message_real(s, iovec, n, ELEMENTSOF(iovec), &ucred, NULL, NULL, 0, NULL, LOG_INFO, 0);
+
+        while (m < n)
+                free(iovec[m++].iov_base);
 }
 
 void server_dispatch_message(
@@ -901,7 +906,8 @@ void server_dispatch_message(
         /* Write a suppression message if we suppressed something */
         if (rl > 1)
                 server_driver_message(s, SD_MESSAGE_JOURNAL_DROPPED,
-                                      "Suppressed %u messages from %s", rl - 1, path);
+                                      LOG_MESSAGE("Suppressed %u messages from %s", rl - 1, path),
+                                      NULL);
 
 finish:
         dispatch_message_real(s, iovec, n, m, ucred, tv, label, label_len, unit_id, priority, object_pid);
@@ -1073,7 +1079,11 @@ finish:
 
         sd_journal_close(j);
 
-        server_driver_message(s, SD_ID128_NULL, "Time spent on flushing to /var is %s for %u entries.", format_timespan(ts, sizeof(ts), now(CLOCK_MONOTONIC) - start, 0), n);
+        server_driver_message(s, SD_ID128_NULL,
+                              LOG_MESSAGE("Time spent on flushing to /var is %s for %u entries.",
+                                          format_timespan(ts, sizeof(ts), now(CLOCK_MONOTONIC) - start, 0),
+                                          n),
+                              NULL);
 
         return r;
 }
diff --git a/src/journal/journald-server.h b/src/journal/journald-server.h
index 1822765228..0ef83d161f 100644
--- a/src/journal/journald-server.h
+++ b/src/journal/journald-server.h
@@ -157,9 +157,10 @@ struct Server {
 #define N_IOVEC_KERNEL_FIELDS 64
 #define N_IOVEC_UDEV_FIELDS 32
 #define N_IOVEC_OBJECT_FIELDS 12
+#define N_IOVEC_PAYLOAD_FIELDS 1
 
 void server_dispatch_message(Server *s, struct iovec *iovec, unsigned n, unsigned m, const struct ucred *ucred, const struct timeval *tv, const char *label, size_t label_len, const char *unit_id, int priority, pid_t object_pid);
-void server_driver_message(Server *s, sd_id128_t message_id, const char *format, ...) _printf_(3,4);
+void server_driver_message(Server *s, sd_id128_t message_id, const char *format, ...) _printf_(3,0) _sentinel_;
 
 /* gperf lookup function */
 const struct ConfigPerfItem* journald_gperf_lookup(const char *key, unsigned length);
diff --git a/src/journal/journald-syslog.c b/src/journal/journald-syslog.c
index 0be73088e2..9f2ccdcc77 100644
--- a/src/journal/journald-syslog.c
+++ b/src/journal/journald-syslog.c
@@ -448,7 +448,10 @@ void server_maybe_warn_forward_syslog_missed(Server *s) {
         if (s->last_warn_forward_syslog_missed + WARN_FORWARD_SYSLOG_MISSED_USEC > n)
                 return;
 
-        server_driver_message(s, SD_MESSAGE_FORWARD_SYSLOG_MISSED, "Forwarding to syslog missed %u messages.", s->n_forward_syslog_missed);
+        server_driver_message(s, SD_MESSAGE_FORWARD_SYSLOG_MISSED,
+                              LOG_MESSAGE("Forwarding to syslog missed %u messages.",
+                                          s->n_forward_syslog_missed),
+                              NULL);
 
         s->n_forward_syslog_missed = 0;
         s->last_warn_forward_syslog_missed = n;
diff --git a/src/journal/journald.c b/src/journal/journald.c
index b9f5c099e1..293b788d03 100644
--- a/src/journal/journald.c
+++ b/src/journal/journald.c
@@ -58,7 +58,9 @@ int main(int argc, char *argv[]) {
         server_flush_dev_kmsg(&server);
 
         log_debug("systemd-journald running as pid "PID_FMT, getpid());
-        server_driver_message(&server, SD_MESSAGE_JOURNAL_START, "Journal started");
+        server_driver_message(&server, SD_MESSAGE_JOURNAL_START,
+                              LOG_MESSAGE("Journal started"),
+                              NULL);
 
         for (;;) {
                 usec_t t = USEC_INFINITY, n;
@@ -109,7 +111,9 @@ int main(int argc, char *argv[]) {
         }
 
         log_debug("systemd-journald stopped as pid "PID_FMT, getpid());
-        server_driver_message(&server, SD_MESSAGE_JOURNAL_STOP, "Journal stopped");
+        server_driver_message(&server, SD_MESSAGE_JOURNAL_STOP,
+                              LOG_MESSAGE("Journal stopped"),
+                              NULL);
 
 finish:
         server_done(&server);