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[STRLEN("[]: ") + 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 *identifier, const char *pid) {
 102         pid_t pid_num;
 103
 104         if (!identifier || !pid)
 105                 return false;
 106
 107         if (parse_pid(pid, &pid_num) < 0)
 108                 return false;
 109
 110         return pid_num == getpid_cached() &&
 111                streq(identifier, program_invocation_short_name);
 112 }
 113
 114 static void dev_kmsg_record(Server *s, const char *p, size_t l) {
 115
 116         _cleanup_free_ char *message = NULL, *syslog_priority = NULL, *syslog_pid = NULL, *syslog_facility = NULL, *syslog_identifier = NULL, *source_time = NULL, *identifier = NULL, *pid = NULL;
 117         struct iovec iovec[N_IOVEC_META_FIELDS + 7 + N_IOVEC_KERNEL_FIELDS + 2 + N_IOVEC_UDEV_FIELDS];
 118         char *kernel_device = NULL;
 119         unsigned long long usec;
 120         size_t n = 0, z = 0, j;
 121         int priority, r;
 122         char *e, *f, *k;
 123         uint64_t serial;
 124         size_t pl;
 125
 126         assert(s);
 127         assert(p);
 128
 129         if (l <= 0)
 130                 return;
 131
 132         e = memchr(p, ',', l);
 133         if (!e)
 134                 return;
 135         *e = 0;
 136
 137         r = safe_atoi(p, &priority);
 138         if (r < 0 || priority < 0 || priority > 999)
 139                 return;
 140
 141         if (s->forward_to_kmsg && LOG_FAC(priority) != LOG_KERN)
 142                 return;
 143
 144         l -= (e - p) + 1;
 145         p = e + 1;
 146         e = memchr(p, ',', l);
 147         if (!e)
 148                 return;
 149         *e = 0;
 150
 151         r = safe_atou64(p, &serial);
 152         if (r < 0)
 153                 return;
 154
 155         if (s->kernel_seqnum) {
 156                 /* We already read this one? */
 157                 if (serial < *s->kernel_seqnum)
 158                         return;
 159
 160                 /* Did we lose any? */
 161                 if (serial > *s->kernel_seqnum)
 162                         server_driver_message(s, 0,
 163                                               "MESSAGE_ID=" SD_MESSAGE_JOURNAL_MISSED_STR,
 164                                               LOG_MESSAGE("Missed %"PRIu64" kernel messages",
 165                                                           serial - *s->kernel_seqnum),
 166                                               NULL);
 167
 168                 /* Make sure we never read this one again. Note that
 169                  * we always store the next message serial we expect
 170                  * here, simply because this makes handling the first
 171                  * message with serial 0 easy. */
 172                 *s->kernel_seqnum = serial + 1;
 173         }
 174
 175         l -= (e - p) + 1;
 176         p = e + 1;
 177         f = memchr(p, ';', l);
 178         if (!f)
 179                 return;
 180         /* Kernel 3.6 has the flags field, kernel 3.5 lacks that */
 181         e = memchr(p, ',', l);
 182         if (!e || f < e)
 183                 e = f;
 184         *e = 0;
 185
 186         r = safe_atollu(p, &usec);
 187         if (r < 0)
 188                 return;
 189
 190         l -= (f - p) + 1;
 191         p = f + 1;
 192         e = memchr(p, '\n', l);
 193         if (!e)
 194                 return;
 195         *e = 0;
 196
 197         pl = e - p;
 198         l -= (e - p) + 1;
 199         k = e + 1;
 200
 201         for (j = 0; l > 0 && j < N_IOVEC_KERNEL_FIELDS; j++) {
 202                 char *m;
 203                 /* Metadata fields attached */
 204
 205                 if (*k != ' ')
 206                         break;
 207
 208                 k++, l--;
 209
 210                 e = memchr(k, '\n', l);
 211                 if (!e)
 212                         return;
 213
 214                 *e = 0;
 215
 216                 if (cunescape_length_with_prefix(k, e - k, "_KERNEL_", UNESCAPE_RELAX, &m) < 0)
 217                         break;
 218
 219                 if (startswith(m, "_KERNEL_DEVICE="))
 220                         kernel_device = m + 15;
 221
 222                 iovec[n++] = IOVEC_MAKE_STRING(m);
 223                 z++;
 224
 225                 l -= (e - k) + 1;
 226                 k = e + 1;
 227         }
 228
 229         if (kernel_device) {
 230                 struct udev_device *ud;
 231
 232                 ud = udev_device_new_from_device_id(s->udev, kernel_device);
 233                 if (ud) {
 234                         const char *g;
 235                         struct udev_list_entry *ll;
 236                         char *b;
 237
 238                         g = udev_device_get_devnode(ud);
 239                         if (g) {
 240                                 b = strappend("_UDEV_DEVNODE=", g);
 241                                 if (b) {
 242                                         iovec[n++] = IOVEC_MAKE_STRING(b);
 243                                         z++;
 244                                 }
 245                         }
 246
 247                         g = udev_device_get_sysname(ud);
 248                         if (g) {
 249                                 b = strappend("_UDEV_SYSNAME=", g);
 250                                 if (b) {
 251                                         iovec[n++] = IOVEC_MAKE_STRING(b);
 252                                         z++;
 253                                 }
 254                         }
 255
 256                         j = 0;
 257                         ll = udev_device_get_devlinks_list_entry(ud);
 258                         udev_list_entry_foreach(ll, ll) {
 259
 260                                 if (j > N_IOVEC_UDEV_FIELDS)
 261                                         break;
 262
 263                                 g = udev_list_entry_get_name(ll);
 264                                 if (g) {
 265                                         b = strappend("_UDEV_DEVLINK=", g);
 266                                         if (b) {
 267                                                 iovec[n++] = IOVEC_MAKE_STRING(b);
 268                                                 z++;
 269                                         }
 270                                 }
 271
 272                                 j++;
 273                         }
 274
 275                         udev_device_unref(ud);
 276                 }
 277         }
 278
 279         if (asprintf(&source_time, "_SOURCE_MONOTONIC_TIMESTAMP=%llu", usec) >= 0)
 280                 iovec[n++] = IOVEC_MAKE_STRING(source_time);
 281
 282         iovec[n++] = IOVEC_MAKE_STRING("_TRANSPORT=kernel");
 283
 284         if (asprintf(&syslog_priority, "PRIORITY=%i", priority & LOG_PRIMASK) >= 0)
 285                 iovec[n++] = IOVEC_MAKE_STRING(syslog_priority);
 286
 287         if (asprintf(&syslog_facility, "SYSLOG_FACILITY=%i", LOG_FAC(priority)) >= 0)
 288                 iovec[n++] = IOVEC_MAKE_STRING(syslog_facility);
 289
 290         if (LOG_FAC(priority) == LOG_KERN)
 291                 iovec[n++] = IOVEC_MAKE_STRING("SYSLOG_IDENTIFIER=kernel");
 292         else {
 293                 pl -= syslog_parse_identifier((const char**) &p, &identifier, &pid);
 294
 295                 /* Avoid any messages we generated ourselves via
 296                  * log_info() and friends. */
 297                 if (is_us(identifier, pid))
 298                         goto finish;
 299
 300                 if (identifier) {
 301                         syslog_identifier = strappend("SYSLOG_IDENTIFIER=", identifier);
 302                         if (syslog_identifier)
 303                                 iovec[n++] = IOVEC_MAKE_STRING(syslog_identifier);
 304                 }
 305
 306                 if (pid) {
 307                         syslog_pid = strappend("SYSLOG_PID=", pid);
 308                         if (syslog_pid)
 309                                 iovec[n++] = IOVEC_MAKE_STRING(syslog_pid);
 310                 }
 311         }
 312
 313         if (cunescape_length_with_prefix(p, pl, "MESSAGE=", UNESCAPE_RELAX, &message) >= 0)
 314                 iovec[n++] = IOVEC_MAKE_STRING(message);
 315
 316         server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, NULL, priority, 0);
 317
 318 finish:
 319         for (j = 0; j < z; j++)
 320                 free(iovec[j].iov_base);
 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 (IN_SET(errno, EAGAIN, EINTR, EPIPE))
 343                         return 0;
 344
 345                 return log_error_errno(errno, "Failed to read from kernel: %m");
 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         mode_t mode;
 395         int r;
 396
 397         assert(s);
 398
 399         if (s->read_kmsg)
 400                 mode = O_RDWR|O_CLOEXEC|O_NONBLOCK|O_NOCTTY;
 401         else
 402                 mode = O_WRONLY|O_CLOEXEC|O_NONBLOCK|O_NOCTTY;
 403
 404         s->dev_kmsg_fd = open("/dev/kmsg", mode);
 405         if (s->dev_kmsg_fd < 0) {
 406                 log_full(errno == ENOENT ? LOG_DEBUG : LOG_WARNING,
 407                          "Failed to open /dev/kmsg, ignoring: %m");
 408                 return 0;
 409         }
 410
 411         if (!s->read_kmsg)
 412                 return 0;
 413
 414         r = sd_event_add_io(s->event, &s->dev_kmsg_event_source, s->dev_kmsg_fd, EPOLLIN, dispatch_dev_kmsg, s);
 415         if (r < 0) {
 416
 417                 /* This will fail with EPERM on older kernels where
 418                  * /dev/kmsg is not readable. */
 419                 if (r == -EPERM) {
 420                         r = 0;
 421                         goto fail;
 422                 }
 423
 424                 log_error_errno(r, "Failed to add /dev/kmsg fd to event loop: %m");
 425                 goto fail;
 426         }
 427
 428         r = sd_event_source_set_priority(s->dev_kmsg_event_source, SD_EVENT_PRIORITY_IMPORTANT+10);
 429         if (r < 0) {
 430                 log_error_errno(r, "Failed to adjust priority of kmsg event source: %m");
 431                 goto fail;
 432         }
 433
 434         s->dev_kmsg_readable = true;
 435
 436         return 0;
 437
 438 fail:
 439         s->dev_kmsg_event_source = sd_event_source_unref(s->dev_kmsg_event_source);
 440         s->dev_kmsg_fd = safe_close(s->dev_kmsg_fd);
 441
 442         return r;
 443 }
 444
 445 int server_open_kernel_seqnum(Server *s) {
 446         _cleanup_close_ int fd;
 447         uint64_t *p;
 448         int r;
 449
 450         assert(s);
 451
 452         /* We store the seqnum we last read in an mmaped file. That
 453          * way we can just use it like a variable, but it is
 454          * persistent and automatically flushed at reboot. */
 455
 456         fd = open("/run/systemd/journal/kernel-seqnum", O_RDWR|O_CREAT|O_CLOEXEC|O_NOCTTY|O_NOFOLLOW, 0644);
 457         if (fd < 0) {
 458                 log_error_errno(errno, "Failed to open /run/systemd/journal/kernel-seqnum, ignoring: %m");
 459                 return 0;
 460         }
 461
 462         r = posix_fallocate(fd, 0, sizeof(uint64_t));
 463         if (r != 0) {
 464                 log_error_errno(r, "Failed to allocate sequential number file, ignoring: %m");
 465                 return 0;
 466         }
 467
 468         p = mmap(NULL, sizeof(uint64_t), PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0);
 469         if (p == MAP_FAILED) {
 470                 log_error_errno(errno, "Failed to map sequential number file, ignoring: %m");
 471                 return 0;
 472         }
 473
 474         s->kernel_seqnum = p;
 475
 476         return 0;
 477 }