Branch data Line data Source code
1 : : /* SPDX-License-Identifier: LGPL-2.1+ */
2 : :
3 : : #if HAVE_SELINUX
4 : : #include <selinux/selinux.h>
5 : : #endif
6 : : #include <sys/ioctl.h>
7 : : #include <sys/mman.h>
8 : : #include <sys/signalfd.h>
9 : : #include <sys/statvfs.h>
10 : : #include <linux/sockios.h>
11 : :
12 : : #include "sd-daemon.h"
13 : : #include "sd-journal.h"
14 : : #include "sd-messages.h"
15 : :
16 : : #include "acl-util.h"
17 : : #include "alloc-util.h"
18 : : #include "audit-util.h"
19 : : #include "cgroup-util.h"
20 : : #include "conf-parser.h"
21 : : #include "dirent-util.h"
22 : : #include "extract-word.h"
23 : : #include "fd-util.h"
24 : : #include "fileio.h"
25 : : #include "format-util.h"
26 : : #include "fs-util.h"
27 : : #include "hashmap.h"
28 : : #include "hostname-util.h"
29 : : #include "id128-util.h"
30 : : #include "io-util.h"
31 : : #include "journal-authenticate.h"
32 : : #include "journal-file.h"
33 : : #include "journal-internal.h"
34 : : #include "journal-vacuum.h"
35 : : #include "journald-audit.h"
36 : : #include "journald-context.h"
37 : : #include "journald-kmsg.h"
38 : : #include "journald-native.h"
39 : : #include "journald-rate-limit.h"
40 : : #include "journald-server.h"
41 : : #include "journald-stream.h"
42 : : #include "journald-syslog.h"
43 : : #include "log.h"
44 : : #include "missing.h"
45 : : #include "mkdir.h"
46 : : #include "parse-util.h"
47 : : #include "proc-cmdline.h"
48 : : #include "process-util.h"
49 : : #include "rm-rf.h"
50 : : #include "selinux-util.h"
51 : : #include "signal-util.h"
52 : : #include "socket-util.h"
53 : : #include "stdio-util.h"
54 : : #include "string-table.h"
55 : : #include "string-util.h"
56 : : #include "syslog-util.h"
57 : : #include "user-util.h"
58 : :
59 : : #define USER_JOURNALS_MAX 1024
60 : :
61 : : #define DEFAULT_SYNC_INTERVAL_USEC (5*USEC_PER_MINUTE)
62 : : #define DEFAULT_RATE_LIMIT_INTERVAL (30*USEC_PER_SEC)
63 : : #define DEFAULT_RATE_LIMIT_BURST 10000
64 : : #define DEFAULT_MAX_FILE_USEC USEC_PER_MONTH
65 : :
66 : : #define RECHECK_SPACE_USEC (30*USEC_PER_SEC)
67 : :
68 : : #define NOTIFY_SNDBUF_SIZE (8*1024*1024)
69 : :
70 : : /* The period to insert between posting changes for coalescing */
71 : : #define POST_CHANGE_TIMER_INTERVAL_USEC (250*USEC_PER_MSEC)
72 : :
73 : : /* Pick a good default that is likely to fit into AF_UNIX and AF_INET SOCK_DGRAM datagrams, and even leaves some room
74 : : * for a bit of additional metadata. */
75 : : #define DEFAULT_LINE_MAX (48*1024)
76 : :
77 : : #define DEFERRED_CLOSES_MAX (4096)
78 : :
79 : 0 : static int determine_path_usage(Server *s, const char *path, uint64_t *ret_used, uint64_t *ret_free) {
80 : 0 : _cleanup_closedir_ DIR *d = NULL;
81 : : struct dirent *de;
82 : : struct statvfs ss;
83 : :
84 [ # # ]: 0 : assert(ret_used);
85 [ # # ]: 0 : assert(ret_free);
86 : :
87 : 0 : d = opendir(path);
88 [ # # ]: 0 : if (!d)
89 [ # # # # ]: 0 : return log_full_errno(errno == ENOENT ? LOG_DEBUG : LOG_ERR,
90 : : errno, "Failed to open %s: %m", path);
91 : :
92 [ # # ]: 0 : if (fstatvfs(dirfd(d), &ss) < 0)
93 [ # # ]: 0 : return log_error_errno(errno, "Failed to fstatvfs(%s): %m", path);
94 : :
95 : 0 : *ret_free = ss.f_bsize * ss.f_bavail;
96 : 0 : *ret_used = 0;
97 [ # # # # ]: 0 : FOREACH_DIRENT_ALL(de, d, break) {
98 : : struct stat st;
99 : :
100 [ # # ]: 0 : if (!endswith(de->d_name, ".journal") &&
101 [ # # ]: 0 : !endswith(de->d_name, ".journal~"))
102 : 0 : continue;
103 : :
104 [ # # ]: 0 : if (fstatat(dirfd(d), de->d_name, &st, AT_SYMLINK_NOFOLLOW) < 0) {
105 [ # # ]: 0 : log_debug_errno(errno, "Failed to stat %s/%s, ignoring: %m", path, de->d_name);
106 : 0 : continue;
107 : : }
108 : :
109 [ # # ]: 0 : if (!S_ISREG(st.st_mode))
110 : 0 : continue;
111 : :
112 : 0 : *ret_used += (uint64_t) st.st_blocks * 512UL;
113 : : }
114 : :
115 : 0 : return 0;
116 : : }
117 : :
118 : 0 : static void cache_space_invalidate(JournalStorageSpace *space) {
119 [ # # ]: 0 : zero(*space);
120 : 0 : }
121 : :
122 : 0 : static int cache_space_refresh(Server *s, JournalStorage *storage) {
123 : : JournalStorageSpace *space;
124 : : JournalMetrics *metrics;
125 : : uint64_t vfs_used, vfs_avail, avail;
126 : : usec_t ts;
127 : : int r;
128 : :
129 [ # # ]: 0 : assert(s);
130 : :
131 : 0 : metrics = &storage->metrics;
132 : 0 : space = &storage->space;
133 : :
134 : 0 : ts = now(CLOCK_MONOTONIC);
135 : :
136 [ # # # # ]: 0 : if (space->timestamp != 0 && space->timestamp + RECHECK_SPACE_USEC > ts)
137 : 0 : return 0;
138 : :
139 : 0 : r = determine_path_usage(s, storage->path, &vfs_used, &vfs_avail);
140 [ # # ]: 0 : if (r < 0)
141 : 0 : return r;
142 : :
143 : 0 : space->vfs_used = vfs_used;
144 : 0 : space->vfs_available = vfs_avail;
145 : :
146 [ # # ]: 0 : avail = LESS_BY(vfs_avail, metrics->keep_free);
147 : :
148 : 0 : space->limit = MIN(MAX(vfs_used + avail, metrics->min_use), metrics->max_use);
149 [ # # ]: 0 : space->available = LESS_BY(space->limit, vfs_used);
150 : 0 : space->timestamp = ts;
151 : 0 : return 1;
152 : : }
153 : :
154 : 0 : static void patch_min_use(JournalStorage *storage) {
155 [ # # ]: 0 : assert(storage);
156 : :
157 : : /* Let's bump the min_use limit to the current usage on disk. We do
158 : : * this when starting up and first opening the journal files. This way
159 : : * sudden spikes in disk usage will not cause journald to vacuum files
160 : : * without bounds. Note that this means that only a restart of journald
161 : : * will make it reset this value. */
162 : :
163 : 0 : storage->metrics.min_use = MAX(storage->metrics.min_use, storage->space.vfs_used);
164 : 0 : }
165 : :
166 : 0 : static int determine_space(Server *s, uint64_t *available, uint64_t *limit) {
167 : : JournalStorage *js;
168 : : int r;
169 : :
170 [ # # ]: 0 : assert(s);
171 : :
172 [ # # ]: 0 : js = s->system_journal ? &s->system_storage : &s->runtime_storage;
173 : :
174 : 0 : r = cache_space_refresh(s, js);
175 [ # # ]: 0 : if (r >= 0) {
176 [ # # ]: 0 : if (available)
177 : 0 : *available = js->space.available;
178 [ # # ]: 0 : if (limit)
179 : 0 : *limit = js->space.limit;
180 : : }
181 : 0 : return r;
182 : : }
183 : :
184 : 0 : void server_space_usage_message(Server *s, JournalStorage *storage) {
185 : : char fb1[FORMAT_BYTES_MAX], fb2[FORMAT_BYTES_MAX], fb3[FORMAT_BYTES_MAX],
186 : : fb4[FORMAT_BYTES_MAX], fb5[FORMAT_BYTES_MAX], fb6[FORMAT_BYTES_MAX];
187 : : JournalMetrics *metrics;
188 : :
189 [ # # ]: 0 : assert(s);
190 : :
191 [ # # ]: 0 : if (!storage)
192 [ # # ]: 0 : storage = s->system_journal ? &s->system_storage : &s->runtime_storage;
193 : :
194 [ # # ]: 0 : if (cache_space_refresh(s, storage) < 0)
195 : 0 : return;
196 : :
197 : 0 : metrics = &storage->metrics;
198 : 0 : format_bytes(fb1, sizeof(fb1), storage->space.vfs_used);
199 : 0 : format_bytes(fb2, sizeof(fb2), metrics->max_use);
200 : 0 : format_bytes(fb3, sizeof(fb3), metrics->keep_free);
201 : 0 : format_bytes(fb4, sizeof(fb4), storage->space.vfs_available);
202 : 0 : format_bytes(fb5, sizeof(fb5), storage->space.limit);
203 : 0 : format_bytes(fb6, sizeof(fb6), storage->space.available);
204 : :
205 : 0 : server_driver_message(s, 0,
206 : : "MESSAGE_ID=" SD_MESSAGE_JOURNAL_USAGE_STR,
207 : : LOG_MESSAGE("%s (%s) is %s, max %s, %s free.",
208 : : storage->name, storage->path, fb1, fb5, fb6),
209 : : "JOURNAL_NAME=%s", storage->name,
210 : : "JOURNAL_PATH=%s", storage->path,
211 : : "CURRENT_USE=%"PRIu64, storage->space.vfs_used,
212 : : "CURRENT_USE_PRETTY=%s", fb1,
213 : : "MAX_USE=%"PRIu64, metrics->max_use,
214 : : "MAX_USE_PRETTY=%s", fb2,
215 : : "DISK_KEEP_FREE=%"PRIu64, metrics->keep_free,
216 : : "DISK_KEEP_FREE_PRETTY=%s", fb3,
217 : : "DISK_AVAILABLE=%"PRIu64, storage->space.vfs_available,
218 : : "DISK_AVAILABLE_PRETTY=%s", fb4,
219 : : "LIMIT=%"PRIu64, storage->space.limit,
220 : : "LIMIT_PRETTY=%s", fb5,
221 : : "AVAILABLE=%"PRIu64, storage->space.available,
222 : : "AVAILABLE_PRETTY=%s", fb6,
223 : : NULL);
224 : : }
225 : :
226 : 0 : static bool uid_for_system_journal(uid_t uid) {
227 : :
228 : : /* Returns true if the specified UID shall get its data stored in the system journal*/
229 : :
230 [ # # # # : 0 : return uid_is_system(uid) || uid_is_dynamic(uid) || uid == UID_NOBODY;
# # ]
231 : : }
232 : :
233 : 0 : static void server_add_acls(JournalFile *f, uid_t uid) {
234 : : #if HAVE_ACL
235 : : int r;
236 : : #endif
237 [ # # ]: 0 : assert(f);
238 : :
239 : : #if HAVE_ACL
240 [ # # ]: 0 : if (uid_for_system_journal(uid))
241 : 0 : return;
242 : :
243 : 0 : r = add_acls_for_user(f->fd, uid);
244 [ # # ]: 0 : if (r < 0)
245 [ # # ]: 0 : log_warning_errno(r, "Failed to set ACL on %s, ignoring: %m", f->path);
246 : : #endif
247 : : }
248 : :
249 : 0 : static int open_journal(
250 : : Server *s,
251 : : bool reliably,
252 : : const char *fname,
253 : : int flags,
254 : : bool seal,
255 : : JournalMetrics *metrics,
256 : : JournalFile **ret) {
257 : :
258 : 0 : _cleanup_(journal_file_closep) JournalFile *f = NULL;
259 : : int r;
260 : :
261 [ # # ]: 0 : assert(s);
262 [ # # ]: 0 : assert(fname);
263 [ # # ]: 0 : assert(ret);
264 : :
265 [ # # ]: 0 : if (reliably)
266 : 0 : r = journal_file_open_reliably(fname, flags, 0640, s->compress.enabled, s->compress.threshold_bytes,
267 : : seal, metrics, s->mmap, s->deferred_closes, NULL, &f);
268 : : else
269 : 0 : r = journal_file_open(-1, fname, flags, 0640, s->compress.enabled, s->compress.threshold_bytes, seal,
270 : : metrics, s->mmap, s->deferred_closes, NULL, &f);
271 : :
272 [ # # ]: 0 : if (r < 0)
273 : 0 : return r;
274 : :
275 : 0 : r = journal_file_enable_post_change_timer(f, s->event, POST_CHANGE_TIMER_INTERVAL_USEC);
276 [ # # ]: 0 : if (r < 0)
277 : 0 : return r;
278 : :
279 : 0 : *ret = TAKE_PTR(f);
280 : 0 : return r;
281 : : }
282 : :
283 : 0 : static bool flushed_flag_is_set(void) {
284 : 0 : return access("/run/systemd/journal/flushed", F_OK) >= 0;
285 : : }
286 : :
287 : 0 : static int system_journal_open(Server *s, bool flush_requested, bool relinquish_requested) {
288 : : const char *fn;
289 : 0 : int r = 0;
290 : :
291 [ # # ]: 0 : if (!s->system_journal &&
292 [ # # # # : 0 : IN_SET(s->storage, STORAGE_PERSISTENT, STORAGE_AUTO) &&
# # ]
293 [ # # ]: 0 : (flush_requested || flushed_flag_is_set()) &&
294 [ # # ]: 0 : !relinquish_requested) {
295 : :
296 : : /* If in auto mode: first try to create the machine
297 : : * path, but not the prefix.
298 : : *
299 : : * If in persistent mode: create /var/log/journal and
300 : : * the machine path */
301 : :
302 [ # # ]: 0 : if (s->storage == STORAGE_PERSISTENT)
303 : 0 : (void) mkdir_p("/var/log/journal/", 0755);
304 : :
305 : 0 : (void) mkdir(s->system_storage.path, 0755);
306 : :
307 [ # # # # : 0 : fn = strjoina(s->system_storage.path, "/system.journal");
# # # # #
# # # ]
308 : 0 : r = open_journal(s, true, fn, O_RDWR|O_CREAT, s->seal, &s->system_storage.metrics, &s->system_journal);
309 [ # # ]: 0 : if (r >= 0) {
310 : 0 : server_add_acls(s->system_journal, 0);
311 : 0 : (void) cache_space_refresh(s, &s->system_storage);
312 : 0 : patch_min_use(&s->system_storage);
313 : : } else {
314 [ # # # # ]: 0 : if (!IN_SET(r, -ENOENT, -EROFS))
315 [ # # ]: 0 : log_warning_errno(r, "Failed to open system journal: %m");
316 : :
317 : 0 : r = 0;
318 : : }
319 : :
320 : : /* If the runtime journal is open, and we're post-flush, we're
321 : : * recovering from a failed system journal rotate (ENOSPC)
322 : : * for which the runtime journal was reopened.
323 : : *
324 : : * Perform an implicit flush to var, leaving the runtime
325 : : * journal closed, now that the system journal is back.
326 : : */
327 [ # # ]: 0 : if (!flush_requested)
328 : 0 : (void) server_flush_to_var(s, true);
329 : : }
330 : :
331 [ # # ]: 0 : if (!s->runtime_journal &&
332 [ # # ]: 0 : (s->storage != STORAGE_NONE)) {
333 : :
334 [ # # # # : 0 : fn = strjoina(s->runtime_storage.path, "/system.journal");
# # # # #
# # # ]
335 : :
336 [ # # # # ]: 0 : if (s->system_journal && !relinquish_requested) {
337 : :
338 : : /* Try to open the runtime journal, but only
339 : : * if it already exists, so that we can flush
340 : : * it into the system journal */
341 : :
342 : 0 : r = open_journal(s, false, fn, O_RDWR, false, &s->runtime_storage.metrics, &s->runtime_journal);
343 [ # # ]: 0 : if (r < 0) {
344 [ # # ]: 0 : if (r != -ENOENT)
345 [ # # ]: 0 : log_warning_errno(r, "Failed to open runtime journal: %m");
346 : :
347 : 0 : r = 0;
348 : : }
349 : :
350 : : } else {
351 : :
352 : : /* OK, we really need the runtime journal, so create
353 : : * it if necessary. */
354 : :
355 : 0 : (void) mkdir("/run/log", 0755);
356 : 0 : (void) mkdir("/run/log/journal", 0755);
357 : 0 : (void) mkdir_parents(fn, 0750);
358 : :
359 : 0 : r = open_journal(s, true, fn, O_RDWR|O_CREAT, false, &s->runtime_storage.metrics, &s->runtime_journal);
360 [ # # ]: 0 : if (r < 0)
361 [ # # ]: 0 : return log_error_errno(r, "Failed to open runtime journal: %m");
362 : : }
363 : :
364 [ # # ]: 0 : if (s->runtime_journal) {
365 : 0 : server_add_acls(s->runtime_journal, 0);
366 : 0 : (void) cache_space_refresh(s, &s->runtime_storage);
367 : 0 : patch_min_use(&s->runtime_storage);
368 : : }
369 : : }
370 : :
371 : 0 : return r;
372 : : }
373 : :
374 : 0 : static JournalFile* find_journal(Server *s, uid_t uid) {
375 : 0 : _cleanup_free_ char *p = NULL;
376 : : int r;
377 : : JournalFile *f;
378 : : sd_id128_t machine;
379 : :
380 [ # # ]: 0 : assert(s);
381 : :
382 : : /* A rotate that fails to create the new journal (ENOSPC) leaves the
383 : : * rotated journal as NULL. Unless we revisit opening, even after
384 : : * space is made available we'll continue to return NULL indefinitely.
385 : : *
386 : : * system_journal_open() is a noop if the journals are already open, so
387 : : * we can just call it here to recover from failed rotates (or anything
388 : : * else that's left the journals as NULL).
389 : : *
390 : : * Fixes https://github.com/systemd/systemd/issues/3968 */
391 : 0 : (void) system_journal_open(s, false, false);
392 : :
393 : : /* We split up user logs only on /var, not on /run. If the
394 : : * runtime file is open, we write to it exclusively, in order
395 : : * to guarantee proper order as soon as we flush /run to
396 : : * /var and close the runtime file. */
397 : :
398 [ # # ]: 0 : if (s->runtime_journal)
399 : 0 : return s->runtime_journal;
400 : :
401 [ # # ]: 0 : if (uid_for_system_journal(uid))
402 : 0 : return s->system_journal;
403 : :
404 : 0 : f = ordered_hashmap_get(s->user_journals, UID_TO_PTR(uid));
405 [ # # ]: 0 : if (f)
406 : 0 : return f;
407 : :
408 : 0 : r = sd_id128_get_machine(&machine);
409 [ # # ]: 0 : if (r < 0) {
410 [ # # ]: 0 : log_debug_errno(r, "Failed to determine machine ID, using system log: %m");
411 : 0 : return s->system_journal;
412 : : }
413 : :
414 [ # # ]: 0 : if (asprintf(&p, "/var/log/journal/" SD_ID128_FORMAT_STR "/user-"UID_FMT".journal",
415 : 0 : SD_ID128_FORMAT_VAL(machine), uid) < 0) {
416 : 0 : log_oom();
417 : 0 : return s->system_journal;
418 : : }
419 : :
420 [ # # ]: 0 : while (ordered_hashmap_size(s->user_journals) >= USER_JOURNALS_MAX) {
421 : : /* Too many open? Then let's close one */
422 : 0 : f = ordered_hashmap_steal_first(s->user_journals);
423 [ # # ]: 0 : assert(f);
424 : 0 : (void) journal_file_close(f);
425 : : }
426 : :
427 : 0 : r = open_journal(s, true, p, O_RDWR|O_CREAT, s->seal, &s->system_storage.metrics, &f);
428 [ # # ]: 0 : if (r < 0)
429 : 0 : return s->system_journal;
430 : :
431 : 0 : server_add_acls(f, uid);
432 : :
433 : 0 : r = ordered_hashmap_put(s->user_journals, UID_TO_PTR(uid), f);
434 [ # # ]: 0 : if (r < 0) {
435 : 0 : (void) journal_file_close(f);
436 : 0 : return s->system_journal;
437 : : }
438 : :
439 : 0 : return f;
440 : : }
441 : :
442 : 0 : static int do_rotate(
443 : : Server *s,
444 : : JournalFile **f,
445 : : const char* name,
446 : : bool seal,
447 : : uint32_t uid) {
448 : :
449 : : int r;
450 [ # # ]: 0 : assert(s);
451 : :
452 [ # # ]: 0 : if (!*f)
453 : 0 : return -EINVAL;
454 : :
455 : 0 : r = journal_file_rotate(f, s->compress.enabled, s->compress.threshold_bytes, seal, s->deferred_closes);
456 [ # # ]: 0 : if (r < 0) {
457 [ # # ]: 0 : if (*f)
458 [ # # ]: 0 : return log_error_errno(r, "Failed to rotate %s: %m", (*f)->path);
459 : : else
460 [ # # ]: 0 : return log_error_errno(r, "Failed to create new %s journal: %m", name);
461 : : }
462 : :
463 : 0 : server_add_acls(*f, uid);
464 : :
465 : 0 : return r;
466 : : }
467 : :
468 : 0 : static void server_process_deferred_closes(Server *s) {
469 : : JournalFile *f;
470 : : Iterator i;
471 : :
472 : : /* Perform any deferred closes which aren't still offlining. */
473 [ # # ]: 0 : SET_FOREACH(f, s->deferred_closes, i) {
474 [ # # ]: 0 : if (journal_file_is_offlining(f))
475 : 0 : continue;
476 : :
477 : 0 : (void) set_remove(s->deferred_closes, f);
478 : 0 : (void) journal_file_close(f);
479 : : }
480 : 0 : }
481 : :
482 : 0 : static void server_vacuum_deferred_closes(Server *s) {
483 [ # # ]: 0 : assert(s);
484 : :
485 : : /* Make some room in the deferred closes list, so that it doesn't grow without bounds */
486 [ # # ]: 0 : if (set_size(s->deferred_closes) < DEFERRED_CLOSES_MAX)
487 : 0 : return;
488 : :
489 : : /* Let's first remove all journal files that might already have completed closing */
490 : 0 : server_process_deferred_closes(s);
491 : :
492 : : /* And now, let's close some more until we reach the limit again. */
493 [ # # ]: 0 : while (set_size(s->deferred_closes) >= DEFERRED_CLOSES_MAX) {
494 : : JournalFile *f;
495 : :
496 [ # # ]: 0 : assert_se(f = set_steal_first(s->deferred_closes));
497 : 0 : journal_file_close(f);
498 : : }
499 : : }
500 : :
501 : 0 : static int open_user_journal_directory(Server *s, DIR **ret_dir, char **ret_path) {
502 : 0 : _cleanup_closedir_ DIR *dir = NULL;
503 : 0 : _cleanup_free_ char *path = NULL;
504 : : sd_id128_t machine;
505 : : int r;
506 : :
507 [ # # ]: 0 : assert(s);
508 : :
509 : 0 : r = sd_id128_get_machine(&machine);
510 [ # # ]: 0 : if (r < 0)
511 [ # # ]: 0 : return log_error_errno(r, "Failed to determine machine ID, ignoring: %m");
512 : :
513 [ # # ]: 0 : if (asprintf(&path, "/var/log/journal/" SD_ID128_FORMAT_STR "/", SD_ID128_FORMAT_VAL(machine)) < 0)
514 : 0 : return log_oom();
515 : :
516 : 0 : dir = opendir(path);
517 [ # # ]: 0 : if (!dir)
518 [ # # ]: 0 : return log_error_errno(errno, "Failed to open user journal directory '%s': %m", path);
519 : :
520 [ # # ]: 0 : if (ret_dir)
521 : 0 : *ret_dir = TAKE_PTR(dir);
522 [ # # ]: 0 : if (ret_path)
523 : 0 : *ret_path = TAKE_PTR(path);
524 : :
525 : 0 : return 0;
526 : : }
527 : :
528 : 0 : void server_rotate(Server *s) {
529 : 0 : _cleanup_free_ char *path = NULL;
530 : 0 : _cleanup_closedir_ DIR *d = NULL;
531 : : JournalFile *f;
532 : : Iterator i;
533 : : void *k;
534 : : int r;
535 : :
536 [ # # ]: 0 : log_debug("Rotating...");
537 : :
538 : : /* First, rotate the system journal (either in its runtime flavour or in its runtime flavour) */
539 : 0 : (void) do_rotate(s, &s->runtime_journal, "runtime", false, 0);
540 : 0 : (void) do_rotate(s, &s->system_journal, "system", s->seal, 0);
541 : :
542 : : /* Then, rotate all user journals we have open (keeping them open) */
543 [ # # ]: 0 : ORDERED_HASHMAP_FOREACH_KEY(f, k, s->user_journals, i) {
544 : 0 : r = do_rotate(s, &f, "user", s->seal, PTR_TO_UID(k));
545 [ # # ]: 0 : if (r >= 0)
546 : 0 : ordered_hashmap_replace(s->user_journals, k, f);
547 [ # # ]: 0 : else if (!f)
548 : : /* Old file has been closed and deallocated */
549 : 0 : ordered_hashmap_remove(s->user_journals, k);
550 : : }
551 : :
552 : : /* Finally, also rotate all user journals we currently do not have open. (But do so only if we actually have
553 : : * access to /var, i.e. are not in the log-to-runtime-journal mode). */
554 [ # # # # ]: 0 : if (!s->runtime_journal &&
555 : 0 : open_user_journal_directory(s, &d, &path) >= 0) {
556 : :
557 : : struct dirent *de;
558 : :
559 [ # # # # : 0 : FOREACH_DIRENT(de, d, log_warning_errno(errno, "Failed to enumerate %s, ignoring: %m", path)) {
# # # # ]
560 [ # # # # : 0 : _cleanup_free_ char *u = NULL, *full = NULL;
# # ]
561 [ # # # ]: 0 : _cleanup_close_ int fd = -1;
562 : : const char *a, *b;
563 : : uid_t uid;
564 : :
565 : 0 : a = startswith(de->d_name, "user-");
566 [ # # ]: 0 : if (!a)
567 : 0 : continue;
568 : 0 : b = endswith(de->d_name, ".journal");
569 [ # # ]: 0 : if (!b)
570 : 0 : continue;
571 : :
572 : 0 : u = strndup(a, b-a);
573 [ # # ]: 0 : if (!u) {
574 : 0 : log_oom();
575 : 0 : break;
576 : : }
577 : :
578 : 0 : r = parse_uid(u, &uid);
579 [ # # ]: 0 : if (r < 0) {
580 [ # # ]: 0 : log_debug_errno(r, "Failed to parse UID from file name '%s', ignoring: %m", de->d_name);
581 : 0 : continue;
582 : : }
583 : :
584 : : /* Already rotated in the above loop? i.e. is it an open user journal? */
585 [ # # ]: 0 : if (ordered_hashmap_contains(s->user_journals, UID_TO_PTR(uid)))
586 : 0 : continue;
587 : :
588 : 0 : full = strjoin(path, de->d_name);
589 [ # # ]: 0 : if (!full) {
590 : 0 : log_oom();
591 : 0 : break;
592 : : }
593 : :
594 : 0 : fd = openat(dirfd(d), de->d_name, O_RDWR|O_CLOEXEC|O_NOCTTY|O_NOFOLLOW|O_NONBLOCK);
595 [ # # ]: 0 : if (fd < 0) {
596 [ # # # # : 0 : log_full_errno(IN_SET(errno, ELOOP, ENOENT) ? LOG_DEBUG : LOG_WARNING, errno,
# # ]
597 : : "Failed to open journal file '%s' for rotation: %m", full);
598 : 0 : continue;
599 : : }
600 : :
601 : : /* Make some room in the set of deferred close()s */
602 : 0 : server_vacuum_deferred_closes(s);
603 : :
604 : : /* Open the file briefly, so that we can archive it */
605 : 0 : r = journal_file_open(fd,
606 : : full,
607 : : O_RDWR,
608 : : 0640,
609 : 0 : s->compress.enabled,
610 : : s->compress.threshold_bytes,
611 : 0 : s->seal,
612 : : &s->system_storage.metrics,
613 : : s->mmap,
614 : : s->deferred_closes,
615 : : NULL,
616 : : &f);
617 [ # # ]: 0 : if (r < 0) {
618 [ # # ]: 0 : log_warning_errno(r, "Failed to read journal file %s for rotation, trying to move it out of the way: %m", full);
619 : :
620 : 0 : r = journal_file_dispose(dirfd(d), de->d_name);
621 [ # # ]: 0 : if (r < 0)
622 [ # # ]: 0 : log_warning_errno(r, "Failed to move %s out of the way, ignoring: %m", full);
623 : : else
624 [ # # ]: 0 : log_debug("Successfully moved %s out of the way.", full);
625 : :
626 : 0 : continue;
627 : : }
628 : :
629 : 0 : TAKE_FD(fd); /* Donated to journal_file_open() */
630 : :
631 : 0 : r = journal_file_archive(f);
632 [ # # ]: 0 : if (r < 0)
633 [ # # ]: 0 : log_debug_errno(r, "Failed to archive journal file '%s', ignoring: %m", full);
634 : :
635 : 0 : f = journal_initiate_close(f, s->deferred_closes);
636 : : }
637 : : }
638 : :
639 : 0 : server_process_deferred_closes(s);
640 : 0 : }
641 : :
642 : 0 : void server_sync(Server *s) {
643 : : JournalFile *f;
644 : : Iterator i;
645 : : int r;
646 : :
647 [ # # ]: 0 : if (s->system_journal) {
648 : 0 : r = journal_file_set_offline(s->system_journal, false);
649 [ # # ]: 0 : if (r < 0)
650 [ # # ]: 0 : log_warning_errno(r, "Failed to sync system journal, ignoring: %m");
651 : : }
652 : :
653 [ # # ]: 0 : ORDERED_HASHMAP_FOREACH(f, s->user_journals, i) {
654 : 0 : r = journal_file_set_offline(f, false);
655 [ # # ]: 0 : if (r < 0)
656 [ # # ]: 0 : log_warning_errno(r, "Failed to sync user journal, ignoring: %m");
657 : : }
658 : :
659 [ # # ]: 0 : if (s->sync_event_source) {
660 : 0 : r = sd_event_source_set_enabled(s->sync_event_source, SD_EVENT_OFF);
661 [ # # ]: 0 : if (r < 0)
662 [ # # ]: 0 : log_error_errno(r, "Failed to disable sync timer source: %m");
663 : : }
664 : :
665 : 0 : s->sync_scheduled = false;
666 : 0 : }
667 : :
668 : 0 : static void do_vacuum(Server *s, JournalStorage *storage, bool verbose) {
669 : :
670 : : int r;
671 : :
672 [ # # ]: 0 : assert(s);
673 [ # # ]: 0 : assert(storage);
674 : :
675 : 0 : (void) cache_space_refresh(s, storage);
676 : :
677 [ # # ]: 0 : if (verbose)
678 : 0 : server_space_usage_message(s, storage);
679 : :
680 : 0 : r = journal_directory_vacuum(storage->path, storage->space.limit,
681 : : storage->metrics.n_max_files, s->max_retention_usec,
682 : : &s->oldest_file_usec, verbose);
683 [ # # # # ]: 0 : if (r < 0 && r != -ENOENT)
684 [ # # ]: 0 : log_warning_errno(r, "Failed to vacuum %s, ignoring: %m", storage->path);
685 : :
686 : 0 : cache_space_invalidate(&storage->space);
687 : 0 : }
688 : :
689 : 0 : int server_vacuum(Server *s, bool verbose) {
690 [ # # ]: 0 : assert(s);
691 : :
692 [ # # ]: 0 : log_debug("Vacuuming...");
693 : :
694 : 0 : s->oldest_file_usec = 0;
695 : :
696 [ # # ]: 0 : if (s->system_journal)
697 : 0 : do_vacuum(s, &s->system_storage, verbose);
698 [ # # ]: 0 : if (s->runtime_journal)
699 : 0 : do_vacuum(s, &s->runtime_storage, verbose);
700 : :
701 : 0 : return 0;
702 : : }
703 : :
704 : 0 : static void server_cache_machine_id(Server *s) {
705 : : sd_id128_t id;
706 : : int r;
707 : :
708 [ # # ]: 0 : assert(s);
709 : :
710 : 0 : r = sd_id128_get_machine(&id);
711 [ # # ]: 0 : if (r < 0)
712 : 0 : return;
713 : :
714 : 0 : sd_id128_to_string(id, stpcpy(s->machine_id_field, "_MACHINE_ID="));
715 : : }
716 : :
717 : 0 : static void server_cache_boot_id(Server *s) {
718 : : sd_id128_t id;
719 : : int r;
720 : :
721 [ # # ]: 0 : assert(s);
722 : :
723 : 0 : r = sd_id128_get_boot(&id);
724 [ # # ]: 0 : if (r < 0)
725 : 0 : return;
726 : :
727 : 0 : sd_id128_to_string(id, stpcpy(s->boot_id_field, "_BOOT_ID="));
728 : : }
729 : :
730 : 0 : static void server_cache_hostname(Server *s) {
731 [ # # ]: 0 : _cleanup_free_ char *t = NULL;
732 : : char *x;
733 : :
734 [ # # ]: 0 : assert(s);
735 : :
736 : 0 : t = gethostname_malloc();
737 [ # # ]: 0 : if (!t)
738 : 0 : return;
739 : :
740 : 0 : x = strjoin("_HOSTNAME=", t);
741 [ # # ]: 0 : if (!x)
742 : 0 : return;
743 : :
744 : 0 : free(s->hostname_field);
745 : 0 : s->hostname_field = x;
746 : : }
747 : :
748 : 0 : static bool shall_try_append_again(JournalFile *f, int r) {
749 [ # # # # : 0 : switch(r) {
# # # # #
# ]
750 : :
751 : 0 : case -E2BIG: /* Hit configured limit */
752 : : case -EFBIG: /* Hit fs limit */
753 : : case -EDQUOT: /* Quota limit hit */
754 : : case -ENOSPC: /* Disk full */
755 [ # # ]: 0 : log_debug("%s: Allocation limit reached, rotating.", f->path);
756 : 0 : return true;
757 : :
758 : 0 : case -EIO: /* I/O error of some kind (mmap) */
759 [ # # ]: 0 : log_warning("%s: IO error, rotating.", f->path);
760 : 0 : return true;
761 : :
762 : 0 : case -EHOSTDOWN: /* Other machine */
763 [ # # ]: 0 : log_info("%s: Journal file from other machine, rotating.", f->path);
764 : 0 : return true;
765 : :
766 : 0 : case -EBUSY: /* Unclean shutdown */
767 [ # # ]: 0 : log_info("%s: Unclean shutdown, rotating.", f->path);
768 : 0 : return true;
769 : :
770 : 0 : case -EPROTONOSUPPORT: /* Unsupported feature */
771 [ # # ]: 0 : log_info("%s: Unsupported feature, rotating.", f->path);
772 : 0 : return true;
773 : :
774 : 0 : case -EBADMSG: /* Corrupted */
775 : : case -ENODATA: /* Truncated */
776 : : case -ESHUTDOWN: /* Already archived */
777 [ # # ]: 0 : log_warning("%s: Journal file corrupted, rotating.", f->path);
778 : 0 : return true;
779 : :
780 : 0 : case -EIDRM: /* Journal file has been deleted */
781 [ # # ]: 0 : log_warning("%s: Journal file has been deleted, rotating.", f->path);
782 : 0 : return true;
783 : :
784 : 0 : case -ETXTBSY: /* Journal file is from the future */
785 [ # # ]: 0 : log_warning("%s: Journal file is from the future, rotating.", f->path);
786 : 0 : return true;
787 : :
788 : 0 : case -EAFNOSUPPORT:
789 [ # # ]: 0 : log_warning("%s: underlying file system does not support memory mapping or another required file system feature.", f->path);
790 : 0 : return false;
791 : :
792 : 0 : default:
793 : 0 : return false;
794 : : }
795 : : }
796 : :
797 : 0 : static void write_to_journal(Server *s, uid_t uid, struct iovec *iovec, size_t n, int priority) {
798 : 0 : bool vacuumed = false, rotate = false;
799 : : struct dual_timestamp ts;
800 : : JournalFile *f;
801 : : int r;
802 : :
803 [ # # ]: 0 : assert(s);
804 [ # # ]: 0 : assert(iovec);
805 [ # # ]: 0 : assert(n > 0);
806 : :
807 : : /* Get the closest, linearized time we have for this log event from the event loop. (Note that we do not use
808 : : * the source time, and not even the time the event was originally seen, but instead simply the time we started
809 : : * processing it, as we want strictly linear ordering in what we write out.) */
810 [ # # ]: 0 : assert_se(sd_event_now(s->event, CLOCK_REALTIME, &ts.realtime) >= 0);
811 [ # # ]: 0 : assert_se(sd_event_now(s->event, CLOCK_MONOTONIC, &ts.monotonic) >= 0);
812 : :
813 [ # # ]: 0 : if (ts.realtime < s->last_realtime_clock) {
814 : : /* When the time jumps backwards, let's immediately rotate. Of course, this should not happen during
815 : : * regular operation. However, when it does happen, then we should make sure that we start fresh files
816 : : * to ensure that the entries in the journal files are strictly ordered by time, in order to ensure
817 : : * bisection works correctly. */
818 : :
819 [ # # ]: 0 : log_debug("Time jumped backwards, rotating.");
820 : 0 : rotate = true;
821 : : } else {
822 : :
823 : 0 : f = find_journal(s, uid);
824 [ # # ]: 0 : if (!f)
825 : 0 : return;
826 : :
827 [ # # ]: 0 : if (journal_file_rotate_suggested(f, s->max_file_usec)) {
828 [ # # ]: 0 : log_debug("%s: Journal header limits reached or header out-of-date, rotating.", f->path);
829 : 0 : rotate = true;
830 : : }
831 : : }
832 : :
833 [ # # ]: 0 : if (rotate) {
834 : 0 : server_rotate(s);
835 : 0 : server_vacuum(s, false);
836 : 0 : vacuumed = true;
837 : :
838 : 0 : f = find_journal(s, uid);
839 [ # # ]: 0 : if (!f)
840 : 0 : return;
841 : : }
842 : :
843 : 0 : s->last_realtime_clock = ts.realtime;
844 : :
845 : 0 : r = journal_file_append_entry(f, &ts, NULL, iovec, n, &s->seqnum, NULL, NULL);
846 [ # # ]: 0 : if (r >= 0) {
847 : 0 : server_schedule_sync(s, priority);
848 : 0 : return;
849 : : }
850 : :
851 [ # # # # ]: 0 : if (vacuumed || !shall_try_append_again(f, r)) {
852 [ # # ]: 0 : log_error_errno(r, "Failed to write entry (%zu items, %zu bytes), ignoring: %m", n, IOVEC_TOTAL_SIZE(iovec, n));
853 : 0 : return;
854 : : }
855 : :
856 : 0 : server_rotate(s);
857 : 0 : server_vacuum(s, false);
858 : :
859 : 0 : f = find_journal(s, uid);
860 [ # # ]: 0 : if (!f)
861 : 0 : return;
862 : :
863 [ # # ]: 0 : log_debug("Retrying write.");
864 : 0 : r = journal_file_append_entry(f, &ts, NULL, iovec, n, &s->seqnum, NULL, NULL);
865 [ # # ]: 0 : if (r < 0)
866 [ # # ]: 0 : log_error_errno(r, "Failed to write entry (%zu items, %zu bytes) despite vacuuming, ignoring: %m", n, IOVEC_TOTAL_SIZE(iovec, n));
867 : : else
868 : 0 : server_schedule_sync(s, priority);
869 : : }
870 : :
871 : : #define IOVEC_ADD_NUMERIC_FIELD(iovec, n, value, type, isset, format, field) \
872 : : if (isset(value)) { \
873 : : char *k; \
874 : : k = newa(char, STRLEN(field "=") + DECIMAL_STR_MAX(type) + 1); \
875 : : sprintf(k, field "=" format, value); \
876 : : iovec[n++] = IOVEC_MAKE_STRING(k); \
877 : : }
878 : :
879 : : #define IOVEC_ADD_STRING_FIELD(iovec, n, value, field) \
880 : : if (!isempty(value)) { \
881 : : char *k; \
882 : : k = strjoina(field "=", value); \
883 : : iovec[n++] = IOVEC_MAKE_STRING(k); \
884 : : }
885 : :
886 : : #define IOVEC_ADD_ID128_FIELD(iovec, n, value, field) \
887 : : if (!sd_id128_is_null(value)) { \
888 : : char *k; \
889 : : k = newa(char, STRLEN(field "=") + SD_ID128_STRING_MAX); \
890 : : sd_id128_to_string(value, stpcpy(k, field "=")); \
891 : : iovec[n++] = IOVEC_MAKE_STRING(k); \
892 : : }
893 : :
894 : : #define IOVEC_ADD_SIZED_FIELD(iovec, n, value, value_size, field) \
895 : : if (value_size > 0) { \
896 : : char *k; \
897 : : k = newa(char, STRLEN(field "=") + value_size + 1); \
898 : : *((char*) mempcpy(stpcpy(k, field "="), value, value_size)) = 0; \
899 : : iovec[n++] = IOVEC_MAKE_STRING(k); \
900 : : } \
901 : :
902 : 0 : static void dispatch_message_real(
903 : : Server *s,
904 : : struct iovec *iovec, size_t n, size_t m,
905 : : const ClientContext *c,
906 : : const struct timeval *tv,
907 : : int priority,
908 : : pid_t object_pid) {
909 : :
910 : : char source_time[sizeof("_SOURCE_REALTIME_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t)];
911 : 0 : _cleanup_free_ char *cmdline1 = NULL, *cmdline2 = NULL;
912 : : uid_t journal_uid;
913 : : ClientContext *o;
914 : :
915 [ # # ]: 0 : assert(s);
916 [ # # ]: 0 : assert(iovec);
917 [ # # ]: 0 : assert(n > 0);
918 [ # # # # ]: 0 : assert(n +
919 : : N_IOVEC_META_FIELDS +
920 : : (pid_is_valid(object_pid) ? N_IOVEC_OBJECT_FIELDS : 0) +
921 : : client_context_extra_fields_n_iovec(c) <= m);
922 : :
923 [ # # ]: 0 : if (c) {
924 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, c->pid, pid_t, pid_is_valid, PID_FMT, "_PID");
# # ]
925 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, c->uid, uid_t, uid_is_valid, UID_FMT, "_UID");
# # ]
926 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, c->gid, gid_t, gid_is_valid, GID_FMT, "_GID");
# # ]
927 : :
928 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, c->comm, "_COMM"); /* At most TASK_COMM_LENGTH (16 bytes) */
# # # # #
# # # #
# ]
929 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, c->exe, "_EXE"); /* A path, so at most PATH_MAX (4096 bytes) */
# # # # #
# # # #
# ]
930 : :
931 [ # # ]: 0 : if (c->cmdline)
932 : : /* At most _SC_ARG_MAX (2MB usually), which is too much to put on stack.
933 : : * Let's use a heap allocation for this one. */
934 : 0 : cmdline1 = set_iovec_string_field(iovec, &n, "_CMDLINE=", c->cmdline);
935 : :
936 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, c->capeff, "_CAP_EFFECTIVE"); /* Read from /proc/.../status */
# # # # #
# # # #
# ]
937 [ # # # # : 0 : IOVEC_ADD_SIZED_FIELD(iovec, n, c->label, c->label_size, "_SELINUX_CONTEXT");
# # ]
938 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, c->auditid, uint32_t, audit_session_is_valid, "%" PRIu32, "_AUDIT_SESSION");
# # ]
939 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, c->loginuid, uid_t, uid_is_valid, UID_FMT, "_AUDIT_LOGINUID");
# # ]
940 : :
941 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, c->cgroup, "_SYSTEMD_CGROUP"); /* A path */
# # # # #
# # # #
# ]
942 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, c->session, "_SYSTEMD_SESSION");
# # # # #
# # # #
# ]
943 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, c->owner_uid, uid_t, uid_is_valid, UID_FMT, "_SYSTEMD_OWNER_UID");
# # ]
944 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, c->unit, "_SYSTEMD_UNIT"); /* Unit names are bounded by UNIT_NAME_MAX */
# # # # #
# # # #
# ]
945 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, c->user_unit, "_SYSTEMD_USER_UNIT");
# # # # #
# # # #
# ]
946 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, c->slice, "_SYSTEMD_SLICE");
# # # # #
# # # #
# ]
947 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, c->user_slice, "_SYSTEMD_USER_SLICE");
# # # # #
# # # #
# ]
948 : :
949 [ # # # # : 0 : IOVEC_ADD_ID128_FIELD(iovec, n, c->invocation_id, "_SYSTEMD_INVOCATION_ID");
# # ]
950 : :
951 [ # # ]: 0 : if (c->extra_fields_n_iovec > 0) {
952 : 0 : memcpy(iovec + n, c->extra_fields_iovec, c->extra_fields_n_iovec * sizeof(struct iovec));
953 : 0 : n += c->extra_fields_n_iovec;
954 : : }
955 : : }
956 : :
957 [ # # ]: 0 : assert(n <= m);
958 : :
959 [ # # # # ]: 0 : if (pid_is_valid(object_pid) && client_context_get(s, object_pid, NULL, NULL, 0, NULL, &o) >= 0) {
960 : :
961 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, o->pid, pid_t, pid_is_valid, PID_FMT, "OBJECT_PID");
# # ]
962 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, o->uid, uid_t, uid_is_valid, UID_FMT, "OBJECT_UID");
# # ]
963 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, o->gid, gid_t, gid_is_valid, GID_FMT, "OBJECT_GID");
# # ]
964 : :
965 : : /* See above for size limits, only ->cmdline may be large, so use a heap allocation for it. */
966 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, o->comm, "OBJECT_COMM");
# # # # #
# # # #
# ]
967 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, o->exe, "OBJECT_EXE");
# # # # #
# # # #
# ]
968 [ # # ]: 0 : if (o->cmdline)
969 : 0 : cmdline2 = set_iovec_string_field(iovec, &n, "OBJECT_CMDLINE=", o->cmdline);
970 : :
971 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, o->capeff, "OBJECT_CAP_EFFECTIVE");
# # # # #
# # # #
# ]
972 [ # # # # : 0 : IOVEC_ADD_SIZED_FIELD(iovec, n, o->label, o->label_size, "OBJECT_SELINUX_CONTEXT");
# # ]
973 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, o->auditid, uint32_t, audit_session_is_valid, "%" PRIu32, "OBJECT_AUDIT_SESSION");
# # ]
974 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, o->loginuid, uid_t, uid_is_valid, UID_FMT, "OBJECT_AUDIT_LOGINUID");
# # ]
975 : :
976 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, o->cgroup, "OBJECT_SYSTEMD_CGROUP");
# # # # #
# # # #
# ]
977 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, o->session, "OBJECT_SYSTEMD_SESSION");
# # # # #
# # # #
# ]
978 [ # # # # : 0 : IOVEC_ADD_NUMERIC_FIELD(iovec, n, o->owner_uid, uid_t, uid_is_valid, UID_FMT, "OBJECT_SYSTEMD_OWNER_UID");
# # ]
979 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, o->unit, "OBJECT_SYSTEMD_UNIT");
# # # # #
# # # #
# ]
980 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, o->user_unit, "OBJECT_SYSTEMD_USER_UNIT");
# # # # #
# # # #
# ]
981 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, o->slice, "OBJECT_SYSTEMD_SLICE");
# # # # #
# # # #
# ]
982 [ # # # # : 0 : IOVEC_ADD_STRING_FIELD(iovec, n, o->user_slice, "OBJECT_SYSTEMD_USER_SLICE");
# # # # #
# # # #
# ]
983 : :
984 [ # # # # : 0 : IOVEC_ADD_ID128_FIELD(iovec, n, o->invocation_id, "OBJECT_SYSTEMD_INVOCATION_ID=");
# # ]
985 : : }
986 : :
987 [ # # ]: 0 : assert(n <= m);
988 : :
989 [ # # ]: 0 : if (tv) {
990 : 0 : sprintf(source_time, "_SOURCE_REALTIME_TIMESTAMP=" USEC_FMT, timeval_load(tv));
991 : 0 : iovec[n++] = IOVEC_MAKE_STRING(source_time);
992 : : }
993 : :
994 : : /* Note that strictly speaking storing the boot id here is
995 : : * redundant since the entry includes this in-line
996 : : * anyway. However, we need this indexed, too. */
997 [ # # ]: 0 : if (!isempty(s->boot_id_field))
998 : 0 : iovec[n++] = IOVEC_MAKE_STRING(s->boot_id_field);
999 : :
1000 [ # # ]: 0 : if (!isempty(s->machine_id_field))
1001 : 0 : iovec[n++] = IOVEC_MAKE_STRING(s->machine_id_field);
1002 : :
1003 [ # # ]: 0 : if (!isempty(s->hostname_field))
1004 : 0 : iovec[n++] = IOVEC_MAKE_STRING(s->hostname_field);
1005 : :
1006 [ # # ]: 0 : assert(n <= m);
1007 : :
1008 [ # # # # : 0 : if (s->split_mode == SPLIT_UID && c && uid_is_valid(c->uid))
# # ]
1009 : : /* Split up strictly by (non-root) UID */
1010 : 0 : journal_uid = c->uid;
1011 [ # # # # : 0 : else if (s->split_mode == SPLIT_LOGIN && c && c->uid > 0 && uid_is_valid(c->owner_uid))
# # # # ]
1012 : : /* Split up by login UIDs. We do this only if the
1013 : : * realuid is not root, in order not to accidentally
1014 : : * leak privileged information to the user that is
1015 : : * logged by a privileged process that is part of an
1016 : : * unprivileged session. */
1017 : 0 : journal_uid = c->owner_uid;
1018 : : else
1019 : 0 : journal_uid = 0;
1020 : :
1021 : 0 : write_to_journal(s, journal_uid, iovec, n, priority);
1022 : 0 : }
1023 : :
1024 : 0 : void server_driver_message(Server *s, pid_t object_pid, const char *message_id, const char *format, ...) {
1025 : :
1026 : : struct iovec *iovec;
1027 : 0 : size_t n = 0, k, m;
1028 : : va_list ap;
1029 : : int r;
1030 : :
1031 [ # # ]: 0 : assert(s);
1032 [ # # ]: 0 : assert(format);
1033 : :
1034 : 0 : m = N_IOVEC_META_FIELDS + 5 + N_IOVEC_PAYLOAD_FIELDS + client_context_extra_fields_n_iovec(s->my_context) + N_IOVEC_OBJECT_FIELDS;
1035 [ # # # # ]: 0 : iovec = newa(struct iovec, m);
1036 : :
1037 : : assert_cc(3 == LOG_FAC(LOG_DAEMON));
1038 : 0 : iovec[n++] = IOVEC_MAKE_STRING("SYSLOG_FACILITY=3");
1039 : 0 : iovec[n++] = IOVEC_MAKE_STRING("SYSLOG_IDENTIFIER=systemd-journald");
1040 : :
1041 : 0 : iovec[n++] = IOVEC_MAKE_STRING("_TRANSPORT=driver");
1042 : : assert_cc(6 == LOG_INFO);
1043 : 0 : iovec[n++] = IOVEC_MAKE_STRING("PRIORITY=6");
1044 : :
1045 [ # # ]: 0 : if (message_id)
1046 : 0 : iovec[n++] = IOVEC_MAKE_STRING(message_id);
1047 : 0 : k = n;
1048 : :
1049 : 0 : va_start(ap, format);
1050 : 0 : r = log_format_iovec(iovec, m, &n, false, 0, format, ap);
1051 : : /* Error handling below */
1052 : 0 : va_end(ap);
1053 : :
1054 [ # # ]: 0 : if (r >= 0)
1055 : 0 : dispatch_message_real(s, iovec, n, m, s->my_context, NULL, LOG_INFO, object_pid);
1056 : :
1057 [ # # ]: 0 : while (k < n)
1058 : 0 : free(iovec[k++].iov_base);
1059 : :
1060 [ # # ]: 0 : if (r < 0) {
1061 : : /* We failed to format the message. Emit a warning instead. */
1062 : : char buf[LINE_MAX];
1063 : :
1064 [ # # ]: 0 : xsprintf(buf, "MESSAGE=Entry printing failed: %s", strerror_safe(r));
1065 : :
1066 : 0 : n = 3;
1067 : 0 : iovec[n++] = IOVEC_MAKE_STRING("PRIORITY=4");
1068 : 0 : iovec[n++] = IOVEC_MAKE_STRING(buf);
1069 : 0 : dispatch_message_real(s, iovec, n, m, s->my_context, NULL, LOG_INFO, object_pid);
1070 : : }
1071 : 0 : }
1072 : :
1073 : 0 : void server_dispatch_message(
1074 : : Server *s,
1075 : : struct iovec *iovec, size_t n, size_t m,
1076 : : ClientContext *c,
1077 : : const struct timeval *tv,
1078 : : int priority,
1079 : : pid_t object_pid) {
1080 : :
1081 : 0 : uint64_t available = 0;
1082 : : int rl;
1083 : :
1084 [ # # ]: 0 : assert(s);
1085 [ # # # # ]: 0 : assert(iovec || n == 0);
1086 : :
1087 [ # # ]: 0 : if (n == 0)
1088 : 0 : return;
1089 : :
1090 [ # # ]: 0 : if (LOG_PRI(priority) > s->max_level_store)
1091 : 0 : return;
1092 : :
1093 : : /* Stop early in case the information will not be stored
1094 : : * in a journal. */
1095 [ # # ]: 0 : if (s->storage == STORAGE_NONE)
1096 : 0 : return;
1097 : :
1098 [ # # # # ]: 0 : if (c && c->unit) {
1099 : 0 : (void) determine_space(s, &available, NULL);
1100 : :
1101 : 0 : rl = journal_rate_limit_test(s->rate_limit, c->unit, c->log_rate_limit_interval, c->log_rate_limit_burst, priority & LOG_PRIMASK, available);
1102 [ # # ]: 0 : if (rl == 0)
1103 : 0 : return;
1104 : :
1105 : : /* Write a suppression message if we suppressed something */
1106 [ # # ]: 0 : if (rl > 1)
1107 : 0 : server_driver_message(s, c->pid,
1108 : : "MESSAGE_ID=" SD_MESSAGE_JOURNAL_DROPPED_STR,
1109 : : LOG_MESSAGE("Suppressed %i messages from %s", rl - 1, c->unit),
1110 : : "N_DROPPED=%i", rl - 1,
1111 : : NULL);
1112 : : }
1113 : :
1114 : 0 : dispatch_message_real(s, iovec, n, m, c, tv, priority, object_pid);
1115 : : }
1116 : :
1117 : 0 : int server_flush_to_var(Server *s, bool require_flag_file) {
1118 : : sd_id128_t machine;
1119 : 0 : sd_journal *j = NULL;
1120 : : char ts[FORMAT_TIMESPAN_MAX];
1121 : : usec_t start;
1122 : 0 : unsigned n = 0;
1123 : : int r, k;
1124 : :
1125 [ # # ]: 0 : assert(s);
1126 : :
1127 [ # # # # ]: 0 : if (!IN_SET(s->storage, STORAGE_AUTO, STORAGE_PERSISTENT))
1128 : 0 : return 0;
1129 : :
1130 [ # # ]: 0 : if (!s->runtime_journal)
1131 : 0 : return 0;
1132 : :
1133 [ # # # # ]: 0 : if (require_flag_file && !flushed_flag_is_set())
1134 : 0 : return 0;
1135 : :
1136 : 0 : (void) system_journal_open(s, true, false);
1137 : :
1138 [ # # ]: 0 : if (!s->system_journal)
1139 : 0 : return 0;
1140 : :
1141 [ # # ]: 0 : log_debug("Flushing to /var...");
1142 : :
1143 : 0 : start = now(CLOCK_MONOTONIC);
1144 : :
1145 : 0 : r = sd_id128_get_machine(&machine);
1146 [ # # ]: 0 : if (r < 0)
1147 : 0 : return r;
1148 : :
1149 : 0 : r = sd_journal_open(&j, SD_JOURNAL_RUNTIME_ONLY);
1150 [ # # ]: 0 : if (r < 0)
1151 [ # # ]: 0 : return log_error_errno(r, "Failed to read runtime journal: %m");
1152 : :
1153 : 0 : sd_journal_set_data_threshold(j, 0);
1154 : :
1155 [ # # # # ]: 0 : SD_JOURNAL_FOREACH(j) {
1156 : 0 : Object *o = NULL;
1157 : : JournalFile *f;
1158 : :
1159 : 0 : f = j->current_file;
1160 [ # # # # ]: 0 : assert(f && f->current_offset > 0);
1161 : :
1162 : 0 : n++;
1163 : :
1164 : 0 : r = journal_file_move_to_object(f, OBJECT_ENTRY, f->current_offset, &o);
1165 [ # # ]: 0 : if (r < 0) {
1166 [ # # ]: 0 : log_error_errno(r, "Can't read entry: %m");
1167 : 0 : goto finish;
1168 : : }
1169 : :
1170 : 0 : r = journal_file_copy_entry(f, s->system_journal, o, f->current_offset);
1171 [ # # ]: 0 : if (r >= 0)
1172 : 0 : continue;
1173 : :
1174 [ # # ]: 0 : if (!shall_try_append_again(s->system_journal, r)) {
1175 [ # # ]: 0 : log_error_errno(r, "Can't write entry: %m");
1176 : 0 : goto finish;
1177 : : }
1178 : :
1179 : 0 : server_rotate(s);
1180 : 0 : server_vacuum(s, false);
1181 : :
1182 [ # # ]: 0 : if (!s->system_journal) {
1183 [ # # ]: 0 : log_notice("Didn't flush runtime journal since rotation of system journal wasn't successful.");
1184 : 0 : r = -EIO;
1185 : 0 : goto finish;
1186 : : }
1187 : :
1188 [ # # ]: 0 : log_debug("Retrying write.");
1189 : 0 : r = journal_file_copy_entry(f, s->system_journal, o, f->current_offset);
1190 [ # # ]: 0 : if (r < 0) {
1191 [ # # ]: 0 : log_error_errno(r, "Can't write entry: %m");
1192 : 0 : goto finish;
1193 : : }
1194 : : }
1195 : :
1196 : 0 : r = 0;
1197 : :
1198 : 0 : finish:
1199 [ # # ]: 0 : if (s->system_journal)
1200 : 0 : journal_file_post_change(s->system_journal);
1201 : :
1202 : 0 : s->runtime_journal = journal_file_close(s->runtime_journal);
1203 : :
1204 [ # # ]: 0 : if (r >= 0)
1205 : 0 : (void) rm_rf("/run/log/journal", REMOVE_ROOT);
1206 : :
1207 : 0 : sd_journal_close(j);
1208 : :
1209 : 0 : server_driver_message(s, 0, NULL,
1210 : 0 : LOG_MESSAGE("Time spent on flushing to /var is %s for %u entries.",
1211 : : format_timespan(ts, sizeof(ts), now(CLOCK_MONOTONIC) - start, 0),
1212 : : n),
1213 : : NULL);
1214 : :
1215 : 0 : k = touch("/run/systemd/journal/flushed");
1216 [ # # ]: 0 : if (k < 0)
1217 [ # # ]: 0 : log_warning_errno(k, "Failed to touch /run/systemd/journal/flushed, ignoring: %m");
1218 : :
1219 : 0 : return r;
1220 : : }
1221 : :
1222 : 0 : static int server_relinquish_var(Server *s) {
1223 [ # # ]: 0 : assert(s);
1224 : :
1225 [ # # ]: 0 : if (s->storage == STORAGE_NONE)
1226 : 0 : return 0;
1227 : :
1228 [ # # # # ]: 0 : if (s->runtime_journal && !s->system_journal)
1229 : 0 : return 0;
1230 : :
1231 [ # # ]: 0 : log_debug("Relinquishing /var...");
1232 : :
1233 : 0 : (void) system_journal_open(s, false, true);
1234 : :
1235 : 0 : s->system_journal = journal_file_close(s->system_journal);
1236 [ # # ]: 0 : ordered_hashmap_clear_with_destructor(s->user_journals, journal_file_close);
1237 [ # # ]: 0 : set_clear_with_destructor(s->deferred_closes, journal_file_close);
1238 : :
1239 [ # # # # ]: 0 : if (unlink("/run/systemd/journal/flushed") < 0 && errno != ENOENT)
1240 [ # # ]: 0 : log_warning_errno(errno, "Failed to unlink /run/systemd/journal/flushed, ignoring: %m");
1241 : :
1242 : 0 : return 0;
1243 : : }
1244 : :
1245 : 0 : int server_process_datagram(sd_event_source *es, int fd, uint32_t revents, void *userdata) {
1246 : 0 : Server *s = userdata;
1247 : 0 : struct ucred *ucred = NULL;
1248 : 0 : struct timeval *tv = NULL;
1249 : : struct cmsghdr *cmsg;
1250 : 0 : char *label = NULL;
1251 : 0 : size_t label_len = 0, m;
1252 : : struct iovec iovec;
1253 : : ssize_t n;
1254 : 0 : int *fds = NULL, v = 0;
1255 : 0 : size_t n_fds = 0;
1256 : :
1257 : : union {
1258 : : struct cmsghdr cmsghdr;
1259 : :
1260 : : /* We use NAME_MAX space for the SELinux label
1261 : : * here. The kernel currently enforces no
1262 : : * limit, but according to suggestions from
1263 : : * the SELinux people this will change and it
1264 : : * will probably be identical to NAME_MAX. For
1265 : : * now we use that, but this should be updated
1266 : : * one day when the final limit is known. */
1267 : : uint8_t buf[CMSG_SPACE(sizeof(struct ucred)) +
1268 : : CMSG_SPACE(sizeof(struct timeval)) +
1269 : : CMSG_SPACE(sizeof(int)) + /* fd */
1270 : : CMSG_SPACE(NAME_MAX)]; /* selinux label */
1271 : 0 : } control = {};
1272 : :
1273 : 0 : union sockaddr_union sa = {};
1274 : :
1275 : 0 : struct msghdr msghdr = {
1276 : : .msg_iov = &iovec,
1277 : : .msg_iovlen = 1,
1278 : : .msg_control = &control,
1279 : : .msg_controllen = sizeof(control),
1280 : : .msg_name = &sa,
1281 : : .msg_namelen = sizeof(sa),
1282 : : };
1283 : :
1284 [ # # ]: 0 : assert(s);
1285 [ # # # # : 0 : assert(fd == s->native_fd || fd == s->syslog_fd || fd == s->audit_fd);
# # # # ]
1286 : :
1287 [ # # ]: 0 : if (revents != EPOLLIN)
1288 [ # # ]: 0 : return log_error_errno(SYNTHETIC_ERRNO(EIO),
1289 : : "Got invalid event from epoll for datagram fd: %" PRIx32,
1290 : : revents);
1291 : :
1292 : : /* Try to get the right size, if we can. (Not all sockets support SIOCINQ, hence we just try, but don't rely on
1293 : : * it.) */
1294 : 0 : (void) ioctl(fd, SIOCINQ, &v);
1295 : :
1296 : : /* Fix it up, if it is too small. We use the same fixed value as auditd here. Awful! */
1297 : 0 : m = PAGE_ALIGN(MAX3((size_t) v + 1,
1298 : : (size_t) LINE_MAX,
1299 : : ALIGN(sizeof(struct nlmsghdr)) + ALIGN((size_t) MAX_AUDIT_MESSAGE_LENGTH)) + 1);
1300 : :
1301 [ # # ]: 0 : if (!GREEDY_REALLOC(s->buffer, s->buffer_size, m))
1302 : 0 : return log_oom();
1303 : :
1304 : 0 : iovec = IOVEC_MAKE(s->buffer, s->buffer_size - 1); /* Leave room for trailing NUL we add later */
1305 : :
1306 : 0 : n = recvmsg(fd, &msghdr, MSG_DONTWAIT|MSG_CMSG_CLOEXEC);
1307 [ # # ]: 0 : if (n < 0) {
1308 [ # # # # ]: 0 : if (IN_SET(errno, EINTR, EAGAIN))
1309 : 0 : return 0;
1310 : :
1311 [ # # ]: 0 : return log_error_errno(errno, "recvmsg() failed: %m");
1312 : : }
1313 : :
1314 [ # # # # ]: 0 : CMSG_FOREACH(cmsg, &msghdr)
1315 [ # # ]: 0 : if (cmsg->cmsg_level == SOL_SOCKET &&
1316 [ # # ]: 0 : cmsg->cmsg_type == SCM_CREDENTIALS &&
1317 [ # # ]: 0 : cmsg->cmsg_len == CMSG_LEN(sizeof(struct ucred)))
1318 : 0 : ucred = (struct ucred*) CMSG_DATA(cmsg);
1319 [ # # ]: 0 : else if (cmsg->cmsg_level == SOL_SOCKET &&
1320 [ # # ]: 0 : cmsg->cmsg_type == SCM_SECURITY) {
1321 : 0 : label = (char*) CMSG_DATA(cmsg);
1322 : 0 : label_len = cmsg->cmsg_len - CMSG_LEN(0);
1323 [ # # ]: 0 : } else if (cmsg->cmsg_level == SOL_SOCKET &&
1324 [ # # ]: 0 : cmsg->cmsg_type == SO_TIMESTAMP &&
1325 [ # # ]: 0 : cmsg->cmsg_len == CMSG_LEN(sizeof(struct timeval)))
1326 : 0 : tv = (struct timeval*) CMSG_DATA(cmsg);
1327 [ # # ]: 0 : else if (cmsg->cmsg_level == SOL_SOCKET &&
1328 [ # # ]: 0 : cmsg->cmsg_type == SCM_RIGHTS) {
1329 : 0 : fds = (int*) CMSG_DATA(cmsg);
1330 : 0 : n_fds = (cmsg->cmsg_len - CMSG_LEN(0)) / sizeof(int);
1331 : : }
1332 : :
1333 : : /* And a trailing NUL, just in case */
1334 : 0 : s->buffer[n] = 0;
1335 : :
1336 [ # # ]: 0 : if (fd == s->syslog_fd) {
1337 [ # # # # ]: 0 : if (n > 0 && n_fds == 0)
1338 : 0 : server_process_syslog_message(s, s->buffer, n, ucred, tv, label, label_len);
1339 [ # # ]: 0 : else if (n_fds > 0)
1340 [ # # ]: 0 : log_warning("Got file descriptors via syslog socket. Ignoring.");
1341 : :
1342 [ # # ]: 0 : } else if (fd == s->native_fd) {
1343 [ # # # # ]: 0 : if (n > 0 && n_fds == 0)
1344 : 0 : server_process_native_message(s, s->buffer, n, ucred, tv, label, label_len);
1345 [ # # # # ]: 0 : else if (n == 0 && n_fds == 1)
1346 : 0 : server_process_native_file(s, fds[0], ucred, tv, label, label_len);
1347 [ # # ]: 0 : else if (n_fds > 0)
1348 [ # # ]: 0 : log_warning("Got too many file descriptors via native socket. Ignoring.");
1349 : :
1350 : : } else {
1351 [ # # ]: 0 : assert(fd == s->audit_fd);
1352 : :
1353 [ # # # # ]: 0 : if (n > 0 && n_fds == 0)
1354 : 0 : server_process_audit_message(s, s->buffer, n, ucred, &sa, msghdr.msg_namelen);
1355 [ # # ]: 0 : else if (n_fds > 0)
1356 [ # # ]: 0 : log_warning("Got file descriptors via audit socket. Ignoring.");
1357 : : }
1358 : :
1359 : 0 : close_many(fds, n_fds);
1360 : 0 : return 0;
1361 : : }
1362 : :
1363 : 0 : static void server_full_flush(Server *s) {
1364 [ # # ]: 0 : assert(s);
1365 : :
1366 : 0 : (void) server_flush_to_var(s, false);
1367 : 0 : server_sync(s);
1368 : 0 : server_vacuum(s, false);
1369 : :
1370 : 0 : server_space_usage_message(s, NULL);
1371 : 0 : }
1372 : :
1373 : 0 : static int dispatch_sigusr1(sd_event_source *es, const struct signalfd_siginfo *si, void *userdata) {
1374 : 0 : Server *s = userdata;
1375 : :
1376 [ # # ]: 0 : assert(s);
1377 : :
1378 [ # # ]: 0 : log_info("Received SIGUSR1 signal from PID " PID_FMT ", as request to flush runtime journal.", si->ssi_pid);
1379 : 0 : server_full_flush(s);
1380 : :
1381 : 0 : return 0;
1382 : : }
1383 : :
1384 : 0 : static void server_full_rotate(Server *s) {
1385 : : int r;
1386 : :
1387 [ # # ]: 0 : assert(s);
1388 : :
1389 : 0 : server_rotate(s);
1390 : 0 : server_vacuum(s, true);
1391 : :
1392 [ # # ]: 0 : if (s->system_journal)
1393 : 0 : patch_min_use(&s->system_storage);
1394 [ # # ]: 0 : if (s->runtime_journal)
1395 : 0 : patch_min_use(&s->runtime_storage);
1396 : :
1397 : : /* Let clients know when the most recent rotation happened. */
1398 : 0 : r = write_timestamp_file_atomic("/run/systemd/journal/rotated", now(CLOCK_MONOTONIC));
1399 [ # # ]: 0 : if (r < 0)
1400 [ # # ]: 0 : log_warning_errno(r, "Failed to write /run/systemd/journal/rotated, ignoring: %m");
1401 : 0 : }
1402 : :
1403 : 0 : static int dispatch_sigusr2(sd_event_source *es, const struct signalfd_siginfo *si, void *userdata) {
1404 : 0 : Server *s = userdata;
1405 : :
1406 [ # # ]: 0 : assert(s);
1407 : :
1408 [ # # ]: 0 : log_info("Received SIGUSR2 signal from PID " PID_FMT ", as request to rotate journal.", si->ssi_pid);
1409 : 0 : server_full_rotate(s);
1410 : :
1411 : 0 : return 0;
1412 : : }
1413 : :
1414 : 0 : static int dispatch_sigterm(sd_event_source *es, const struct signalfd_siginfo *si, void *userdata) {
1415 : 0 : Server *s = userdata;
1416 : :
1417 [ # # ]: 0 : assert(s);
1418 : :
1419 : 0 : log_received_signal(LOG_INFO, si);
1420 : :
1421 : 0 : sd_event_exit(s->event, 0);
1422 : 0 : return 0;
1423 : : }
1424 : :
1425 : 0 : static void server_full_sync(Server *s) {
1426 : : int r;
1427 : :
1428 [ # # ]: 0 : assert(s);
1429 : :
1430 : 0 : server_sync(s);
1431 : :
1432 : : /* Let clients know when the most recent sync happened. */
1433 : 0 : r = write_timestamp_file_atomic("/run/systemd/journal/synced", now(CLOCK_MONOTONIC));
1434 [ # # ]: 0 : if (r < 0)
1435 [ # # ]: 0 : log_warning_errno(r, "Failed to write /run/systemd/journal/synced, ignoring: %m");
1436 : :
1437 : 0 : return;
1438 : : }
1439 : :
1440 : 0 : static int dispatch_sigrtmin1(sd_event_source *es, const struct signalfd_siginfo *si, void *userdata) {
1441 : 0 : Server *s = userdata;
1442 : :
1443 [ # # ]: 0 : assert(s);
1444 : :
1445 [ # # ]: 0 : log_debug("Received SIGRTMIN1 signal from PID " PID_FMT ", as request to sync.", si->ssi_pid );
1446 : 0 : server_full_sync(s);
1447 : :
1448 : 0 : return 0;
1449 : : }
1450 : :
1451 : 0 : static int setup_signals(Server *s) {
1452 : : int r;
1453 : :
1454 [ # # ]: 0 : assert(s);
1455 : :
1456 [ # # ]: 0 : assert_se(sigprocmask_many(SIG_SETMASK, NULL, SIGINT, SIGTERM, SIGUSR1, SIGUSR2, SIGRTMIN+1, -1) >= 0);
1457 : :
1458 : 0 : r = sd_event_add_signal(s->event, &s->sigusr1_event_source, SIGUSR1, dispatch_sigusr1, s);
1459 [ # # ]: 0 : if (r < 0)
1460 : 0 : return r;
1461 : :
1462 : 0 : r = sd_event_add_signal(s->event, &s->sigusr2_event_source, SIGUSR2, dispatch_sigusr2, s);
1463 [ # # ]: 0 : if (r < 0)
1464 : 0 : return r;
1465 : :
1466 : 0 : r = sd_event_add_signal(s->event, &s->sigterm_event_source, SIGTERM, dispatch_sigterm, s);
1467 [ # # ]: 0 : if (r < 0)
1468 : 0 : return r;
1469 : :
1470 : : /* Let's process SIGTERM late, so that we flush all queued messages to disk before we exit */
1471 : 0 : r = sd_event_source_set_priority(s->sigterm_event_source, SD_EVENT_PRIORITY_NORMAL+20);
1472 [ # # ]: 0 : if (r < 0)
1473 : 0 : return r;
1474 : :
1475 : : /* When journald is invoked on the terminal (when debugging), it's useful if C-c is handled
1476 : : * equivalent to SIGTERM. */
1477 : 0 : r = sd_event_add_signal(s->event, &s->sigint_event_source, SIGINT, dispatch_sigterm, s);
1478 [ # # ]: 0 : if (r < 0)
1479 : 0 : return r;
1480 : :
1481 : 0 : r = sd_event_source_set_priority(s->sigint_event_source, SD_EVENT_PRIORITY_NORMAL+20);
1482 [ # # ]: 0 : if (r < 0)
1483 : 0 : return r;
1484 : :
1485 : : /* SIGRTMIN+1 causes an immediate sync. We process this very late, so that everything else queued at
1486 : : * this point is really written to disk. Clients can watch /run/systemd/journal/synced with inotify
1487 : : * until its mtime changes to see when a sync happened. */
1488 : 0 : r = sd_event_add_signal(s->event, &s->sigrtmin1_event_source, SIGRTMIN+1, dispatch_sigrtmin1, s);
1489 [ # # ]: 0 : if (r < 0)
1490 : 0 : return r;
1491 : :
1492 : 0 : r = sd_event_source_set_priority(s->sigrtmin1_event_source, SD_EVENT_PRIORITY_NORMAL+15);
1493 [ # # ]: 0 : if (r < 0)
1494 : 0 : return r;
1495 : :
1496 : 0 : return 0;
1497 : : }
1498 : :
1499 : 0 : static int parse_proc_cmdline_item(const char *key, const char *value, void *data) {
1500 : 0 : Server *s = data;
1501 : : int r;
1502 : :
1503 [ # # ]: 0 : assert(s);
1504 : :
1505 [ # # ]: 0 : if (proc_cmdline_key_streq(key, "systemd.journald.forward_to_syslog")) {
1506 : :
1507 [ # # ]: 0 : r = value ? parse_boolean(value) : true;
1508 [ # # ]: 0 : if (r < 0)
1509 [ # # ]: 0 : log_warning("Failed to parse forward to syslog switch \"%s\". Ignoring.", value);
1510 : : else
1511 : 0 : s->forward_to_syslog = r;
1512 : :
1513 [ # # ]: 0 : } else if (proc_cmdline_key_streq(key, "systemd.journald.forward_to_kmsg")) {
1514 : :
1515 [ # # ]: 0 : r = value ? parse_boolean(value) : true;
1516 [ # # ]: 0 : if (r < 0)
1517 [ # # ]: 0 : log_warning("Failed to parse forward to kmsg switch \"%s\". Ignoring.", value);
1518 : : else
1519 : 0 : s->forward_to_kmsg = r;
1520 : :
1521 [ # # ]: 0 : } else if (proc_cmdline_key_streq(key, "systemd.journald.forward_to_console")) {
1522 : :
1523 [ # # ]: 0 : r = value ? parse_boolean(value) : true;
1524 [ # # ]: 0 : if (r < 0)
1525 [ # # ]: 0 : log_warning("Failed to parse forward to console switch \"%s\". Ignoring.", value);
1526 : : else
1527 : 0 : s->forward_to_console = r;
1528 : :
1529 [ # # ]: 0 : } else if (proc_cmdline_key_streq(key, "systemd.journald.forward_to_wall")) {
1530 : :
1531 [ # # ]: 0 : r = value ? parse_boolean(value) : true;
1532 [ # # ]: 0 : if (r < 0)
1533 [ # # ]: 0 : log_warning("Failed to parse forward to wall switch \"%s\". Ignoring.", value);
1534 : : else
1535 : 0 : s->forward_to_wall = r;
1536 : :
1537 [ # # ]: 0 : } else if (proc_cmdline_key_streq(key, "systemd.journald.max_level_console")) {
1538 : :
1539 [ # # ]: 0 : if (proc_cmdline_value_missing(key, value))
1540 : 0 : return 0;
1541 : :
1542 : 0 : r = log_level_from_string(value);
1543 [ # # ]: 0 : if (r < 0)
1544 [ # # ]: 0 : log_warning("Failed to parse max level console value \"%s\". Ignoring.", value);
1545 : : else
1546 : 0 : s->max_level_console = r;
1547 : :
1548 [ # # ]: 0 : } else if (proc_cmdline_key_streq(key, "systemd.journald.max_level_store")) {
1549 : :
1550 [ # # ]: 0 : if (proc_cmdline_value_missing(key, value))
1551 : 0 : return 0;
1552 : :
1553 : 0 : r = log_level_from_string(value);
1554 [ # # ]: 0 : if (r < 0)
1555 [ # # ]: 0 : log_warning("Failed to parse max level store value \"%s\". Ignoring.", value);
1556 : : else
1557 : 0 : s->max_level_store = r;
1558 : :
1559 [ # # ]: 0 : } else if (proc_cmdline_key_streq(key, "systemd.journald.max_level_syslog")) {
1560 : :
1561 [ # # ]: 0 : if (proc_cmdline_value_missing(key, value))
1562 : 0 : return 0;
1563 : :
1564 : 0 : r = log_level_from_string(value);
1565 [ # # ]: 0 : if (r < 0)
1566 [ # # ]: 0 : log_warning("Failed to parse max level syslog value \"%s\". Ignoring.", value);
1567 : : else
1568 : 0 : s->max_level_syslog = r;
1569 : :
1570 [ # # ]: 0 : } else if (proc_cmdline_key_streq(key, "systemd.journald.max_level_kmsg")) {
1571 : :
1572 [ # # ]: 0 : if (proc_cmdline_value_missing(key, value))
1573 : 0 : return 0;
1574 : :
1575 : 0 : r = log_level_from_string(value);
1576 [ # # ]: 0 : if (r < 0)
1577 [ # # ]: 0 : log_warning("Failed to parse max level kmsg value \"%s\". Ignoring.", value);
1578 : : else
1579 : 0 : s->max_level_kmsg = r;
1580 : :
1581 [ # # ]: 0 : } else if (proc_cmdline_key_streq(key, "systemd.journald.max_level_wall")) {
1582 : :
1583 [ # # ]: 0 : if (proc_cmdline_value_missing(key, value))
1584 : 0 : return 0;
1585 : :
1586 : 0 : r = log_level_from_string(value);
1587 [ # # ]: 0 : if (r < 0)
1588 [ # # ]: 0 : log_warning("Failed to parse max level wall value \"%s\". Ignoring.", value);
1589 : : else
1590 : 0 : s->max_level_wall = r;
1591 : :
1592 [ # # ]: 0 : } else if (startswith(key, "systemd.journald"))
1593 [ # # ]: 0 : log_warning("Unknown journald kernel command line option \"%s\". Ignoring.", key);
1594 : :
1595 : : /* do not warn about state here, since probably systemd already did */
1596 : 0 : return 0;
1597 : : }
1598 : :
1599 : 0 : static int server_parse_config_file(Server *s) {
1600 [ # # ]: 0 : assert(s);
1601 : :
1602 : 0 : return config_parse_many_nulstr(PKGSYSCONFDIR "/journald.conf",
1603 : : CONF_PATHS_NULSTR("systemd/journald.conf.d"),
1604 : : "Journal\0",
1605 : : config_item_perf_lookup, journald_gperf_lookup,
1606 : : CONFIG_PARSE_WARN, s);
1607 : : }
1608 : :
1609 : 0 : static int server_dispatch_sync(sd_event_source *es, usec_t t, void *userdata) {
1610 : 0 : Server *s = userdata;
1611 : :
1612 [ # # ]: 0 : assert(s);
1613 : :
1614 : 0 : server_sync(s);
1615 : 0 : return 0;
1616 : : }
1617 : :
1618 : 0 : int server_schedule_sync(Server *s, int priority) {
1619 : : int r;
1620 : :
1621 [ # # ]: 0 : assert(s);
1622 : :
1623 [ # # ]: 0 : if (priority <= LOG_CRIT) {
1624 : : /* Immediately sync to disk when this is of priority CRIT, ALERT, EMERG */
1625 : 0 : server_sync(s);
1626 : 0 : return 0;
1627 : : }
1628 : :
1629 [ # # ]: 0 : if (s->sync_scheduled)
1630 : 0 : return 0;
1631 : :
1632 [ # # ]: 0 : if (s->sync_interval_usec > 0) {
1633 : : usec_t when;
1634 : :
1635 : 0 : r = sd_event_now(s->event, CLOCK_MONOTONIC, &when);
1636 [ # # ]: 0 : if (r < 0)
1637 : 0 : return r;
1638 : :
1639 : 0 : when += s->sync_interval_usec;
1640 : :
1641 [ # # ]: 0 : if (!s->sync_event_source) {
1642 : 0 : r = sd_event_add_time(
1643 : : s->event,
1644 : : &s->sync_event_source,
1645 : : CLOCK_MONOTONIC,
1646 : : when, 0,
1647 : : server_dispatch_sync, s);
1648 [ # # ]: 0 : if (r < 0)
1649 : 0 : return r;
1650 : :
1651 : 0 : r = sd_event_source_set_priority(s->sync_event_source, SD_EVENT_PRIORITY_IMPORTANT);
1652 : : } else {
1653 : 0 : r = sd_event_source_set_time(s->sync_event_source, when);
1654 [ # # ]: 0 : if (r < 0)
1655 : 0 : return r;
1656 : :
1657 : 0 : r = sd_event_source_set_enabled(s->sync_event_source, SD_EVENT_ONESHOT);
1658 : : }
1659 [ # # ]: 0 : if (r < 0)
1660 : 0 : return r;
1661 : :
1662 : 0 : s->sync_scheduled = true;
1663 : : }
1664 : :
1665 : 0 : return 0;
1666 : : }
1667 : :
1668 : 0 : static int dispatch_hostname_change(sd_event_source *es, int fd, uint32_t revents, void *userdata) {
1669 : 0 : Server *s = userdata;
1670 : :
1671 [ # # ]: 0 : assert(s);
1672 : :
1673 : 0 : server_cache_hostname(s);
1674 : 0 : return 0;
1675 : : }
1676 : :
1677 : 0 : static int server_open_hostname(Server *s) {
1678 : : int r;
1679 : :
1680 [ # # ]: 0 : assert(s);
1681 : :
1682 : 0 : s->hostname_fd = open("/proc/sys/kernel/hostname",
1683 : : O_RDONLY|O_CLOEXEC|O_NONBLOCK|O_NOCTTY);
1684 [ # # ]: 0 : if (s->hostname_fd < 0)
1685 [ # # ]: 0 : return log_error_errno(errno, "Failed to open /proc/sys/kernel/hostname: %m");
1686 : :
1687 : 0 : r = sd_event_add_io(s->event, &s->hostname_event_source, s->hostname_fd, 0, dispatch_hostname_change, s);
1688 [ # # ]: 0 : if (r < 0) {
1689 : : /* kernels prior to 3.2 don't support polling this file. Ignore
1690 : : * the failure. */
1691 [ # # ]: 0 : if (r == -EPERM) {
1692 [ # # ]: 0 : log_warning_errno(r, "Failed to register hostname fd in event loop, ignoring: %m");
1693 : 0 : s->hostname_fd = safe_close(s->hostname_fd);
1694 : 0 : return 0;
1695 : : }
1696 : :
1697 [ # # ]: 0 : return log_error_errno(r, "Failed to register hostname fd in event loop: %m");
1698 : : }
1699 : :
1700 : 0 : r = sd_event_source_set_priority(s->hostname_event_source, SD_EVENT_PRIORITY_IMPORTANT-10);
1701 [ # # ]: 0 : if (r < 0)
1702 [ # # ]: 0 : return log_error_errno(r, "Failed to adjust priority of host name event source: %m");
1703 : :
1704 : 0 : return 0;
1705 : : }
1706 : :
1707 : 0 : static int dispatch_notify_event(sd_event_source *es, int fd, uint32_t revents, void *userdata) {
1708 : 0 : Server *s = userdata;
1709 : : int r;
1710 : :
1711 [ # # ]: 0 : assert(s);
1712 [ # # ]: 0 : assert(s->notify_event_source == es);
1713 [ # # ]: 0 : assert(s->notify_fd == fd);
1714 : :
1715 : : /* The $NOTIFY_SOCKET is writable again, now send exactly one
1716 : : * message on it. Either it's the watchdog event, the initial
1717 : : * READY=1 event or an stdout stream event. If there's nothing
1718 : : * to write anymore, turn our event source off. The next time
1719 : : * there's something to send it will be turned on again. */
1720 : :
1721 [ # # ]: 0 : if (!s->sent_notify_ready) {
1722 : : static const char p[] =
1723 : : "READY=1\n"
1724 : : "STATUS=Processing requests...";
1725 : : ssize_t l;
1726 : :
1727 : 0 : l = send(s->notify_fd, p, strlen(p), MSG_DONTWAIT);
1728 [ # # ]: 0 : if (l < 0) {
1729 [ # # ]: 0 : if (errno == EAGAIN)
1730 : 0 : return 0;
1731 : :
1732 [ # # ]: 0 : return log_error_errno(errno, "Failed to send READY=1 notification message: %m");
1733 : : }
1734 : :
1735 : 0 : s->sent_notify_ready = true;
1736 [ # # ]: 0 : log_debug("Sent READY=1 notification.");
1737 : :
1738 [ # # ]: 0 : } else if (s->send_watchdog) {
1739 : :
1740 : : static const char p[] =
1741 : : "WATCHDOG=1";
1742 : :
1743 : : ssize_t l;
1744 : :
1745 : 0 : l = send(s->notify_fd, p, strlen(p), MSG_DONTWAIT);
1746 [ # # ]: 0 : if (l < 0) {
1747 [ # # ]: 0 : if (errno == EAGAIN)
1748 : 0 : return 0;
1749 : :
1750 [ # # ]: 0 : return log_error_errno(errno, "Failed to send WATCHDOG=1 notification message: %m");
1751 : : }
1752 : :
1753 : 0 : s->send_watchdog = false;
1754 [ # # ]: 0 : log_debug("Sent WATCHDOG=1 notification.");
1755 : :
1756 [ # # ]: 0 : } else if (s->stdout_streams_notify_queue)
1757 : : /* Dispatch one stream notification event */
1758 : 0 : stdout_stream_send_notify(s->stdout_streams_notify_queue);
1759 : :
1760 : : /* Leave us enabled if there's still more to do. */
1761 [ # # # # ]: 0 : if (s->send_watchdog || s->stdout_streams_notify_queue)
1762 : 0 : return 0;
1763 : :
1764 : : /* There was nothing to do anymore, let's turn ourselves off. */
1765 : 0 : r = sd_event_source_set_enabled(es, SD_EVENT_OFF);
1766 [ # # ]: 0 : if (r < 0)
1767 [ # # ]: 0 : return log_error_errno(r, "Failed to turn off notify event source: %m");
1768 : :
1769 : 0 : return 0;
1770 : : }
1771 : :
1772 : 0 : static int dispatch_watchdog(sd_event_source *es, uint64_t usec, void *userdata) {
1773 : 0 : Server *s = userdata;
1774 : : int r;
1775 : :
1776 [ # # ]: 0 : assert(s);
1777 : :
1778 : 0 : s->send_watchdog = true;
1779 : :
1780 : 0 : r = sd_event_source_set_enabled(s->notify_event_source, SD_EVENT_ON);
1781 [ # # ]: 0 : if (r < 0)
1782 [ # # ]: 0 : log_warning_errno(r, "Failed to turn on notify event source: %m");
1783 : :
1784 : 0 : r = sd_event_source_set_time(s->watchdog_event_source, usec + s->watchdog_usec / 2);
1785 [ # # ]: 0 : if (r < 0)
1786 [ # # ]: 0 : return log_error_errno(r, "Failed to restart watchdog event source: %m");
1787 : :
1788 : 0 : r = sd_event_source_set_enabled(s->watchdog_event_source, SD_EVENT_ON);
1789 [ # # ]: 0 : if (r < 0)
1790 [ # # ]: 0 : return log_error_errno(r, "Failed to enable watchdog event source: %m");
1791 : :
1792 : 0 : return 0;
1793 : : }
1794 : :
1795 : 0 : static int server_connect_notify(Server *s) {
1796 : 0 : union sockaddr_union sa = {};
1797 : : const char *e;
1798 : : int r, salen;
1799 : :
1800 [ # # ]: 0 : assert(s);
1801 [ # # ]: 0 : assert(s->notify_fd < 0);
1802 [ # # ]: 0 : assert(!s->notify_event_source);
1803 : :
1804 : : /*
1805 : : * So here's the problem: we'd like to send notification messages to PID 1, but we cannot do that via
1806 : : * sd_notify(), since that's synchronous, and we might end up blocking on it. Specifically: given
1807 : : * that PID 1 might block on dbus-daemon during IPC, and dbus-daemon is logging to us, and might
1808 : : * hence block on us, we might end up in a deadlock if we block on sending PID 1 notification
1809 : : * messages — by generating a full blocking circle. To avoid this, let's create a non-blocking
1810 : : * socket, and connect it to the notification socket, and then wait for POLLOUT before we send
1811 : : * anything. This should efficiently avoid any deadlocks, as we'll never block on PID 1, hence PID 1
1812 : : * can safely block on dbus-daemon which can safely block on us again.
1813 : : *
1814 : : * Don't think that this issue is real? It is, see: https://github.com/systemd/systemd/issues/1505
1815 : : */
1816 : :
1817 : 0 : e = getenv("NOTIFY_SOCKET");
1818 [ # # ]: 0 : if (!e)
1819 : 0 : return 0;
1820 : :
1821 : 0 : salen = sockaddr_un_set_path(&sa.un, e);
1822 [ # # ]: 0 : if (salen < 0)
1823 [ # # ]: 0 : return log_error_errno(salen, "NOTIFY_SOCKET set to invalid value '%s': %m", e);
1824 : :
1825 : 0 : s->notify_fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0);
1826 [ # # ]: 0 : if (s->notify_fd < 0)
1827 [ # # ]: 0 : return log_error_errno(errno, "Failed to create notify socket: %m");
1828 : :
1829 : 0 : (void) fd_inc_sndbuf(s->notify_fd, NOTIFY_SNDBUF_SIZE);
1830 : :
1831 : 0 : r = connect(s->notify_fd, &sa.sa, salen);
1832 [ # # ]: 0 : if (r < 0)
1833 [ # # ]: 0 : return log_error_errno(errno, "Failed to connect to notify socket: %m");
1834 : :
1835 : 0 : r = sd_event_add_io(s->event, &s->notify_event_source, s->notify_fd, EPOLLOUT, dispatch_notify_event, s);
1836 [ # # ]: 0 : if (r < 0)
1837 [ # # ]: 0 : return log_error_errno(r, "Failed to watch notification socket: %m");
1838 : :
1839 [ # # ]: 0 : if (sd_watchdog_enabled(false, &s->watchdog_usec) > 0) {
1840 : 0 : s->send_watchdog = true;
1841 : :
1842 : 0 : r = sd_event_add_time(s->event, &s->watchdog_event_source, CLOCK_MONOTONIC, now(CLOCK_MONOTONIC) + s->watchdog_usec/2, s->watchdog_usec/4, dispatch_watchdog, s);
1843 [ # # ]: 0 : if (r < 0)
1844 [ # # ]: 0 : return log_error_errno(r, "Failed to add watchdog time event: %m");
1845 : : }
1846 : :
1847 : : /* This should fire pretty soon, which we'll use to send the READY=1 event. */
1848 : :
1849 : 0 : return 0;
1850 : : }
1851 : :
1852 : 0 : static int synchronize_second_half(sd_event_source *event_source, void *userdata) {
1853 : 0 : Varlink *link = userdata;
1854 : : Server *s;
1855 : : int r;
1856 : :
1857 [ # # ]: 0 : assert(link);
1858 [ # # ]: 0 : assert_se(s = varlink_get_userdata(link));
1859 : :
1860 : : /* This is the "second half" of the Synchronize() varlink method. This function is called as deferred
1861 : : * event source at a low priority to ensure the synchronization completes after all queued log
1862 : : * messages are processed. */
1863 : 0 : server_full_sync(s);
1864 : :
1865 : : /* Let's get rid of the event source now, by marking it as non-floating again. It then has no ref
1866 : : * anymore and is immediately destroyed after we return from this function, i.e. from this event
1867 : : * source handler at the end. */
1868 : 0 : r = sd_event_source_set_floating(event_source, false);
1869 [ # # ]: 0 : if (r < 0)
1870 [ # # ]: 0 : return log_error_errno(r, "Failed to mark event source as non-floating: %m");
1871 : :
1872 : 0 : return varlink_reply(link, NULL);
1873 : : }
1874 : :
1875 : 0 : static void synchronize_destroy(void *userdata) {
1876 : 0 : varlink_unref(userdata);
1877 : 0 : }
1878 : :
1879 : 0 : static int vl_method_synchronize(Varlink *link, JsonVariant *parameters, VarlinkMethodFlags flags, void *userdata) {
1880 : 0 : _cleanup_(sd_event_source_unrefp) sd_event_source *event_source = NULL;
1881 : 0 : Server *s = userdata;
1882 : : int r;
1883 : :
1884 [ # # ]: 0 : assert(link);
1885 [ # # ]: 0 : assert(s);
1886 : :
1887 [ # # ]: 0 : if (json_variant_elements(parameters) > 0)
1888 : 0 : return varlink_error_invalid_parameter(link, parameters);
1889 : :
1890 [ # # ]: 0 : log_info("Received client request to rotate journal.");
1891 : :
1892 : : /* We don't do the main work now, but instead enqueue a deferred event loop job which will do
1893 : : * it. That job is scheduled at low priority, so that we return from this method call only after all
1894 : : * queued but not processed log messages are written to disk, so that this method call returning can
1895 : : * be used as nice synchronization point. */
1896 : 0 : r = sd_event_add_defer(s->event, &event_source, synchronize_second_half, link);
1897 [ # # ]: 0 : if (r < 0)
1898 [ # # ]: 0 : return log_error_errno(r, "Failed to allocate defer event source: %m");
1899 : :
1900 : 0 : r = sd_event_source_set_destroy_callback(event_source, synchronize_destroy);
1901 [ # # ]: 0 : if (r < 0)
1902 [ # # ]: 0 : return log_error_errno(r, "Failed to set event source destroy callback: %m");
1903 : :
1904 : 0 : varlink_ref(link); /* The varlink object is now left to the destroy callack to unref */
1905 : :
1906 : 0 : r = sd_event_source_set_priority(event_source, SD_EVENT_PRIORITY_NORMAL+15);
1907 [ # # ]: 0 : if (r < 0)
1908 [ # # ]: 0 : return log_error_errno(r, "Failed to set defer event source priority: %m");
1909 : :
1910 : : /* Give up ownership of this event source. It will now be destroyed along with event loop itself,
1911 : : * unless it destroys itself earlier. */
1912 : 0 : r = sd_event_source_set_floating(event_source, true);
1913 [ # # ]: 0 : if (r < 0)
1914 [ # # ]: 0 : return log_error_errno(r, "Failed to mark event source as floating: %m");
1915 : :
1916 : 0 : (void) sd_event_source_set_description(event_source, "deferred-sync");
1917 : :
1918 : 0 : return 0;
1919 : : }
1920 : :
1921 : 0 : static int vl_method_rotate(Varlink *link, JsonVariant *parameters, VarlinkMethodFlags flags, void *userdata) {
1922 : 0 : Server *s = userdata;
1923 : :
1924 [ # # ]: 0 : assert(link);
1925 [ # # ]: 0 : assert(s);
1926 : :
1927 [ # # ]: 0 : if (json_variant_elements(parameters) > 0)
1928 : 0 : return varlink_error_invalid_parameter(link, parameters);
1929 : :
1930 [ # # ]: 0 : log_info("Received client request to rotate journal.");
1931 : 0 : server_full_rotate(s);
1932 : :
1933 : 0 : return varlink_reply(link, NULL);
1934 : : }
1935 : :
1936 : 0 : static int vl_method_flush_to_var(Varlink *link, JsonVariant *parameters, VarlinkMethodFlags flags, void *userdata) {
1937 : 0 : Server *s = userdata;
1938 : :
1939 [ # # ]: 0 : assert(link);
1940 [ # # ]: 0 : assert(s);
1941 : :
1942 [ # # ]: 0 : if (json_variant_elements(parameters) > 0)
1943 : 0 : return varlink_error_invalid_parameter(link, parameters);
1944 : :
1945 [ # # ]: 0 : log_info("Received client request to flush runtime journal.");
1946 : 0 : server_full_flush(s);
1947 : :
1948 : 0 : return varlink_reply(link, NULL);
1949 : : }
1950 : :
1951 : 0 : static int vl_method_relinquish_var(Varlink *link, JsonVariant *parameters, VarlinkMethodFlags flags, void *userdata) {
1952 : 0 : Server *s = userdata;
1953 : :
1954 [ # # ]: 0 : assert(link);
1955 [ # # ]: 0 : assert(s);
1956 : :
1957 [ # # ]: 0 : if (json_variant_elements(parameters) > 0)
1958 : 0 : return varlink_error_invalid_parameter(link, parameters);
1959 : :
1960 [ # # ]: 0 : log_info("Received client request to relinquish /var access.");
1961 : 0 : server_relinquish_var(s);
1962 : :
1963 : 0 : return varlink_reply(link, NULL);
1964 : : }
1965 : :
1966 : 0 : static int server_open_varlink(Server *s) {
1967 : : int r;
1968 : :
1969 [ # # ]: 0 : assert(s);
1970 : :
1971 : 0 : r = varlink_server_new(&s->varlink_server, VARLINK_SERVER_ROOT_ONLY);
1972 [ # # ]: 0 : if (r < 0)
1973 : 0 : return r;
1974 : :
1975 : 0 : varlink_server_set_userdata(s->varlink_server, s);
1976 : :
1977 : 0 : r = varlink_server_bind_method_many(
1978 : : s->varlink_server,
1979 : : "io.systemd.Journal.Synchronize", vl_method_synchronize,
1980 : : "io.systemd.Journal.Rotate", vl_method_rotate,
1981 : : "io.systemd.Journal.FlushToVar", vl_method_flush_to_var,
1982 : : "io.systemd.Journal.RelinquishVar", vl_method_relinquish_var);
1983 [ # # ]: 0 : if (r < 0)
1984 : 0 : return r;
1985 : :
1986 : 0 : r = varlink_server_listen_address(s->varlink_server, "/run/systemd/journal/io.systemd.journal", 0600);
1987 [ # # ]: 0 : if (r < 0)
1988 : 0 : return r;
1989 : :
1990 : 0 : r = varlink_server_attach_event(s->varlink_server, s->event, SD_EVENT_PRIORITY_NORMAL);
1991 [ # # ]: 0 : if (r < 0)
1992 : 0 : return r;
1993 : :
1994 : 0 : return 0;
1995 : : }
1996 : :
1997 : 0 : int server_init(Server *s) {
1998 : 0 : _cleanup_fdset_free_ FDSet *fds = NULL;
1999 : : int n, r, fd;
2000 : : bool no_sockets;
2001 : :
2002 [ # # ]: 0 : assert(s);
2003 : :
2004 : 0 : *s = (Server) {
2005 : : .syslog_fd = -1,
2006 : : .native_fd = -1,
2007 : : .stdout_fd = -1,
2008 : : .dev_kmsg_fd = -1,
2009 : : .audit_fd = -1,
2010 : : .hostname_fd = -1,
2011 : : .notify_fd = -1,
2012 : :
2013 : : .compress.enabled = true,
2014 : : .compress.threshold_bytes = (uint64_t) -1,
2015 : : .seal = true,
2016 : : .read_kmsg = true,
2017 : :
2018 : : .watchdog_usec = USEC_INFINITY,
2019 : :
2020 : : .sync_interval_usec = DEFAULT_SYNC_INTERVAL_USEC,
2021 : : .sync_scheduled = false,
2022 : :
2023 : : .rate_limit_interval = DEFAULT_RATE_LIMIT_INTERVAL,
2024 : : .rate_limit_burst = DEFAULT_RATE_LIMIT_BURST,
2025 : :
2026 : : .forward_to_wall = true,
2027 : :
2028 : : .max_file_usec = DEFAULT_MAX_FILE_USEC,
2029 : :
2030 : : .max_level_store = LOG_DEBUG,
2031 : : .max_level_syslog = LOG_DEBUG,
2032 : : .max_level_kmsg = LOG_NOTICE,
2033 : : .max_level_console = LOG_INFO,
2034 : : .max_level_wall = LOG_EMERG,
2035 : :
2036 : : .line_max = DEFAULT_LINE_MAX,
2037 : :
2038 : : .runtime_storage.name = "Runtime Journal",
2039 : : .system_storage.name = "System Journal",
2040 : : };
2041 : :
2042 : 0 : journal_reset_metrics(&s->system_storage.metrics);
2043 : 0 : journal_reset_metrics(&s->runtime_storage.metrics);
2044 : :
2045 : 0 : server_parse_config_file(s);
2046 : :
2047 : 0 : r = proc_cmdline_parse(parse_proc_cmdline_item, s, PROC_CMDLINE_STRIP_RD_PREFIX);
2048 [ # # ]: 0 : if (r < 0)
2049 [ # # ]: 0 : log_warning_errno(r, "Failed to parse kernel command line, ignoring: %m");
2050 : :
2051 [ # # ]: 0 : if (!!s->rate_limit_interval ^ !!s->rate_limit_burst) {
2052 [ # # ]: 0 : log_debug("Setting both rate limit interval and burst from "USEC_FMT",%u to 0,0",
2053 : : s->rate_limit_interval, s->rate_limit_burst);
2054 : 0 : s->rate_limit_interval = s->rate_limit_burst = 0;
2055 : : }
2056 : :
2057 : 0 : (void) mkdir_p("/run/systemd/journal", 0755);
2058 : :
2059 : 0 : s->user_journals = ordered_hashmap_new(NULL);
2060 [ # # ]: 0 : if (!s->user_journals)
2061 : 0 : return log_oom();
2062 : :
2063 : 0 : s->mmap = mmap_cache_new();
2064 [ # # ]: 0 : if (!s->mmap)
2065 : 0 : return log_oom();
2066 : :
2067 : 0 : s->deferred_closes = set_new(NULL);
2068 [ # # ]: 0 : if (!s->deferred_closes)
2069 : 0 : return log_oom();
2070 : :
2071 : 0 : r = sd_event_default(&s->event);
2072 [ # # ]: 0 : if (r < 0)
2073 [ # # ]: 0 : return log_error_errno(r, "Failed to create event loop: %m");
2074 : :
2075 : 0 : n = sd_listen_fds(true);
2076 [ # # ]: 0 : if (n < 0)
2077 [ # # ]: 0 : return log_error_errno(n, "Failed to read listening file descriptors from environment: %m");
2078 : :
2079 [ # # ]: 0 : for (fd = SD_LISTEN_FDS_START; fd < SD_LISTEN_FDS_START + n; fd++) {
2080 : :
2081 [ # # ]: 0 : if (sd_is_socket_unix(fd, SOCK_DGRAM, -1, "/run/systemd/journal/socket", 0) > 0) {
2082 : :
2083 [ # # ]: 0 : if (s->native_fd >= 0)
2084 [ # # ]: 0 : return log_error_errno(SYNTHETIC_ERRNO(EINVAL),
2085 : : "Too many native sockets passed.");
2086 : :
2087 : 0 : s->native_fd = fd;
2088 : :
2089 [ # # ]: 0 : } else if (sd_is_socket_unix(fd, SOCK_STREAM, 1, "/run/systemd/journal/stdout", 0) > 0) {
2090 : :
2091 [ # # ]: 0 : if (s->stdout_fd >= 0)
2092 [ # # ]: 0 : return log_error_errno(SYNTHETIC_ERRNO(EINVAL),
2093 : : "Too many stdout sockets passed.");
2094 : :
2095 : 0 : s->stdout_fd = fd;
2096 : :
2097 [ # # # # ]: 0 : } else if (sd_is_socket_unix(fd, SOCK_DGRAM, -1, "/dev/log", 0) > 0 ||
2098 : 0 : sd_is_socket_unix(fd, SOCK_DGRAM, -1, "/run/systemd/journal/dev-log", 0) > 0) {
2099 : :
2100 [ # # ]: 0 : if (s->syslog_fd >= 0)
2101 [ # # ]: 0 : return log_error_errno(SYNTHETIC_ERRNO(EINVAL),
2102 : : "Too many /dev/log sockets passed.");
2103 : :
2104 : 0 : s->syslog_fd = fd;
2105 : :
2106 [ # # ]: 0 : } else if (sd_is_socket(fd, AF_NETLINK, SOCK_RAW, -1) > 0) {
2107 : :
2108 [ # # ]: 0 : if (s->audit_fd >= 0)
2109 [ # # ]: 0 : return log_error_errno(SYNTHETIC_ERRNO(EINVAL),
2110 : : "Too many audit sockets passed.");
2111 : :
2112 : 0 : s->audit_fd = fd;
2113 : :
2114 : : } else {
2115 : :
2116 [ # # ]: 0 : if (!fds) {
2117 : 0 : fds = fdset_new();
2118 [ # # ]: 0 : if (!fds)
2119 : 0 : return log_oom();
2120 : : }
2121 : :
2122 : 0 : r = fdset_put(fds, fd);
2123 [ # # ]: 0 : if (r < 0)
2124 : 0 : return log_oom();
2125 : : }
2126 : : }
2127 : :
2128 : : /* Try to restore streams, but don't bother if this fails */
2129 : 0 : (void) server_restore_streams(s, fds);
2130 : :
2131 [ # # ]: 0 : if (fdset_size(fds) > 0) {
2132 [ # # ]: 0 : log_warning("%u unknown file descriptors passed, closing.", fdset_size(fds));
2133 : 0 : fds = fdset_free(fds);
2134 : : }
2135 : :
2136 [ # # # # : 0 : no_sockets = s->native_fd < 0 && s->stdout_fd < 0 && s->syslog_fd < 0 && s->audit_fd < 0;
# # # # ]
2137 : :
2138 : : /* always open stdout, syslog, native, and kmsg sockets */
2139 : :
2140 : : /* systemd-journald.socket: /run/systemd/journal/stdout */
2141 : 0 : r = server_open_stdout_socket(s);
2142 [ # # ]: 0 : if (r < 0)
2143 : 0 : return r;
2144 : :
2145 : : /* systemd-journald-dev-log.socket: /run/systemd/journal/dev-log */
2146 : 0 : r = server_open_syslog_socket(s);
2147 [ # # ]: 0 : if (r < 0)
2148 : 0 : return r;
2149 : :
2150 : : /* systemd-journald.socket: /run/systemd/journal/socket */
2151 : 0 : r = server_open_native_socket(s);
2152 [ # # ]: 0 : if (r < 0)
2153 : 0 : return r;
2154 : :
2155 : : /* /dev/kmsg */
2156 : 0 : r = server_open_dev_kmsg(s);
2157 [ # # ]: 0 : if (r < 0)
2158 : 0 : return r;
2159 : :
2160 : : /* Unless we got *some* sockets and not audit, open audit socket */
2161 [ # # # # ]: 0 : if (s->audit_fd >= 0 || no_sockets) {
2162 : 0 : r = server_open_audit(s);
2163 [ # # ]: 0 : if (r < 0)
2164 : 0 : return r;
2165 : : }
2166 : :
2167 : 0 : r = server_open_varlink(s);
2168 [ # # ]: 0 : if (r < 0)
2169 : 0 : return r;
2170 : :
2171 : 0 : r = server_open_kernel_seqnum(s);
2172 [ # # ]: 0 : if (r < 0)
2173 : 0 : return r;
2174 : :
2175 : 0 : r = server_open_hostname(s);
2176 [ # # ]: 0 : if (r < 0)
2177 : 0 : return r;
2178 : :
2179 : 0 : r = setup_signals(s);
2180 [ # # ]: 0 : if (r < 0)
2181 : 0 : return r;
2182 : :
2183 : 0 : s->rate_limit = journal_rate_limit_new();
2184 [ # # ]: 0 : if (!s->rate_limit)
2185 : 0 : return -ENOMEM;
2186 : :
2187 : 0 : r = cg_get_root_path(&s->cgroup_root);
2188 [ # # ]: 0 : if (r < 0)
2189 : 0 : return r;
2190 : :
2191 : 0 : server_cache_hostname(s);
2192 : 0 : server_cache_boot_id(s);
2193 : 0 : server_cache_machine_id(s);
2194 : :
2195 : 0 : s->runtime_storage.path = path_join("/run/log/journal", SERVER_MACHINE_ID(s));
2196 : 0 : s->system_storage.path = path_join("/var/log/journal", SERVER_MACHINE_ID(s));
2197 [ # # # # ]: 0 : if (!s->runtime_storage.path || !s->system_storage.path)
2198 : 0 : return -ENOMEM;
2199 : :
2200 : 0 : (void) server_connect_notify(s);
2201 : :
2202 : 0 : (void) client_context_acquire_default(s);
2203 : :
2204 : 0 : return system_journal_open(s, false, false);
2205 : : }
2206 : :
2207 : 0 : void server_maybe_append_tags(Server *s) {
2208 : : #if HAVE_GCRYPT
2209 : : JournalFile *f;
2210 : : Iterator i;
2211 : : usec_t n;
2212 : :
2213 : 0 : n = now(CLOCK_REALTIME);
2214 : :
2215 [ # # ]: 0 : if (s->system_journal)
2216 : 0 : journal_file_maybe_append_tag(s->system_journal, n);
2217 : :
2218 [ # # ]: 0 : ORDERED_HASHMAP_FOREACH(f, s->user_journals, i)
2219 : 0 : journal_file_maybe_append_tag(f, n);
2220 : : #endif
2221 : 0 : }
2222 : :
2223 : 0 : void server_done(Server *s) {
2224 [ # # ]: 0 : assert(s);
2225 : :
2226 [ # # ]: 0 : set_free_with_destructor(s->deferred_closes, journal_file_close);
2227 : :
2228 [ # # ]: 0 : while (s->stdout_streams)
2229 : 0 : stdout_stream_free(s->stdout_streams);
2230 : :
2231 : 0 : client_context_flush_all(s);
2232 : :
2233 : 0 : (void) journal_file_close(s->system_journal);
2234 : 0 : (void) journal_file_close(s->runtime_journal);
2235 : :
2236 [ # # ]: 0 : ordered_hashmap_free_with_destructor(s->user_journals, journal_file_close);
2237 : :
2238 : 0 : varlink_server_unref(s->varlink_server);
2239 : :
2240 : 0 : sd_event_source_unref(s->syslog_event_source);
2241 : 0 : sd_event_source_unref(s->native_event_source);
2242 : 0 : sd_event_source_unref(s->stdout_event_source);
2243 : 0 : sd_event_source_unref(s->dev_kmsg_event_source);
2244 : 0 : sd_event_source_unref(s->audit_event_source);
2245 : 0 : sd_event_source_unref(s->sync_event_source);
2246 : 0 : sd_event_source_unref(s->sigusr1_event_source);
2247 : 0 : sd_event_source_unref(s->sigusr2_event_source);
2248 : 0 : sd_event_source_unref(s->sigterm_event_source);
2249 : 0 : sd_event_source_unref(s->sigint_event_source);
2250 : 0 : sd_event_source_unref(s->sigrtmin1_event_source);
2251 : 0 : sd_event_source_unref(s->hostname_event_source);
2252 : 0 : sd_event_source_unref(s->notify_event_source);
2253 : 0 : sd_event_source_unref(s->watchdog_event_source);
2254 : 0 : sd_event_unref(s->event);
2255 : :
2256 : 0 : safe_close(s->syslog_fd);
2257 : 0 : safe_close(s->native_fd);
2258 : 0 : safe_close(s->stdout_fd);
2259 : 0 : safe_close(s->dev_kmsg_fd);
2260 : 0 : safe_close(s->audit_fd);
2261 : 0 : safe_close(s->hostname_fd);
2262 : 0 : safe_close(s->notify_fd);
2263 : :
2264 [ # # ]: 0 : if (s->rate_limit)
2265 : 0 : journal_rate_limit_free(s->rate_limit);
2266 : :
2267 [ # # ]: 0 : if (s->kernel_seqnum)
2268 : 0 : munmap(s->kernel_seqnum, sizeof(uint64_t));
2269 : :
2270 : 0 : free(s->buffer);
2271 : 0 : free(s->tty_path);
2272 : 0 : free(s->cgroup_root);
2273 : 0 : free(s->hostname_field);
2274 : 0 : free(s->runtime_storage.path);
2275 : 0 : free(s->system_storage.path);
2276 : :
2277 : 0 : mmap_cache_unref(s->mmap);
2278 : 0 : }
2279 : :
2280 : : static const char* const storage_table[_STORAGE_MAX] = {
2281 : : [STORAGE_AUTO] = "auto",
2282 : : [STORAGE_VOLATILE] = "volatile",
2283 : : [STORAGE_PERSISTENT] = "persistent",
2284 : : [STORAGE_NONE] = "none"
2285 : : };
2286 : :
2287 [ + + + + ]: 48 : DEFINE_STRING_TABLE_LOOKUP(storage, Storage);
2288 [ # # # # : 0 : DEFINE_CONFIG_PARSE_ENUM(config_parse_storage, storage, Storage, "Failed to parse storage setting");
# # # # #
# # # ]
2289 : :
2290 : : static const char* const split_mode_table[_SPLIT_MAX] = {
2291 : : [SPLIT_LOGIN] = "login",
2292 : : [SPLIT_UID] = "uid",
2293 : : [SPLIT_NONE] = "none",
2294 : : };
2295 : :
2296 [ + + + + ]: 40 : DEFINE_STRING_TABLE_LOOKUP(split_mode, SplitMode);
2297 [ # # # # : 0 : DEFINE_CONFIG_PARSE_ENUM(config_parse_split_mode, split_mode, SplitMode, "Failed to parse split mode setting");
# # # # #
# # # ]
2298 : :
2299 : 0 : int config_parse_line_max(
2300 : : const char* unit,
2301 : : const char *filename,
2302 : : unsigned line,
2303 : : const char *section,
2304 : : unsigned section_line,
2305 : : const char *lvalue,
2306 : : int ltype,
2307 : : const char *rvalue,
2308 : : void *data,
2309 : : void *userdata) {
2310 : :
2311 : 0 : size_t *sz = data;
2312 : : int r;
2313 : :
2314 [ # # ]: 0 : assert(filename);
2315 [ # # ]: 0 : assert(lvalue);
2316 [ # # ]: 0 : assert(rvalue);
2317 [ # # ]: 0 : assert(data);
2318 : :
2319 [ # # ]: 0 : if (isempty(rvalue))
2320 : : /* Empty assignment means default */
2321 : 0 : *sz = DEFAULT_LINE_MAX;
2322 : : else {
2323 : : uint64_t v;
2324 : :
2325 : 0 : r = parse_size(rvalue, 1024, &v);
2326 [ # # ]: 0 : if (r < 0) {
2327 [ # # ]: 0 : log_syntax(unit, LOG_ERR, filename, line, r, "Failed to parse LineMax= value, ignoring: %s", rvalue);
2328 : 0 : return 0;
2329 : : }
2330 : :
2331 [ # # ]: 0 : if (v < 79) {
2332 : : /* Why specify 79 here as minimum line length? Simply, because the most common traditional
2333 : : * terminal size is 80ch, and it might make sense to break one character before the natural
2334 : : * line break would occur on that. */
2335 [ # # ]: 0 : log_syntax(unit, LOG_WARNING, filename, line, 0, "LineMax= too small, clamping to 79: %s", rvalue);
2336 : 0 : *sz = 79;
2337 [ # # ]: 0 : } else if (v > (uint64_t) (SSIZE_MAX-1)) {
2338 : : /* So, why specify SSIZE_MAX-1 here? Because that's one below the largest size value read()
2339 : : * can return, and we need one extra byte for the trailing NUL byte. Of course IRL such large
2340 : : * memory allocations will fail anyway, hence this limit is mostly theoretical anyway, as we'll
2341 : : * fail much earlier anyway. */
2342 [ # # ]: 0 : log_syntax(unit, LOG_WARNING, filename, line, 0, "LineMax= too large, clamping to %" PRIu64 ": %s", (uint64_t) (SSIZE_MAX-1), rvalue);
2343 : 0 : *sz = SSIZE_MAX-1;
2344 : : } else
2345 : 0 : *sz = (size_t) v;
2346 : : }
2347 : :
2348 : 0 : return 0;
2349 : : }
2350 : :
2351 : 76 : int config_parse_compress(
2352 : : const char* unit,
2353 : : const char *filename,
2354 : : unsigned line,
2355 : : const char *section,
2356 : : unsigned section_line,
2357 : : const char *lvalue,
2358 : : int ltype,
2359 : : const char *rvalue,
2360 : : void *data,
2361 : : void *userdata) {
2362 : :
2363 : 76 : JournalCompressOptions* compress = data;
2364 : : int r;
2365 : :
2366 [ + + ]: 76 : if (isempty(rvalue)) {
2367 : 4 : compress->enabled = true;
2368 : 4 : compress->threshold_bytes = (uint64_t) -1;
2369 [ + + ]: 72 : } else if (streq(rvalue, "1")) {
2370 [ + - ]: 4 : log_syntax(unit, LOG_WARNING, filename, line, 0,
2371 : : "Compress= ambiguously specified as 1, enabling compression with default threshold");
2372 : 4 : compress->enabled = true;
2373 [ + + ]: 68 : } else if (streq(rvalue, "0")) {
2374 [ + - ]: 4 : log_syntax(unit, LOG_WARNING, filename, line, 0,
2375 : : "Compress= ambiguously specified as 0, disabling compression");
2376 : 4 : compress->enabled = false;
2377 : : } else {
2378 : 64 : r = parse_boolean(rvalue);
2379 [ + + ]: 64 : if (r < 0) {
2380 : 24 : r = parse_size(rvalue, 1024, &compress->threshold_bytes);
2381 [ + + ]: 24 : if (r < 0)
2382 [ + - ]: 8 : log_syntax(unit, LOG_ERR, filename, line, r,
2383 : : "Failed to parse Compress= value, ignoring: %s", rvalue);
2384 : : else
2385 : 16 : compress->enabled = true;
2386 : : } else
2387 : 40 : compress->enabled = r;
2388 : : }
2389 : :
2390 : 76 : return 0;
2391 : : }
|