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