LCOV - code coverage report
Current view: top level - journal - journald-kmsg.c (source / functions) Hit Total Coverage
Test: main_coverage.info Lines: 0 237 0.0 %
Date: 2019-08-22 15:41:25 Functions: 0 8 0.0 %

          Line data    Source code
       1             : /* SPDX-License-Identifier: LGPL-2.1+ */
       2             : 
       3             : #include <fcntl.h>
       4             : #include <sys/epoll.h>
       5             : #include <sys/mman.h>
       6             : #include <sys/socket.h>
       7             : #include <unistd.h>
       8             : 
       9             : #include "sd-device.h"
      10             : #include "sd-messages.h"
      11             : 
      12             : #include "alloc-util.h"
      13             : #include "device-util.h"
      14             : #include "escape.h"
      15             : #include "fd-util.h"
      16             : #include "format-util.h"
      17             : #include "io-util.h"
      18             : #include "journald-kmsg.h"
      19             : #include "journald-server.h"
      20             : #include "journald-syslog.h"
      21             : #include "parse-util.h"
      22             : #include "process-util.h"
      23             : #include "stdio-util.h"
      24             : #include "string-util.h"
      25             : 
      26           0 : void server_forward_kmsg(
      27             :         Server *s,
      28             :         int priority,
      29             :         const char *identifier,
      30             :         const char *message,
      31             :         const struct ucred *ucred) {
      32             : 
      33           0 :         _cleanup_free_ char *ident_buf = NULL;
      34             :         struct iovec iovec[5];
      35             :         char header_priority[DECIMAL_STR_MAX(priority) + 3],
      36             :              header_pid[STRLEN("[]: ") + DECIMAL_STR_MAX(pid_t) + 1];
      37           0 :         int n = 0;
      38             : 
      39           0 :         assert(s);
      40           0 :         assert(priority >= 0);
      41           0 :         assert(priority <= 999);
      42           0 :         assert(message);
      43             : 
      44           0 :         if (_unlikely_(LOG_PRI(priority) > s->max_level_kmsg))
      45           0 :                 return;
      46             : 
      47           0 :         if (_unlikely_(s->dev_kmsg_fd < 0))
      48           0 :                 return;
      49             : 
      50             :         /* Never allow messages with kernel facility to be written to
      51             :          * kmsg, regardless where the data comes from. */
      52           0 :         priority = syslog_fixup_facility(priority);
      53             : 
      54             :         /* First: priority field */
      55           0 :         xsprintf(header_priority, "<%i>", priority);
      56           0 :         iovec[n++] = IOVEC_MAKE_STRING(header_priority);
      57             : 
      58             :         /* Second: identifier and PID */
      59           0 :         if (ucred) {
      60           0 :                 if (!identifier) {
      61           0 :                         get_process_comm(ucred->pid, &ident_buf);
      62           0 :                         identifier = ident_buf;
      63             :                 }
      64             : 
      65           0 :                 xsprintf(header_pid, "["PID_FMT"]: ", ucred->pid);
      66             : 
      67           0 :                 if (identifier)
      68           0 :                         iovec[n++] = IOVEC_MAKE_STRING(identifier);
      69             : 
      70           0 :                 iovec[n++] = IOVEC_MAKE_STRING(header_pid);
      71           0 :         } else if (identifier) {
      72           0 :                 iovec[n++] = IOVEC_MAKE_STRING(identifier);
      73           0 :                 iovec[n++] = IOVEC_MAKE_STRING(": ");
      74             :         }
      75             : 
      76             :         /* Fourth: message */
      77           0 :         iovec[n++] = IOVEC_MAKE_STRING(message);
      78           0 :         iovec[n++] = IOVEC_MAKE_STRING("\n");
      79             : 
      80           0 :         if (writev(s->dev_kmsg_fd, iovec, n) < 0)
      81           0 :                 log_debug_errno(errno, "Failed to write to /dev/kmsg for logging: %m");
      82             : }
      83             : 
      84           0 : static bool is_us(const char *identifier, const char *pid) {
      85             :         pid_t pid_num;
      86             : 
      87           0 :         if (!identifier || !pid)
      88           0 :                 return false;
      89             : 
      90           0 :         if (parse_pid(pid, &pid_num) < 0)
      91           0 :                 return false;
      92             : 
      93           0 :         return pid_num == getpid_cached() &&
      94           0 :                streq(identifier, program_invocation_short_name);
      95             : }
      96             : 
      97           0 : void dev_kmsg_record(Server *s, char *p, size_t l) {
      98             : 
      99           0 :         _cleanup_free_ char *message = NULL, *syslog_priority = NULL, *syslog_pid = NULL, *syslog_facility = NULL, *syslog_identifier = NULL, *source_time = NULL, *identifier = NULL, *pid = NULL;
     100             :         struct iovec iovec[N_IOVEC_META_FIELDS + 7 + N_IOVEC_KERNEL_FIELDS + 2 + N_IOVEC_UDEV_FIELDS];
     101           0 :         char *kernel_device = NULL;
     102             :         unsigned long long usec;
     103           0 :         size_t n = 0, z = 0, j;
     104             :         int priority, r;
     105             :         char *e, *f, *k;
     106             :         uint64_t serial;
     107             :         size_t pl;
     108             : 
     109           0 :         assert(s);
     110           0 :         assert(p);
     111             : 
     112           0 :         if (l <= 0)
     113           0 :                 return;
     114             : 
     115           0 :         e = memchr(p, ',', l);
     116           0 :         if (!e)
     117           0 :                 return;
     118           0 :         *e = 0;
     119             : 
     120           0 :         r = safe_atoi(p, &priority);
     121           0 :         if (r < 0 || priority < 0 || priority > 999)
     122           0 :                 return;
     123             : 
     124           0 :         if (s->forward_to_kmsg && LOG_FAC(priority) != LOG_KERN)
     125           0 :                 return;
     126             : 
     127           0 :         l -= (e - p) + 1;
     128           0 :         p = e + 1;
     129           0 :         e = memchr(p, ',', l);
     130           0 :         if (!e)
     131           0 :                 return;
     132           0 :         *e = 0;
     133             : 
     134           0 :         r = safe_atou64(p, &serial);
     135           0 :         if (r < 0)
     136           0 :                 return;
     137             : 
     138           0 :         if (s->kernel_seqnum) {
     139             :                 /* We already read this one? */
     140           0 :                 if (serial < *s->kernel_seqnum)
     141           0 :                         return;
     142             : 
     143             :                 /* Did we lose any? */
     144           0 :                 if (serial > *s->kernel_seqnum)
     145           0 :                         server_driver_message(s, 0,
     146             :                                               "MESSAGE_ID=" SD_MESSAGE_JOURNAL_MISSED_STR,
     147           0 :                                               LOG_MESSAGE("Missed %"PRIu64" kernel messages",
     148             :                                                           serial - *s->kernel_seqnum),
     149             :                                               NULL);
     150             : 
     151             :                 /* Make sure we never read this one again. Note that
     152             :                  * we always store the next message serial we expect
     153             :                  * here, simply because this makes handling the first
     154             :                  * message with serial 0 easy. */
     155           0 :                 *s->kernel_seqnum = serial + 1;
     156             :         }
     157             : 
     158           0 :         l -= (e - p) + 1;
     159           0 :         p = e + 1;
     160           0 :         f = memchr(p, ';', l);
     161           0 :         if (!f)
     162           0 :                 return;
     163             :         /* Kernel 3.6 has the flags field, kernel 3.5 lacks that */
     164           0 :         e = memchr(p, ',', l);
     165           0 :         if (!e || f < e)
     166           0 :                 e = f;
     167           0 :         *e = 0;
     168             : 
     169           0 :         r = safe_atollu(p, &usec);
     170           0 :         if (r < 0)
     171           0 :                 return;
     172             : 
     173           0 :         l -= (f - p) + 1;
     174           0 :         p = f + 1;
     175           0 :         e = memchr(p, '\n', l);
     176           0 :         if (!e)
     177           0 :                 return;
     178           0 :         *e = 0;
     179             : 
     180           0 :         pl = e - p;
     181           0 :         l -= (e - p) + 1;
     182           0 :         k = e + 1;
     183             : 
     184           0 :         for (j = 0; l > 0 && j < N_IOVEC_KERNEL_FIELDS; j++) {
     185             :                 char *m;
     186             :                 /* Metadata fields attached */
     187             : 
     188           0 :                 if (*k != ' ')
     189           0 :                         break;
     190             : 
     191           0 :                 k++, l--;
     192             : 
     193           0 :                 e = memchr(k, '\n', l);
     194           0 :                 if (!e)
     195           0 :                         goto finish;
     196             : 
     197           0 :                 *e = 0;
     198             : 
     199           0 :                 if (cunescape_length_with_prefix(k, e - k, "_KERNEL_", UNESCAPE_RELAX, &m) < 0)
     200           0 :                         break;
     201             : 
     202           0 :                 if (startswith(m, "_KERNEL_DEVICE="))
     203           0 :                         kernel_device = m + 15;
     204             : 
     205           0 :                 iovec[n++] = IOVEC_MAKE_STRING(m);
     206           0 :                 z++;
     207             : 
     208           0 :                 l -= (e - k) + 1;
     209           0 :                 k = e + 1;
     210             :         }
     211             : 
     212           0 :         if (kernel_device) {
     213           0 :                 _cleanup_(sd_device_unrefp) sd_device *d = NULL;
     214             : 
     215           0 :                 if (sd_device_new_from_device_id(&d, kernel_device) >= 0) {
     216             :                         const char *g;
     217             :                         char *b;
     218             : 
     219           0 :                         if (sd_device_get_devname(d, &g) >= 0) {
     220           0 :                                 b = strjoin("_UDEV_DEVNODE=", g);
     221           0 :                                 if (b) {
     222           0 :                                         iovec[n++] = IOVEC_MAKE_STRING(b);
     223           0 :                                         z++;
     224             :                                 }
     225             :                         }
     226             : 
     227           0 :                         if (sd_device_get_sysname(d, &g) >= 0) {
     228           0 :                                 b = strjoin("_UDEV_SYSNAME=", g);
     229           0 :                                 if (b) {
     230           0 :                                         iovec[n++] = IOVEC_MAKE_STRING(b);
     231           0 :                                         z++;
     232             :                                 }
     233             :                         }
     234             : 
     235           0 :                         j = 0;
     236           0 :                         FOREACH_DEVICE_DEVLINK(d, g) {
     237             : 
     238           0 :                                 if (j >= N_IOVEC_UDEV_FIELDS)
     239           0 :                                         break;
     240             : 
     241           0 :                                 b = strjoin("_UDEV_DEVLINK=", g);
     242           0 :                                 if (b) {
     243           0 :                                         iovec[n++] = IOVEC_MAKE_STRING(b);
     244           0 :                                         z++;
     245             :                                 }
     246             : 
     247           0 :                                 j++;
     248             :                         }
     249             :                 }
     250             :         }
     251             : 
     252           0 :         if (asprintf(&source_time, "_SOURCE_MONOTONIC_TIMESTAMP=%llu", usec) >= 0)
     253           0 :                 iovec[n++] = IOVEC_MAKE_STRING(source_time);
     254             : 
     255           0 :         iovec[n++] = IOVEC_MAKE_STRING("_TRANSPORT=kernel");
     256             : 
     257           0 :         if (asprintf(&syslog_priority, "PRIORITY=%i", priority & LOG_PRIMASK) >= 0)
     258           0 :                 iovec[n++] = IOVEC_MAKE_STRING(syslog_priority);
     259             : 
     260           0 :         if (asprintf(&syslog_facility, "SYSLOG_FACILITY=%i", LOG_FAC(priority)) >= 0)
     261           0 :                 iovec[n++] = IOVEC_MAKE_STRING(syslog_facility);
     262             : 
     263           0 :         if (LOG_FAC(priority) == LOG_KERN)
     264           0 :                 iovec[n++] = IOVEC_MAKE_STRING("SYSLOG_IDENTIFIER=kernel");
     265             :         else {
     266           0 :                 pl -= syslog_parse_identifier((const char**) &p, &identifier, &pid);
     267             : 
     268             :                 /* Avoid any messages we generated ourselves via
     269             :                  * log_info() and friends. */
     270           0 :                 if (is_us(identifier, pid))
     271           0 :                         goto finish;
     272             : 
     273           0 :                 if (identifier) {
     274           0 :                         syslog_identifier = strjoin("SYSLOG_IDENTIFIER=", identifier);
     275           0 :                         if (syslog_identifier)
     276           0 :                                 iovec[n++] = IOVEC_MAKE_STRING(syslog_identifier);
     277             :                 }
     278             : 
     279           0 :                 if (pid) {
     280           0 :                         syslog_pid = strjoin("SYSLOG_PID=", pid);
     281           0 :                         if (syslog_pid)
     282           0 :                                 iovec[n++] = IOVEC_MAKE_STRING(syslog_pid);
     283             :                 }
     284             :         }
     285             : 
     286           0 :         if (cunescape_length_with_prefix(p, pl, "MESSAGE=", UNESCAPE_RELAX, &message) >= 0)
     287           0 :                 iovec[n++] = IOVEC_MAKE_STRING(message);
     288             : 
     289           0 :         server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, NULL, priority, 0);
     290             : 
     291           0 : finish:
     292           0 :         for (j = 0; j < z; j++)
     293           0 :                 free(iovec[j].iov_base);
     294             : }
     295             : 
     296           0 : static int server_read_dev_kmsg(Server *s) {
     297             :         char buffer[8192+1]; /* the kernel-side limit per record is 8K currently */
     298             :         ssize_t l;
     299             : 
     300           0 :         assert(s);
     301           0 :         assert(s->dev_kmsg_fd >= 0);
     302             : 
     303           0 :         l = read(s->dev_kmsg_fd, buffer, sizeof(buffer) - 1);
     304           0 :         if (l == 0)
     305           0 :                 return 0;
     306           0 :         if (l < 0) {
     307             :                 /* Old kernels who don't allow reading from /dev/kmsg
     308             :                  * return EINVAL when we try. So handle this cleanly,
     309             :                  * but don' try to ever read from it again. */
     310           0 :                 if (errno == EINVAL) {
     311           0 :                         s->dev_kmsg_event_source = sd_event_source_unref(s->dev_kmsg_event_source);
     312           0 :                         return 0;
     313             :                 }
     314             : 
     315           0 :                 if (IN_SET(errno, EAGAIN, EINTR, EPIPE))
     316           0 :                         return 0;
     317             : 
     318           0 :                 return log_error_errno(errno, "Failed to read from kernel: %m");
     319             :         }
     320             : 
     321           0 :         dev_kmsg_record(s, buffer, l);
     322           0 :         return 1;
     323             : }
     324             : 
     325           0 : int server_flush_dev_kmsg(Server *s) {
     326             :         int r;
     327             : 
     328           0 :         assert(s);
     329             : 
     330           0 :         if (s->dev_kmsg_fd < 0)
     331           0 :                 return 0;
     332             : 
     333           0 :         if (!s->dev_kmsg_readable)
     334           0 :                 return 0;
     335             : 
     336           0 :         log_debug("Flushing /dev/kmsg...");
     337             : 
     338             :         for (;;) {
     339           0 :                 r = server_read_dev_kmsg(s);
     340           0 :                 if (r < 0)
     341           0 :                         return r;
     342             : 
     343           0 :                 if (r == 0)
     344           0 :                         break;
     345             :         }
     346             : 
     347           0 :         return 0;
     348             : }
     349             : 
     350           0 : static int dispatch_dev_kmsg(sd_event_source *es, int fd, uint32_t revents, void *userdata) {
     351           0 :         Server *s = userdata;
     352             : 
     353           0 :         assert(es);
     354           0 :         assert(fd == s->dev_kmsg_fd);
     355           0 :         assert(s);
     356             : 
     357           0 :         if (revents & EPOLLERR)
     358           0 :                 log_warning("/dev/kmsg buffer overrun, some messages lost.");
     359             : 
     360           0 :         if (!(revents & EPOLLIN))
     361           0 :                 log_error("Got invalid event from epoll for /dev/kmsg: %"PRIx32, revents);
     362             : 
     363           0 :         return server_read_dev_kmsg(s);
     364             : }
     365             : 
     366           0 : int server_open_dev_kmsg(Server *s) {
     367             :         mode_t mode;
     368             :         int r;
     369             : 
     370           0 :         assert(s);
     371             : 
     372           0 :         if (s->read_kmsg)
     373           0 :                 mode = O_RDWR|O_CLOEXEC|O_NONBLOCK|O_NOCTTY;
     374             :         else
     375           0 :                 mode = O_WRONLY|O_CLOEXEC|O_NONBLOCK|O_NOCTTY;
     376             : 
     377           0 :         s->dev_kmsg_fd = open("/dev/kmsg", mode);
     378           0 :         if (s->dev_kmsg_fd < 0) {
     379           0 :                 log_full(errno == ENOENT ? LOG_DEBUG : LOG_WARNING,
     380             :                          "Failed to open /dev/kmsg, ignoring: %m");
     381           0 :                 return 0;
     382             :         }
     383             : 
     384           0 :         if (!s->read_kmsg)
     385           0 :                 return 0;
     386             : 
     387           0 :         r = sd_event_add_io(s->event, &s->dev_kmsg_event_source, s->dev_kmsg_fd, EPOLLIN, dispatch_dev_kmsg, s);
     388           0 :         if (r < 0) {
     389             : 
     390             :                 /* This will fail with EPERM on older kernels where
     391             :                  * /dev/kmsg is not readable. */
     392           0 :                 if (r == -EPERM) {
     393           0 :                         r = 0;
     394           0 :                         goto fail;
     395             :                 }
     396             : 
     397           0 :                 log_error_errno(r, "Failed to add /dev/kmsg fd to event loop: %m");
     398           0 :                 goto fail;
     399             :         }
     400             : 
     401           0 :         r = sd_event_source_set_priority(s->dev_kmsg_event_source, SD_EVENT_PRIORITY_IMPORTANT+10);
     402           0 :         if (r < 0) {
     403           0 :                 log_error_errno(r, "Failed to adjust priority of kmsg event source: %m");
     404           0 :                 goto fail;
     405             :         }
     406             : 
     407           0 :         s->dev_kmsg_readable = true;
     408             : 
     409           0 :         return 0;
     410             : 
     411           0 : fail:
     412           0 :         s->dev_kmsg_event_source = sd_event_source_unref(s->dev_kmsg_event_source);
     413           0 :         s->dev_kmsg_fd = safe_close(s->dev_kmsg_fd);
     414             : 
     415           0 :         return r;
     416             : }
     417             : 
     418           0 : int server_open_kernel_seqnum(Server *s) {
     419           0 :         _cleanup_close_ int fd;
     420             :         uint64_t *p;
     421             :         int r;
     422             : 
     423           0 :         assert(s);
     424             : 
     425             :         /* We store the seqnum we last read in an mmaped file. That
     426             :          * way we can just use it like a variable, but it is
     427             :          * persistent and automatically flushed at reboot. */
     428             : 
     429           0 :         fd = open("/run/systemd/journal/kernel-seqnum", O_RDWR|O_CREAT|O_CLOEXEC|O_NOCTTY|O_NOFOLLOW, 0644);
     430           0 :         if (fd < 0) {
     431           0 :                 log_error_errno(errno, "Failed to open /run/systemd/journal/kernel-seqnum, ignoring: %m");
     432           0 :                 return 0;
     433             :         }
     434             : 
     435           0 :         r = posix_fallocate(fd, 0, sizeof(uint64_t));
     436           0 :         if (r != 0) {
     437           0 :                 log_error_errno(r, "Failed to allocate sequential number file, ignoring: %m");
     438           0 :                 return 0;
     439             :         }
     440             : 
     441           0 :         p = mmap(NULL, sizeof(uint64_t), PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0);
     442           0 :         if (p == MAP_FAILED) {
     443           0 :                 log_error_errno(errno, "Failed to map sequential number file, ignoring: %m");
     444           0 :                 return 0;
     445             :         }
     446             : 
     447           0 :         s->kernel_seqnum = p;
     448             : 
     449           0 :         return 0;
     450             : }

Generated by: LCOV version 1.14