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