From 8a03c9ef744e13dc700a7e7ca6cae8afdcf0d71c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Sun, 8 Nov 2015 14:05:55 -0500 Subject: [PATCH] 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. --- src/basic/log.c | 89 +++++++++++++++++++++-------------- src/basic/log.h | 10 ++++ src/journal/journald-kmsg.c | 6 ++- src/journal/journald-server.c | 36 +++++++++----- src/journal/journald-server.h | 3 +- src/journal/journald-syslog.c | 5 +- src/journal/journald.c | 8 +++- 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 #include #include +#include #include #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);