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