src/journal/journald-kmsg.c

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