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