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