src/logger.c

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