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 #include "formats-util.h"
  35
  36 void server_forward_kmsg(
  37         Server *s,
  38         int priority,
  39         const char *identifier,
  40         const char *message,
  41         const struct ucred *ucred) {
  42
  43         struct iovec iovec[5];
  44         char header_priority[DECIMAL_STR_MAX(priority) + 3],
  45              header_pid[sizeof("[]: ")-1 + DECIMAL_STR_MAX(pid_t) + 1];
  46         int n = 0;
  47         char *ident_buf = NULL;
  48
  49         assert(s);
  50         assert(priority >= 0);
  51         assert(priority <= 999);
  52         assert(message);
  53
  54         if (_unlikely_(LOG_PRI(priority) > s->max_level_kmsg))
  55                 return;
  56
  57         if (_unlikely_(s->dev_kmsg_fd < 0))
  58                 return;
  59
  60         /* Never allow messages with kernel facility to be written to
  61          * kmsg, regardless where the data comes from. */
  62         priority = syslog_fixup_facility(priority);
  63
  64         /* First: priority field */
  65         xsprintf(header_priority, "<%i>", priority);
  66         IOVEC_SET_STRING(iovec[n++], header_priority);
  67
  68         /* Second: identifier and PID */
  69         if (ucred) {
  70                 if (!identifier) {
  71                         get_process_comm(ucred->pid, &ident_buf);
  72                         identifier = ident_buf;
  73                 }
  74
  75                 xsprintf(header_pid, "["PID_FMT"]: ", ucred->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_errno(errno, "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, const 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);
 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                 if (cunescape_length_with_prefix(k, e - k, "_KERNEL_", UNESCAPE_RELAX, &m) < 0)
 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         if (cunescape_length_with_prefix(p, pl, "MESSAGE=", UNESCAPE_RELAX, &message) >= 0)
 303                 IOVEC_SET_STRING(iovec[n++], message);
 304
 305         server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, NULL, NULL, 0, NULL, priority, 0);
 306
 307 finish:
 308         for (j = 0; j < z; j++)
 309                 free(iovec[j].iov_base);
 310
 311         free(message);
 312         free(syslog_priority);
 313         free(syslog_identifier);
 314         free(syslog_pid);
 315         free(syslog_facility);
 316         free(source_time);
 317         free(identifier);
 318         free(pid);
 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 (errno == EAGAIN || errno == EINTR || errno == EPIPE)
 341                         return 0;
 342
 343                 log_error_errno(errno, "Failed to read from kernel: %m");
 344                 return -errno;
 345         }
 346
 347         dev_kmsg_record(s, buffer, l);
 348         return 1;
 349 }
 350
 351 int server_flush_dev_kmsg(Server *s) {
 352         int r;
 353
 354         assert(s);
 355
 356         if (s->dev_kmsg_fd < 0)
 357                 return 0;
 358
 359         if (!s->dev_kmsg_readable)
 360                 return 0;
 361
 362         log_debug("Flushing /dev/kmsg...");
 363
 364         for (;;) {
 365                 r = server_read_dev_kmsg(s);
 366                 if (r < 0)
 367                         return r;
 368
 369                 if (r == 0)
 370                         break;
 371         }
 372
 373         return 0;
 374 }
 375
 376 static int dispatch_dev_kmsg(sd_event_source *es, int fd, uint32_t revents, void *userdata) {
 377         Server *s = userdata;
 378
 379         assert(es);
 380         assert(fd == s->dev_kmsg_fd);
 381         assert(s);
 382
 383         if (revents & EPOLLERR)
 384                 log_warning("/dev/kmsg buffer overrun, some messages lost.");
 385
 386         if (!(revents & EPOLLIN))
 387                 log_error("Got invalid event from epoll for /dev/kmsg: %"PRIx32, revents);
 388
 389         return server_read_dev_kmsg(s);
 390 }
 391
 392 int server_open_dev_kmsg(Server *s) {
 393         int r;
 394
 395         assert(s);
 396
 397         s->dev_kmsg_fd = open("/dev/kmsg", O_RDWR|O_CLOEXEC|O_NONBLOCK|O_NOCTTY);
 398         if (s->dev_kmsg_fd < 0) {
 399                 log_full(errno == ENOENT ? LOG_DEBUG : LOG_WARNING,
 400                          "Failed to open /dev/kmsg, ignoring: %m");
 401                 return 0;
 402         }
 403
 404         r = sd_event_add_io(s->event, &s->dev_kmsg_event_source, s->dev_kmsg_fd, EPOLLIN, dispatch_dev_kmsg, s);
 405         if (r < 0) {
 406
 407                 /* This will fail with EPERM on older kernels where
 408                  * /dev/kmsg is not readable. */
 409                 if (r == -EPERM) {
 410                         r = 0;
 411                         goto fail;
 412                 }
 413
 414                 log_error_errno(r, "Failed to add /dev/kmsg fd to event loop: %m");
 415                 goto fail;
 416         }
 417
 418         r = sd_event_source_set_priority(s->dev_kmsg_event_source, SD_EVENT_PRIORITY_IMPORTANT+10);
 419         if (r < 0) {
 420                 log_error_errno(r, "Failed to adjust priority of kmsg event source: %m");
 421                 goto fail;
 422         }
 423
 424         s->dev_kmsg_readable = true;
 425
 426         return 0;
 427
 428 fail:
 429         s->dev_kmsg_event_source = sd_event_source_unref(s->dev_kmsg_event_source);
 430         s->dev_kmsg_fd = safe_close(s->dev_kmsg_fd);
 431
 432         return r;
 433 }
 434
 435 int server_open_kernel_seqnum(Server *s) {
 436         _cleanup_close_ int fd;
 437         uint64_t *p;
 438
 439         assert(s);
 440
 441         /* We store the seqnum we last read in an mmaped file. That
 442          * way we can just use it like a variable, but it is
 443          * persistent and automatically flushed at reboot. */
 444
 445         fd = open("/run/systemd/journal/kernel-seqnum", O_RDWR|O_CREAT|O_CLOEXEC|O_NOCTTY|O_NOFOLLOW, 0644);
 446         if (fd < 0) {
 447                 log_error_errno(errno, "Failed to open /run/systemd/journal/kernel-seqnum, ignoring: %m");
 448                 return 0;
 449         }
 450
 451         if (posix_fallocate(fd, 0, sizeof(uint64_t)) < 0) {
 452                 log_error_errno(errno, "Failed to allocate sequential number file, ignoring: %m");
 453                 return 0;
 454         }
 455
 456         p = mmap(NULL, sizeof(uint64_t), PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0);
 457         if (p == MAP_FAILED) {
 458                 log_error_errno(errno, "Failed to map sequential number file, ignoring: %m");
 459                 return 0;
 460         }
 461
 462         s->kernel_seqnum = p;
 463
 464         return 0;
 465 }