src/journal/journald-kmsg.c

   1 /*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/
   2
   3 /***
   4   This file is part of systemd.
   5
   6   Copyright 2011 Lennart Poettering
   7
   8   systemd is free software; you can redistribute it and/or modify it
   9   under the terms of the GNU Lesser General Public License as published by
  10   the Free Software Foundation; either version 2.1 of the License, or
  11   (at your option) any later version.
  12
  13   systemd is distributed in the hope that it will be useful, but
  14   WITHOUT ANY WARRANTY; without even the implied warranty of
  15   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
  16   Lesser General Public License for more details.
  17
  18   You should have received a copy of the GNU Lesser General Public License
  19   along with systemd; If not, see <http://www.gnu.org/licenses/>.
  20 ***/
  21
  22 #include <unistd.h>
  23 #include <sys/epoll.h>
  24 #include <fcntl.h>
  25 #include <sys/mman.h>
  26
  27 #include <systemd/sd-messages.h>
  28 #include <libudev.h>
  29
  30 #include "journald.h"
  31 #include "journald-kmsg.h"
  32 #include "journald-syslog.h"
  33
  34 void server_forward_kmsg(
  35         Server *s,
  36         int priority,
  37         const char *identifier,
  38         const char *message,
  39         struct ucred *ucred) {
  40
  41         struct iovec iovec[5];
  42         char header_priority[6], header_pid[16];
  43         int n = 0;
  44         char *ident_buf = NULL;
  45
  46         assert(s);
  47         assert(priority >= 0);
  48         assert(priority <= 999);
  49         assert(message);
  50
  51         if (_unlikely_(LOG_PRI(priority) > s->max_level_kmsg))
  52                 return;
  53
  54         if (_unlikely_(s->dev_kmsg_fd < 0))
  55                 return;
  56
  57         /* Never allow messages with kernel facility to be written to
  58          * kmsg, regardless where the data comes from. */
  59         priority = syslog_fixup_facility(priority);
  60
  61         /* First: priority field */
  62         snprintf(header_priority, sizeof(header_priority), "<%i>", priority);
  63         char_array_0(header_priority);
  64         IOVEC_SET_STRING(iovec[n++], header_priority);
  65
  66         /* Second: identifier and PID */
  67         if (ucred) {
  68                 if (!identifier) {
  69                         get_process_comm(ucred->pid, &ident_buf);
  70                         identifier = ident_buf;
  71                 }
  72
  73                 snprintf(header_pid, sizeof(header_pid), "[%lu]: ", (unsigned long) ucred->pid);
  74                 char_array_0(header_pid);
  75
  76                 if (identifier)
  77                         IOVEC_SET_STRING(iovec[n++], identifier);
  78
  79                 IOVEC_SET_STRING(iovec[n++], header_pid);
  80         } else if (identifier) {
  81                 IOVEC_SET_STRING(iovec[n++], identifier);
  82                 IOVEC_SET_STRING(iovec[n++], ": ");
  83         }
  84
  85         /* Fourth: message */
  86         IOVEC_SET_STRING(iovec[n++], message);
  87         IOVEC_SET_STRING(iovec[n++], "\n");
  88
  89         if (writev(s->dev_kmsg_fd, iovec, n) < 0)
  90                 log_debug("Failed to write to /dev/kmsg for logging: %s", strerror(errno));
  91
  92         free(ident_buf);
  93 }
  94
  95 static bool is_us(const char *pid) {
  96         pid_t t;
  97
  98         assert(pid);
  99
 100         if (parse_pid(pid, &t) < 0)
 101                 return false;
 102
 103         return t == getpid();
 104 }
 105
 106 static void dev_kmsg_record(Server *s, char *p, size_t l) {
 107         struct iovec iovec[N_IOVEC_META_FIELDS + 7 + N_IOVEC_KERNEL_FIELDS + 2 + N_IOVEC_UDEV_FIELDS];
 108         char *message = NULL, *syslog_priority = NULL, *syslog_pid = NULL, *syslog_facility = NULL, *syslog_identifier = NULL, *source_time = NULL;
 109         int priority, r;
 110         unsigned n = 0, z = 0, j;
 111         usec_t usec;
 112         char *identifier = NULL, *pid = NULL, *e, *f, *k;
 113         uint64_t serial;
 114         size_t pl;
 115         char *kernel_device = NULL;
 116
 117         assert(s);
 118         assert(p);
 119
 120         if (l <= 0)
 121                 return;
 122
 123         e = memchr(p, ',', l);
 124         if (!e)
 125                 return;
 126         *e = 0;
 127
 128         r = safe_atoi(p, &priority);
 129         if (r < 0 || priority < 0 || priority > 999)
 130                 return;
 131
 132         if (s->forward_to_kmsg && (priority & LOG_FACMASK) != LOG_KERN)
 133                 return;
 134
 135         l -= (e - p) + 1;
 136         p = e + 1;
 137         e = memchr(p, ',', l);
 138         if (!e)
 139                 return;
 140         *e = 0;
 141
 142         r = safe_atou64(p, &serial);
 143         if (r < 0)
 144                 return;
 145
 146         if (s->kernel_seqnum) {
 147                 /* We already read this one? */
 148                 if (serial < *s->kernel_seqnum)
 149                         return;
 150
 151                 /* Did we lose any? */
 152                 if (serial > *s->kernel_seqnum)
 153                         server_driver_message(s, SD_MESSAGE_JOURNAL_MISSED, "Missed %llu kernel messages", (unsigned long long) serial - *s->kernel_seqnum - 1);
 154
 155                 /* Make sure we never read this one again. Note that
 156                  * we always store the next message serial we expect
 157                  * here, simply because this makes handling the first
 158                  * message with serial 0 easy. */
 159                 *s->kernel_seqnum = serial + 1;
 160         }
 161
 162         l -= (e - p) + 1;
 163         p = e + 1;
 164         f = memchr(p, ';', l);
 165         if (!f)
 166                 return;
 167         /* Kernel 3.6 has the flags field, kernel 3.5 lacks that */
 168         e = memchr(p, ',', l);
 169         if (!e || f < e)
 170                 e = f;
 171         *e = 0;
 172
 173         r = parse_usec(p, &usec);
 174         if (r < 0)
 175                 return;
 176
 177         l -= (f - p) + 1;
 178         p = f + 1;
 179         e = memchr(p, '\n', l);
 180         if (!e)
 181                 return;
 182         *e = 0;
 183
 184         pl = e - p;
 185         l -= (e - p) + 1;
 186         k = e + 1;
 187
 188         for (j = 0; l > 0 && j < N_IOVEC_KERNEL_FIELDS; j++) {
 189                 char *m;
 190                 /* Meta data fields attached */
 191
 192                 if (*k != ' ')
 193                         break;
 194
 195                 k ++, l --;
 196
 197                 e = memchr(k, '\n', l);
 198                 if (!e)
 199                         return;
 200
 201                 *e = 0;
 202
 203                 m = cunescape_length_with_prefix(k, e - k, "_KERNEL_");
 204                 if (!m)
 205                         break;
 206
 207                 if (startswith(m, "_KERNEL_DEVICE="))
 208                         kernel_device = m + 15;
 209
 210                 IOVEC_SET_STRING(iovec[n++], m);
 211                 z++;
 212
 213                 l -= (e - k) + 1;
 214                 k = e + 1;
 215         }
 216
 217         if (kernel_device) {
 218                 struct udev_device *ud;
 219
 220                 ud = udev_device_new_from_device_id(s->udev, kernel_device);
 221                 if (ud) {
 222                         const char *g;
 223                         struct udev_list_entry *ll;
 224                         char *b;
 225
 226                         g = udev_device_get_devnode(ud);
 227                         if (g) {
 228                                 b = strappend("_UDEV_DEVNODE=", g);
 229                                 if (b) {
 230                                         IOVEC_SET_STRING(iovec[n++], b);
 231                                         z++;
 232                                 }
 233                         }
 234
 235                         g = udev_device_get_sysname(ud);
 236                         if (g) {
 237                                 b = strappend("_UDEV_SYSNAME=", g);
 238                                 if (b) {
 239                                         IOVEC_SET_STRING(iovec[n++], b);
 240                                         z++;
 241                                 }
 242                         }
 243
 244                         j = 0;
 245                         ll = udev_device_get_devlinks_list_entry(ud);
 246                         udev_list_entry_foreach(ll, ll) {
 247
 248                                 if (j > N_IOVEC_UDEV_FIELDS)
 249                                         break;
 250
 251                                 g = udev_list_entry_get_name(ll);
 252                                 b = strappend("_UDEV_DEVLINK=", g);
 253                                 if (g) {
 254                                         IOVEC_SET_STRING(iovec[n++], b);
 255                                         z++;
 256                                 }
 257
 258                                 j++;
 259                         }
 260
 261                         udev_device_unref(ud);
 262                 }
 263         }
 264
 265         if (asprintf(&source_time, "_SOURCE_MONOTONIC_TIMESTAMP=%llu",
 266                      (unsigned long long) usec) >= 0)
 267                 IOVEC_SET_STRING(iovec[n++], source_time);
 268
 269         IOVEC_SET_STRING(iovec[n++], "_TRANSPORT=kernel");
 270
 271         if (asprintf(&syslog_priority, "PRIORITY=%i", priority & LOG_PRIMASK) >= 0)
 272                 IOVEC_SET_STRING(iovec[n++], syslog_priority);
 273
 274         if ((priority & LOG_FACMASK) == LOG_KERN)
 275                 IOVEC_SET_STRING(iovec[n++], "SYSLOG_IDENTIFIER=kernel");
 276         else {
 277                 syslog_read_identifier((const char**) &p, &identifier, &pid);
 278
 279                 /* Avoid any messages we generated ourselves via
 280                  * log_info() and friends. */
 281                 if (pid && is_us(pid))
 282                         goto finish;
 283
 284                 if (identifier) {
 285                         syslog_identifier = strappend("SYSLOG_IDENTIFIER=", identifier);
 286                         if (syslog_identifier)
 287                                 IOVEC_SET_STRING(iovec[n++], syslog_identifier);
 288                 }
 289
 290                 if (pid) {
 291                         syslog_pid = strappend("SYSLOG_PID=", pid);
 292                         if (syslog_pid)
 293                                 IOVEC_SET_STRING(iovec[n++], syslog_pid);
 294                 }
 295
 296                 if (asprintf(&syslog_facility, "SYSLOG_FACILITY=%i", LOG_FAC(priority)) >= 0)
 297                         IOVEC_SET_STRING(iovec[n++], syslog_facility);
 298         }
 299
 300         message = cunescape_length_with_prefix(p, pl, "MESSAGE=");
 301         if (message)
 302                 IOVEC_SET_STRING(iovec[n++], message);
 303
 304         server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, NULL, NULL, 0, NULL, priority);
 305
 306 finish:
 307         for (j = 0; j < z; j++)
 308                 free(iovec[j].iov_base);
 309
 310         free(message);
 311         free(syslog_priority);
 312         free(syslog_identifier);
 313         free(syslog_pid);
 314         free(syslog_facility);
 315         free(source_time);
 316         free(identifier);
 317         free(pid);
 318 }
 319
 320 int server_read_dev_kmsg(Server *s) {
 321         char buffer[8192+1]; /* the kernel-side limit per record is 8K currently */
 322         ssize_t l;
 323
 324         assert(s);
 325         assert(s->dev_kmsg_fd >= 0);
 326
 327         l = read(s->dev_kmsg_fd, buffer, sizeof(buffer) - 1);
 328         if (l == 0)
 329                 return 0;
 330         if (l < 0) {
 331                 /* Old kernels who don't allow reading from /dev/kmsg
 332                  * return EINVAL when we try. So handle this cleanly,
 333                  * but don' try to ever read from it again. */
 334                 if (errno == EINVAL) {
 335                         epoll_ctl(s->epoll_fd, EPOLL_CTL_DEL, s->dev_kmsg_fd, NULL);
 336                         return 0;
 337                 }
 338
 339                 if (errno == EAGAIN || errno == EINTR || errno == EPIPE)
 340                         return 0;
 341
 342                 log_error("Failed to read from kernel: %m");
 343                 return -errno;
 344         }
 345
 346         dev_kmsg_record(s, buffer, l);
 347         return 1;
 348 }
 349
 350 int server_flush_dev_kmsg(Server *s) {
 351         int r;
 352
 353         assert(s);
 354
 355         if (s->dev_kmsg_fd < 0)
 356                 return 0;
 357
 358         if (!s->dev_kmsg_readable)
 359                 return 0;
 360
 361         log_info("Flushing /dev/kmsg...");
 362
 363         for (;;) {
 364                 r = server_read_dev_kmsg(s);
 365                 if (r < 0)
 366                         return r;
 367
 368                 if (r == 0)
 369                         break;
 370         }
 371
 372         return 0;
 373 }
 374
 375 int server_open_dev_kmsg(Server *s) {
 376         struct epoll_event ev;
 377
 378         assert(s);
 379
 380         s->dev_kmsg_fd = open("/dev/kmsg", O_RDWR|O_CLOEXEC|O_NONBLOCK|O_NOCTTY);
 381         if (s->dev_kmsg_fd < 0) {
 382                 log_warning("Failed to open /dev/kmsg, ignoring: %m");
 383                 return 0;
 384         }
 385
 386         zero(ev);
 387         ev.events = EPOLLIN;
 388         ev.data.fd = s->dev_kmsg_fd;
 389         if (epoll_ctl(s->epoll_fd, EPOLL_CTL_ADD, s->dev_kmsg_fd, &ev) < 0) {
 390
 391                 /* This will fail with EPERM on older kernels where
 392                  * /dev/kmsg is not readable. */
 393                 if (errno == EPERM)
 394                         return 0;
 395
 396                 log_error("Failed to add /dev/kmsg fd to epoll object: %m");
 397                 return -errno;
 398         }
 399
 400         s->dev_kmsg_readable = true;
 401
 402         return 0;
 403 }
 404
 405 int server_open_kernel_seqnum(Server *s) {
 406         int fd;
 407         uint64_t *p;
 408
 409         assert(s);
 410
 411         /* We store the seqnum we last read in an mmaped file. That
 412          * way we can just use it like a variable, but it is
 413          * persistant and automatically flushed at reboot. */
 414
 415         fd = open("/run/systemd/journal/kernel-seqnum", O_RDWR|O_CREAT|O_CLOEXEC|O_NOCTTY|O_NOFOLLOW, 0644);
 416         if (fd < 0) {
 417                 log_error("Failed to open /run/systemd/journal/kernel-seqnum, ignoring: %m");
 418                 return 0;
 419         }
 420
 421         if (posix_fallocate(fd, 0, sizeof(uint64_t)) < 0) {
 422                 log_error("Failed to allocate sequential number file, ignoring: %m");
 423                 close_nointr_nofail(fd);
 424                 return 0;
 425         }
 426
 427         p = mmap(NULL, sizeof(uint64_t), PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0);
 428         if (p == MAP_FAILED) {
 429                 log_error("Failed to map sequential number file, ignoring: %m");
 430                 close_nointr_nofail(fd);
 431                 return 0;
 432         }
 433
 434         close_nointr_nofail(fd);
 435         s->kernel_seqnum = p;
 436
 437         return 0;
 438 }