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