journald: when logging about dropped messages, include more meta data

When we drop messages of a unit, we log about. Let's add some structured
data to that. Let's include how many messages we dropped, but more
importantly, let's link up the message we generate to the unit we
dropped the messages from by using the "OBJECT" logic, i.e. by
generating OBJECT_SYSTEMD_UNIT= fields and suchlike, that "journalctl
-u" and friends already look for.

Fixes: #6494
This commit is contained in:
Lennart Poettering 2017-10-30 20:01:50 +01:00
parent 500cbc4e9e
commit 131819424d
5 changed files with 15 additions and 12 deletions

View file

@ -155,7 +155,7 @@ 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,
server_driver_message(s, 0,
"MESSAGE_ID=" SD_MESSAGE_JOURNAL_MISSED_STR,
LOG_MESSAGE("Missed %"PRIu64" kernel messages",
serial - *s->kernel_seqnum),

View file

@ -219,7 +219,8 @@ void server_space_usage_message(Server *s, JournalStorage *storage) {
format_bytes(fb5, sizeof(fb5), storage->space.limit);
format_bytes(fb6, sizeof(fb6), storage->space.available);
server_driver_message(s, "MESSAGE_ID=" SD_MESSAGE_JOURNAL_USAGE_STR,
server_driver_message(s, 0,
"MESSAGE_ID=" SD_MESSAGE_JOURNAL_USAGE_STR,
LOG_MESSAGE("%s (%s) is %s, max %s, %s free.",
storage->name, storage->path, fb1, fb5, fb6),
"JOURNAL_NAME=%s", storage->name,
@ -859,7 +860,7 @@ static void dispatch_message_real(
write_to_journal(s, journal_uid, iovec, n, priority);
}
void server_driver_message(Server *s, const char *message_id, const char *format, ...) {
void server_driver_message(Server *s, pid_t object_pid, const char *message_id, const char *format, ...) {
struct iovec iovec[N_IOVEC_META_FIELDS + 5 + N_IOVEC_PAYLOAD_FIELDS];
unsigned n = 0, m;
@ -887,7 +888,7 @@ void server_driver_message(Server *s, const char *message_id, const char *format
va_end(ap);
if (r >= 0)
dispatch_message_real(s, iovec, n, ELEMENTSOF(iovec), s->my_context, NULL, LOG_INFO, 0);
dispatch_message_real(s, iovec, n, ELEMENTSOF(iovec), s->my_context, NULL, LOG_INFO, object_pid);
while (m < n)
free(iovec[m++].iov_base);
@ -901,7 +902,7 @@ void server_driver_message(Server *s, const char *message_id, const char *format
n = 3;
iovec[n++] = IOVEC_MAKE_STRING("PRIORITY=4");
iovec[n++] = IOVEC_MAKE_STRING(buf);
dispatch_message_real(s, iovec, n, ELEMENTSOF(iovec), s->my_context, NULL, LOG_INFO, 0);
dispatch_message_real(s, iovec, n, ELEMENTSOF(iovec), s->my_context, NULL, LOG_INFO, object_pid);
}
}
@ -939,8 +940,10 @@ void server_dispatch_message(
/* Write a suppression message if we suppressed something */
if (rl > 1)
server_driver_message(s, "MESSAGE_ID=" SD_MESSAGE_JOURNAL_DROPPED_STR,
LOG_MESSAGE("Suppressed %u messages from %s", rl - 1, c->unit),
server_driver_message(s, c->pid,
"MESSAGE_ID=" SD_MESSAGE_JOURNAL_DROPPED_STR,
LOG_MESSAGE("Suppressed %i messages from %s", rl - 1, c->unit),
LOG_MESSAGE("N_DROPPED=%i", rl - 1),
NULL);
}
@ -1038,7 +1041,7 @@ finish:
sd_journal_close(j);
server_driver_message(s, NULL,
server_driver_message(s, 0, 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),

View file

@ -188,7 +188,7 @@ struct Server {
#define N_IOVEC_PAYLOAD_FIELDS 15
void server_dispatch_message(Server *s, struct iovec *iovec, unsigned n, unsigned m, ClientContext *c, const struct timeval *tv, int priority, pid_t object_pid);
void server_driver_message(Server *s, const char *message_id, const char *format, ...) _printf_(3,0) _sentinel_;
void server_driver_message(Server *s, pid_t object_pid, const char *message_id, const char *format, ...) _sentinel_;
/* gperf lookup function */
const struct ConfigPerfItem* journald_gperf_lookup(const char *key, GPERF_LEN_TYPE length);

View file

@ -449,7 +449,7 @@ 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,
server_driver_message(s, 0,
"MESSAGE_ID=" SD_MESSAGE_FORWARD_SYSLOG_MISSED_STR,
LOG_MESSAGE("Forwarding to syslog missed %u messages.",
s->n_forward_syslog_missed),

View file

@ -56,7 +56,7 @@ int main(int argc, char *argv[]) {
server_flush_dev_kmsg(&server);
log_debug("systemd-journald running as pid "PID_FMT, getpid_cached());
server_driver_message(&server,
server_driver_message(&server, 0,
"MESSAGE_ID=" SD_MESSAGE_JOURNAL_START_STR,
LOG_MESSAGE("Journal started"),
NULL);
@ -115,7 +115,7 @@ int main(int argc, char *argv[]) {
}
log_debug("systemd-journald stopped as pid "PID_FMT, getpid_cached());
server_driver_message(&server,
server_driver_message(&server, 0,
"MESSAGE_ID=" SD_MESSAGE_JOURNAL_STOP_STR,
LOG_MESSAGE("Journal stopped"),
NULL);