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