logger.c

   1 /*-*- Mode: C; c-basic-offset: 8 -*-*/
   2
   3 #include <sys/socket.h>
   4 #include <sys/types.h>
   5 #include <assert.h>
   6 #include <time.h>
   7 #include <string.h>
   8 #include <stdio.h>
   9 #include <errno.h>
  10 #include <unistd.h>
  11 #include <sys/poll.h>
  12 #include <sys/epoll.h>
  13 #include <sys/un.h>
  14
  15 #include "util.h"
  16 #include "log.h"
  17 #include "list.h"
  18
  19 #define STREAM_BUFFER 2048
  20 #define STREAMS_MAX 256
  21 #define SERVER_FD_START 3
  22 #define SERVER_FD_MAX 16
  23 #define TIMEOUT ((int) (10*MSEC_PER_SEC))
  24
  25 typedef struct Stream Stream;
  26
  27 typedef struct Server {
  28         int log_fd;
  29         int epoll_fd;
  30
  31         unsigned n_server_fd;
  32
  33         LIST_HEAD(Stream, streams);
  34         unsigned n_streams;
  35 } Server;
  36
  37 typedef enum StreamState {
  38         STREAM_PRIORITY,
  39         STREAM_PROCESS,
  40         STREAM_RUNNING
  41 } StreamState;
  42
  43 struct Stream {
  44         Server *server;
  45
  46         StreamState state;
  47
  48         int fd;
  49         int priority;
  50         char *process;
  51
  52         char buffer[STREAM_BUFFER];
  53         size_t length;
  54
  55         pid_t pid;
  56
  57         LIST_FIELDS(Stream, stream);
  58 };
  59
  60 #define IOVEC_SET_STRING(iovec, s)              \
  61         do {                                    \
  62                 (iovec).iov_base = s;           \
  63                 (iovec).iov_len = strlen(s);    \
  64         } while(false);
  65
  66 static int stream_log(Stream *s, char *p, usec_t timestamp) {
  67
  68         char header_priority[16], header_time[64], header_pid[16];
  69         time_t t;
  70         struct tm *tm;
  71         struct msghdr msghdr;
  72         struct iovec iovec[5];
  73
  74         assert(s);
  75         assert(p);
  76
  77         if (*p == 0)
  78                 return 0;
  79
  80         /*
  81          * The format glibc uses is:
  82          *
  83          * <priority>time process[pid]: msg
  84          */
  85
  86         snprintf(header_priority, sizeof(header_priority), "<%i>", s->priority);
  87         char_array_0(header_priority);
  88
  89         t = (time_t) (timestamp / USEC_PER_SEC);
  90         if (!(tm = localtime(&t)))
  91                 return -EINVAL;
  92
  93         if (strftime(header_time, sizeof(header_time), "%h %e %T ", tm) <= 0)
  94                 return -EINVAL;
  95
  96         snprintf(header_pid, sizeof(header_pid), "[%llu]: ", (unsigned long long) s->pid);
  97         char_array_0(header_pid);
  98
  99         zero(iovec);
 100         IOVEC_SET_STRING(iovec[0], header_priority);
 101         IOVEC_SET_STRING(iovec[1], header_time);
 102         IOVEC_SET_STRING(iovec[2], s->process);
 103         IOVEC_SET_STRING(iovec[3], header_pid);
 104         IOVEC_SET_STRING(iovec[4], p);
 105
 106         zero(msghdr);
 107         msghdr.msg_iov = iovec;
 108         msghdr.msg_iovlen = ELEMENTSOF(iovec);
 109
 110         if (sendmsg(s->server->log_fd, &msghdr, MSG_NOSIGNAL) < 0)
 111                 return -errno;
 112
 113         return 0;
 114 }
 115
 116 static int stream_line(Stream *s, char *p, usec_t timestamp) {
 117         int r;
 118
 119         assert(s);
 120         assert(p);
 121
 122         p = strstrip(p);
 123
 124         switch (s->state) {
 125
 126         case STREAM_PRIORITY:
 127                 if ((r = safe_atoi(p, &s->priority)) < 0)
 128                         return r;
 129
 130                 if (s->priority < 0)
 131                         return -ERANGE;
 132
 133                 s->state = STREAM_PROCESS;
 134                 return 0;
 135
 136         case STREAM_PROCESS:
 137                 if (!(s->process = strdup(p)))
 138                         return -ENOMEM;
 139
 140                 s->state = STREAM_RUNNING;
 141                 return 0;
 142
 143         case STREAM_RUNNING:
 144                 return stream_log(s, p, timestamp);
 145         }
 146
 147         assert_not_reached("Unknown stream state");
 148 }
 149
 150 static int stream_scan(Stream *s, usec_t timestamp) {
 151         char *p;
 152         size_t remaining;
 153         int r = 0;
 154
 155         assert(s);
 156
 157         p = s->buffer;
 158         remaining = s->length;
 159         for (;;) {
 160                 char *newline;
 161
 162                 if (!(newline = memchr(p, '\n', remaining)))
 163                         break;
 164
 165                 *newline = 0;
 166
 167                 if ((r = stream_line(s, p, timestamp)) >= 0) {
 168                         remaining -= newline-p+1;
 169                         p = newline+1;
 170                 }
 171         }
 172
 173         if (p > s->buffer) {
 174                 memmove(s->buffer, p, remaining);
 175                 s->length = remaining;
 176         }
 177
 178         return r;
 179 }
 180
 181 static int stream_process(Stream *s, usec_t timestamp) {
 182         ssize_t l;
 183         int r;
 184         assert(s);
 185
 186         if ((l = read(s->fd, s->buffer+s->length, STREAM_BUFFER-s->length)) < 0) {
 187
 188                 if (errno == EAGAIN)
 189                         return 0;
 190
 191                 log_warning("Failed to read from stream: %s", strerror(errno));
 192                 return -1;
 193         }
 194
 195
 196         if (l == 0)
 197                 return 0;
 198
 199         s->length += l;
 200         r = stream_scan(s, timestamp);
 201
 202         if (r < 0)
 203                 return r;
 204
 205         return 1;
 206 }
 207
 208 static void stream_free(Stream *s) {
 209         assert(s);
 210
 211         if (s->server) {
 212                 assert(s->server->n_streams > 0);
 213                 s->server->n_streams--;
 214                 LIST_REMOVE(Stream, stream, s->server->streams, s);
 215
 216         }
 217
 218         if (s->fd >= 0) {
 219                 if (s->server)
 220                         epoll_ctl(s->server->epoll_fd, EPOLL_CTL_DEL, s->fd, NULL);
 221
 222                 assert_se(close_nointr(s->fd) == 0);
 223         }
 224
 225         free(s->process);
 226         free(s);
 227 }
 228
 229 static int stream_new(Server *s, int server_fd) {
 230         Stream *stream;
 231         int fd;
 232         struct ucred ucred;
 233         socklen_t len = sizeof(ucred);
 234         struct epoll_event ev;
 235         int r;
 236
 237         assert(s);
 238
 239         if ((fd = accept4(server_fd, NULL, NULL, SOCK_NONBLOCK|SOCK_CLOEXEC)) < 0)
 240                 return -errno;
 241
 242         if (s->n_streams >= STREAMS_MAX) {
 243                 log_warning("Too many connections, refusing connection.");
 244                 assert_se(close_nointr(fd) == 0);
 245                 return 0;
 246         }
 247
 248         if (!(stream = new0(Stream, 1))) {
 249                 assert_se(close_nointr(fd) == 0);
 250                 return -ENOMEM;
 251         }
 252
 253         stream->fd = fd;
 254
 255         if (getsockopt(stream->fd, SOL_SOCKET, SO_PEERCRED, &ucred, &len) < 0) {
 256                 r = -errno;
 257                 goto fail;
 258         }
 259
 260         if (shutdown(fd, SHUT_WR) < 0) {
 261                 r = -errno;
 262                 goto fail;
 263         }
 264
 265         zero(ev);
 266         ev.data.ptr = stream;
 267         ev.events = POLLIN;
 268         if (epoll_ctl(s->epoll_fd, EPOLL_CTL_ADD, fd, &ev) < 0) {
 269                 r = -errno;
 270                 goto fail;
 271         }
 272
 273         stream->pid = ucred.pid;
 274
 275         stream->server = s;
 276         LIST_PREPEND(Stream, stream, s->streams, stream);
 277         s->n_streams ++;
 278
 279         return 0;
 280
 281 fail:
 282         stream_free(stream);
 283         return r;
 284 }
 285
 286 static int verify_environment(unsigned *n_sockets) {
 287         unsigned long long pid;
 288         const char *e;
 289         int r;
 290         unsigned ns;
 291
 292         assert_se(n_sockets);
 293
 294         if (!(e = getenv("LISTEN_PID"))) {
 295                 log_error("Missing $LISTEN_PID environment variable.");
 296                 return -ENOENT;
 297         }
 298
 299         if ((r = safe_atollu(e, &pid)) < 0) {
 300                 log_error("Failed to parse $LISTEN_PID: %s", strerror(-r));
 301                 return r;
 302         }
 303
 304         if (pid != (unsigned long long) getpid()) {
 305                 log_error("Socket nor for me.");
 306                 return -ENOENT;
 307         }
 308
 309         if (!(e = getenv("LISTEN_FDS"))) {
 310                 log_error("Missing $LISTEN_FDS environment variable.");
 311                 return -ENOENT;
 312         }
 313
 314         if ((r = safe_atou(e, &ns)) < 0) {
 315                 log_error("Failed to parse $LISTEN_FDS: %s", strerror(-r));
 316                 return -E2BIG;
 317         }
 318
 319         if (ns <= 0 || ns > SERVER_FD_MAX) {
 320                 log_error("Wrong number of file descriptors passed: %s", e);
 321                 return -E2BIG;
 322         }
 323
 324         *n_sockets = ns;
 325
 326         return 0;
 327 }
 328
 329 static void server_done(Server *s) {
 330         unsigned i;
 331         assert(s);
 332
 333         while (s->streams)
 334                 stream_free(s->streams);
 335
 336         for (i = 0; i < s->n_server_fd; i++)
 337                 assert_se(close_nointr(SERVER_FD_START+i) == 0);
 338
 339         if (s->log_fd >= 0)
 340                 assert_se(close_nointr(s->log_fd) == 0);
 341
 342         if (s->epoll_fd >= 0)
 343                 assert_se(close_nointr(s->epoll_fd) == 0);
 344 }
 345
 346 static int server_init(Server *s, unsigned n_sockets) {
 347         int r;
 348         unsigned i;
 349         union {
 350                 struct sockaddr sa;
 351                 struct sockaddr_un un;
 352         } sa;
 353
 354         assert(s);
 355         assert(n_sockets > 0);
 356
 357         zero(*s);
 358
 359         s->n_server_fd = n_sockets;
 360         s->log_fd = -1;
 361
 362         if ((s->epoll_fd = epoll_create1(EPOLL_CLOEXEC)) < 0) {
 363                 r = -errno;
 364                 log_error("Failed to create epoll object: %s", strerror(errno));
 365                 goto fail;
 366         }
 367
 368         for (i = 0; i < n_sockets; i++) {
 369                 struct epoll_event ev;
 370
 371                 zero(ev);
 372                 ev.events = POLLIN;
 373                 ev.data.ptr = UINT_TO_PTR(SERVER_FD_START+i);
 374                 if (epoll_ctl(s->epoll_fd, EPOLL_CTL_ADD, SERVER_FD_START+i, &ev) < 0) {
 375                         r = -errno;
 376                         log_error("Failed to add server fd to epoll object: %s", strerror(errno));
 377                         goto fail;
 378                 }
 379         }
 380
 381         if ((s->log_fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0)) < 0) {
 382                 r = -errno;
 383                 log_error("Failed to create log fd: %s", strerror(errno));
 384                 goto fail;
 385         }
 386
 387         zero(sa);
 388         sa.un.sun_family = AF_UNIX;
 389         strncpy(sa.un.sun_path, "/dev/log", sizeof(sa.un.sun_path));
 390
 391         if (connect(s->log_fd, &sa.sa, sizeof(sa)) < 0) {
 392                 r = -errno;
 393                 log_error("Failed to connect log socket to /dev/log: %s", strerror(errno));
 394                 goto fail;
 395         }
 396
 397         return 0;
 398
 399 fail:
 400         server_done(s);
 401         return r;
 402 }
 403
 404 static int process_event(Server *s, struct epoll_event *ev) {
 405         int r;
 406
 407         assert(s);
 408
 409         /* Yes, this is a bit ugly, we assume that that valid pointers
 410          * are > SERVER_FD_START+SERVER_FD_MAX. Which is certainly
 411          * true on Linux (and probably most other OSes, too, since the
 412          * first 4k usually are part of a seperate null pointer
 413          * dereference page. */
 414
 415         if (PTR_TO_UINT(ev->data.ptr) >= SERVER_FD_START &&
 416             PTR_TO_UINT(ev->data.ptr) < SERVER_FD_START+s->n_server_fd) {
 417
 418                 if (ev->events != POLLIN) {
 419                         log_info("Got invalid event from epoll. (1)");
 420                         return -EIO;
 421                 }
 422
 423                 if ((r = stream_new(s, PTR_TO_UINT(ev->data.ptr))) < 0) {
 424                         log_info("Failed to accept new connection: %s", strerror(-r));
 425                         return r;
 426                 }
 427
 428         } else {
 429                 usec_t timestamp;
 430                 Stream *stream = ev->data.ptr;
 431
 432                 timestamp = now(CLOCK_REALTIME);
 433
 434                 if (!(ev->events & POLLIN)) {
 435                         log_info("Got invalid event from epoll. (3)");
 436                         stream_free(stream);
 437                         return 0;
 438                 }
 439
 440                 if ((r = stream_process(stream, timestamp)) <= 0) {
 441
 442                         if (r < 0)
 443                                 log_info("Got error on stream: %s", strerror(-r));
 444
 445                         stream_free(stream);
 446                         return 0;
 447                 }
 448         }
 449
 450         return 0;
 451 }
 452
 453 int main(int argc, char *argv[]) {
 454         Server server;
 455         int r = 3;
 456         unsigned n;
 457
 458         log_info("systemd-logger running as pid %llu", (unsigned long long) getpid());
 459
 460         if (verify_environment(&n) < 0)
 461                 return 1;
 462
 463         if (server_init(&server, n) < 0)
 464                 return 2;
 465
 466
 467         for (;;) {
 468                 struct epoll_event event;
 469                 int n;
 470
 471                 if ((n = epoll_wait(server.epoll_fd,
 472                                     &event, 1,
 473                                     server.n_streams <= 0 ? TIMEOUT : -1)) < 0) {
 474
 475                         if (errno == EINTR)
 476                                 continue;
 477
 478                         log_error("epoll_wait() failed: %s", strerror(errno));
 479                         goto fail;
 480                 }
 481
 482                 if (n <= 0)
 483                         break;
 484
 485                 if ((r = process_event(&server, &event)) < 0)
 486                         goto fail;
 487         }
 488         r = 0;
 489
 490 fail:
 491         server_done(&server);
 492
 493         log_info("systemd-logger stopped as pid %llu", (unsigned long long) getpid());
 494
 495         return r;
 496 }