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