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