src/logger.c

   1 /*-*- Mode: C; c-basic-offset: 8 -*-*/
   2
   3 /***
   4   This file is part of systemd.
   5
   6   Copyright 2010 Lennart Poettering
   7
   8   systemd is free software; you can redistribute it and/or modify it
   9   under the terms of the GNU General Public License as published by
  10   the Free Software Foundation; either version 2 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   General Public License for more details.
  17
  18   You should have received a copy of the GNU General Public License
  19   along with systemd; If not, see <http://www.gnu.org/licenses/>.
  20 ***/
  21
  22 #include <sys/socket.h>
  23 #include <sys/types.h>
  24 #include <assert.h>
  25 #include <time.h>
  26 #include <string.h>
  27 #include <stdio.h>
  28 #include <errno.h>
  29 #include <unistd.h>
  30 #include <sys/poll.h>
  31 #include <sys/epoll.h>
  32 #include <sys/un.h>
  33 #include <fcntl.h>
  34
  35 #include "util.h"
  36 #include "log.h"
  37 #include "list.h"
  38 #include "sd-daemon.h"
  39 #include "tcpwrap.h"
  40
  41 #define STREAM_BUFFER 2048
  42 #define STREAMS_MAX 256
  43 #define SERVER_FD_MAX 16
  44 #define TIMEOUT ((int) (10*MSEC_PER_SEC))
  45
  46 typedef struct Stream Stream;
  47
  48 typedef struct Server {
  49         int syslog_fd;
  50         int kmsg_fd;
  51         int epoll_fd;
  52
  53         unsigned n_server_fd;
  54
  55         LIST_HEAD(Stream, streams);
  56         unsigned n_streams;
  57 } Server;
  58
  59 typedef enum StreamTarget {
  60         STREAM_SYSLOG,
  61         STREAM_KMSG
  62 } StreamTarget;
  63
  64 typedef enum StreamState {
  65         STREAM_TARGET,
  66         STREAM_PRIORITY,
  67         STREAM_PROCESS,
  68         STREAM_PREFIX,
  69         STREAM_RUNNING
  70 } StreamState;
  71
  72 struct Stream {
  73         Server *server;
  74
  75         StreamState state;
  76
  77         int fd;
  78
  79         StreamTarget target;
  80         int priority;
  81         char *process;
  82         pid_t pid;
  83         uid_t uid;
  84
  85         bool prefix;
  86
  87         char buffer[STREAM_BUFFER];
  88         size_t length;
  89
  90         LIST_FIELDS(Stream, stream);
  91 };
  92
  93 static int stream_log(Stream *s, char *p, usec_t ts) {
  94
  95         char header_priority[16], header_time[64], header_pid[16];
  96         struct iovec iovec[5];
  97         int priority;
  98
  99         assert(s);
 100         assert(p);
 101
 102         priority = s->priority;
 103
 104         if (s->prefix &&
 105             p[0] == '<' &&
 106             p[1] >= '0' && p[1] <= '7' &&
 107             p[2] == '>') {
 108
 109                 /* Detected priority prefix */
 110                 priority = LOG_MAKEPRI(LOG_FAC(priority), (p[1] - '0'));
 111
 112                 p += 3;
 113         }
 114
 115         if (*p == 0)
 116                 return 0;
 117
 118         /*
 119          * The format glibc uses to talk to the syslog daemon is:
 120          *
 121          *     <priority>time process[pid]: msg
 122          *
 123          * The format the kernel uses is:
 124          *
 125          *     <priority>msg\n
 126          *
 127          *  We extend the latter to include the process name and pid.
 128          */
 129
 130         snprintf(header_priority, sizeof(header_priority), "<%i>",
 131                  s->target == STREAM_SYSLOG ? priority : LOG_PRI(priority));
 132         char_array_0(header_priority);
 133
 134         if (s->target == STREAM_SYSLOG) {
 135                 time_t t;
 136                 struct tm *tm;
 137
 138                 t = (time_t) (ts / USEC_PER_SEC);
 139                 if (!(tm = localtime(&t)))
 140                         return -EINVAL;
 141
 142                 if (strftime(header_time, sizeof(header_time), "%h %e %T ", tm) <= 0)
 143                         return -EINVAL;
 144         }
 145
 146         snprintf(header_pid, sizeof(header_pid), "[%lu]: ", (unsigned long) s->pid);
 147         char_array_0(header_pid);
 148
 149         zero(iovec);
 150         IOVEC_SET_STRING(iovec[0], header_priority);
 151
 152         if (s->target == STREAM_SYSLOG) {
 153                 struct msghdr msghdr;
 154
 155                 IOVEC_SET_STRING(iovec[1], header_time);
 156                 IOVEC_SET_STRING(iovec[2], s->process);
 157                 IOVEC_SET_STRING(iovec[3], header_pid);
 158                 IOVEC_SET_STRING(iovec[4], p);
 159
 160                 zero(msghdr);
 161                 msghdr.msg_iov = iovec;
 162                 msghdr.msg_iovlen = ELEMENTSOF(iovec);
 163
 164                 if (sendmsg(s->server->syslog_fd, &msghdr, MSG_NOSIGNAL) < 0)
 165                         return -errno;
 166
 167         } else if (s->target == STREAM_KMSG) {
 168                 IOVEC_SET_STRING(iovec[1], s->process);
 169                 IOVEC_SET_STRING(iovec[2], header_pid);
 170                 IOVEC_SET_STRING(iovec[3], p);
 171                 IOVEC_SET_STRING(iovec[4], (char*) "\n");
 172
 173                 if (writev(s->server->kmsg_fd, iovec, ELEMENTSOF(iovec)) < 0)
 174                         return -errno;
 175         } else
 176                 assert_not_reached("Unknown log target");
 177
 178         return 0;
 179 }
 180
 181 static int stream_line(Stream *s, char *p, usec_t ts) {
 182         int r;
 183
 184         assert(s);
 185         assert(p);
 186
 187         p = strstrip(p);
 188
 189         switch (s->state) {
 190
 191         case STREAM_TARGET:
 192                 if (streq(p, "syslog"))
 193                         s->target = STREAM_SYSLOG;
 194                 else if (streq(p, "kmsg")) {
 195
 196                         if (s->server->kmsg_fd >= 0 && s->uid == 0)
 197                                 s->target = STREAM_KMSG;
 198                         else {
 199                                 log_warning("/dev/kmsg logging not available.");
 200                                 return -EPERM;
 201                         }
 202                 } else {
 203                         log_warning("Failed to parse log target line.");
 204                         return -EBADMSG;
 205                 }
 206                 s->state = STREAM_PRIORITY;
 207                 return 0;
 208
 209         case STREAM_PRIORITY:
 210                 if ((r = safe_atoi(p, &s->priority)) < 0) {
 211                         log_warning("Failed to parse log priority line: %s", strerror(errno));
 212                         return r;
 213                 }
 214
 215                 if (s->priority < 0) {
 216                         log_warning("Log priority negative: %s", strerror(errno));
 217                         return -ERANGE;
 218                 }
 219
 220                 s->state = STREAM_PROCESS;
 221                 return 0;
 222
 223         case STREAM_PROCESS:
 224                 if (!(s->process = strdup(p)))
 225                         return -ENOMEM;
 226
 227                 s->state = STREAM_PREFIX;
 228                 return 0;
 229
 230         case STREAM_PREFIX:
 231
 232                 if ((r = parse_boolean(p)) < 0)
 233                         return r;
 234
 235                 s->prefix = r;
 236                 s->state = STREAM_RUNNING;
 237                 return 0;
 238
 239         case STREAM_RUNNING:
 240                 return stream_log(s, p, ts);
 241         }
 242
 243         assert_not_reached("Unknown stream state");
 244 }
 245
 246 static int stream_scan(Stream *s, usec_t ts) {
 247         char *p;
 248         size_t remaining;
 249         int r = 0;
 250
 251         assert(s);
 252
 253         p = s->buffer;
 254         remaining = s->length;
 255         for (;;) {
 256                 char *newline;
 257
 258                 if (!(newline = memchr(p, '\n', remaining)))
 259                         break;
 260
 261                 *newline = 0;
 262
 263                 if ((r = stream_line(s, p, ts)) >= 0) {
 264                         remaining -= newline-p+1;
 265                         p = newline+1;
 266                 }
 267         }
 268
 269         if (p > s->buffer) {
 270                 memmove(s->buffer, p, remaining);
 271                 s->length = remaining;
 272         }
 273
 274         return r;
 275 }
 276
 277 static int stream_process(Stream *s, usec_t ts) {
 278         ssize_t l;
 279         int r;
 280         assert(s);
 281
 282         if ((l = read(s->fd, s->buffer+s->length, STREAM_BUFFER-s->length)) < 0) {
 283
 284                 if (errno == EAGAIN)
 285                         return 0;
 286
 287                 log_warning("Failed to read from stream: %s", strerror(errno));
 288                 return -1;
 289         }
 290
 291
 292         if (l == 0)
 293                 return 0;
 294
 295         s->length += l;
 296         r = stream_scan(s, ts);
 297
 298         if (r < 0)
 299                 return r;
 300
 301         return 1;
 302 }
 303
 304 static void stream_free(Stream *s) {
 305         assert(s);
 306
 307         if (s->server) {
 308                 assert(s->server->n_streams > 0);
 309                 s->server->n_streams--;
 310                 LIST_REMOVE(Stream, stream, s->server->streams, s);
 311
 312         }
 313
 314         if (s->fd >= 0) {
 315                 if (s->server)
 316                         epoll_ctl(s->server->epoll_fd, EPOLL_CTL_DEL, s->fd, NULL);
 317
 318                 close_nointr_nofail(s->fd);
 319         }
 320
 321         free(s->process);
 322         free(s);
 323 }
 324
 325 static int stream_new(Server *s, int server_fd) {
 326         Stream *stream;
 327         int fd;
 328         struct ucred ucred;
 329         socklen_t len = sizeof(ucred);
 330         struct epoll_event ev;
 331         int r;
 332
 333         assert(s);
 334
 335         if ((fd = accept4(server_fd, NULL, NULL, SOCK_NONBLOCK|SOCK_CLOEXEC)) < 0)
 336                 return -errno;
 337
 338         if (s->n_streams >= STREAMS_MAX) {
 339                 log_warning("Too many connections, refusing connection.");
 340                 close_nointr_nofail(fd);
 341                 return 0;
 342         }
 343
 344         if (!socket_tcpwrap(fd, "systemd-logger")) {
 345                 close_nointr_nofail(fd);
 346                 return 0;
 347         }
 348
 349         if (!(stream = new0(Stream, 1))) {
 350                 close_nointr_nofail(fd);
 351                 return -ENOMEM;
 352         }
 353
 354         stream->fd = fd;
 355
 356         if (getsockopt(stream->fd, SOL_SOCKET, SO_PEERCRED, &ucred, &len) < 0) {
 357                 r = -errno;
 358                 goto fail;
 359         }
 360
 361         if (shutdown(fd, SHUT_WR) < 0) {
 362                 r = -errno;
 363                 goto fail;
 364         }
 365
 366         zero(ev);
 367         ev.data.ptr = stream;
 368         ev.events = EPOLLIN;
 369         if (epoll_ctl(s->epoll_fd, EPOLL_CTL_ADD, fd, &ev) < 0) {
 370                 r = -errno;
 371                 goto fail;
 372         }
 373
 374         stream->pid = ucred.pid;
 375         stream->uid = ucred.uid;
 376
 377         stream->server = s;
 378         LIST_PREPEND(Stream, stream, s->streams, stream);
 379         s->n_streams ++;
 380
 381         return 0;
 382
 383 fail:
 384         stream_free(stream);
 385         return r;
 386 }
 387
 388 static void server_done(Server *s) {
 389         unsigned i;
 390         assert(s);
 391
 392         while (s->streams)
 393                 stream_free(s->streams);
 394
 395         for (i = 0; i < s->n_server_fd; i++)
 396                 close_nointr_nofail(SD_LISTEN_FDS_START+i);
 397
 398         if (s->syslog_fd >= 0)
 399                 close_nointr_nofail(s->syslog_fd);
 400
 401         if (s->epoll_fd >= 0)
 402                 close_nointr_nofail(s->epoll_fd);
 403
 404         if (s->kmsg_fd >= 0)
 405                 close_nointr_nofail(s->kmsg_fd);
 406 }
 407
 408 static int server_init(Server *s, unsigned n_sockets) {
 409         int r;
 410         unsigned i;
 411         union {
 412                 struct sockaddr sa;
 413                 struct sockaddr_un un;
 414         } sa;
 415
 416         assert(s);
 417         assert(n_sockets > 0);
 418
 419         zero(*s);
 420
 421         s->n_server_fd = n_sockets;
 422         s->syslog_fd = -1;
 423         s->kmsg_fd = -1;
 424
 425         if ((s->epoll_fd = epoll_create1(EPOLL_CLOEXEC)) < 0) {
 426                 r = -errno;
 427                 log_error("Failed to create epoll object: %s", strerror(errno));
 428                 goto fail;
 429         }
 430
 431         for (i = 0; i < n_sockets; i++) {
 432                 struct epoll_event ev;
 433                 int fd;
 434
 435                 fd = SD_LISTEN_FDS_START+i;
 436
 437                 if ((r = sd_is_socket(fd, AF_UNSPEC, SOCK_STREAM, 1)) < 0) {
 438                         log_error("Failed to determine file descriptor type: %s", strerror(-r));
 439                         goto fail;
 440                 }
 441
 442                 if (!r) {
 443                         log_error("Wrong file descriptor type.");
 444                         r = -EINVAL;
 445                         goto fail;
 446                 }
 447
 448                 zero(ev);
 449                 ev.events = EPOLLIN;
 450                 ev.data.ptr = UINT_TO_PTR(fd);
 451                 if (epoll_ctl(s->epoll_fd, EPOLL_CTL_ADD, fd, &ev) < 0) {
 452                         r = -errno;
 453                         log_error("Failed to add server fd to epoll object: %s", strerror(errno));
 454                         goto fail;
 455                 }
 456         }
 457
 458         if ((s->syslog_fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0)) < 0) {
 459                 r = -errno;
 460                 log_error("Failed to create log fd: %s", strerror(errno));
 461                 goto fail;
 462         }
 463
 464         zero(sa);
 465         sa.un.sun_family = AF_UNIX;
 466         strncpy(sa.un.sun_path, "/dev/log", sizeof(sa.un.sun_path));
 467
 468         if (connect(s->syslog_fd, &sa.sa, sizeof(sa)) < 0) {
 469                 r = -errno;
 470                 log_error("Failed to connect log socket to /dev/log: %s", strerror(errno));
 471                 goto fail;
 472         }
 473
 474         /* /dev/kmsg logging is strictly optional */
 475         if ((s->kmsg_fd = open("/dev/kmsg", O_WRONLY|O_NOCTTY|O_CLOEXEC)) < 0)
 476                 log_debug("Failed to open /dev/kmsg for logging, disabling kernel log buffer support: %s", strerror(errno));
 477
 478         return 0;
 479
 480 fail:
 481         server_done(s);
 482         return r;
 483 }
 484
 485 static int process_event(Server *s, struct epoll_event *ev) {
 486         int r;
 487
 488         assert(s);
 489
 490         /* Yes, this is a bit ugly, we assume that that valid pointers
 491          * are > SD_LISTEN_FDS_START+SERVER_FD_MAX. Which is certainly
 492          * true on Linux (and probably most other OSes, too, since the
 493          * first 4k usually are part of a seperate null pointer
 494          * dereference page. */
 495
 496         if (PTR_TO_UINT(ev->data.ptr) >= SD_LISTEN_FDS_START &&
 497             PTR_TO_UINT(ev->data.ptr) < SD_LISTEN_FDS_START+s->n_server_fd) {
 498
 499                 if (ev->events != EPOLLIN) {
 500                         log_info("Got invalid event from epoll. (1)");
 501                         return -EIO;
 502                 }
 503
 504                 if ((r = stream_new(s, PTR_TO_UINT(ev->data.ptr))) < 0) {
 505                         log_info("Failed to accept new connection: %s", strerror(-r));
 506                         return r;
 507                 }
 508
 509         } else {
 510                 usec_t ts;
 511                 Stream *stream = ev->data.ptr;
 512
 513                 ts = now(CLOCK_REALTIME);
 514
 515                 if (!(ev->events & EPOLLIN)) {
 516                         log_info("Got invalid event from epoll. (2)");
 517                         stream_free(stream);
 518                         return 0;
 519                 }
 520
 521                 if ((r = stream_process(stream, ts)) <= 0) {
 522
 523                         if (r < 0)
 524                                 log_info("Got error on stream: %s", strerror(-r));
 525
 526                         stream_free(stream);
 527                         return 0;
 528                 }
 529         }
 530
 531         return 0;
 532 }
 533
 534 int main(int argc, char *argv[]) {
 535         Server server;
 536         int r = 3, n;
 537
 538         log_set_target(LOG_TARGET_SYSLOG_OR_KMSG);
 539         log_parse_environment();
 540
 541         log_info("systemd-logger running as pid %lu", (unsigned long) getpid());
 542
 543         if ((n = sd_listen_fds(true)) < 0) {
 544                 log_error("Failed to read listening file descriptors from environment: %s", strerror(-r));
 545                 return 1;
 546         }
 547
 548         if (n <= 0 || n > SERVER_FD_MAX) {
 549                 log_error("No or too many file descriptors passed.");
 550                 return 2;
 551         }
 552
 553         if (server_init(&server, (unsigned) n) < 0)
 554                 return 3;
 555
 556         sd_notify(false,
 557                   "READY=1\n"
 558                   "STATUS=Processing requests...");
 559
 560         for (;;) {
 561                 struct epoll_event event;
 562                 int k;
 563
 564                 if ((k = epoll_wait(server.epoll_fd,
 565                                     &event, 1,
 566                                     server.n_streams <= 0 ? TIMEOUT : -1)) < 0) {
 567
 568                         if (errno == EINTR)
 569                                 continue;
 570
 571                         log_error("epoll_wait() failed: %s", strerror(errno));
 572                         goto fail;
 573                 }
 574
 575                 if (k <= 0)
 576                         break;
 577
 578                 if ((k = process_event(&server, &event)) < 0)
 579                         goto fail;
 580         }
 581         r = 0;
 582
 583 fail:
 584         sd_notify(false,
 585                   "STATUS=Shutting down...");
 586
 587         server_done(&server);
 588
 589         log_info("systemd-logger stopped as pid %lu", (unsigned long) getpid());
 590
 591         return r;
 592 }