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