chiark / gitweb /
service: honour that for services RestartSec=0 means immediate restarts but TimeoutSe...
[elogind.git] / src / journal / journald-kmsg.c
1 /*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/
2
3 /***
4   This file is part of systemd.
5
6   Copyright 2011 Lennart Poettering
7
8   systemd is free software; you can redistribute it and/or modify it
9   under the terms of the GNU Lesser General Public License as published by
10   the Free Software Foundation; either version 2.1 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   Lesser General Public License for more details.
17
18   You should have received a copy of the GNU Lesser General Public License
19   along with systemd; If not, see <http://www.gnu.org/licenses/>.
20 ***/
21
22 #include <unistd.h>
23 #include <sys/epoll.h>
24 #include <fcntl.h>
25 #include <sys/mman.h>
26 #include <sys/socket.h>
27
28 #include <systemd/sd-messages.h>
29 #include <libudev.h>
30
31 #include "journald-server.h"
32 #include "journald-kmsg.h"
33 #include "journald-syslog.h"
34
35 void server_forward_kmsg(
36         Server *s,
37         int priority,
38         const char *identifier,
39         const char *message,
40         struct ucred *ucred) {
41
42         struct iovec iovec[5];
43         char header_priority[6], header_pid[16];
44         int n = 0;
45         char *ident_buf = NULL;
46
47         assert(s);
48         assert(priority >= 0);
49         assert(priority <= 999);
50         assert(message);
51
52         if (_unlikely_(LOG_PRI(priority) > s->max_level_kmsg))
53                 return;
54
55         if (_unlikely_(s->dev_kmsg_fd < 0))
56                 return;
57
58         /* Never allow messages with kernel facility to be written to
59          * kmsg, regardless where the data comes from. */
60         priority = syslog_fixup_facility(priority);
61
62         /* First: priority field */
63         snprintf(header_priority, sizeof(header_priority), "<%i>", priority);
64         char_array_0(header_priority);
65         IOVEC_SET_STRING(iovec[n++], header_priority);
66
67         /* Second: identifier and PID */
68         if (ucred) {
69                 if (!identifier) {
70                         get_process_comm(ucred->pid, &ident_buf);
71                         identifier = ident_buf;
72                 }
73
74                 snprintf(header_pid, sizeof(header_pid), "[%lu]: ", (unsigned long) ucred->pid);
75                 char_array_0(header_pid);
76
77                 if (identifier)
78                         IOVEC_SET_STRING(iovec[n++], identifier);
79
80                 IOVEC_SET_STRING(iovec[n++], header_pid);
81         } else if (identifier) {
82                 IOVEC_SET_STRING(iovec[n++], identifier);
83                 IOVEC_SET_STRING(iovec[n++], ": ");
84         }
85
86         /* Fourth: message */
87         IOVEC_SET_STRING(iovec[n++], message);
88         IOVEC_SET_STRING(iovec[n++], "\n");
89
90         if (writev(s->dev_kmsg_fd, iovec, n) < 0)
91                 log_debug("Failed to write to /dev/kmsg for logging: %s", strerror(errno));
92
93         free(ident_buf);
94 }
95
96 static bool is_us(const char *pid) {
97         pid_t t;
98
99         assert(pid);
100
101         if (parse_pid(pid, &t) < 0)
102                 return false;
103
104         return t == getpid();
105 }
106
107 static void dev_kmsg_record(Server *s, char *p, size_t l) {
108         struct iovec iovec[N_IOVEC_META_FIELDS + 7 + N_IOVEC_KERNEL_FIELDS + 2 + N_IOVEC_UDEV_FIELDS];
109         char *message = NULL, *syslog_priority = NULL, *syslog_pid = NULL, *syslog_facility = NULL, *syslog_identifier = NULL, *source_time = NULL;
110         int priority, r;
111         unsigned n = 0, z = 0, j;
112         unsigned long long usec;
113         char *identifier = NULL, *pid = NULL, *e, *f, *k;
114         uint64_t serial;
115         size_t pl;
116         char *kernel_device = NULL;
117
118         assert(s);
119         assert(p);
120
121         if (l <= 0)
122                 return;
123
124         e = memchr(p, ',', l);
125         if (!e)
126                 return;
127         *e = 0;
128
129         r = safe_atoi(p, &priority);
130         if (r < 0 || priority < 0 || priority > 999)
131                 return;
132
133         if (s->forward_to_kmsg && (priority & LOG_FACMASK) != LOG_KERN)
134                 return;
135
136         l -= (e - p) + 1;
137         p = e + 1;
138         e = memchr(p, ',', l);
139         if (!e)
140                 return;
141         *e = 0;
142
143         r = safe_atou64(p, &serial);
144         if (r < 0)
145                 return;
146
147         if (s->kernel_seqnum) {
148                 /* We already read this one? */
149                 if (serial < *s->kernel_seqnum)
150                         return;
151
152                 /* Did we lose any? */
153                 if (serial > *s->kernel_seqnum)
154                         server_driver_message(s, SD_MESSAGE_JOURNAL_MISSED, "Missed %"PRIu64" kernel messages",
155                                               serial - *s->kernel_seqnum - 1);
156
157                 /* Make sure we never read this one again. Note that
158                  * we always store the next message serial we expect
159                  * here, simply because this makes handling the first
160                  * message with serial 0 easy. */
161                 *s->kernel_seqnum = serial + 1;
162         }
163
164         l -= (e - p) + 1;
165         p = e + 1;
166         f = memchr(p, ';', l);
167         if (!f)
168                 return;
169         /* Kernel 3.6 has the flags field, kernel 3.5 lacks that */
170         e = memchr(p, ',', l);
171         if (!e || f < e)
172                 e = f;
173         *e = 0;
174
175         r = safe_atollu(p, &usec);
176         if (r < 0)
177                 return;
178
179         l -= (f - p) + 1;
180         p = f + 1;
181         e = memchr(p, '\n', l);
182         if (!e)
183                 return;
184         *e = 0;
185
186         pl = e - p;
187         l -= (e - p) + 1;
188         k = e + 1;
189
190         for (j = 0; l > 0 && j < N_IOVEC_KERNEL_FIELDS; j++) {
191                 char *m;
192                 /* Meta data fields attached */
193
194                 if (*k != ' ')
195                         break;
196
197                 k ++, l --;
198
199                 e = memchr(k, '\n', l);
200                 if (!e)
201                         return;
202
203                 *e = 0;
204
205                 m = cunescape_length_with_prefix(k, e - k, "_KERNEL_");
206                 if (!m)
207                         break;
208
209                 if (startswith(m, "_KERNEL_DEVICE="))
210                         kernel_device = m + 15;
211
212                 IOVEC_SET_STRING(iovec[n++], m);
213                 z++;
214
215                 l -= (e - k) + 1;
216                 k = e + 1;
217         }
218
219         if (kernel_device) {
220                 struct udev_device *ud;
221
222                 ud = udev_device_new_from_device_id(s->udev, kernel_device);
223                 if (ud) {
224                         const char *g;
225                         struct udev_list_entry *ll;
226                         char *b;
227
228                         g = udev_device_get_devnode(ud);
229                         if (g) {
230                                 b = strappend("_UDEV_DEVNODE=", g);
231                                 if (b) {
232                                         IOVEC_SET_STRING(iovec[n++], b);
233                                         z++;
234                                 }
235                         }
236
237                         g = udev_device_get_sysname(ud);
238                         if (g) {
239                                 b = strappend("_UDEV_SYSNAME=", g);
240                                 if (b) {
241                                         IOVEC_SET_STRING(iovec[n++], b);
242                                         z++;
243                                 }
244                         }
245
246                         j = 0;
247                         ll = udev_device_get_devlinks_list_entry(ud);
248                         udev_list_entry_foreach(ll, ll) {
249
250                                 if (j > N_IOVEC_UDEV_FIELDS)
251                                         break;
252
253                                 g = udev_list_entry_get_name(ll);
254                                 if (g) {
255                                         b = strappend("_UDEV_DEVLINK=", g);
256                                         if (b) {
257                                                 IOVEC_SET_STRING(iovec[n++], b);
258                                                 z++;
259                                         }
260                                 }
261
262                                 j++;
263                         }
264
265                         udev_device_unref(ud);
266                 }
267         }
268
269         if (asprintf(&source_time, "_SOURCE_MONOTONIC_TIMESTAMP=%llu", usec) >= 0)
270                 IOVEC_SET_STRING(iovec[n++], source_time);
271
272         IOVEC_SET_STRING(iovec[n++], "_TRANSPORT=kernel");
273
274         if (asprintf(&syslog_priority, "PRIORITY=%i", priority & LOG_PRIMASK) >= 0)
275                 IOVEC_SET_STRING(iovec[n++], syslog_priority);
276
277         if ((priority & LOG_FACMASK) == LOG_KERN)
278                 IOVEC_SET_STRING(iovec[n++], "SYSLOG_IDENTIFIER=kernel");
279         else {
280                 pl -= syslog_parse_identifier((const char**) &p, &identifier, &pid);
281
282                 /* Avoid any messages we generated ourselves via
283                  * log_info() and friends. */
284                 if (pid && is_us(pid))
285                         goto finish;
286
287                 if (identifier) {
288                         syslog_identifier = strappend("SYSLOG_IDENTIFIER=", identifier);
289                         if (syslog_identifier)
290                                 IOVEC_SET_STRING(iovec[n++], syslog_identifier);
291                 }
292
293                 if (pid) {
294                         syslog_pid = strappend("SYSLOG_PID=", pid);
295                         if (syslog_pid)
296                                 IOVEC_SET_STRING(iovec[n++], syslog_pid);
297                 }
298
299                 if (asprintf(&syslog_facility, "SYSLOG_FACILITY=%i", LOG_FAC(priority)) >= 0)
300                         IOVEC_SET_STRING(iovec[n++], syslog_facility);
301         }
302
303         message = cunescape_length_with_prefix(p, pl, "MESSAGE=");
304         if (message)
305                 IOVEC_SET_STRING(iovec[n++], message);
306
307         server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, NULL, NULL, 0, NULL, priority, 0);
308
309 finish:
310         for (j = 0; j < z; j++)
311                 free(iovec[j].iov_base);
312
313         free(message);
314         free(syslog_priority);
315         free(syslog_identifier);
316         free(syslog_pid);
317         free(syslog_facility);
318         free(source_time);
319         free(identifier);
320         free(pid);
321 }
322
323 int server_read_dev_kmsg(Server *s) {
324         char buffer[8192+1]; /* the kernel-side limit per record is 8K currently */
325         ssize_t l;
326
327         assert(s);
328         assert(s->dev_kmsg_fd >= 0);
329
330         l = read(s->dev_kmsg_fd, buffer, sizeof(buffer) - 1);
331         if (l == 0)
332                 return 0;
333         if (l < 0) {
334                 /* Old kernels who don't allow reading from /dev/kmsg
335                  * return EINVAL when we try. So handle this cleanly,
336                  * but don' try to ever read from it again. */
337                 if (errno == EINVAL) {
338                         epoll_ctl(s->epoll_fd, EPOLL_CTL_DEL, s->dev_kmsg_fd, NULL);
339                         return 0;
340                 }
341
342                 if (errno == EAGAIN || errno == EINTR || errno == EPIPE)
343                         return 0;
344
345                 log_error("Failed to read from kernel: %m");
346                 return -errno;
347         }
348
349         dev_kmsg_record(s, buffer, l);
350         return 1;
351 }
352
353 int server_flush_dev_kmsg(Server *s) {
354         int r;
355
356         assert(s);
357
358         if (s->dev_kmsg_fd < 0)
359                 return 0;
360
361         if (!s->dev_kmsg_readable)
362                 return 0;
363
364         log_debug("Flushing /dev/kmsg...");
365
366         for (;;) {
367                 r = server_read_dev_kmsg(s);
368                 if (r < 0)
369                         return r;
370
371                 if (r == 0)
372                         break;
373         }
374
375         return 0;
376 }
377
378 int server_open_dev_kmsg(Server *s) {
379         struct epoll_event ev;
380
381         assert(s);
382
383         s->dev_kmsg_fd = open("/dev/kmsg", O_RDWR|O_CLOEXEC|O_NONBLOCK|O_NOCTTY);
384         if (s->dev_kmsg_fd < 0) {
385                 log_warning("Failed to open /dev/kmsg, ignoring: %m");
386                 return 0;
387         }
388
389         zero(ev);
390         ev.events = EPOLLIN;
391         ev.data.fd = s->dev_kmsg_fd;
392         if (epoll_ctl(s->epoll_fd, EPOLL_CTL_ADD, s->dev_kmsg_fd, &ev) < 0) {
393
394                 /* This will fail with EPERM on older kernels where
395                  * /dev/kmsg is not readable. */
396                 if (errno == EPERM)
397                         return 0;
398
399                 log_error("Failed to add /dev/kmsg fd to epoll object: %m");
400                 return -errno;
401         }
402
403         s->dev_kmsg_readable = true;
404
405         return 0;
406 }
407
408 int server_open_kernel_seqnum(Server *s) {
409         int fd;
410         uint64_t *p;
411
412         assert(s);
413
414         /* We store the seqnum we last read in an mmaped file. That
415          * way we can just use it like a variable, but it is
416          * persistent and automatically flushed at reboot. */
417
418         fd = open("/run/systemd/journal/kernel-seqnum", O_RDWR|O_CREAT|O_CLOEXEC|O_NOCTTY|O_NOFOLLOW, 0644);
419         if (fd < 0) {
420                 log_error("Failed to open /run/systemd/journal/kernel-seqnum, ignoring: %m");
421                 return 0;
422         }
423
424         if (posix_fallocate(fd, 0, sizeof(uint64_t)) < 0) {
425                 log_error("Failed to allocate sequential number file, ignoring: %m");
426                 close_nointr_nofail(fd);
427                 return 0;
428         }
429
430         p = mmap(NULL, sizeof(uint64_t), PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0);
431         if (p == MAP_FAILED) {
432                 log_error("Failed to map sequential number file, ignoring: %m");
433                 close_nointr_nofail(fd);
434                 return 0;
435         }
436
437         close_nointr_nofail(fd);
438         s->kernel_seqnum = p;
439
440         return 0;
441 }