Merge pull request #2424 from keszybz/journald-disk-usage

Journald disk usage

7 files changed, 140 insertions, 67 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 c3add87ed1..8c1b064e86 100644
--- a/src/journal/journald-server.c
+++ b/src/journal/journald-server.c
@@ -67,9 +67,11 @@
 #include "selinux-util.h"
 #include "signal-util.h"
 #include "socket-util.h"
+#include "stdio-util.h"
 #include "string-table.h"
 #include "string-util.h"
 #include "user-util.h"
+#include "log.h"
 
 #define USER_JOURNALS_MAX 1024
 
@@ -145,7 +147,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
@@ -165,19 +167,31 @@ static int determine_space_for(
         if (verbose) {
                 char    fb1[FORMAT_BYTES_MAX], fb2[FORMAT_BYTES_MAX], fb3[FORMAT_BYTES_MAX],
                         fb4[FORMAT_BYTES_MAX], fb5[FORMAT_BYTES_MAX], fb6[FORMAT_BYTES_MAX];
+                format_bytes(fb1, sizeof(fb1), sum);
+                format_bytes(fb2, sizeof(fb2), metrics->max_use);
+                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);
 
                 server_driver_message(s, SD_MESSAGE_JOURNAL_USAGE,
-                                      "%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"
-                                      "Enforced usage limit is thus %s, of which %s are still available.",
-                                      name, path,
-                                      format_bytes(fb1, sizeof(fb1), sum),
-                                      format_bytes(fb2, sizeof(fb2), metrics->max_use),
-                                      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));
+                                      LOG_MESSAGE("%s (%s) is %s, max %s, %s free.",
+                                                  name, path, fb1, fb5, fb6),
+                                      "JOURNAL_NAME=%s", name,
+                                      "JOURNAL_PATH=%s", path,
+                                      "CURRENT_USE=%"PRIu64, sum,
+                                      "CURRENT_USE_PRETTY=%s", fb1,
+                                      "MAX_USE=%"PRIu64, metrics->max_use,
+                                      "MAX_USE_PRETTY=%s", fb2,
+                                      "DISK_KEEP_FREE=%"PRIu64, metrics->keep_free,
+                                      "DISK_KEEP_FREE_PRETTY=%s", fb3,
+                                      "DISK_AVAILABLE=%"PRIu64, ss_avail,
+                                      "DISK_AVAILABLE_PRETTY=%s", fb4,
+                                      "LIMIT=%"PRIu64, s->cached_space_limit,
+                                      "LIMIT_PRETTY=%s", fb5,
+                                      "AVAILABLE=%"PRIu64, s->cached_space_available,
+                                      "AVAILABLE_PRETTY=%s", fb6,
+                                      NULL);
         }
 
         if (available)
@@ -843,9 +857,9 @@ 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;
+        int r;
         va_list ap;
         struct ucred ucred = {};
 
@@ -855,25 +869,42 @@ void server_driver_message(Server *s, sd_id128_t message_id, const char *format,
         IOVEC_SET_STRING(iovec[n++], "SYSLOG_FACILITY=3");
         IOVEC_SET_STRING(iovec[n++], "SYSLOG_IDENTIFIER=systemd-journald");
 
-        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);
+        IOVEC_SET_STRING(iovec[n++], "PRIORITY=6");
 
         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);
+        r = log_format_iovec(iovec, ELEMENTSOF(iovec), &n, false, 0, format, ap);
+        /* Error handling below */
+        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);
+        if (r >= 0)
+                dispatch_message_real(s, iovec, n, ELEMENTSOF(iovec), &ucred, NULL, NULL, 0, NULL, LOG_INFO, 0);
+
+        while (m < n)
+                free(iovec[m++].iov_base);
+
+        if (r < 0) {
+                /* We failed to format the message. Emit a warning instead. */
+                char buf[LINE_MAX];
+
+                xsprintf(buf, "MESSAGE=Entry printing failed: %s", strerror(-r));
+
+                n = 3;
+                IOVEC_SET_STRING(iovec[n++], "PRIORITY=4");
+                IOVEC_SET_STRING(iovec[n++], buf);
+                dispatch_message_real(s, iovec, n, ELEMENTSOF(iovec), &ucred, NULL, NULL, 0, NULL, LOG_INFO, 0);
+        }
 }
 
 void server_dispatch_message(
@@ -936,7 +967,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);
@@ -1108,7 +1140,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..49bbee0646 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 15
 
 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);