chiark / gitweb /
journal: properly implement matching with multiple matches
[elogind.git] / src / stdout-syslog-bridge.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 #include "def.h"
41
42 #define STREAMS_MAX 4096
43 #define SERVER_FD_MAX 16
44 #define TIMEOUT_MSEC ((int) (DEFAULT_EXIT_USEC/USEC_PER_MSEC))
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         bool syslog_is_stream;
56
57         LIST_HEAD(Stream, streams);
58         unsigned n_streams;
59 } Server;
60
61 typedef enum StreamTarget {
62         STREAM_SYSLOG,
63         STREAM_KMSG
64 } StreamTarget;
65
66 typedef enum StreamState {
67         STREAM_TARGET,
68         STREAM_PRIORITY,
69         STREAM_PROCESS,
70         STREAM_PREFIX,
71         STREAM_RUNNING
72 } StreamState;
73
74 struct Stream {
75         Server *server;
76
77         StreamState state;
78
79         int fd;
80
81         StreamTarget target;
82         int priority;
83         char *process;
84         pid_t pid;
85         uid_t uid;
86         gid_t gid;
87
88         bool prefix:1;
89         bool tee_console:1;
90
91         char buffer[LINE_MAX+1];
92         size_t length;
93
94         LIST_FIELDS(Stream, stream);
95 };
96
97 static int stream_log(Stream *s, char *p, usec_t ts) {
98
99         char header_priority[16], header_time[64], header_pid[16];
100         struct iovec iovec[5];
101         int priority;
102
103         assert(s);
104         assert(p);
105
106         priority = s->priority;
107
108         if (s->prefix)
109                 parse_syslog_priority(&p, &priority);
110
111         if (*p == 0)
112                 return 0;
113
114         /* Patch in configured facility if necessary */
115         if ((priority & LOG_FACMASK) == 0)
116                 priority = (s->priority & LOG_FACMASK) | priority;
117
118         /*
119          * The format glibc uses to talk to the syslog daemon is:
120          *
121          *     <priority>time process[pid]: msg
122          *
123          * The format the kernel uses is:
124          *
125          *     <priority>msg\n
126          *
127          *  We extend the latter to include the process name and pid.
128          */
129
130         snprintf(header_priority, sizeof(header_priority), "<%i>", 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), "[%lu]: ", (unsigned 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                 union {
154                         struct cmsghdr cmsghdr;
155                         uint8_t buf[CMSG_SPACE(sizeof(struct ucred))];
156                 } control;
157                 struct ucred *ucred;
158
159                 zero(control);
160                 control.cmsghdr.cmsg_level = SOL_SOCKET;
161                 control.cmsghdr.cmsg_type = SCM_CREDENTIALS;
162                 control.cmsghdr.cmsg_len = CMSG_LEN(sizeof(struct ucred));
163
164                 ucred = (struct ucred*) CMSG_DATA(&control.cmsghdr);
165                 ucred->pid = s->pid;
166                 ucred->uid = s->uid;
167                 ucred->gid = s->gid;
168
169                 IOVEC_SET_STRING(iovec[1], header_time);
170                 IOVEC_SET_STRING(iovec[2], s->process);
171                 IOVEC_SET_STRING(iovec[3], header_pid);
172                 IOVEC_SET_STRING(iovec[4], p);
173
174                 /* When using syslog via SOCK_STREAM separate the messages by NUL chars */
175                 if (s->server->syslog_is_stream)
176                         iovec[4].iov_len++;
177
178                 zero(msghdr);
179                 msghdr.msg_iov = iovec;
180                 msghdr.msg_iovlen = ELEMENTSOF(iovec);
181                 msghdr.msg_control = &control;
182                 msghdr.msg_controllen = control.cmsghdr.cmsg_len;
183
184                 for (;;) {
185                         ssize_t n;
186
187                         if ((n = sendmsg(s->server->syslog_fd, &msghdr, MSG_NOSIGNAL)) < 0) {
188
189                                 if (errno == ESRCH) {
190                                         pid_t our_pid;
191
192                                         /* Hmm, maybe the process this
193                                          * line originates from is
194                                          * dead? Then let's patch in
195                                          * our own pid and retry,
196                                          * since we have nothing
197                                          * better */
198
199                                         our_pid = getpid();
200
201                                         if (ucred->pid != our_pid) {
202                                                 ucred->pid = our_pid;
203                                                 continue;
204                                         }
205                                 }
206
207                                 return -errno;
208                         }
209
210                         if (!s->server->syslog_is_stream ||
211                             (size_t) n >= IOVEC_TOTAL_SIZE(iovec, ELEMENTSOF(iovec)))
212                                 break;
213
214                         IOVEC_INCREMENT(iovec, ELEMENTSOF(iovec), n);
215                 }
216
217         } else if (s->target == STREAM_KMSG) {
218                 IOVEC_SET_STRING(iovec[1], s->process);
219                 IOVEC_SET_STRING(iovec[2], header_pid);
220                 IOVEC_SET_STRING(iovec[3], p);
221                 IOVEC_SET_STRING(iovec[4], (char*) "\n");
222
223                 if (writev(s->server->kmsg_fd, iovec, ELEMENTSOF(iovec)) < 0)
224                         return -errno;
225         } else
226                 assert_not_reached("Unknown log target");
227
228         if (s->tee_console) {
229                 int console;
230
231                 if ((console = open_terminal("/dev/console", O_WRONLY|O_NOCTTY|O_CLOEXEC)) >= 0) {
232                         IOVEC_SET_STRING(iovec[0], s->process);
233                         IOVEC_SET_STRING(iovec[1], header_pid);
234                         IOVEC_SET_STRING(iovec[2], p);
235                         IOVEC_SET_STRING(iovec[3], (char*) "\n");
236
237                         writev(console, iovec, 4);
238                 }
239
240         }
241
242         return 0;
243 }
244
245 static int stream_line(Stream *s, char *p, usec_t ts) {
246         int r;
247
248         assert(s);
249         assert(p);
250
251         p = strstrip(p);
252
253         switch (s->state) {
254
255         case STREAM_TARGET:
256                 if (streq(p, "syslog") || streq(p, "syslog+console"))
257                         s->target = STREAM_SYSLOG;
258                 else if (streq(p, "kmsg") || streq(p, "kmsg+console")) {
259
260                         if (s->server->kmsg_fd >= 0 && s->uid == 0)
261                                 s->target = STREAM_KMSG;
262                         else {
263                                 log_warning("/dev/kmsg logging not available.");
264                                 return -EPERM;
265                         }
266                 } else {
267                         log_warning("Failed to parse log target line.");
268                         return -EBADMSG;
269                 }
270
271                 if (endswith(p, "+console"))
272                         s->tee_console = true;
273
274                 s->state = STREAM_PRIORITY;
275                 return 0;
276
277         case STREAM_PRIORITY:
278                 if ((r = safe_atoi(p, &s->priority)) < 0) {
279                         log_warning("Failed to parse log priority line: %m");
280                         return r;
281                 }
282
283                 if (s->priority < 0) {
284                         log_warning("Log priority negative: %m");
285                         return -ERANGE;
286                 }
287
288                 s->state = STREAM_PROCESS;
289                 return 0;
290
291         case STREAM_PROCESS:
292                 if (!(s->process = strdup(p)))
293                         return -ENOMEM;
294
295                 s->state = STREAM_PREFIX;
296                 return 0;
297
298         case STREAM_PREFIX:
299
300                 if ((r = parse_boolean(p)) < 0)
301                         return r;
302
303                 s->prefix = r;
304                 s->state = STREAM_RUNNING;
305                 return 0;
306
307         case STREAM_RUNNING:
308                 return stream_log(s, p, ts);
309         }
310
311         assert_not_reached("Unknown stream state");
312 }
313
314 static int stream_scan(Stream *s, usec_t ts) {
315         char *p;
316         size_t remaining;
317         int r = 0;
318
319         assert(s);
320
321         p = s->buffer;
322         remaining = s->length;
323         for (;;) {
324                 char *end;
325                 size_t skip;
326
327                 end = memchr(p, '\n', remaining);
328                 if (!end) {
329                         if (remaining >= LINE_MAX) {
330                                 end = p + LINE_MAX;
331                                 skip = LINE_MAX;
332                         } else
333                                 break;
334                 } else
335                         skip = end - p + 1;
336
337                 *end = 0;
338
339                 r = stream_line(s, p, ts);
340                 if (r >= 0) {
341                         remaining -= skip;
342                         p += skip;
343                 }
344         }
345
346         if (p > s->buffer) {
347                 memmove(s->buffer, p, remaining);
348                 s->length = remaining;
349         }
350
351         return r;
352 }
353
354 static int stream_process(Stream *s, usec_t ts) {
355         ssize_t l;
356         int r;
357         assert(s);
358
359         l = read(s->fd, s->buffer+s->length, LINE_MAX-s->length);
360         if (l < 0) {
361
362                 if (errno == EAGAIN)
363                         return 0;
364
365                 log_warning("Failed to read from stream: %m");
366                 return -errno;
367         }
368
369
370         if (l == 0)
371                 return 0;
372
373         s->length += l;
374         r = stream_scan(s, ts);
375
376         if (r < 0)
377                 return r;
378
379         return 1;
380 }
381
382 static void stream_free(Stream *s) {
383         assert(s);
384
385         if (s->server) {
386                 assert(s->server->n_streams > 0);
387                 s->server->n_streams--;
388                 LIST_REMOVE(Stream, stream, s->server->streams, s);
389
390         }
391
392         if (s->fd >= 0) {
393                 if (s->server)
394                         epoll_ctl(s->server->epoll_fd, EPOLL_CTL_DEL, s->fd, NULL);
395
396                 close_nointr_nofail(s->fd);
397         }
398
399         free(s->process);
400         free(s);
401 }
402
403 static int stream_new(Server *s, int server_fd) {
404         Stream *stream;
405         int fd;
406         struct ucred ucred;
407         socklen_t len = sizeof(ucred);
408         struct epoll_event ev;
409         int r;
410
411         assert(s);
412
413         if ((fd = accept4(server_fd, NULL, NULL, SOCK_NONBLOCK|SOCK_CLOEXEC)) < 0)
414                 return -errno;
415
416         if (s->n_streams >= STREAMS_MAX) {
417                 log_warning("Too many connections, refusing connection.");
418                 close_nointr_nofail(fd);
419                 return 0;
420         }
421
422         if (!socket_tcpwrap(fd, "systemd-stdout-syslog-bridge")) {
423                 close_nointr_nofail(fd);
424                 return 0;
425         }
426
427         if (!(stream = new0(Stream, 1))) {
428                 close_nointr_nofail(fd);
429                 return -ENOMEM;
430         }
431
432         stream->fd = fd;
433
434         if (getsockopt(stream->fd, SOL_SOCKET, SO_PEERCRED, &ucred, &len) < 0) {
435                 r = -errno;
436                 goto fail;
437         }
438
439         if (shutdown(fd, SHUT_WR) < 0) {
440                 r = -errno;
441                 goto fail;
442         }
443
444         zero(ev);
445         ev.data.ptr = stream;
446         ev.events = EPOLLIN;
447         if (epoll_ctl(s->epoll_fd, EPOLL_CTL_ADD, fd, &ev) < 0) {
448                 r = -errno;
449                 goto fail;
450         }
451
452         stream->pid = ucred.pid;
453         stream->uid = ucred.uid;
454         stream->gid = ucred.gid;
455
456         stream->server = s;
457         LIST_PREPEND(Stream, stream, s->streams, stream);
458         s->n_streams ++;
459
460         return 0;
461
462 fail:
463         stream_free(stream);
464         return r;
465 }
466
467 static void server_done(Server *s) {
468         unsigned i;
469         assert(s);
470
471         while (s->streams)
472                 stream_free(s->streams);
473
474         for (i = 0; i < s->n_server_fd; i++)
475                 close_nointr_nofail(SD_LISTEN_FDS_START+i);
476
477         if (s->syslog_fd >= 0)
478                 close_nointr_nofail(s->syslog_fd);
479
480         if (s->epoll_fd >= 0)
481                 close_nointr_nofail(s->epoll_fd);
482
483         if (s->kmsg_fd >= 0)
484                 close_nointr_nofail(s->kmsg_fd);
485 }
486
487 static int server_init(Server *s, unsigned n_sockets) {
488         int r;
489         unsigned i;
490         union {
491                 struct sockaddr sa;
492                 struct sockaddr_un un;
493         } sa;
494
495         assert(s);
496         assert(n_sockets > 0);
497
498         zero(*s);
499
500         s->n_server_fd = n_sockets;
501         s->syslog_fd = -1;
502         s->kmsg_fd = -1;
503
504         if ((s->epoll_fd = epoll_create1(EPOLL_CLOEXEC)) < 0) {
505                 r = -errno;
506                 log_error("Failed to create epoll object: %m");
507                 goto fail;
508         }
509
510         for (i = 0; i < n_sockets; i++) {
511                 struct epoll_event ev;
512                 int fd;
513
514                 fd = SD_LISTEN_FDS_START+i;
515
516                 if ((r = sd_is_socket(fd, AF_UNSPEC, SOCK_STREAM, 1)) < 0) {
517                         log_error("Failed to determine file descriptor type: %s", strerror(-r));
518                         goto fail;
519                 }
520
521                 if (!r) {
522                         log_error("Wrong file descriptor type.");
523                         r = -EINVAL;
524                         goto fail;
525                 }
526
527                 /* We use ev.data.ptr instead of ev.data.fd here,
528                  * since on 64bit archs fd is 32bit while a pointer is
529                  * 64bit. To make sure we can easily distinguish fd
530                  * values and pointer values we want to make sure to
531                  * write the full field unconditionally. */
532
533                 zero(ev);
534                 ev.events = EPOLLIN;
535                 ev.data.ptr = INT_TO_PTR(fd);
536                 if (epoll_ctl(s->epoll_fd, EPOLL_CTL_ADD, fd, &ev) < 0) {
537                         r = -errno;
538                         log_error("Failed to add server fd to epoll object: %m");
539                         goto fail;
540                 }
541         }
542
543         zero(sa);
544         sa.un.sun_family = AF_UNIX;
545         strncpy(sa.un.sun_path, "/dev/log", sizeof(sa.un.sun_path));
546
547         if ((s->syslog_fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0)) < 0) {
548                 r = -errno;
549                 log_error("Failed to create log fd: %m");
550                 goto fail;
551         }
552
553         if (connect(s->syslog_fd, &sa.sa, sizeof(sa)) < 0) {
554                 close_nointr_nofail(s->syslog_fd);
555
556                 if ((s->syslog_fd = socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC, 0)) < 0) {
557                         r = -errno;
558                         log_error("Failed to create log fd: %m");
559                         goto fail;
560                 }
561
562                 if (connect(s->syslog_fd, &sa.sa, sizeof(sa)) < 0) {
563                         r = -errno;
564                         log_error("Failed to connect log socket to /dev/log: %m");
565                         goto fail;
566                 }
567
568                 s->syslog_is_stream = true;
569         } else
570                 s->syslog_is_stream = false;
571
572         /* /dev/kmsg logging is strictly optional */
573         if ((s->kmsg_fd = open("/dev/kmsg", O_WRONLY|O_NOCTTY|O_CLOEXEC)) < 0)
574                 log_warning("Failed to open /dev/kmsg for logging, disabling kernel log buffer support: %m");
575
576         return 0;
577
578 fail:
579         server_done(s);
580         return r;
581 }
582
583 static int process_event(Server *s, struct epoll_event *ev) {
584         int r;
585
586         assert(s);
587
588         /* Yes, this is a bit ugly, we assume that that valid pointers
589          * are > SD_LISTEN_FDS_START+SERVER_FD_MAX. Which is certainly
590          * true on Linux (and probably most other OSes, too, since the
591          * first 4k usually are part of a separate null pointer
592          * dereference page. */
593
594         if (PTR_TO_INT(ev->data.ptr) >= SD_LISTEN_FDS_START &&
595             PTR_TO_INT(ev->data.ptr) < SD_LISTEN_FDS_START+(int)s->n_server_fd) {
596
597                 if (ev->events != EPOLLIN) {
598                         log_info("Got invalid event from epoll. (1)");
599                         return -EIO;
600                 }
601
602                 if ((r = stream_new(s, PTR_TO_INT(ev->data.ptr))) < 0) {
603                         log_info("Failed to accept new connection: %s", strerror(-r));
604                         return r;
605                 }
606
607         } else {
608                 usec_t ts;
609                 Stream *stream = ev->data.ptr;
610
611                 ts = now(CLOCK_REALTIME);
612
613                 if (!(ev->events & EPOLLIN)) {
614                         log_info("Got invalid event from epoll. (2)");
615                         stream_free(stream);
616                         return 0;
617                 }
618
619                 if ((r = stream_process(stream, ts)) <= 0) {
620
621                         if (r < 0)
622                                 log_info("Got error on stream: %s", strerror(-r));
623
624                         stream_free(stream);
625                         return 0;
626                 }
627         }
628
629         return 0;
630 }
631
632 int main(int argc, char *argv[]) {
633         Server server;
634         int r = EXIT_FAILURE, n;
635
636         if (getppid() != 1) {
637                 log_error("This program should be invoked by init only.");
638                 return EXIT_FAILURE;
639         }
640
641         if (argc > 1) {
642                 log_error("This program does not take arguments.");
643                 return EXIT_FAILURE;
644         }
645
646         log_set_target(LOG_TARGET_SYSLOG_OR_KMSG);
647         log_parse_environment();
648         log_open();
649
650         umask(0022);
651
652         n = sd_listen_fds(true);
653         if (n < 0) {
654                 log_error("Failed to read listening file descriptors from environment: %s", strerror(-r));
655                 return EXIT_FAILURE;
656         }
657
658         if (n <= 0 || n > SERVER_FD_MAX) {
659                 log_error("No or too many file descriptors passed.");
660                 return EXIT_FAILURE;
661         }
662
663         if (server_init(&server, (unsigned) n) < 0)
664                 return EXIT_FAILURE;
665
666         log_debug("systemd-stdout-syslog-bridge running as pid %lu", (unsigned long) getpid());
667
668         sd_notify(false,
669                   "READY=1\n"
670                   "STATUS=Processing requests...");
671
672         for (;;) {
673                 struct epoll_event event;
674                 int k;
675
676                 if ((k = epoll_wait(server.epoll_fd,
677                                     &event, 1,
678                                     server.n_streams <= 0 ? TIMEOUT_MSEC : -1)) < 0) {
679
680                         if (errno == EINTR)
681                                 continue;
682
683                         log_error("epoll_wait() failed: %m");
684                         goto fail;
685                 }
686
687                 if (k <= 0)
688                         break;
689
690                 if (process_event(&server, &event) < 0)
691                         goto fail;
692         }
693
694         r = EXIT_SUCCESS;
695
696         log_debug("systemd-stdout-syslog-bridge stopped as pid %lu", (unsigned long) getpid());
697
698 fail:
699         sd_notify(false,
700                   "STATUS=Shutting down...");
701
702         server_done(&server);
703
704         return r;
705 }