]> git.proxmox.com Git - systemd.git/blob - src/journal/journald-kmsg.c
Imported Upstream version 226
[systemd.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 #include "formats-util.h"
35 #include "process-util.h"
36
37 void server_forward_kmsg(
38 Server *s,
39 int priority,
40 const char *identifier,
41 const char *message,
42 const struct ucred *ucred) {
43
44 struct iovec iovec[5];
45 char header_priority[DECIMAL_STR_MAX(priority) + 3],
46 header_pid[sizeof("[]: ")-1 + DECIMAL_STR_MAX(pid_t) + 1];
47 int n = 0;
48 char *ident_buf = NULL;
49
50 assert(s);
51 assert(priority >= 0);
52 assert(priority <= 999);
53 assert(message);
54
55 if (_unlikely_(LOG_PRI(priority) > s->max_level_kmsg))
56 return;
57
58 if (_unlikely_(s->dev_kmsg_fd < 0))
59 return;
60
61 /* Never allow messages with kernel facility to be written to
62 * kmsg, regardless where the data comes from. */
63 priority = syslog_fixup_facility(priority);
64
65 /* First: priority field */
66 xsprintf(header_priority, "<%i>", priority);
67 IOVEC_SET_STRING(iovec[n++], header_priority);
68
69 /* Second: identifier and PID */
70 if (ucred) {
71 if (!identifier) {
72 get_process_comm(ucred->pid, &ident_buf);
73 identifier = ident_buf;
74 }
75
76 xsprintf(header_pid, "["PID_FMT"]: ", ucred->pid);
77
78 if (identifier)
79 IOVEC_SET_STRING(iovec[n++], identifier);
80
81 IOVEC_SET_STRING(iovec[n++], header_pid);
82 } else if (identifier) {
83 IOVEC_SET_STRING(iovec[n++], identifier);
84 IOVEC_SET_STRING(iovec[n++], ": ");
85 }
86
87 /* Fourth: message */
88 IOVEC_SET_STRING(iovec[n++], message);
89 IOVEC_SET_STRING(iovec[n++], "\n");
90
91 if (writev(s->dev_kmsg_fd, iovec, n) < 0)
92 log_debug_errno(errno, "Failed to write to /dev/kmsg for logging: %m");
93
94 free(ident_buf);
95 }
96
97 static bool is_us(const char *pid) {
98 pid_t t;
99
100 assert(pid);
101
102 if (parse_pid(pid, &t) < 0)
103 return false;
104
105 return t == getpid();
106 }
107
108 static void dev_kmsg_record(Server *s, const char *p, size_t l) {
109 struct iovec iovec[N_IOVEC_META_FIELDS + 7 + N_IOVEC_KERNEL_FIELDS + 2 + N_IOVEC_UDEV_FIELDS];
110 char *message = NULL, *syslog_priority = NULL, *syslog_pid = NULL, *syslog_facility = NULL, *syslog_identifier = NULL, *source_time = NULL;
111 int priority, r;
112 unsigned n = 0, z = 0, j;
113 unsigned long long usec;
114 char *identifier = NULL, *pid = NULL, *e, *f, *k;
115 uint64_t serial;
116 size_t pl;
117 char *kernel_device = NULL;
118
119 assert(s);
120 assert(p);
121
122 if (l <= 0)
123 return;
124
125 e = memchr(p, ',', l);
126 if (!e)
127 return;
128 *e = 0;
129
130 r = safe_atoi(p, &priority);
131 if (r < 0 || priority < 0 || priority > 999)
132 return;
133
134 if (s->forward_to_kmsg && (priority & LOG_FACMASK) != LOG_KERN)
135 return;
136
137 l -= (e - p) + 1;
138 p = e + 1;
139 e = memchr(p, ',', l);
140 if (!e)
141 return;
142 *e = 0;
143
144 r = safe_atou64(p, &serial);
145 if (r < 0)
146 return;
147
148 if (s->kernel_seqnum) {
149 /* We already read this one? */
150 if (serial < *s->kernel_seqnum)
151 return;
152
153 /* Did we lose any? */
154 if (serial > *s->kernel_seqnum)
155 server_driver_message(s, SD_MESSAGE_JOURNAL_MISSED, "Missed %"PRIu64" kernel messages",
156 serial - *s->kernel_seqnum);
157
158 /* Make sure we never read this one again. Note that
159 * we always store the next message serial we expect
160 * here, simply because this makes handling the first
161 * message with serial 0 easy. */
162 *s->kernel_seqnum = serial + 1;
163 }
164
165 l -= (e - p) + 1;
166 p = e + 1;
167 f = memchr(p, ';', l);
168 if (!f)
169 return;
170 /* Kernel 3.6 has the flags field, kernel 3.5 lacks that */
171 e = memchr(p, ',', l);
172 if (!e || f < e)
173 e = f;
174 *e = 0;
175
176 r = safe_atollu(p, &usec);
177 if (r < 0)
178 return;
179
180 l -= (f - p) + 1;
181 p = f + 1;
182 e = memchr(p, '\n', l);
183 if (!e)
184 return;
185 *e = 0;
186
187 pl = e - p;
188 l -= (e - p) + 1;
189 k = e + 1;
190
191 for (j = 0; l > 0 && j < N_IOVEC_KERNEL_FIELDS; j++) {
192 char *m;
193 /* Metadata fields attached */
194
195 if (*k != ' ')
196 break;
197
198 k ++, l --;
199
200 e = memchr(k, '\n', l);
201 if (!e)
202 return;
203
204 *e = 0;
205
206 if (cunescape_length_with_prefix(k, e - k, "_KERNEL_", UNESCAPE_RELAX, &m) < 0)
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 (asprintf(&syslog_facility, "SYSLOG_FACILITY=%i", LOG_FAC(priority)) >= 0)
278 IOVEC_SET_STRING(iovec[n++], syslog_facility);
279
280 if ((priority & LOG_FACMASK) == LOG_KERN)
281 IOVEC_SET_STRING(iovec[n++], "SYSLOG_IDENTIFIER=kernel");
282 else {
283 pl -= syslog_parse_identifier((const char**) &p, &identifier, &pid);
284
285 /* Avoid any messages we generated ourselves via
286 * log_info() and friends. */
287 if (pid && is_us(pid))
288 goto finish;
289
290 if (identifier) {
291 syslog_identifier = strappend("SYSLOG_IDENTIFIER=", identifier);
292 if (syslog_identifier)
293 IOVEC_SET_STRING(iovec[n++], syslog_identifier);
294 }
295
296 if (pid) {
297 syslog_pid = strappend("SYSLOG_PID=", pid);
298 if (syslog_pid)
299 IOVEC_SET_STRING(iovec[n++], syslog_pid);
300 }
301 }
302
303 if (cunescape_length_with_prefix(p, pl, "MESSAGE=", UNESCAPE_RELAX, &message) >= 0)
304 IOVEC_SET_STRING(iovec[n++], message);
305
306 server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, NULL, NULL, 0, NULL, priority, 0);
307
308 finish:
309 for (j = 0; j < z; j++)
310 free(iovec[j].iov_base);
311
312 free(message);
313 free(syslog_priority);
314 free(syslog_identifier);
315 free(syslog_pid);
316 free(syslog_facility);
317 free(source_time);
318 free(identifier);
319 free(pid);
320 }
321
322 static int server_read_dev_kmsg(Server *s) {
323 char buffer[8192+1]; /* the kernel-side limit per record is 8K currently */
324 ssize_t l;
325
326 assert(s);
327 assert(s->dev_kmsg_fd >= 0);
328
329 l = read(s->dev_kmsg_fd, buffer, sizeof(buffer) - 1);
330 if (l == 0)
331 return 0;
332 if (l < 0) {
333 /* Old kernels who don't allow reading from /dev/kmsg
334 * return EINVAL when we try. So handle this cleanly,
335 * but don' try to ever read from it again. */
336 if (errno == EINVAL) {
337 s->dev_kmsg_event_source = sd_event_source_unref(s->dev_kmsg_event_source);
338 return 0;
339 }
340
341 if (errno == EAGAIN || errno == EINTR || errno == EPIPE)
342 return 0;
343
344 log_error_errno(errno, "Failed to read from kernel: %m");
345 return -errno;
346 }
347
348 dev_kmsg_record(s, buffer, l);
349 return 1;
350 }
351
352 int server_flush_dev_kmsg(Server *s) {
353 int r;
354
355 assert(s);
356
357 if (s->dev_kmsg_fd < 0)
358 return 0;
359
360 if (!s->dev_kmsg_readable)
361 return 0;
362
363 log_debug("Flushing /dev/kmsg...");
364
365 for (;;) {
366 r = server_read_dev_kmsg(s);
367 if (r < 0)
368 return r;
369
370 if (r == 0)
371 break;
372 }
373
374 return 0;
375 }
376
377 static int dispatch_dev_kmsg(sd_event_source *es, int fd, uint32_t revents, void *userdata) {
378 Server *s = userdata;
379
380 assert(es);
381 assert(fd == s->dev_kmsg_fd);
382 assert(s);
383
384 if (revents & EPOLLERR)
385 log_warning("/dev/kmsg buffer overrun, some messages lost.");
386
387 if (!(revents & EPOLLIN))
388 log_error("Got invalid event from epoll for /dev/kmsg: %"PRIx32, revents);
389
390 return server_read_dev_kmsg(s);
391 }
392
393 int server_open_dev_kmsg(Server *s) {
394 int r;
395
396 assert(s);
397
398 s->dev_kmsg_fd = open("/dev/kmsg", O_RDWR|O_CLOEXEC|O_NONBLOCK|O_NOCTTY);
399 if (s->dev_kmsg_fd < 0) {
400 log_full(errno == ENOENT ? LOG_DEBUG : LOG_WARNING,
401 "Failed to open /dev/kmsg, ignoring: %m");
402 return 0;
403 }
404
405 r = sd_event_add_io(s->event, &s->dev_kmsg_event_source, s->dev_kmsg_fd, EPOLLIN, dispatch_dev_kmsg, s);
406 if (r < 0) {
407
408 /* This will fail with EPERM on older kernels where
409 * /dev/kmsg is not readable. */
410 if (r == -EPERM) {
411 r = 0;
412 goto fail;
413 }
414
415 log_error_errno(r, "Failed to add /dev/kmsg fd to event loop: %m");
416 goto fail;
417 }
418
419 r = sd_event_source_set_priority(s->dev_kmsg_event_source, SD_EVENT_PRIORITY_IMPORTANT+10);
420 if (r < 0) {
421 log_error_errno(r, "Failed to adjust priority of kmsg event source: %m");
422 goto fail;
423 }
424
425 s->dev_kmsg_readable = true;
426
427 return 0;
428
429 fail:
430 s->dev_kmsg_event_source = sd_event_source_unref(s->dev_kmsg_event_source);
431 s->dev_kmsg_fd = safe_close(s->dev_kmsg_fd);
432
433 return r;
434 }
435
436 int server_open_kernel_seqnum(Server *s) {
437 _cleanup_close_ int fd;
438 uint64_t *p;
439
440 assert(s);
441
442 /* We store the seqnum we last read in an mmaped file. That
443 * way we can just use it like a variable, but it is
444 * persistent and automatically flushed at reboot. */
445
446 fd = open("/run/systemd/journal/kernel-seqnum", O_RDWR|O_CREAT|O_CLOEXEC|O_NOCTTY|O_NOFOLLOW, 0644);
447 if (fd < 0) {
448 log_error_errno(errno, "Failed to open /run/systemd/journal/kernel-seqnum, ignoring: %m");
449 return 0;
450 }
451
452 if (posix_fallocate(fd, 0, sizeof(uint64_t)) < 0) {
453 log_error_errno(errno, "Failed to allocate sequential number file, ignoring: %m");
454 return 0;
455 }
456
457 p = mmap(NULL, sizeof(uint64_t), PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0);
458 if (p == MAP_FAILED) {
459 log_error_errno(errno, "Failed to map sequential number file, ignoring: %m");
460 return 0;
461 }
462
463 s->kernel_seqnum = p;
464
465 return 0;
466 }