chiark / gitweb /
journald: augment journal entries from the kernel with data from udev
[elogind.git] / src / journal / journald.c
index 1d40fa843ef9092d8f9f7f113010b5862c31bd18..2429dd3e278380e229b447665eed6a51587b9689 100644 (file)
@@ -29,7 +29,9 @@
 #include <sys/ioctl.h>
 #include <linux/sockios.h>
 #include <sys/statvfs.h>
+#include <sys/mman.h>
 
+#include <libudev.h>
 #include <systemd/sd-journal.h>
 #include <systemd/sd-messages.h>
 #include <systemd/sd-daemon.h>
@@ -46,6 +48,8 @@
 #include "list.h"
 #include "journal-rate-limit.h"
 #include "journal-internal.h"
+#include "journal-vacuum.h"
+#include "journal-authenticate.h"
 #include "conf-parser.h"
 #include "journald.h"
 #include "virt.h"
@@ -70,6 +74,8 @@
 #define RECHECK_AVAILABLE_SPACE_USEC (30*USEC_PER_SEC)
 
 #define N_IOVEC_META_FIELDS 17
+#define N_IOVEC_KERNEL_FIELDS 64
+#define N_IOVEC_UDEV_FIELDS 32
 
 #define ENTRY_SIZE_MAX (1024*1024*32)
 
