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