@@ -279,7 +285,6 @@ static JournalFile* find_journal(Server *s, uid_t uid) {
         char *p;
         int r;
         JournalFile *f;
-        char ids[33];
         sd_id128_t machine;
 
         assert(s);
@@ -303,7 +308,8 @@ static JournalFile* find_journal(Server *s, uid_t uid) {
         if (f)
                 return f;
 
-        if (asprintf(&p, "/var/log/journal/%s/user-%lu.journal", sd_id128_to_string(machine, ids), (unsigned long) uid) < 0)
+        if (asprintf(&p, "/var/log/journal/" SD_ID128_FORMAT_STR "/user-%lu.journal",
+                     SD_ID128_FORMAT_VAL(machine), (unsigned long) uid) < 0)
                 return s->system_journal;
 
         while (hashmap_size(s->user_journals) >= USER_JOURNALS_MAX) {
@@ -313,7 +319,7 @@ static JournalFile* find_journal(Server *s, uid_t uid) {
                 journal_file_close(f);
         }
 
-        r = journal_file_open_reliably(p, O_RDWR|O_CREAT, 0640, &s->system_metrics, s->system_journal, &f);
+        r = journal_file_open_reliably(p, O_RDWR|O_CREAT, 0640, s->compress, s->seal, &s->system_metrics, s->mmap, s->system_journal, &f);
         free(p);
 
         if (r < 0)
@@ -339,7 +345,7 @@ static void server_rotate(Server *s) {
         log_info("Rotating...");
 
         if (s->runtime_journal) {
-                r = journal_file_rotate(&s->runtime_journal);
+                r = journal_file_rotate(&s->runtime_journal, s->compress, false);
                 if (r < 0)
                         if (s->runtime_journal)
                                 log_error("Failed to rotate %s: %s", s->runtime_journal->path, strerror(-r));
@@ -350,7 +356,7 @@ static void server_rotate(Server *s) {
         }
 
         if (s->system_journal) {
-                r = journal_file_rotate(&s->system_journal);
+                r = journal_file_rotate(&s->system_journal, s->compress, s->seal);
                 if (r < 0)
                         if (s->system_journal)
                                 log_error("Failed to rotate %s: %s", s->system_journal->path, strerror(-r));
@@ -362,7 +368,7 @@ static void server_rotate(Server *s) {
         }
 
         HASHMAP_FOREACH_KEY(f, k, s->user_journals, i) {
-                r = journal_file_rotate(&f);
+                r = journal_file_rotate(&f, s->compress, s->seal);
                 if (r < 0)
                         if (f->path)
                                 log_error("Failed to rotate %s: %s", f->path, strerror(-r));
@@ -1807,13 +1813,15 @@ static bool is_us(const char *pid) {
 }
 
 static void dev_kmsg_record(Server *s, char *p, size_t l) {
-        struct iovec iovec[N_IOVEC_META_FIELDS + 7];
+        struct iovec iovec[N_IOVEC_META_FIELDS + 7 + N_IOVEC_KERNEL_FIELDS + 2 + N_IOVEC_UDEV_FIELDS];
         char *message = NULL, *syslog_priority = NULL, *syslog_pid = NULL, *syslog_facility = NULL, *syslog_identifier = NULL, *source_time = NULL;
         int priority, r;
-        unsigned n = 0;
+        unsigned n = 0, z = 0, j;
         usec_t usec;
-        char *identifier = NULL, *pid = NULL, *e, *f;
+        char *identifier = NULL, *pid = NULL, *e, *f, *k;
         uint64_t serial;
+        size_t pl;
+        char *kernel_device = NULL;
 
         assert(s);
         assert(p);
@@ -1844,6 +1852,22 @@ static void dev_kmsg_record(Server *s, char *p, size_t l) {
         if (r < 0)
                 return;
 
+        if (s->kernel_seqnum) {
+                /* We already read this one? */
+                if (serial < *s->kernel_seqnum)
+                        return;
+
+                /* Did we lose any? */
+                if (serial > *s->kernel_seqnum)
+                        driver_message(s, SD_MESSAGE_JOURNAL_MISSED, "Missed %llu kernel messages", (unsigned long long) serial - *s->kernel_seqnum - 1);
+
+                /* Make sure we never read this one again. Note that
+                 * we always store the next message serial we expect
+                 * here, simply because this makes handling the first
+                 * message with serial 0 easy. */
+                *s->kernel_seqnum = serial + 1;
+        }
+
         l -= (e - p) + 1;
         p = e + 1;
         f = memchr(p, ';', l);
@@ -1862,9 +1886,91 @@ static void dev_kmsg_record(Server *s, char *p, size_t l) {
         l -= (f - p) + 1;
         p = f + 1;
         e = memchr(p, '\n', l);
-        if (e)
+        if (!e)
+                return;
+        *e = 0;
+
+        pl = e - p;
+        l -= (e - p) + 1;
+        k = e + 1;
+
+        for (j = 0; l > 0 && j < N_IOVEC_KERNEL_FIELDS; j++) {
+                char *m;
+                /* Meta data fields attached */
+
+                if (*k != ' ')
+                        break;
+
+                k ++, l --;
+
+                e = memchr(k, '\n', l);
+                if (!e)
+                        return;
+
                 *e = 0;
 
+                m = cunescape_length_with_prefix(k, e - k, "_KERNEL_");
+                if (!m)
+                        break;
+
+                if (startswith(m, "_KERNEL_DEVICE="))
+                        kernel_device = m + 15;
+
+                IOVEC_SET_STRING(iovec[n++], m);
+                z++;
+
+                l -= (e - k) + 1;
+                k = e + 1;
+        }
+
+        if (kernel_device) {
+                struct udev_device *ud;
+
+                ud = udev_device_new_from_device_id(s->udev, kernel_device);
+                if (ud) {
+                        const char *g;
+                        struct udev_list_entry *ll;
+                        char *b;
+
+                        g = udev_device_get_devnode(ud);
+                        if (g) {
+                                b = strappend("_UDEV_DEVNODE=", g);
+                                if (b) {
+                                        IOVEC_SET_STRING(iovec[n++], b);
+                                        z++;
+                                }
+                        }
+
+                        g = udev_device_get_sysname(ud);
+                        if (g) {
+                                b = strappend("_UDEV_SYSNAME=", g);
+                                if (b) {
+                                        IOVEC_SET_STRING(iovec[n++], b);
+                                        z++;
+                                }
+                        }
+
+                        j = 0;
+                        ll = udev_device_get_devlinks_list_entry(ud);
+                        udev_list_entry_foreach(ll, ll) {
+
+                                if (j > N_IOVEC_UDEV_FIELDS)
+                                        break;
+
+                                g = udev_list_entry_get_name(ll);
+                                b = strappend("_UDEV_DEVLINK=", g);
+                                if (g) {
+                                        IOVEC_SET_STRING(iovec[n++], b);
+                                        z++;
+                                }
+
+                                j++;
+                        }
+
+                        udev_device_unref(ud);
+                }
+        }
+
         if (asprintf(&source_time, "_SOURCE_MONOTONIC_TIMESTAMP=%llu",
                      (unsigned long long) usec) >= 0)
                 IOVEC_SET_STRING(iovec[n++], source_time);
@@ -1900,13 +2006,16 @@ static void dev_kmsg_record(Server *s, char *p, size_t l) {
                         IOVEC_SET_STRING(iovec[n++], syslog_facility);
         }
 
-        message = strappend("MESSAGE=", p);
+        message = cunescape_length_with_prefix(p, pl, "MESSAGE=");
         if (message)
                 IOVEC_SET_STRING(iovec[n++], message);
 
         dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, NULL, NULL, 0, NULL, priority);
 
 finish:
+        for (j = 0; j < z; j++)
+                free(iovec[j].iov_base);
+
         free(message);
         free(syslog_priority);
         free(syslog_identifier);
@@ -1953,14 +2062,12 @@ static int system_journal_open(Server *s) {
                 if (!fn)
                         return -ENOMEM;
 
-                r = journal_file_open_reliably(fn, O_RDWR|O_CREAT, 0640, &s->system_metrics, NULL, &s->system_journal);
+                r = journal_file_open_reliably(fn, O_RDWR|O_CREAT, 0640, s->compress, s->seal, &s->system_metrics, s->mmap, NULL, &s->system_journal);
                 free(fn);
 
-                if (r >= 0) {
-                        s->system_journal->compress = s->compress;
-
+                if (r >= 0)
                         server_fix_perms(s, s->system_journal, 0);
-                else if (r < 0) {
+                else if (r < 0) {
 
                         if (r != -ENOENT && r != -EROFS)
                                 log_warning("Failed to open system journal: %s", strerror(-r));
@@ -1982,7 +2089,7 @@ static int system_journal_open(Server *s) {
                          * if it already exists, so that we can flush
                          * it into the system journal */
 
-                        r = journal_file_open(fn, O_RDWR, 0640, &s->runtime_metrics, NULL, &s->runtime_journal);
+                        r = journal_file_open(fn, O_RDWR, 0640, s->compress, false, &s->runtime_metrics, s->mmap, NULL, &s->runtime_journal);
                         free(fn);
 
                         if (r < 0) {
@@ -1998,7 +2105,7 @@ static int system_journal_open(Server *s) {
                          * it if necessary. */
 
                         (void) mkdir_parents(fn, 0755);
-                        r = journal_file_open_reliably(fn, O_RDWR|O_CREAT, 0640, &s->runtime_metrics, NULL, &s->runtime_journal);
+                        r = journal_file_open_reliably(fn, O_RDWR|O_CREAT, 0640, s->compress, false, &s->runtime_metrics, s->mmap, NULL, &s->runtime_journal);
                         free(fn);
 
                         if (r < 0) {
@@ -2007,11 +2114,8 @@ static int system_journal_open(Server *s) {
                         }
                 }
 
-                if (s->runtime_journal) {
-                        s->runtime_journal->compress = s->compress;
-
+                if (s->runtime_journal)
                         server_fix_perms(s, s->runtime_journal, 0);
-                }
         }
 
         return r;
@@ -2111,7 +2215,7 @@ static int server_read_dev_kmsg(Server *s) {
                         return 0;
                 }
 
-                if (errno == EAGAIN || errno == EINTR)
+                if (errno == EAGAIN || errno == EINTR || errno == EPIPE)
                         return 0;
 
                 log_error("Failed to read from kernel: %m");
@@ -2571,6 +2675,41 @@ static int open_dev_kmsg(Server *s) {
         return 0;
 }
 
+static int open_kernel_seqnum(Server *s) {
+        int fd;
+        uint64_t *p;
+
+        assert(s);
+
+        /* We store the seqnum we last read in an mmaped file. That
+         * way we can just use it like a variable, but it is
+         * persistant and automatically flushed at reboot. */
+
+        fd = open("/run/systemd/journal/kernel-seqnum", O_RDWR|O_CREAT|O_CLOEXEC|O_NOCTTY|O_NOFOLLOW, 0644);
+        if (fd < 0) {
+                log_error("Failed to open /run/systemd/journal/kernel-seqnum, ignoring: %m");
+                return 0;
+        }
+
+        if (posix_fallocate(fd, 0, sizeof(uint64_t)) < 0) {
+                log_error("Failed to allocate sequential number file, ignoring: %m");
+                close_nointr_nofail(fd);
+                return 0;
+        }
+
+        p = mmap(NULL, sizeof(uint64_t), PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0);
+        if (p == MAP_FAILED) {
+                log_error("Failed to map sequential number file, ignoring: %m");
+                close_nointr_nofail(fd);
+                return 0;
+        }
+
+        close_nointr_nofail(fd);
+        s->kernel_seqnum = p;
+
+        return 0;
+}
+
 static int open_signalfd(Server *s) {
         sigset_t mask;
         struct epoll_event ev;
@@ -2687,6 +2826,7 @@ static int server_init(Server *s) {
         zero(*s);
         s->syslog_fd = s->native_fd = s->stdout_fd = s->signal_fd = s->epoll_fd = s->dev_kmsg_fd = -1;
         s->compress = true;
+        s->seal = true;
 
         s->rate_limit_interval = DEFAULT_RATE_LIMIT_INTERVAL;
         s->rate_limit_burst = DEFAULT_RATE_LIMIT_BURST;
@@ -2704,10 +2844,16 @@ static int server_init(Server *s) {
         server_parse_config_file(s);
         server_parse_proc_cmdline(s);
 
+        mkdir_p("/run/systemd/journal", 0755);
+
         s->user_journals = hashmap_new(trivial_hash_func, trivial_compare_func);
         if (!s->user_journals)
                 return log_oom();
 
+        s->mmap = mmap_cache_new();
+        if (!s->mmap)
+                return log_oom();
+
         s->epoll_fd = epoll_create1(EPOLL_CLOEXEC);
         if (s->epoll_fd < 0) {
                 log_error("Failed to create epoll object: %m");
@@ -2771,10 +2917,18 @@ static int server_init(Server *s) {
         if (r < 0)
                 return r;
 
+        r = open_kernel_seqnum(s);
+        if (r < 0)
+                return r;
+
         r = open_signalfd(s);
         if (r < 0)
                 return r;
 
+        s->udev = udev_new();
+        if (!s->udev)
+                return -ENOMEM;
+
         s->rate_limit = journal_rate_limit_new(s->rate_limit_interval, s->rate_limit_burst);
         if (!s->rate_limit)
                 return -ENOMEM;
@@ -2825,8 +2979,17 @@ static void server_done(Server *s) {
         if (s->rate_limit)
                 journal_rate_limit_free(s->rate_limit);
 
+        if (s->kernel_seqnum)
+                munmap(s->kernel_seqnum, sizeof(uint64_t));
+
         free(s->buffer);
         free(s->tty_path);
+
+        if (s->mmap)
+                mmap_cache_unref(s->mmap);
+
+        if (s->udev)
+                udev_unref(s->udev);
 }
 
 int main(int argc, char *argv[]) {
@@ -2845,6 +3008,7 @@ int main(int argc, char *argv[]) {
 
         log_set_target(LOG_TARGET_SAFE);
         log_set_facility(LOG_SYSLOG);
+        log_set_max_level(LOG_DEBUG);
         log_parse_environment();
         log_open();
 
@@ -2867,8 +3031,26 @@ int main(int argc, char *argv[]) {
 
         for (;;) {
                 struct epoll_event event;
+                int t;
+
+#ifdef HAVE_GCRYPT
+                usec_t u;
+
+                if (server.system_journal &&
+                    journal_file_next_evolve_usec(server.system_journal, &u)) {
+                        usec_t n;
+
+                        n = now(CLOCK_MONOTONIC);
+
+                        if (n >= u)
+                                t = 0;
+                        else
+                                t = (int) ((u - n + USEC_PER_MSEC - 1) / USEC_PER_MSEC);
+                } else
+#endif
+                        t = -1;
 
-                r = epoll_wait(server.epoll_fd, &event, 1, -1);
+                r = epoll_wait(server.epoll_fd, &event, 1, t);
                 if (r < 0) {
 
                         if (errno == EINTR)
@@ -2877,14 +3059,20 @@ int main(int argc, char *argv[]) {
                         log_error("epoll_wait() failed: %m");
                         r = -errno;
                         goto finish;
-                } else if (r == 0)
-                        break;
+                }
 
-                r = process_event(&server, &event);
-                if (r < 0)
-                        goto finish;
-                else if (r == 0)
-                        break;
+                if (r > 0) {
+                        r = process_event(&server, &event);
+                        if (r < 0)
+                                goto finish;
+                        else if (r == 0)
+                                break;
+                }
+
+#ifdef HAVE_GCRYPT
+                if (server.system_journal)
+                        journal_file_maybe_append_tag(server.system_journal, 0);
+#endif
         }
 
         log_debug("systemd-journald stopped as pid %lu", (unsigned long) getpid());