1 /* SPDX-License-Identifier: LGPL-2.1-or-later */
4 #include <selinux/selinux.h>
8 #include <sys/signalfd.h>
9 #include <sys/statvfs.h>
10 #include <linux/sockios.h>
12 #include "sd-daemon.h"
13 #include "sd-journal.h"
14 #include "sd-messages.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"
25 #include "format-util.h"
28 #include "hostname-util.h"
29 #include "id128-util.h"
30 #include "initrd-util.h"
31 #include "iovec-util.h"
32 #include "journal-authenticate.h"
33 #include "journal-file-util.h"
34 #include "journal-internal.h"
35 #include "journal-vacuum.h"
36 #include "journald-audit.h"
37 #include "journald-context.h"
38 #include "journald-kmsg.h"
39 #include "journald-native.h"
40 #include "journald-rate-limit.h"
41 #include "journald-server.h"
42 #include "journald-stream.h"
43 #include "journald-syslog.h"
45 #include "missing_audit.h"
47 #include "parse-util.h"
48 #include "path-util.h"
49 #include "proc-cmdline.h"
50 #include "process-util.h"
52 #include "selinux-util.h"
53 #include "signal-util.h"
54 #include "socket-util.h"
55 #include "stdio-util.h"
56 #include "string-table.h"
57 #include "string-util.h"
58 #include "syslog-util.h"
59 #include "uid-alloc-range.h"
60 #include "user-util.h"
61 #include "varlink-io.systemd.Journal.h"
63 #define USER_JOURNALS_MAX 1024
65 #define DEFAULT_SYNC_INTERVAL_USEC (5*USEC_PER_MINUTE)
66 #define DEFAULT_RATE_LIMIT_INTERVAL (30*USEC_PER_SEC)
67 #define DEFAULT_RATE_LIMIT_BURST 10000
68 #define DEFAULT_MAX_FILE_USEC USEC_PER_MONTH
70 #define DEFAULT_KMSG_OWN_INTERVAL (5 * USEC_PER_SEC)
71 #define DEFAULT_KMSG_OWN_BURST 50
73 #define RECHECK_SPACE_USEC (30*USEC_PER_SEC)
75 #define NOTIFY_SNDBUF_SIZE (8*1024*1024)
77 /* The period to insert between posting changes for coalescing */
78 #define POST_CHANGE_TIMER_INTERVAL_USEC (250*USEC_PER_MSEC)
80 /* Pick a good default that is likely to fit into AF_UNIX and AF_INET SOCK_DGRAM datagrams, and even leaves some room
81 * for a bit of additional metadata. */
82 #define DEFAULT_LINE_MAX (48*1024)
84 #define DEFERRED_CLOSES_MAX (4096)
86 #define IDLE_TIMEOUT_USEC (30*USEC_PER_SEC)
88 #define FAILED_TO_WRITE_ENTRY_RATELIMIT ((const RateLimit) { .interval = 1 * USEC_PER_SEC, .burst = 1 })
90 static int server_determine_path_usage(
96 _cleanup_closedir_
DIR *d
= NULL
;
106 return log_ratelimit_full_errno(errno
== ENOENT
? LOG_DEBUG
: LOG_ERR
,
107 errno
, JOURNAL_LOG_RATELIMIT
, "Failed to open %s: %m", path
);
109 if (fstatvfs(dirfd(d
), &ss
) < 0)
110 return log_ratelimit_error_errno(errno
, JOURNAL_LOG_RATELIMIT
,
111 "Failed to fstatvfs(%s): %m", path
);
113 *ret_free
= ss
.f_bsize
* ss
.f_bavail
;
115 FOREACH_DIRENT_ALL(de
, d
, break) {
118 if (!endswith(de
->d_name
, ".journal") &&
119 !endswith(de
->d_name
, ".journal~"))
122 if (fstatat(dirfd(d
), de
->d_name
, &st
, AT_SYMLINK_NOFOLLOW
) < 0) {
123 log_debug_errno(errno
, "Failed to stat %s/%s, ignoring: %m", path
, de
->d_name
);
127 if (!S_ISREG(st
.st_mode
))
130 *ret_used
+= (uint64_t) st
.st_blocks
* 512UL;
136 static void cache_space_invalidate(JournalStorageSpace
*space
) {
140 static int cache_space_refresh(Server
*s
, JournalStorage
*storage
) {
141 JournalStorageSpace
*space
;
142 JournalMetrics
*metrics
;
143 uint64_t vfs_used
, vfs_avail
, avail
;
149 metrics
= &storage
->metrics
;
150 space
= &storage
->space
;
152 ts
= now(CLOCK_MONOTONIC
);
154 if (space
->timestamp
!= 0 && usec_add(space
->timestamp
, RECHECK_SPACE_USEC
) > ts
)
157 r
= server_determine_path_usage(s
, storage
->path
, &vfs_used
, &vfs_avail
);
161 space
->vfs_used
= vfs_used
;
162 space
->vfs_available
= vfs_avail
;
164 avail
= LESS_BY(vfs_avail
, metrics
->keep_free
);
166 space
->limit
= CLAMP(vfs_used
+ avail
, metrics
->min_use
, metrics
->max_use
);
167 space
->available
= LESS_BY(space
->limit
, vfs_used
);
168 space
->timestamp
= ts
;
172 static void patch_min_use(JournalStorage
*storage
) {
175 /* Let's bump the min_use limit to the current usage on disk. We do
176 * this when starting up and first opening the journal files. This way
177 * sudden spikes in disk usage will not cause journald to vacuum files
178 * without bounds. Note that this means that only a restart of journald
179 * will make it reset this value. */
181 storage
->metrics
.min_use
= MAX(storage
->metrics
.min_use
, storage
->space
.vfs_used
);
184 static JournalStorage
* server_current_storage(Server
*s
) {
187 return s
->system_journal
? &s
->system_storage
: &s
->runtime_storage
;
190 static int server_determine_space(Server
*s
, uint64_t *available
, uint64_t *limit
) {
196 js
= server_current_storage(s
);
198 r
= cache_space_refresh(s
, js
);
201 *available
= js
->space
.available
;
203 *limit
= js
->space
.limit
;
208 void server_space_usage_message(Server
*s
, JournalStorage
*storage
) {
212 storage
= server_current_storage(s
);
214 if (cache_space_refresh(s
, storage
) < 0)
217 const JournalMetrics
*metrics
= &storage
->metrics
;
219 server_driver_message(s
, 0,
220 "MESSAGE_ID=" SD_MESSAGE_JOURNAL_USAGE_STR
,
221 LOG_MESSAGE("%s (%s) is %s, max %s, %s free.",
222 storage
->name
, storage
->path
,
223 FORMAT_BYTES(storage
->space
.vfs_used
),
224 FORMAT_BYTES(storage
->space
.limit
),
225 FORMAT_BYTES(storage
->space
.available
)),
226 "JOURNAL_NAME=%s", storage
->name
,
227 "JOURNAL_PATH=%s", storage
->path
,
228 "CURRENT_USE=%"PRIu64
, storage
->space
.vfs_used
,
229 "CURRENT_USE_PRETTY=%s", FORMAT_BYTES(storage
->space
.vfs_used
),
230 "MAX_USE=%"PRIu64
, metrics
->max_use
,
231 "MAX_USE_PRETTY=%s", FORMAT_BYTES(metrics
->max_use
),
232 "DISK_KEEP_FREE=%"PRIu64
, metrics
->keep_free
,
233 "DISK_KEEP_FREE_PRETTY=%s", FORMAT_BYTES(metrics
->keep_free
),
234 "DISK_AVAILABLE=%"PRIu64
, storage
->space
.vfs_available
,
235 "DISK_AVAILABLE_PRETTY=%s", FORMAT_BYTES(storage
->space
.vfs_available
),
236 "LIMIT=%"PRIu64
, storage
->space
.limit
,
237 "LIMIT_PRETTY=%s", FORMAT_BYTES(storage
->space
.limit
),
238 "AVAILABLE=%"PRIu64
, storage
->space
.available
,
239 "AVAILABLE_PRETTY=%s", FORMAT_BYTES(storage
->space
.available
),
243 static void server_add_acls(JournalFile
*f
, uid_t uid
) {
249 if (uid_for_system_journal(uid
))
252 r
= fd_add_uid_acl_permission(f
->fd
, uid
, ACL_READ
);
254 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
255 "Failed to set ACL on %s, ignoring: %m", f
->path
);
259 static int server_open_journal(
265 JournalMetrics
*metrics
,
268 _cleanup_(journal_file_offline_closep
) JournalFile
*f
= NULL
;
269 JournalFileFlags file_flags
;
277 (s
->compress
.enabled
? JOURNAL_COMPRESS
: 0) |
278 (seal
? JOURNAL_SEAL
: 0) |
279 JOURNAL_STRICT_ORDER
;
281 set_clear_with_destructor(s
->deferred_closes
, journal_file_offline_close
);
284 r
= journal_file_open_reliably(
289 s
->compress
.threshold_bytes
,
292 /* template= */ NULL
,
295 r
= journal_file_open(
301 s
->compress
.threshold_bytes
,
304 /* template= */ NULL
,
309 r
= journal_file_enable_post_change_timer(f
, s
->event
, POST_CHANGE_TIMER_INTERVAL_USEC
);
317 static bool server_flushed_flag_is_set(Server
*s
) {
322 /* We don't support the "flushing" concept for namespace instances, we assume them to always have
327 fn
= strjoina(s
->runtime_directory
, "/flushed");
328 return access(fn
, F_OK
) >= 0;
331 static int server_system_journal_open(
333 bool flush_requested
,
334 bool relinquish_requested
) {
339 if (!s
->system_journal
&&
340 IN_SET(s
->storage
, STORAGE_PERSISTENT
, STORAGE_AUTO
) &&
341 (flush_requested
|| server_flushed_flag_is_set(s
)) &&
342 !relinquish_requested
) {
344 /* If in auto mode: first try to create the machine path, but not the prefix.
346 * If in persistent mode: create /var/log/journal and the machine path */
348 if (s
->storage
== STORAGE_PERSISTENT
)
349 (void) mkdir_parents(s
->system_storage
.path
, 0755);
351 (void) mkdir(s
->system_storage
.path
, 0755);
353 fn
= strjoina(s
->system_storage
.path
, "/system.journal");
354 r
= server_open_journal(
356 /* reliably= */ true,
360 &s
->system_storage
.metrics
,
363 server_add_acls(s
->system_journal
, 0);
364 (void) cache_space_refresh(s
, &s
->system_storage
);
365 patch_min_use(&s
->system_storage
);
367 if (!IN_SET(r
, -ENOENT
, -EROFS
))
368 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
369 "Failed to open system journal: %m");
374 /* If the runtime journal is open, and we're post-flush, we're recovering from a failed
375 * system journal rotate (ENOSPC) for which the runtime journal was reopened.
377 * Perform an implicit flush to var, leaving the runtime journal closed, now that the system
380 if (!flush_requested
)
381 (void) server_flush_to_var(s
, true);
384 if (!s
->runtime_journal
&&
385 (s
->storage
!= STORAGE_NONE
)) {
387 fn
= strjoina(s
->runtime_storage
.path
, "/system.journal");
389 if (!s
->system_journal
|| relinquish_requested
) {
391 /* OK, we really need the runtime journal, so create it if necessary. */
393 (void) mkdir_parents(s
->runtime_storage
.path
, 0755);
394 (void) mkdir(s
->runtime_storage
.path
, 0750);
396 r
= server_open_journal(
398 /* reliably= */ true,
402 &s
->runtime_storage
.metrics
,
403 &s
->runtime_journal
);
405 return log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
406 "Failed to open runtime journal: %m");
408 } else if (!server_flushed_flag_is_set(s
)) {
409 /* Try to open the runtime journal, but only if it already exists, so that we can
410 * flush it into the system journal */
412 r
= server_open_journal(
414 /* reliably= */ false,
418 &s
->runtime_storage
.metrics
,
419 &s
->runtime_journal
);
422 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
423 "Failed to open runtime journal: %m");
429 if (s
->runtime_journal
) {
430 server_add_acls(s
->runtime_journal
, 0);
431 (void) cache_space_refresh(s
, &s
->runtime_storage
);
432 patch_min_use(&s
->runtime_storage
);
439 static int server_find_user_journal(Server
*s
, uid_t uid
, JournalFile
**ret
) {
440 _cleanup_(journal_file_offline_closep
) JournalFile
*f
= NULL
;
441 _cleanup_free_
char *p
= NULL
;
444 assert(!uid_for_system_journal(uid
));
446 f
= ordered_hashmap_get(s
->user_journals
, UID_TO_PTR(uid
));
450 if (asprintf(&p
, "%s/user-" UID_FMT
".journal", s
->system_storage
.path
, uid
) < 0)
453 /* Too many open? Then let's close one (or more) */
454 while (ordered_hashmap_size(s
->user_journals
) >= USER_JOURNALS_MAX
) {
457 assert_se(first
= ordered_hashmap_steal_first(s
->user_journals
));
458 (void) journal_file_offline_close(first
);
461 r
= server_open_journal(
463 /* reliably= */ true,
467 &s
->system_storage
.metrics
,
472 r
= ordered_hashmap_put(s
->user_journals
, UID_TO_PTR(uid
), f
);
476 server_add_acls(f
, uid
);
483 static JournalFile
* server_find_journal(Server
*s
, uid_t uid
) {
488 /* A rotate that fails to create the new journal (ENOSPC) leaves the rotated journal as NULL. Unless
489 * we revisit opening, even after space is made available we'll continue to return NULL indefinitely.
491 * system_journal_open() is a noop if the journals are already open, so we can just call it here to
492 * recover from failed rotates (or anything else that's left the journals as NULL).
494 * Fixes https://github.com/systemd/systemd/issues/3968 */
495 (void) server_system_journal_open(s
, /* flush_requested= */ false, /* relinquish_requested= */ false);
497 /* We split up user logs only on /var, not on /run. If the runtime file is open, we write to it
498 * exclusively, in order to guarantee proper order as soon as we flush /run to /var and close the
501 if (s
->runtime_journal
)
502 return s
->runtime_journal
;
504 /* If we are not in persistent mode, then we need return NULL immediately rather than opening a
505 * persistent journal of any sort.
507 * Fixes https://github.com/systemd/systemd/issues/20390 */
508 if (!IN_SET(s
->storage
, STORAGE_AUTO
, STORAGE_PERSISTENT
))
511 if (!uid_for_system_journal(uid
)) {
512 JournalFile
*f
= NULL
;
514 r
= server_find_user_journal(s
, uid
, &f
);
516 return ASSERT_PTR(f
);
518 log_warning_errno(r
, "Failed to open user journal file, falling back to system journal: %m");
521 return s
->system_journal
;
524 static int server_do_rotate(
531 JournalFileFlags file_flags
;
540 (s
->compress
.enabled
? JOURNAL_COMPRESS
: 0)|
541 (seal
? JOURNAL_SEAL
: 0) |
542 JOURNAL_STRICT_ORDER
;
544 r
= journal_file_rotate(f
, s
->mmap
, file_flags
, s
->compress
.threshold_bytes
, s
->deferred_closes
);
547 return log_ratelimit_error_errno(r
, JOURNAL_LOG_RATELIMIT
,
548 "Failed to rotate %s: %m", (*f
)->path
);
550 return log_ratelimit_error_errno(r
, JOURNAL_LOG_RATELIMIT
,
551 "Failed to create new %s journal: %m", name
);
554 server_add_acls(*f
, uid
);
558 static void server_process_deferred_closes(Server
*s
) {
561 /* Perform any deferred closes which aren't still offlining. */
562 SET_FOREACH(f
, s
->deferred_closes
) {
563 if (journal_file_is_offlining(f
))
566 (void) set_remove(s
->deferred_closes
, f
);
567 (void) journal_file_offline_close(f
);
571 static void server_vacuum_deferred_closes(Server
*s
) {
574 /* Make some room in the deferred closes list, so that it doesn't grow without bounds */
575 if (set_size(s
->deferred_closes
) < DEFERRED_CLOSES_MAX
)
578 /* Let's first remove all journal files that might already have completed closing */
579 server_process_deferred_closes(s
);
581 /* And now, let's close some more until we reach the limit again. */
582 while (set_size(s
->deferred_closes
) >= DEFERRED_CLOSES_MAX
) {
585 assert_se(f
= set_steal_first(s
->deferred_closes
));
586 journal_file_offline_close(f
);
590 static int server_archive_offline_user_journals(Server
*s
) {
591 _cleanup_closedir_
DIR *d
= NULL
;
596 d
= opendir(s
->system_storage
.path
);
601 return log_ratelimit_error_errno(errno
, JOURNAL_LOG_RATELIMIT
,
602 "Failed to open %s: %m", s
->system_storage
.path
);
606 _cleanup_free_
char *full
= NULL
;
607 _cleanup_close_
int fd
= -EBADF
;
613 de
= readdir_no_dot(d
);
616 log_ratelimit_warning_errno(errno
, JOURNAL_LOG_RATELIMIT
,
617 "Failed to enumerate %s, ignoring: %m",
618 s
->system_storage
.path
);
622 r
= journal_file_parse_uid_from_filename(de
->d_name
, &uid
);
624 /* Don't warn if the file is not an online or offline user journal. */
626 log_warning_errno(r
, "Failed to parse UID from file name '%s', ignoring: %m", de
->d_name
);
630 /* Already rotated in the above loop? i.e. is it an open user journal? */
631 if (ordered_hashmap_contains(s
->user_journals
, UID_TO_PTR(uid
)))
634 full
= path_join(s
->system_storage
.path
, de
->d_name
);
638 fd
= openat(dirfd(d
), de
->d_name
, O_RDWR
|O_CLOEXEC
|O_NOCTTY
|O_NOFOLLOW
|O_NONBLOCK
);
640 log_ratelimit_full_errno(IN_SET(errno
, ELOOP
, ENOENT
) ? LOG_DEBUG
: LOG_WARNING
,
641 errno
, JOURNAL_LOG_RATELIMIT
,
642 "Failed to open journal file '%s' for rotation: %m", full
);
646 /* Make some room in the set of deferred close()s */
647 server_vacuum_deferred_closes(s
);
649 /* Open the file briefly, so that we can archive it */
650 r
= journal_file_open(
654 (s
->compress
.enabled
? JOURNAL_COMPRESS
: 0) |
655 (s
->seal
? JOURNAL_SEAL
: 0), /* strict order does not matter here */
657 s
->compress
.threshold_bytes
,
658 &s
->system_storage
.metrics
,
660 /* template= */ NULL
,
663 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
664 "Failed to read journal file %s for rotation, trying to move it out of the way: %m",
667 r
= journal_file_dispose(dirfd(d
), de
->d_name
);
669 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
670 "Failed to move %s out of the way, ignoring: %m",
673 log_debug("Successfully moved %s out of the way.", full
);
678 TAKE_FD(fd
); /* Donated to journal_file_open() */
680 journal_file_write_final_tag(f
);
681 r
= journal_file_archive(f
, NULL
);
683 log_debug_errno(r
, "Failed to archive journal file '%s', ignoring: %m", full
);
685 journal_file_initiate_close(TAKE_PTR(f
), s
->deferred_closes
);
691 void server_rotate(Server
*s
) {
696 log_debug("Rotating...");
698 /* First, rotate the system journal (either in its runtime flavour or in its runtime flavour) */
699 (void) server_do_rotate(s
, &s
->runtime_journal
, "runtime", /* seal= */ false, /* uid= */ 0);
700 (void) server_do_rotate(s
, &s
->system_journal
, "system", s
->seal
, /* uid= */ 0);
702 /* Then, rotate all user journals we have open (keeping them open) */
703 ORDERED_HASHMAP_FOREACH_KEY(f
, k
, s
->user_journals
) {
704 r
= server_do_rotate(s
, &f
, "user", s
->seal
, PTR_TO_UID(k
));
706 ordered_hashmap_replace(s
->user_journals
, k
, f
);
708 /* Old file has been closed and deallocated */
709 ordered_hashmap_remove(s
->user_journals
, k
);
712 /* Finally, also rotate all user journals we currently do not have open. (But do so only if we
713 * actually have access to /var, i.e. are not in the log-to-runtime-journal mode). */
714 if (!s
->runtime_journal
)
715 (void) server_archive_offline_user_journals(s
);
717 server_process_deferred_closes(s
);
720 void server_sync(Server
*s
) {
724 if (s
->system_journal
) {
725 r
= journal_file_set_offline(s
->system_journal
, false);
727 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
728 "Failed to sync system journal, ignoring: %m");
731 ORDERED_HASHMAP_FOREACH(f
, s
->user_journals
) {
732 r
= journal_file_set_offline(f
, false);
734 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
735 "Failed to sync user journal, ignoring: %m");
738 if (s
->sync_event_source
) {
739 r
= sd_event_source_set_enabled(s
->sync_event_source
, SD_EVENT_OFF
);
741 log_ratelimit_error_errno(r
, JOURNAL_LOG_RATELIMIT
,
742 "Failed to disable sync timer source: %m");
745 s
->sync_scheduled
= false;
748 static void server_do_vacuum(Server
*s
, JournalStorage
*storage
, bool verbose
) {
755 (void) cache_space_refresh(s
, storage
);
758 server_space_usage_message(s
, storage
);
760 r
= journal_directory_vacuum(storage
->path
, storage
->space
.limit
,
761 storage
->metrics
.n_max_files
, s
->max_retention_usec
,
762 &s
->oldest_file_usec
, verbose
);
763 if (r
< 0 && r
!= -ENOENT
)
764 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
765 "Failed to vacuum %s, ignoring: %m", storage
->path
);
767 cache_space_invalidate(&storage
->space
);
770 void server_vacuum(Server
*s
, bool verbose
) {
773 log_debug("Vacuuming...");
775 s
->oldest_file_usec
= 0;
777 if (s
->system_journal
)
778 server_do_vacuum(s
, &s
->system_storage
, verbose
);
779 if (s
->runtime_journal
)
780 server_do_vacuum(s
, &s
->runtime_storage
, verbose
);
783 static void server_cache_machine_id(Server
*s
) {
789 r
= sd_id128_get_machine(&id
);
793 sd_id128_to_string(id
, stpcpy(s
->machine_id_field
, "_MACHINE_ID="));
796 static void server_cache_boot_id(Server
*s
) {
802 r
= sd_id128_get_boot(&id
);
806 sd_id128_to_string(id
, stpcpy(s
->boot_id_field
, "_BOOT_ID="));
809 static void server_cache_hostname(Server
*s
) {
810 _cleanup_free_
char *t
= NULL
;
815 t
= gethostname_malloc();
819 x
= strjoin("_HOSTNAME=", t
);
823 free_and_replace(s
->hostname_field
, x
);
826 static bool shall_try_append_again(JournalFile
*f
, int r
) {
829 case -E2BIG
: /* Hit configured limit */
830 case -EFBIG
: /* Hit fs limit */
831 case -EDQUOT
: /* Quota limit hit */
832 case -ENOSPC
: /* Disk full */
833 log_debug_errno(r
, "%s: Allocation limit reached, rotating.", f
->path
);
836 case -EROFS
: /* Read-only file system */
837 /* When appending an entry fails if shall_try_append_again returns true, the journal is
838 * rotated. If the FS is read-only, rotation will fail and s->system_journal will be set to
839 * NULL. After that, when find_journal will try to open the journal since s->system_journal
840 * will be NULL, it will open the runtime journal. */
841 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Read-only file system, rotating.", f
->path
);
844 case -EIO
: /* I/O error of some kind (mmap) */
845 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: IO error, rotating.", f
->path
);
848 case -EHOSTDOWN
: /* Other machine */
849 log_ratelimit_info_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Journal file from other machine, rotating.", f
->path
);
852 case -EBUSY
: /* Unclean shutdown */
853 log_ratelimit_info_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Unclean shutdown, rotating.", f
->path
);
856 case -EPROTONOSUPPORT
: /* Unsupported feature */
857 log_ratelimit_info_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Unsupported feature, rotating.", f
->path
);
860 case -EBADMSG
: /* Corrupted */
861 case -ENODATA
: /* Truncated */
862 case -ESHUTDOWN
: /* Already archived */
863 case -EADDRNOTAVAIL
: /* Referenced object offset out of bounds */
864 log_ratelimit_info_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Journal file corrupted, rotating.", f
->path
);
867 case -EIDRM
: /* Journal file has been deleted */
868 log_ratelimit_info_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Journal file has been deleted, rotating.", f
->path
);
871 case -EREMCHG
: /* Wallclock time (CLOCK_REALTIME) jumped backwards relative to last journal entry */
872 log_ratelimit_info_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Realtime clock jumped backwards relative to last journal entry, rotating.", f
->path
);
875 case -ENOTNAM
: /* Monotonic time (CLOCK_MONOTONIC) jumped backwards relative to last journal entry with the same boot ID */
876 log_ratelimit_info_errno(
878 JOURNAL_LOG_RATELIMIT
,
879 "%s: Monotonic clock jumped backwards relative to last journal entry with the same boot ID, rotating.",
883 case -EILSEQ
: /* seqnum ID last used in the file doesn't match the one we'd passed when writing an entry to it */
884 log_ratelimit_info_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Journal file uses a different sequence number ID, rotating.", f
->path
);
888 log_ratelimit_error_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Underlying file system does not support memory mapping or another required file system feature.", f
->path
);
892 log_ratelimit_error_errno(r
, JOURNAL_LOG_RATELIMIT
, "%s: Unexpected error while writing to journal file: %m", f
->path
);
897 static void server_write_to_journal(
900 const struct iovec
*iovec
,
904 bool vacuumed
= false, rotate
= false;
905 struct dual_timestamp ts
;
913 /* Get the closest, linearized time we have for this log event from the event loop. (Note that we do not use
914 * the source time, and not even the time the event was originally seen, but instead simply the time we started
915 * processing it, as we want strictly linear ordering in what we write out.) */
916 assert_se(sd_event_now(s
->event
, CLOCK_REALTIME
, &ts
.realtime
) >= 0);
917 assert_se(sd_event_now(s
->event
, CLOCK_MONOTONIC
, &ts
.monotonic
) >= 0);
919 if (ts
.realtime
< s
->last_realtime_clock
) {
920 /* When the time jumps backwards, let's immediately rotate. Of course, this should not happen during
921 * regular operation. However, when it does happen, then we should make sure that we start fresh files
922 * to ensure that the entries in the journal files are strictly ordered by time, in order to ensure
923 * bisection works correctly. */
925 log_ratelimit_info(JOURNAL_LOG_RATELIMIT
, "Time jumped backwards, rotating.");
929 f
= server_find_journal(s
, uid
);
933 if (journal_file_rotate_suggested(f
, s
->max_file_usec
, LOG_DEBUG
)) {
934 log_debug("%s: Journal header limits reached or header out-of-date, rotating.",
942 server_vacuum(s
, false);
945 f
= server_find_journal(s
, uid
);
950 s
->last_realtime_clock
= ts
.realtime
;
952 r
= journal_file_append_entry(
959 /* ret_object= */ NULL
,
960 /* ret_offset= */ NULL
);
962 server_schedule_sync(s
, priority
);
966 log_debug_errno(r
, "Failed to write entry to %s (%zu items, %zu bytes): %m", f
->path
, n
, iovec_total_size(iovec
, n
));
968 if (!shall_try_append_again(f
, r
))
971 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
972 "Suppressing rotation, as we already rotated immediately before write attempt. Giving up.");
977 server_vacuum(s
, false);
979 f
= server_find_journal(s
, uid
);
983 log_debug_errno(r
, "Retrying write.");
984 r
= journal_file_append_entry(
991 /* ret_object= */ NULL
,
992 /* ret_offset= */ NULL
);
994 log_ratelimit_error_errno(r
, FAILED_TO_WRITE_ENTRY_RATELIMIT
,
995 "Failed to write entry to %s (%zu items, %zu bytes) despite vacuuming, ignoring: %m",
996 f
->path
, n
, iovec_total_size(iovec
, n
));
998 server_schedule_sync(s
, priority
);
1001 #define IOVEC_ADD_NUMERIC_FIELD(iovec, n, value, type, isset, format, field) \
1002 if (isset(value)) { \
1004 k = newa(char, STRLEN(field "=") + DECIMAL_STR_MAX(type) + 1); \
1005 sprintf(k, field "=" format, value); \
1006 iovec[n++] = IOVEC_MAKE_STRING(k); \
1009 #define IOVEC_ADD_STRING_FIELD(iovec, n, value, field) \
1010 if (!isempty(value)) { \
1012 k = strjoina(field "=", value); \
1013 iovec[n++] = IOVEC_MAKE_STRING(k); \
1016 #define IOVEC_ADD_ID128_FIELD(iovec, n, value, field) \
1017 if (!sd_id128_is_null(value)) { \
1019 k = newa(char, STRLEN(field "=") + SD_ID128_STRING_MAX); \
1020 sd_id128_to_string(value, stpcpy(k, field "=")); \
1021 iovec[n++] = IOVEC_MAKE_STRING(k); \
1024 #define IOVEC_ADD_SIZED_FIELD(iovec, n, value, value_size, field) \
1025 if (value_size > 0) { \
1027 k = newa(char, STRLEN(field "=") + value_size + 1); \
1028 *((char*) mempcpy(stpcpy(k, field "="), value, value_size)) = 0; \
1029 iovec[n++] = IOVEC_MAKE_STRING(k); \
1032 static void server_dispatch_message_real(
1034 struct iovec
*iovec
, size_t n
, size_t m
,
1035 const ClientContext
*c
,
1036 const struct timeval
*tv
,
1040 char source_time
[sizeof("_SOURCE_REALTIME_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t
)];
1041 _unused_ _cleanup_free_
char *cmdline1
= NULL
, *cmdline2
= NULL
;
1049 N_IOVEC_META_FIELDS
+
1050 (pid_is_valid(object_pid
) ? N_IOVEC_OBJECT_FIELDS
: 0) +
1051 client_context_extra_fields_n_iovec(c
) <= m
);
1054 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, c
->pid
, pid_t
, pid_is_valid
, PID_FMT
, "_PID");
1055 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, c
->uid
, uid_t
, uid_is_valid
, UID_FMT
, "_UID");
1056 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, c
->gid
, gid_t
, gid_is_valid
, GID_FMT
, "_GID");
1058 IOVEC_ADD_STRING_FIELD(iovec
, n
, c
->comm
, "_COMM"); /* At most TASK_COMM_LENGTH (16 bytes) */
1059 IOVEC_ADD_STRING_FIELD(iovec
, n
, c
->exe
, "_EXE"); /* A path, so at most PATH_MAX (4096 bytes) */
1062 /* At most _SC_ARG_MAX (2MB usually), which is too much to put on stack.
1063 * Let's use a heap allocation for this one. */
1064 cmdline1
= set_iovec_string_field(iovec
, &n
, "_CMDLINE=", c
->cmdline
);
1066 IOVEC_ADD_STRING_FIELD(iovec
, n
, c
->capeff
, "_CAP_EFFECTIVE"); /* Read from /proc/.../status */
1067 IOVEC_ADD_SIZED_FIELD(iovec
, n
, c
->label
, c
->label_size
, "_SELINUX_CONTEXT");
1068 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, c
->auditid
, uint32_t, audit_session_is_valid
, "%" PRIu32
, "_AUDIT_SESSION");
1069 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, c
->loginuid
, uid_t
, uid_is_valid
, UID_FMT
, "_AUDIT_LOGINUID");
1071 IOVEC_ADD_STRING_FIELD(iovec
, n
, c
->cgroup
, "_SYSTEMD_CGROUP"); /* A path */
1072 IOVEC_ADD_STRING_FIELD(iovec
, n
, c
->session
, "_SYSTEMD_SESSION");
1073 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, c
->owner_uid
, uid_t
, uid_is_valid
, UID_FMT
, "_SYSTEMD_OWNER_UID");
1074 IOVEC_ADD_STRING_FIELD(iovec
, n
, c
->unit
, "_SYSTEMD_UNIT"); /* Unit names are bounded by UNIT_NAME_MAX */
1075 IOVEC_ADD_STRING_FIELD(iovec
, n
, c
->user_unit
, "_SYSTEMD_USER_UNIT");
1076 IOVEC_ADD_STRING_FIELD(iovec
, n
, c
->slice
, "_SYSTEMD_SLICE");
1077 IOVEC_ADD_STRING_FIELD(iovec
, n
, c
->user_slice
, "_SYSTEMD_USER_SLICE");
1079 IOVEC_ADD_ID128_FIELD(iovec
, n
, c
->invocation_id
, "_SYSTEMD_INVOCATION_ID");
1081 if (c
->extra_fields_n_iovec
> 0) {
1082 memcpy(iovec
+ n
, c
->extra_fields_iovec
, c
->extra_fields_n_iovec
* sizeof(struct iovec
));
1083 n
+= c
->extra_fields_n_iovec
;
1089 if (pid_is_valid(object_pid
) && client_context_get(s
, object_pid
, NULL
, NULL
, 0, NULL
, &o
) >= 0) {
1091 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, o
->pid
, pid_t
, pid_is_valid
, PID_FMT
, "OBJECT_PID");
1092 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, o
->uid
, uid_t
, uid_is_valid
, UID_FMT
, "OBJECT_UID");
1093 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, o
->gid
, gid_t
, gid_is_valid
, GID_FMT
, "OBJECT_GID");
1095 /* See above for size limits, only ->cmdline may be large, so use a heap allocation for it. */
1096 IOVEC_ADD_STRING_FIELD(iovec
, n
, o
->comm
, "OBJECT_COMM");
1097 IOVEC_ADD_STRING_FIELD(iovec
, n
, o
->exe
, "OBJECT_EXE");
1099 cmdline2
= set_iovec_string_field(iovec
, &n
, "OBJECT_CMDLINE=", o
->cmdline
);
1101 IOVEC_ADD_STRING_FIELD(iovec
, n
, o
->capeff
, "OBJECT_CAP_EFFECTIVE");
1102 IOVEC_ADD_SIZED_FIELD(iovec
, n
, o
->label
, o
->label_size
, "OBJECT_SELINUX_CONTEXT");
1103 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, o
->auditid
, uint32_t, audit_session_is_valid
, "%" PRIu32
, "OBJECT_AUDIT_SESSION");
1104 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, o
->loginuid
, uid_t
, uid_is_valid
, UID_FMT
, "OBJECT_AUDIT_LOGINUID");
1106 IOVEC_ADD_STRING_FIELD(iovec
, n
, o
->cgroup
, "OBJECT_SYSTEMD_CGROUP");
1107 IOVEC_ADD_STRING_FIELD(iovec
, n
, o
->session
, "OBJECT_SYSTEMD_SESSION");
1108 IOVEC_ADD_NUMERIC_FIELD(iovec
, n
, o
->owner_uid
, uid_t
, uid_is_valid
, UID_FMT
, "OBJECT_SYSTEMD_OWNER_UID");
1109 IOVEC_ADD_STRING_FIELD(iovec
, n
, o
->unit
, "OBJECT_SYSTEMD_UNIT");
1110 IOVEC_ADD_STRING_FIELD(iovec
, n
, o
->user_unit
, "OBJECT_SYSTEMD_USER_UNIT");
1111 IOVEC_ADD_STRING_FIELD(iovec
, n
, o
->slice
, "OBJECT_SYSTEMD_SLICE");
1112 IOVEC_ADD_STRING_FIELD(iovec
, n
, o
->user_slice
, "OBJECT_SYSTEMD_USER_SLICE");
1114 IOVEC_ADD_ID128_FIELD(iovec
, n
, o
->invocation_id
, "OBJECT_SYSTEMD_INVOCATION_ID=");
1120 sprintf(source_time
, "_SOURCE_REALTIME_TIMESTAMP=" USEC_FMT
, timeval_load(tv
));
1121 iovec
[n
++] = IOVEC_MAKE_STRING(source_time
);
1124 /* Note that strictly speaking storing the boot id here is
1125 * redundant since the entry includes this in-line
1126 * anyway. However, we need this indexed, too. */
1127 if (!isempty(s
->boot_id_field
))
1128 iovec
[n
++] = IOVEC_MAKE_STRING(s
->boot_id_field
);
1130 if (!isempty(s
->machine_id_field
))
1131 iovec
[n
++] = IOVEC_MAKE_STRING(s
->machine_id_field
);
1133 if (!isempty(s
->hostname_field
))
1134 iovec
[n
++] = IOVEC_MAKE_STRING(s
->hostname_field
);
1136 if (!isempty(s
->namespace_field
))
1137 iovec
[n
++] = IOVEC_MAKE_STRING(s
->namespace_field
);
1139 iovec
[n
++] = in_initrd() ? IOVEC_MAKE_STRING("_RUNTIME_SCOPE=initrd") : IOVEC_MAKE_STRING("_RUNTIME_SCOPE=system");
1142 if (s
->split_mode
== SPLIT_UID
&& c
&& uid_is_valid(c
->uid
))
1143 /* Split up strictly by (non-root) UID */
1144 journal_uid
= c
->uid
;
1145 else if (s
->split_mode
== SPLIT_LOGIN
&& c
&& c
->uid
> 0 && uid_is_valid(c
->owner_uid
))
1146 /* Split up by login UIDs. We do this only if the
1147 * realuid is not root, in order not to accidentally
1148 * leak privileged information to the user that is
1149 * logged by a privileged process that is part of an
1150 * unprivileged session. */
1151 journal_uid
= c
->owner_uid
;
1155 server_write_to_journal(s
, journal_uid
, iovec
, n
, priority
);
1158 void server_driver_message(Server
*s
, pid_t object_pid
, const char *message_id
, const char *format
, ...) {
1160 struct iovec
*iovec
;
1168 m
= N_IOVEC_META_FIELDS
+ 5 + N_IOVEC_PAYLOAD_FIELDS
+ client_context_extra_fields_n_iovec(s
->my_context
) + N_IOVEC_OBJECT_FIELDS
;
1169 iovec
= newa(struct iovec
, m
);
1171 assert_cc(3 == LOG_FAC(LOG_DAEMON
));
1172 iovec
[n
++] = IOVEC_MAKE_STRING("SYSLOG_FACILITY=3");
1173 iovec
[n
++] = IOVEC_MAKE_STRING("SYSLOG_IDENTIFIER=systemd-journald");
1175 iovec
[n
++] = IOVEC_MAKE_STRING("_TRANSPORT=driver");
1176 assert_cc(6 == LOG_INFO
);
1177 iovec
[n
++] = IOVEC_MAKE_STRING("PRIORITY=6");
1180 iovec
[n
++] = IOVEC_MAKE_STRING(message_id
);
1183 va_start(ap
, format
);
1184 r
= log_format_iovec(iovec
, m
, &n
, false, 0, format
, ap
);
1185 /* Error handling below */
1189 server_dispatch_message_real(s
, iovec
, n
, m
, s
->my_context
, /* tv= */ NULL
, LOG_INFO
, object_pid
);
1192 free(iovec
[k
++].iov_base
);
1195 /* We failed to format the message. Emit a warning instead. */
1199 xsprintf(buf
, "MESSAGE=Entry printing failed: %m");
1202 iovec
[n
++] = IOVEC_MAKE_STRING("PRIORITY=4");
1203 iovec
[n
++] = IOVEC_MAKE_STRING(buf
);
1204 server_dispatch_message_real(s
, iovec
, n
, m
, s
->my_context
, /* tv= */ NULL
, LOG_INFO
, object_pid
);
1208 void server_dispatch_message(
1210 struct iovec
*iovec
, size_t n
, size_t m
,
1212 const struct timeval
*tv
,
1216 uint64_t available
= 0;
1220 assert(iovec
|| n
== 0);
1225 if (LOG_PRI(priority
) > s
->max_level_store
)
1228 /* Stop early in case the information will not be stored
1230 if (s
->storage
== STORAGE_NONE
)
1234 (void) server_determine_space(s
, &available
, /* limit= */ NULL
);
1236 rl
= journal_ratelimit_test(s
->ratelimit
, c
->unit
, c
->log_ratelimit_interval
, c
->log_ratelimit_burst
, priority
& LOG_PRIMASK
, available
);
1240 /* Write a suppression message if we suppressed something */
1242 server_driver_message(s
, c
->pid
,
1243 "MESSAGE_ID=" SD_MESSAGE_JOURNAL_DROPPED_STR
,
1244 LOG_MESSAGE("Suppressed %i messages from %s", rl
- 1, c
->unit
),
1245 "N_DROPPED=%i", rl
- 1,
1249 server_dispatch_message_real(s
, iovec
, n
, m
, c
, tv
, priority
, object_pid
);
1252 int server_flush_to_var(Server
*s
, bool require_flag_file
) {
1253 sd_journal
*j
= NULL
;
1261 if (!IN_SET(s
->storage
, STORAGE_AUTO
, STORAGE_PERSISTENT
))
1264 if (s
->namespace) /* Flushing concept does not exist for namespace instances */
1267 if (!s
->runtime_journal
) /* Nothing to flush? */
1270 if (require_flag_file
&& !server_flushed_flag_is_set(s
))
1273 (void) server_system_journal_open(s
, /* flush_requested=*/ true, /* relinquish_requested= */ false);
1275 if (!s
->system_journal
)
1278 log_debug("Flushing to %s...", s
->system_storage
.path
);
1280 start
= now(CLOCK_MONOTONIC
);
1282 r
= sd_journal_open(&j
, SD_JOURNAL_RUNTIME_ONLY
);
1284 return log_ratelimit_error_errno(r
, JOURNAL_LOG_RATELIMIT
,
1285 "Failed to read runtime journal: %m");
1287 sd_journal_set_data_threshold(j
, 0);
1289 SD_JOURNAL_FOREACH(j
) {
1293 f
= j
->current_file
;
1294 assert(f
&& f
->current_offset
> 0);
1298 r
= journal_file_move_to_object(f
, OBJECT_ENTRY
, f
->current_offset
, &o
);
1300 log_ratelimit_error_errno(r
, JOURNAL_LOG_RATELIMIT
, "Can't read entry: %m");
1304 r
= journal_file_copy_entry(
1314 if (!shall_try_append_again(s
->system_journal
, r
)) {
1315 log_ratelimit_error_errno(r
, JOURNAL_LOG_RATELIMIT
, "Can't write entry: %m");
1319 log_ratelimit_info(JOURNAL_LOG_RATELIMIT
, "Rotating system journal.");
1322 server_vacuum(s
, false);
1324 if (!s
->system_journal
) {
1325 log_ratelimit_notice(JOURNAL_LOG_RATELIMIT
,
1326 "Didn't flush runtime journal since rotation of system journal wasn't successful.");
1331 log_debug("Retrying write.");
1332 r
= journal_file_copy_entry(
1340 log_ratelimit_error_errno(r
, JOURNAL_LOG_RATELIMIT
, "Can't write entry: %m");
1348 if (s
->system_journal
)
1349 journal_file_post_change(s
->system_journal
);
1351 s
->runtime_journal
= journal_file_offline_close(s
->runtime_journal
);
1354 (void) rm_rf(s
->runtime_storage
.path
, REMOVE_ROOT
);
1356 sd_journal_close(j
);
1358 server_driver_message(s
, 0, NULL
,
1359 LOG_MESSAGE("Time spent on flushing to %s is %s for %u entries.",
1360 s
->system_storage
.path
,
1361 FORMAT_TIMESPAN(usec_sub_unsigned(now(CLOCK_MONOTONIC
), start
), 0),
1365 fn
= strjoina(s
->runtime_directory
, "/flushed");
1368 log_ratelimit_warning_errno(k
, JOURNAL_LOG_RATELIMIT
,
1369 "Failed to touch %s, ignoring: %m", fn
);
1371 server_refresh_idle_timer(s
);
1375 static int server_relinquish_var(Server
*s
) {
1379 if (s
->storage
== STORAGE_NONE
)
1382 if (s
->namespace) /* Concept does not exist for namespaced instances */
1385 if (s
->runtime_journal
&& !s
->system_journal
)
1388 log_debug("Relinquishing %s...", s
->system_storage
.path
);
1390 (void) server_system_journal_open(s
, /* flush_requested */ false, /* relinquish_requested=*/ true);
1392 s
->system_journal
= journal_file_offline_close(s
->system_journal
);
1393 ordered_hashmap_clear_with_destructor(s
->user_journals
, journal_file_offline_close
);
1394 set_clear_with_destructor(s
->deferred_closes
, journal_file_offline_close
);
1396 fn
= strjoina(s
->runtime_directory
, "/flushed");
1397 if (unlink(fn
) < 0 && errno
!= ENOENT
)
1398 log_ratelimit_warning_errno(errno
, JOURNAL_LOG_RATELIMIT
,
1399 "Failed to unlink %s, ignoring: %m", fn
);
1401 server_refresh_idle_timer(s
);
1405 int server_process_datagram(
1406 sd_event_source
*es
,
1411 size_t label_len
= 0, m
;
1412 Server
*s
= ASSERT_PTR(userdata
);
1413 struct ucred
*ucred
= NULL
;
1414 struct timeval tv_buf
, *tv
= NULL
;
1415 struct cmsghdr
*cmsg
;
1419 int *fds
= NULL
, v
= 0;
1422 /* We use NAME_MAX space for the SELinux label here. The kernel currently enforces no limit, but
1423 * according to suggestions from the SELinux people this will change and it will probably be
1424 * identical to NAME_MAX. For now we use that, but this should be updated one day when the final
1427 * Here, we need to explicitly initialize the buffer with zero, as glibc has a bug in
1428 * __convert_scm_timestamps(), which assumes the buffer is initialized. See #20741. */
1429 CMSG_BUFFER_TYPE(CMSG_SPACE(sizeof(struct ucred
)) +
1430 CMSG_SPACE_TIMEVAL
+
1431 CMSG_SPACE(sizeof(int)) + /* fd */
1432 CMSG_SPACE(NAME_MAX
) /* selinux label */) control
= {};
1434 union sockaddr_union sa
= {};
1436 struct msghdr msghdr
= {
1439 .msg_control
= &control
,
1440 .msg_controllen
= sizeof(control
),
1442 .msg_namelen
= sizeof(sa
),
1445 assert(fd
== s
->native_fd
|| fd
== s
->syslog_fd
|| fd
== s
->audit_fd
);
1447 if (revents
!= EPOLLIN
)
1448 return log_error_errno(SYNTHETIC_ERRNO(EIO
),
1449 "Got invalid event from epoll for datagram fd: %" PRIx32
,
1452 /* Try to get the right size, if we can. (Not all sockets support SIOCINQ, hence we just try, but don't rely on
1454 (void) ioctl(fd
, SIOCINQ
, &v
);
1456 /* Fix it up, if it is too small. We use the same fixed value as auditd here. Awful! */
1457 m
= PAGE_ALIGN(MAX3((size_t) v
+ 1,
1459 ALIGN(sizeof(struct nlmsghdr
)) + ALIGN((size_t) MAX_AUDIT_MESSAGE_LENGTH
)) + 1);
1461 if (!GREEDY_REALLOC(s
->buffer
, m
))
1464 iovec
= IOVEC_MAKE(s
->buffer
, MALLOC_ELEMENTSOF(s
->buffer
) - 1); /* Leave room for trailing NUL we add later */
1466 n
= recvmsg_safe(fd
, &msghdr
, MSG_DONTWAIT
|MSG_CMSG_CLOEXEC
);
1468 if (ERRNO_IS_TRANSIENT(n
))
1471 log_ratelimit_warning(JOURNAL_LOG_RATELIMIT
,
1472 "Got message with truncated control data (too many fds sent?), ignoring.");
1475 return log_ratelimit_error_errno(n
, JOURNAL_LOG_RATELIMIT
, "recvmsg() failed: %m");
1478 CMSG_FOREACH(cmsg
, &msghdr
)
1479 if (cmsg
->cmsg_level
== SOL_SOCKET
&&
1480 cmsg
->cmsg_type
== SCM_CREDENTIALS
&&
1481 cmsg
->cmsg_len
== CMSG_LEN(sizeof(struct ucred
))) {
1483 ucred
= CMSG_TYPED_DATA(cmsg
, struct ucred
);
1484 } else if (cmsg
->cmsg_level
== SOL_SOCKET
&&
1485 cmsg
->cmsg_type
== SCM_SECURITY
) {
1487 label
= CMSG_TYPED_DATA(cmsg
, char);
1488 label_len
= cmsg
->cmsg_len
- CMSG_LEN(0);
1489 } else if (cmsg
->cmsg_level
== SOL_SOCKET
&&
1490 cmsg
->cmsg_type
== SCM_TIMESTAMP
&&
1491 cmsg
->cmsg_len
== CMSG_LEN(sizeof(struct timeval
))) {
1493 tv
= memcpy(&tv_buf
, CMSG_DATA(cmsg
), sizeof(struct timeval
));
1494 } else if (cmsg
->cmsg_level
== SOL_SOCKET
&&
1495 cmsg
->cmsg_type
== SCM_RIGHTS
) {
1497 fds
= CMSG_TYPED_DATA(cmsg
, int);
1498 n_fds
= (cmsg
->cmsg_len
- CMSG_LEN(0)) / sizeof(int);
1501 /* And a trailing NUL, just in case */
1504 if (fd
== s
->syslog_fd
) {
1505 if (n
> 0 && n_fds
== 0)
1506 server_process_syslog_message(s
, s
->buffer
, n
, ucred
, tv
, label
, label_len
);
1508 log_ratelimit_warning(JOURNAL_LOG_RATELIMIT
,
1509 "Got file descriptors via syslog socket. Ignoring.");
1511 } else if (fd
== s
->native_fd
) {
1512 if (n
> 0 && n_fds
== 0)
1513 server_process_native_message(s
, s
->buffer
, n
, ucred
, tv
, label
, label_len
);
1514 else if (n
== 0 && n_fds
== 1)
1515 server_process_native_file(s
, fds
[0], ucred
, tv
, label
, label_len
);
1517 log_ratelimit_warning(JOURNAL_LOG_RATELIMIT
,
1518 "Got too many file descriptors via native socket. Ignoring.");
1521 assert(fd
== s
->audit_fd
);
1523 if (n
> 0 && n_fds
== 0)
1524 server_process_audit_message(s
, s
->buffer
, n
, ucred
, &sa
, msghdr
.msg_namelen
);
1526 log_ratelimit_warning(JOURNAL_LOG_RATELIMIT
,
1527 "Got file descriptors via audit socket. Ignoring.");
1530 close_many(fds
, n_fds
);
1532 server_refresh_idle_timer(s
);
1536 static void server_full_flush(Server
*s
) {
1539 (void) server_flush_to_var(s
, false);
1541 server_vacuum(s
, false);
1543 server_space_usage_message(s
, NULL
);
1545 server_refresh_idle_timer(s
);
1548 static int dispatch_sigusr1(sd_event_source
*es
, const struct signalfd_siginfo
*si
, void *userdata
) {
1549 Server
*s
= ASSERT_PTR(userdata
);
1552 log_error("Received SIGUSR1 signal from PID %u, but flushing runtime journals not supported for namespaced instances.", si
->ssi_pid
);
1556 log_info("Received SIGUSR1 signal from PID %u, as request to flush runtime journal.", si
->ssi_pid
);
1557 server_full_flush(s
);
1562 static void server_full_rotate(Server
*s
) {
1569 server_vacuum(s
, true);
1571 if (s
->system_journal
)
1572 patch_min_use(&s
->system_storage
);
1573 if (s
->runtime_journal
)
1574 patch_min_use(&s
->runtime_storage
);
1576 /* Let clients know when the most recent rotation happened. */
1577 fn
= strjoina(s
->runtime_directory
, "/rotated");
1578 r
= write_timestamp_file_atomic(fn
, now(CLOCK_MONOTONIC
));
1580 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
1581 "Failed to write %s, ignoring: %m", fn
);
1584 static int dispatch_sigusr2(sd_event_source
*es
, const struct signalfd_siginfo
*si
, void *userdata
) {
1585 Server
*s
= ASSERT_PTR(userdata
);
1587 log_info("Received SIGUSR2 signal from PID %u, as request to rotate journal, rotating.", si
->ssi_pid
);
1588 server_full_rotate(s
);
1593 static int dispatch_sigterm(sd_event_source
*es
, const struct signalfd_siginfo
*si
, void *userdata
) {
1594 _cleanup_(sd_event_source_disable_unrefp
) sd_event_source
*news
= NULL
;
1595 Server
*s
= ASSERT_PTR(userdata
);
1598 log_received_signal(LOG_INFO
, si
);
1600 (void) sd_event_source_set_enabled(es
, SD_EVENT_OFF
); /* Make sure this handler is called at most once */
1602 /* So on one hand we want to ensure that SIGTERMs are definitely handled in appropriate, bounded
1603 * time. On the other hand we want that everything pending is first comprehensively processed and
1604 * written to disk. These goals are incompatible, hence we try to find a middle ground: we'll process
1605 * SIGTERM with high priority, but from the handler (this one right here) we'll install two new event
1606 * sources: one low priority idle one that will issue the exit once everything else is processed (and
1607 * which is hopefully the regular, clean codepath); and one high priority timer that acts as safety
1608 * net: if our idle handler isn't run within 10s, we'll exit anyway.
1610 * TLDR: we'll exit either when everything is processed, or after 10s max, depending on what happens
1613 * Note that exiting before the idle event is hit doesn't typically mean that we lose any data, as
1614 * messages will remain queued in the sockets they came in from, and thus can be processed when we
1615 * start up next – unless we are going down for the final system shutdown, in which case everything
1618 r
= sd_event_add_defer(s
->event
, &news
, NULL
, NULL
); /* NULL handler means → exit when triggered */
1620 log_error_errno(r
, "Failed to allocate exit idle event handler: %m");
1624 (void) sd_event_source_set_description(news
, "exit-idle");
1626 /* Run everything relevant before this. */
1627 r
= sd_event_source_set_priority(news
, SD_EVENT_PRIORITY_NORMAL
+20);
1629 log_error_errno(r
, "Failed to adjust priority of exit idle event handler: %m");
1633 /* Give up ownership, so that this event source is freed automatically when the event loop is freed. */
1634 r
= sd_event_source_set_floating(news
, true);
1636 log_error_errno(r
, "Failed to make exit idle event handler floating: %m");
1640 news
= sd_event_source_unref(news
);
1642 r
= sd_event_add_time_relative(s
->event
, &news
, CLOCK_MONOTONIC
, 10 * USEC_PER_SEC
, 0, NULL
, NULL
);
1644 log_error_errno(r
, "Failed to allocate exit timeout event handler: %m");
1648 (void) sd_event_source_set_description(news
, "exit-timeout");
1650 r
= sd_event_source_set_priority(news
, SD_EVENT_PRIORITY_IMPORTANT
-20); /* This is a safety net, with highest priority */
1652 log_error_errno(r
, "Failed to adjust priority of exit timeout event handler: %m");
1656 r
= sd_event_source_set_floating(news
, true);
1658 log_error_errno(r
, "Failed to make exit timeout event handler floating: %m");
1662 news
= sd_event_source_unref(news
);
1664 log_debug("Exit event sources are now pending.");
1668 sd_event_exit(s
->event
, 0);
1672 static void server_full_sync(Server
*s
) {
1680 /* Let clients know when the most recent sync happened. */
1681 fn
= strjoina(s
->runtime_directory
, "/synced");
1682 r
= write_timestamp_file_atomic(fn
, now(CLOCK_MONOTONIC
));
1684 log_ratelimit_warning_errno(r
, JOURNAL_LOG_RATELIMIT
,
1685 "Failed to write %s, ignoring: %m", fn
);
1690 static int dispatch_sigrtmin1(sd_event_source
*es
, const struct signalfd_siginfo
*si
, void *userdata
) {
1691 Server
*s
= ASSERT_PTR(userdata
);
1693 log_debug("Received SIGRTMIN1 signal from PID %u, as request to sync.", si
->ssi_pid
);
1694 server_full_sync(s
);
1699 static int server_setup_signals(Server
*s
) {
1704 assert_se(sigprocmask_many(SIG_SETMASK
, NULL
, SIGINT
, SIGTERM
, SIGUSR1
, SIGUSR2
, SIGRTMIN
+1, SIGRTMIN
+18, -1) >= 0);
1706 r
= sd_event_add_signal(s
->event
, &s
->sigusr1_event_source
, SIGUSR1
, dispatch_sigusr1
, s
);
1710 r
= sd_event_add_signal(s
->event
, &s
->sigusr2_event_source
, SIGUSR2
, dispatch_sigusr2
, s
);
1714 r
= sd_event_add_signal(s
->event
, &s
->sigterm_event_source
, SIGTERM
, dispatch_sigterm
, s
);
1718 /* Let's process SIGTERM early, so that we definitely react to it */
1719 r
= sd_event_source_set_priority(s
->sigterm_event_source
, SD_EVENT_PRIORITY_IMPORTANT
-10);
1723 /* When journald is invoked on the terminal (when debugging), it's useful if C-c is handled
1724 * equivalent to SIGTERM. */
1725 r
= sd_event_add_signal(s
->event
, &s
->sigint_event_source
, SIGINT
, dispatch_sigterm
, s
);
1729 r
= sd_event_source_set_priority(s
->sigint_event_source
, SD_EVENT_PRIORITY_IMPORTANT
-10);
1733 /* SIGRTMIN+1 causes an immediate sync. We process this very late, so that everything else queued at
1734 * this point is really written to disk. Clients can watch /run/systemd/journal/synced with inotify
1735 * until its mtime changes to see when a sync happened. */
1736 r
= sd_event_add_signal(s
->event
, &s
->sigrtmin1_event_source
, SIGRTMIN
+1, dispatch_sigrtmin1
, s
);
1740 r
= sd_event_source_set_priority(s
->sigrtmin1_event_source
, SD_EVENT_PRIORITY_NORMAL
+15);
1744 r
= sd_event_add_signal(s
->event
, NULL
, SIGRTMIN
+18, sigrtmin18_handler
, &s
->sigrtmin18_info
);
1751 static int parse_proc_cmdline_item(const char *key
, const char *value
, void *data
) {
1752 Server
*s
= ASSERT_PTR(data
);
1755 if (proc_cmdline_key_streq(key
, "systemd.journald.forward_to_syslog")) {
1757 r
= value
? parse_boolean(value
) : true;
1759 log_warning("Failed to parse forward to syslog switch \"%s\". Ignoring.", value
);
1761 s
->forward_to_syslog
= r
;
1763 } else if (proc_cmdline_key_streq(key
, "systemd.journald.forward_to_kmsg")) {
1765 r
= value
? parse_boolean(value
) : true;
1767 log_warning("Failed to parse forward to kmsg switch \"%s\". Ignoring.", value
);
1769 s
->forward_to_kmsg
= r
;
1771 } else if (proc_cmdline_key_streq(key
, "systemd.journald.forward_to_console")) {
1773 r
= value
? parse_boolean(value
) : true;
1775 log_warning("Failed to parse forward to console switch \"%s\". Ignoring.", value
);
1777 s
->forward_to_console
= r
;
1779 } else if (proc_cmdline_key_streq(key
, "systemd.journald.forward_to_wall")) {
1781 r
= value
? parse_boolean(value
) : true;
1783 log_warning("Failed to parse forward to wall switch \"%s\". Ignoring.", value
);
1785 s
->forward_to_wall
= r
;
1787 } else if (proc_cmdline_key_streq(key
, "systemd.journald.max_level_console")) {
1789 if (proc_cmdline_value_missing(key
, value
))
1792 r
= log_level_from_string(value
);
1794 log_warning("Failed to parse max level console value \"%s\". Ignoring.", value
);
1796 s
->max_level_console
= r
;
1798 } else if (proc_cmdline_key_streq(key
, "systemd.journald.max_level_store")) {
1800 if (proc_cmdline_value_missing(key
, value
))
1803 r
= log_level_from_string(value
);
1805 log_warning("Failed to parse max level store value \"%s\". Ignoring.", value
);
1807 s
->max_level_store
= r
;
1809 } else if (proc_cmdline_key_streq(key
, "systemd.journald.max_level_syslog")) {
1811 if (proc_cmdline_value_missing(key
, value
))
1814 r
= log_level_from_string(value
);
1816 log_warning("Failed to parse max level syslog value \"%s\". Ignoring.", value
);
1818 s
->max_level_syslog
= r
;
1820 } else if (proc_cmdline_key_streq(key
, "systemd.journald.max_level_kmsg")) {
1822 if (proc_cmdline_value_missing(key
, value
))
1825 r
= log_level_from_string(value
);
1827 log_warning("Failed to parse max level kmsg value \"%s\". Ignoring.", value
);
1829 s
->max_level_kmsg
= r
;
1831 } else if (proc_cmdline_key_streq(key
, "systemd.journald.max_level_wall")) {
1833 if (proc_cmdline_value_missing(key
, value
))
1836 r
= log_level_from_string(value
);
1838 log_warning("Failed to parse max level wall value \"%s\". Ignoring.", value
);
1840 s
->max_level_wall
= r
;
1842 } else if (startswith(key
, "systemd.journald"))
1843 log_warning("Unknown journald kernel command line option \"%s\". Ignoring.", key
);
1845 /* do not warn about state here, since probably systemd already did */
1849 static int server_parse_config_file(Server
*s
) {
1850 const char *conf_file
= "journald.conf";
1855 conf_file
= strjoina("journald@", s
->namespace, ".conf");
1857 return config_parse_config_file(conf_file
, "Journal\0",
1858 config_item_perf_lookup
, journald_gperf_lookup
,
1859 CONFIG_PARSE_WARN
, s
);
1862 static int server_dispatch_sync(sd_event_source
*es
, usec_t t
, void *userdata
) {
1863 Server
*s
= ASSERT_PTR(userdata
);
1869 int server_schedule_sync(Server
*s
, int priority
) {
1874 if (priority
<= LOG_CRIT
) {
1875 /* Immediately sync to disk when this is of priority CRIT, ALERT, EMERG */
1880 if (!s
->event
|| sd_event_get_state(s
->event
) == SD_EVENT_FINISHED
) {
1881 /* Shutting down the server? Let's sync immediately. */
1886 if (s
->sync_scheduled
)
1889 if (s
->sync_interval_usec
> 0) {
1891 if (!s
->sync_event_source
) {
1892 r
= sd_event_add_time_relative(
1894 &s
->sync_event_source
,
1896 s
->sync_interval_usec
, 0,
1897 server_dispatch_sync
, s
);
1901 r
= sd_event_source_set_priority(s
->sync_event_source
, SD_EVENT_PRIORITY_IMPORTANT
);
1903 r
= sd_event_source_set_time_relative(s
->sync_event_source
, s
->sync_interval_usec
);
1907 r
= sd_event_source_set_enabled(s
->sync_event_source
, SD_EVENT_ONESHOT
);
1912 s
->sync_scheduled
= true;
1918 static int dispatch_hostname_change(sd_event_source
*es
, int fd
, uint32_t revents
, void *userdata
) {
1919 Server
*s
= ASSERT_PTR(userdata
);
1921 server_cache_hostname(s
);
1925 static int server_open_hostname(Server
*s
) {
1930 s
->hostname_fd
= open("/proc/sys/kernel/hostname",
1931 O_RDONLY
|O_CLOEXEC
|O_NONBLOCK
|O_NOCTTY
);
1932 if (s
->hostname_fd
< 0)
1933 return log_error_errno(errno
, "Failed to open /proc/sys/kernel/hostname: %m");
1935 r
= sd_event_add_io(s
->event
, &s
->hostname_event_source
, s
->hostname_fd
, 0, dispatch_hostname_change
, s
);
1937 /* kernels prior to 3.2 don't support polling this file. Ignore
1940 log_warning_errno(r
, "Failed to register hostname fd in event loop, ignoring: %m");
1941 s
->hostname_fd
= safe_close(s
->hostname_fd
);
1945 return log_error_errno(r
, "Failed to register hostname fd in event loop: %m");
1948 r
= sd_event_source_set_priority(s
->hostname_event_source
, SD_EVENT_PRIORITY_IMPORTANT
-10);
1950 return log_error_errno(r
, "Failed to adjust priority of hostname event source: %m");
1955 static int dispatch_notify_event(sd_event_source
*es
, int fd
, uint32_t revents
, void *userdata
) {
1956 Server
*s
= ASSERT_PTR(userdata
);
1959 assert(s
->notify_event_source
== es
);
1960 assert(s
->notify_fd
== fd
);
1962 /* The $NOTIFY_SOCKET is writable again, now send exactly one
1963 * message on it. Either it's the watchdog event, the initial
1964 * READY=1 event or an stdout stream event. If there's nothing
1965 * to write anymore, turn our event source off. The next time
1966 * there's something to send it will be turned on again. */
1968 if (!s
->sent_notify_ready
) {
1969 static const char p
[] = "READY=1\n"
1970 "STATUS=Processing requests...";
1972 if (send(s
->notify_fd
, p
, strlen(p
), MSG_DONTWAIT
) < 0) {
1973 if (errno
== EAGAIN
)
1976 return log_error_errno(errno
, "Failed to send READY=1 notification message: %m");
1979 s
->sent_notify_ready
= true;
1980 log_debug("Sent READY=1 notification.");
1982 } else if (s
->send_watchdog
) {
1983 static const char p
[] = "WATCHDOG=1";
1985 if (send(s
->notify_fd
, p
, strlen(p
), MSG_DONTWAIT
) < 0) {
1986 if (errno
== EAGAIN
)
1989 return log_error_errno(errno
, "Failed to send WATCHDOG=1 notification message: %m");
1992 s
->send_watchdog
= false;
1993 log_debug("Sent WATCHDOG=1 notification.");
1995 } else if (s
->stdout_streams_notify_queue
)
1996 /* Dispatch one stream notification event */
1997 stdout_stream_send_notify(s
->stdout_streams_notify_queue
);
1999 /* Leave us enabled if there's still more to do. */
2000 if (s
->send_watchdog
|| s
->stdout_streams_notify_queue
)
2003 /* There was nothing to do anymore, let's turn ourselves off. */
2004 r
= sd_event_source_set_enabled(es
, SD_EVENT_OFF
);
2006 return log_error_errno(r
, "Failed to turn off notify event source: %m");
2011 static int dispatch_watchdog(sd_event_source
*es
, uint64_t usec
, void *userdata
) {
2012 Server
*s
= ASSERT_PTR(userdata
);
2015 s
->send_watchdog
= true;
2017 r
= sd_event_source_set_enabled(s
->notify_event_source
, SD_EVENT_ON
);
2019 log_warning_errno(r
, "Failed to turn on notify event source: %m");
2021 r
= sd_event_source_set_time(s
->watchdog_event_source
, usec
+ s
->watchdog_usec
/ 2);
2023 return log_error_errno(r
, "Failed to restart watchdog event source: %m");
2025 r
= sd_event_source_set_enabled(s
->watchdog_event_source
, SD_EVENT_ON
);
2027 return log_error_errno(r
, "Failed to enable watchdog event source: %m");
2032 static int server_connect_notify(Server
*s
) {
2033 union sockaddr_union sa
;
2039 assert(s
->notify_fd
< 0);
2040 assert(!s
->notify_event_source
);
2043 * So here's the problem: we'd like to send notification messages to PID 1, but we cannot do that via
2044 * sd_notify(), since that's synchronous, and we might end up blocking on it. Specifically: given
2045 * that PID 1 might block on dbus-daemon during IPC, and dbus-daemon is logging to us, and might
2046 * hence block on us, we might end up in a deadlock if we block on sending PID 1 notification
2047 * messages — by generating a full blocking circle. To avoid this, let's create a non-blocking
2048 * socket, and connect it to the notification socket, and then wait for POLLOUT before we send
2049 * anything. This should efficiently avoid any deadlocks, as we'll never block on PID 1, hence PID 1
2050 * can safely block on dbus-daemon which can safely block on us again.
2052 * Don't think that this issue is real? It is, see: https://github.com/systemd/systemd/issues/1505
2055 e
= getenv("NOTIFY_SOCKET");
2059 r
= sockaddr_un_set_path(&sa
.un
, e
);
2061 return log_error_errno(r
, "NOTIFY_SOCKET set to invalid value '%s': %m", e
);
2064 s
->notify_fd
= socket(AF_UNIX
, SOCK_DGRAM
|SOCK_CLOEXEC
|SOCK_NONBLOCK
, 0);
2065 if (s
->notify_fd
< 0)
2066 return log_error_errno(errno
, "Failed to create notify socket: %m");
2068 (void) fd_inc_sndbuf(s
->notify_fd
, NOTIFY_SNDBUF_SIZE
);
2070 r
= connect(s
->notify_fd
, &sa
.sa
, sa_len
);
2072 return log_error_errno(errno
, "Failed to connect to notify socket: %m");
2074 r
= sd_event_add_io(s
->event
, &s
->notify_event_source
, s
->notify_fd
, EPOLLOUT
, dispatch_notify_event
, s
);
2076 return log_error_errno(r
, "Failed to watch notification socket: %m");
2078 if (sd_watchdog_enabled(false, &s
->watchdog_usec
) > 0) {
2079 s
->send_watchdog
= true;
2081 r
= sd_event_add_time_relative(s
->event
, &s
->watchdog_event_source
, CLOCK_MONOTONIC
, s
->watchdog_usec
/2, s
->watchdog_usec
/4, dispatch_watchdog
, s
);
2083 return log_error_errno(r
, "Failed to add watchdog time event: %m");
2086 /* This should fire pretty soon, which we'll use to send the READY=1 event. */
2091 static int synchronize_second_half(sd_event_source
*event_source
, void *userdata
) {
2092 Varlink
*link
= ASSERT_PTR(userdata
);
2096 assert_se(s
= varlink_get_userdata(link
));
2098 /* This is the "second half" of the Synchronize() varlink method. This function is called as deferred
2099 * event source at a low priority to ensure the synchronization completes after all queued log
2100 * messages are processed. */
2101 server_full_sync(s
);
2103 /* Let's get rid of the event source now, by marking it as non-floating again. It then has no ref
2104 * anymore and is immediately destroyed after we return from this function, i.e. from this event
2105 * source handler at the end. */
2106 r
= sd_event_source_set_floating(event_source
, false);
2108 return log_error_errno(r
, "Failed to mark event source as non-floating: %m");
2110 return varlink_reply(link
, NULL
);
2113 static void synchronize_destroy(void *userdata
) {
2114 varlink_unref(userdata
);
2117 static int vl_method_synchronize(Varlink
*link
, JsonVariant
*parameters
, VarlinkMethodFlags flags
, void *userdata
) {
2118 _cleanup_(sd_event_source_unrefp
) sd_event_source
*event_source
= NULL
;
2119 Server
*s
= ASSERT_PTR(userdata
);
2124 if (json_variant_elements(parameters
) > 0)
2125 return varlink_error_invalid_parameter(link
, parameters
);
2127 log_info("Received client request to sync journal.");
2129 /* We don't do the main work now, but instead enqueue a deferred event loop job which will do
2130 * it. That job is scheduled at low priority, so that we return from this method call only after all
2131 * queued but not processed log messages are written to disk, so that this method call returning can
2132 * be used as nice synchronization point. */
2133 r
= sd_event_add_defer(s
->event
, &event_source
, synchronize_second_half
, link
);
2135 return log_error_errno(r
, "Failed to allocate defer event source: %m");
2137 r
= sd_event_source_set_destroy_callback(event_source
, synchronize_destroy
);
2139 return log_error_errno(r
, "Failed to set event source destroy callback: %m");
2141 varlink_ref(link
); /* The varlink object is now left to the destroy callback to unref */
2143 r
= sd_event_source_set_priority(event_source
, SD_EVENT_PRIORITY_NORMAL
+15);
2145 return log_error_errno(r
, "Failed to set defer event source priority: %m");
2147 /* Give up ownership of this event source. It will now be destroyed along with event loop itself,
2148 * unless it destroys itself earlier. */
2149 r
= sd_event_source_set_floating(event_source
, true);
2151 return log_error_errno(r
, "Failed to mark event source as floating: %m");
2153 (void) sd_event_source_set_description(event_source
, "deferred-sync");
2158 static int vl_method_rotate(Varlink
*link
, JsonVariant
*parameters
, VarlinkMethodFlags flags
, void *userdata
) {
2159 Server
*s
= ASSERT_PTR(userdata
);
2163 if (json_variant_elements(parameters
) > 0)
2164 return varlink_error_invalid_parameter(link
, parameters
);
2166 log_info("Received client request to rotate journal, rotating.");
2167 server_full_rotate(s
);
2169 return varlink_reply(link
, NULL
);
2172 static int vl_method_flush_to_var(Varlink
*link
, JsonVariant
*parameters
, VarlinkMethodFlags flags
, void *userdata
) {
2173 Server
*s
= ASSERT_PTR(userdata
);
2177 if (json_variant_elements(parameters
) > 0)
2178 return varlink_error_invalid_parameter(link
, parameters
);
2180 return varlink_error(link
, "io.systemd.Journal.NotSupportedByNamespaces", NULL
);
2182 log_info("Received client request to flush runtime journal.");
2183 server_full_flush(s
);
2185 return varlink_reply(link
, NULL
);
2188 static int vl_method_relinquish_var(Varlink
*link
, JsonVariant
*parameters
, VarlinkMethodFlags flags
, void *userdata
) {
2189 Server
*s
= ASSERT_PTR(userdata
);
2193 if (json_variant_elements(parameters
) > 0)
2194 return varlink_error_invalid_parameter(link
, parameters
);
2196 return varlink_error(link
, "io.systemd.Journal.NotSupportedByNamespaces", NULL
);
2198 log_info("Received client request to relinquish %s access.", s
->system_storage
.path
);
2199 server_relinquish_var(s
);
2201 return varlink_reply(link
, NULL
);
2204 static int vl_connect(VarlinkServer
*server
, Varlink
*link
, void *userdata
) {
2205 Server
*s
= ASSERT_PTR(userdata
);
2210 (void) server_start_or_stop_idle_timer(s
); /* maybe we are no longer idle */
2215 static void vl_disconnect(VarlinkServer
*server
, Varlink
*link
, void *userdata
) {
2216 Server
*s
= ASSERT_PTR(userdata
);
2221 (void) server_start_or_stop_idle_timer(s
); /* maybe we are idle now */
2224 static int server_open_varlink(Server
*s
, const char *socket
, int fd
) {
2229 r
= varlink_server_new(&s
->varlink_server
, VARLINK_SERVER_ROOT_ONLY
|VARLINK_SERVER_INHERIT_USERDATA
);
2233 varlink_server_set_userdata(s
->varlink_server
, s
);
2235 r
= varlink_server_add_interface(s
->varlink_server
, &vl_interface_io_systemd_Journal
);
2237 return log_error_errno(r
, "Failed to add Journal interface to varlink server: %m");
2239 r
= varlink_server_bind_method_many(
2241 "io.systemd.Journal.Synchronize", vl_method_synchronize
,
2242 "io.systemd.Journal.Rotate", vl_method_rotate
,
2243 "io.systemd.Journal.FlushToVar", vl_method_flush_to_var
,
2244 "io.systemd.Journal.RelinquishVar", vl_method_relinquish_var
);
2248 r
= varlink_server_bind_connect(s
->varlink_server
, vl_connect
);
2252 r
= varlink_server_bind_disconnect(s
->varlink_server
, vl_disconnect
);
2257 r
= varlink_server_listen_address(s
->varlink_server
, socket
, 0600);
2259 r
= varlink_server_listen_fd(s
->varlink_server
, fd
);
2263 r
= varlink_server_attach_event(s
->varlink_server
, s
->event
, SD_EVENT_PRIORITY_NORMAL
);
2270 int server_map_seqnum_file(
2276 _cleanup_free_
char *fn
= NULL
;
2277 _cleanup_close_
int fd
= -EBADF
;
2286 fn
= path_join(s
->runtime_directory
, fname
);
2290 fd
= open(fn
, O_RDWR
|O_CREAT
|O_CLOEXEC
|O_NOCTTY
|O_NOFOLLOW
, 0644);
2294 r
= posix_fallocate_loop(fd
, 0, size
);
2298 p
= mmap(NULL
, size
, PROT_READ
|PROT_WRITE
, MAP_SHARED
, fd
, 0);
2299 if (p
== MAP_FAILED
)
2306 void server_unmap_seqnum_file(void *p
, size_t size
) {
2312 assert_se(munmap(p
, size
) >= 0);
2315 static bool server_is_idle(Server
*s
) {
2318 /* The server for the main namespace is never idle */
2322 /* If a retention maximum is set larger than the idle time we need to be running to enforce it, hence
2323 * turn off the idle logic. */
2324 if (s
->max_retention_usec
> IDLE_TIMEOUT_USEC
)
2327 /* We aren't idle if we have a varlink client */
2328 if (varlink_server_current_connections(s
->varlink_server
) > 0)
2331 /* If we have stdout streams we aren't idle */
2332 if (s
->n_stdout_streams
> 0)
2338 static int server_idle_handler(sd_event_source
*source
, uint64_t usec
, void *userdata
) {
2339 Server
*s
= ASSERT_PTR(userdata
);
2343 log_debug("Server is idle, exiting.");
2344 sd_event_exit(s
->event
, 0);
2348 int server_start_or_stop_idle_timer(Server
*s
) {
2349 _cleanup_(sd_event_source_unrefp
) sd_event_source
*source
= NULL
;
2354 if (!server_is_idle(s
)) {
2355 s
->idle_event_source
= sd_event_source_disable_unref(s
->idle_event_source
);
2359 if (s
->idle_event_source
)
2362 r
= sd_event_add_time_relative(s
->event
, &source
, CLOCK_MONOTONIC
, IDLE_TIMEOUT_USEC
, 0, server_idle_handler
, s
);
2364 return log_error_errno(r
, "Failed to allocate idle timer: %m");
2366 r
= sd_event_source_set_priority(source
, SD_EVENT_PRIORITY_IDLE
);
2368 return log_error_errno(r
, "Failed to set idle timer priority: %m");
2370 (void) sd_event_source_set_description(source
, "idle-timer");
2372 s
->idle_event_source
= TAKE_PTR(source
);
2376 int server_refresh_idle_timer(Server
*s
) {
2381 if (!s
->idle_event_source
)
2384 r
= sd_event_source_set_time_relative(s
->idle_event_source
, IDLE_TIMEOUT_USEC
);
2386 return log_error_errno(r
, "Failed to refresh idle timer: %m");
2391 static int server_set_namespace(Server
*s
, const char *namespace) {
2397 if (!log_namespace_name_valid(namespace))
2398 return log_error_errno(SYNTHETIC_ERRNO(EINVAL
), "Specified namespace name not valid, refusing: %s", namespace);
2400 s
->namespace = strdup(namespace);
2404 s
->namespace_field
= strjoin("_NAMESPACE=", namespace);
2405 if (!s
->namespace_field
)
2411 static int server_memory_pressure(sd_event_source
*es
, void *userdata
) {
2412 Server
*s
= ASSERT_PTR(userdata
);
2414 log_info("Under memory pressure, flushing caches.");
2416 /* Flushed the cached info we might have about client processes */
2417 client_context_flush_regular(s
);
2419 /* Let's also close all user files (but keep the system/runtime one open) */
2421 JournalFile
*first
= ordered_hashmap_steal_first(s
->user_journals
);
2426 (void) journal_file_offline_close(first
);
2429 sd_event_trim_memory();
2434 static int server_setup_memory_pressure(Server
*s
) {
2439 r
= sd_event_add_memory_pressure(s
->event
, NULL
, server_memory_pressure
, s
);
2441 log_full_errno(ERRNO_IS_NOT_SUPPORTED(r
) || ERRNO_IS_PRIVILEGE(r
) || (r
== -EHOSTDOWN
) ? LOG_DEBUG
: LOG_NOTICE
, r
,
2442 "Failed to install memory pressure event source, ignoring: %m");
2447 int server_new(Server
**ret
) {
2448 _cleanup_(server_freep
) Server
*s
= NULL
;
2457 .syslog_fd
= -EBADF
,
2458 .native_fd
= -EBADF
,
2459 .stdout_fd
= -EBADF
,
2460 .dev_kmsg_fd
= -EBADF
,
2462 .hostname_fd
= -EBADF
,
2463 .notify_fd
= -EBADF
,
2465 .compress
.enabled
= true,
2466 .compress
.threshold_bytes
= UINT64_MAX
,
2471 .watchdog_usec
= USEC_INFINITY
,
2473 .sync_interval_usec
= DEFAULT_SYNC_INTERVAL_USEC
,
2474 .sync_scheduled
= false,
2476 .ratelimit_interval
= DEFAULT_RATE_LIMIT_INTERVAL
,
2477 .ratelimit_burst
= DEFAULT_RATE_LIMIT_BURST
,
2479 .forward_to_wall
= true,
2481 .max_file_usec
= DEFAULT_MAX_FILE_USEC
,
2483 .max_level_store
= LOG_DEBUG
,
2484 .max_level_syslog
= LOG_DEBUG
,
2485 .max_level_kmsg
= LOG_NOTICE
,
2486 .max_level_console
= LOG_INFO
,
2487 .max_level_wall
= LOG_EMERG
,
2489 .line_max
= DEFAULT_LINE_MAX
,
2491 .runtime_storage
.name
= "Runtime Journal",
2492 .system_storage
.name
= "System Journal",
2494 .kmsg_own_ratelimit
= {
2495 .interval
= DEFAULT_KMSG_OWN_INTERVAL
,
2496 .burst
= DEFAULT_KMSG_OWN_BURST
,
2499 .sigrtmin18_info
.memory_pressure_handler
= server_memory_pressure
,
2500 .sigrtmin18_info
.memory_pressure_userdata
= s
,
2507 int server_init(Server
*s
, const char *namespace) {
2508 const char *native_socket
, *syslog_socket
, *stdout_socket
, *varlink_socket
, *e
;
2509 _cleanup_fdset_free_ FDSet
*fds
= NULL
;
2510 int n
, r
, fd
, varlink_fd
= -EBADF
;
2515 r
= server_set_namespace(s
, namespace);
2519 /* By default, only read from /dev/kmsg if are the main namespace */
2520 s
->read_kmsg
= !s
->namespace;
2521 s
->storage
= s
->namespace ? STORAGE_PERSISTENT
: STORAGE_AUTO
;
2523 journal_reset_metrics(&s
->system_storage
.metrics
);
2524 journal_reset_metrics(&s
->runtime_storage
.metrics
);
2526 server_parse_config_file(s
);
2528 if (!s
->namespace) {
2529 /* Parse kernel command line, but only if we are not a namespace instance */
2530 r
= proc_cmdline_parse(parse_proc_cmdline_item
, s
, PROC_CMDLINE_STRIP_RD_PREFIX
);
2532 log_warning_errno(r
, "Failed to parse kernel command line, ignoring: %m");
2535 if (!!s
->ratelimit_interval
!= !!s
->ratelimit_burst
) { /* One set to 0 and the other not? */
2536 log_debug("Setting both rate limit interval and burst from "USEC_FMT
",%u to 0,0",
2537 s
->ratelimit_interval
, s
->ratelimit_burst
);
2538 s
->ratelimit_interval
= s
->ratelimit_burst
= 0;
2541 e
= getenv("RUNTIME_DIRECTORY");
2543 s
->runtime_directory
= strdup(e
);
2544 else if (s
->namespace)
2545 s
->runtime_directory
= strjoin("/run/systemd/journal.", s
->namespace);
2547 s
->runtime_directory
= strdup("/run/systemd/journal");
2548 if (!s
->runtime_directory
)
2551 (void) mkdir_p(s
->runtime_directory
, 0755);
2553 s
->user_journals
= ordered_hashmap_new(NULL
);
2554 if (!s
->user_journals
)
2557 s
->mmap
= mmap_cache_new();
2561 s
->deferred_closes
= set_new(NULL
);
2562 if (!s
->deferred_closes
)
2565 r
= sd_event_default(&s
->event
);
2567 return log_error_errno(r
, "Failed to create event loop: %m");
2569 n
= sd_listen_fds(true);
2571 return log_error_errno(n
, "Failed to read listening file descriptors from environment: %m");
2573 native_socket
= strjoina(s
->runtime_directory
, "/socket");
2574 stdout_socket
= strjoina(s
->runtime_directory
, "/stdout");
2575 syslog_socket
= strjoina(s
->runtime_directory
, "/dev-log");
2576 varlink_socket
= strjoina(s
->runtime_directory
, "/io.systemd.journal");
2578 for (fd
= SD_LISTEN_FDS_START
; fd
< SD_LISTEN_FDS_START
+ n
; fd
++) {
2580 if (sd_is_socket_unix(fd
, SOCK_DGRAM
, -1, native_socket
, 0) > 0) {
2582 if (s
->native_fd
>= 0)
2583 return log_error_errno(SYNTHETIC_ERRNO(EINVAL
),
2584 "Too many native sockets passed.");
2588 } else if (sd_is_socket_unix(fd
, SOCK_STREAM
, 1, stdout_socket
, 0) > 0) {
2590 if (s
->stdout_fd
>= 0)
2591 return log_error_errno(SYNTHETIC_ERRNO(EINVAL
),
2592 "Too many stdout sockets passed.");
2596 } else if (sd_is_socket_unix(fd
, SOCK_DGRAM
, -1, syslog_socket
, 0) > 0) {
2598 if (s
->syslog_fd
>= 0)
2599 return log_error_errno(SYNTHETIC_ERRNO(EINVAL
),
2600 "Too many /dev/log sockets passed.");
2604 } else if (sd_is_socket_unix(fd
, SOCK_STREAM
, 1, varlink_socket
, 0) > 0) {
2606 if (varlink_fd
>= 0)
2607 return log_error_errno(SYNTHETIC_ERRNO(EINVAL
),
2608 "Too many varlink sockets passed.");
2611 } else if (sd_is_socket(fd
, AF_NETLINK
, SOCK_RAW
, -1) > 0) {
2613 if (s
->audit_fd
>= 0)
2614 return log_error_errno(SYNTHETIC_ERRNO(EINVAL
),
2615 "Too many audit sockets passed.");
2627 r
= fdset_put(fds
, fd
);
2633 /* Try to restore streams, but don't bother if this fails */
2634 (void) server_restore_streams(s
, fds
);
2636 if (fdset_size(fds
) > 0) {
2637 log_warning("%u unknown file descriptors passed, closing.", fdset_size(fds
));
2638 fds
= fdset_free(fds
);
2641 no_sockets
= s
->native_fd
< 0 && s
->stdout_fd
< 0 && s
->syslog_fd
< 0 && s
->audit_fd
< 0 && varlink_fd
< 0;
2643 /* always open stdout, syslog, native, and kmsg sockets */
2645 /* systemd-journald.socket: /run/systemd/journal/stdout */
2646 r
= server_open_stdout_socket(s
, stdout_socket
);
2650 /* systemd-journald-dev-log.socket: /run/systemd/journal/dev-log */
2651 r
= server_open_syslog_socket(s
, syslog_socket
);
2655 /* systemd-journald.socket: /run/systemd/journal/socket */
2656 r
= server_open_native_socket(s
, native_socket
);
2661 r
= server_open_dev_kmsg(s
);
2665 /* Unless we got *some* sockets and not audit, open audit socket */
2666 if (s
->audit_fd
>= 0 || no_sockets
) {
2667 log_info("Collecting audit messages is enabled.");
2669 r
= server_open_audit(s
);
2673 log_info("Collecting audit messages is disabled.");
2675 r
= server_open_varlink(s
, varlink_socket
, varlink_fd
);
2679 r
= server_map_seqnum_file(s
, "seqnum", sizeof(SeqnumData
), (void**) &s
->seqnum
);
2681 return log_error_errno(r
, "Failed to map main seqnum file: %m");
2683 r
= server_open_kernel_seqnum(s
);
2687 r
= server_open_hostname(s
);
2691 r
= server_setup_signals(s
);
2695 r
= server_setup_memory_pressure(s
);
2699 s
->ratelimit
= journal_ratelimit_new();
2703 r
= cg_get_root_path(&s
->cgroup_root
);
2705 return log_error_errno(r
, "Failed to acquire cgroup root path: %m");
2707 server_cache_hostname(s
);
2708 server_cache_boot_id(s
);
2709 server_cache_machine_id(s
);
2712 s
->runtime_storage
.path
= strjoin("/run/log/journal/", SERVER_MACHINE_ID(s
), ".", s
->namespace);
2714 s
->runtime_storage
.path
= strjoin("/run/log/journal/", SERVER_MACHINE_ID(s
));
2715 if (!s
->runtime_storage
.path
)
2718 e
= getenv("LOGS_DIRECTORY");
2720 s
->system_storage
.path
= strdup(e
);
2721 else if (s
->namespace)
2722 s
->system_storage
.path
= strjoin("/var/log/journal/", SERVER_MACHINE_ID(s
), ".", s
->namespace);
2724 s
->system_storage
.path
= strjoin("/var/log/journal/", SERVER_MACHINE_ID(s
));
2725 if (!s
->system_storage
.path
)
2728 (void) server_connect_notify(s
);
2730 (void) client_context_acquire_default(s
);
2732 r
= server_system_journal_open(s
, /* flush_requested= */ false, /* relinquish_requested= */ false);
2736 server_start_or_stop_idle_timer(s
);
2741 void server_maybe_append_tags(Server
*s
) {
2746 n
= now(CLOCK_REALTIME
);
2748 if (s
->system_journal
)
2749 journal_file_maybe_append_tag(s
->system_journal
, n
);
2751 ORDERED_HASHMAP_FOREACH(f
, s
->user_journals
)
2752 journal_file_maybe_append_tag(f
, n
);
2756 Server
* server_free(Server
*s
) {
2761 free(s
->namespace_field
);
2763 set_free_with_destructor(s
->deferred_closes
, journal_file_offline_close
);
2765 while (s
->stdout_streams
)
2766 stdout_stream_free(s
->stdout_streams
);
2768 client_context_flush_all(s
);
2770 (void) journal_file_offline_close(s
->system_journal
);
2771 (void) journal_file_offline_close(s
->runtime_journal
);
2773 ordered_hashmap_free_with_destructor(s
->user_journals
, journal_file_offline_close
);
2775 varlink_server_unref(s
->varlink_server
);
2777 sd_event_source_unref(s
->syslog_event_source
);
2778 sd_event_source_unref(s
->native_event_source
);
2779 sd_event_source_unref(s
->stdout_event_source
);
2780 sd_event_source_unref(s
->dev_kmsg_event_source
);
2781 sd_event_source_unref(s
->audit_event_source
);
2782 sd_event_source_unref(s
->sync_event_source
);
2783 sd_event_source_unref(s
->sigusr1_event_source
);
2784 sd_event_source_unref(s
->sigusr2_event_source
);
2785 sd_event_source_unref(s
->sigterm_event_source
);
2786 sd_event_source_unref(s
->sigint_event_source
);
2787 sd_event_source_unref(s
->sigrtmin1_event_source
);
2788 sd_event_source_unref(s
->hostname_event_source
);
2789 sd_event_source_unref(s
->notify_event_source
);
2790 sd_event_source_unref(s
->watchdog_event_source
);
2791 sd_event_source_unref(s
->idle_event_source
);
2792 sd_event_unref(s
->event
);
2794 safe_close(s
->syslog_fd
);
2795 safe_close(s
->native_fd
);
2796 safe_close(s
->stdout_fd
);
2797 safe_close(s
->dev_kmsg_fd
);
2798 safe_close(s
->audit_fd
);
2799 safe_close(s
->hostname_fd
);
2800 safe_close(s
->notify_fd
);
2803 journal_ratelimit_free(s
->ratelimit
);
2805 server_unmap_seqnum_file(s
->seqnum
, sizeof(*s
->seqnum
));
2806 server_unmap_seqnum_file(s
->kernel_seqnum
, sizeof(*s
->kernel_seqnum
));
2810 free(s
->cgroup_root
);
2811 free(s
->hostname_field
);
2812 free(s
->runtime_storage
.path
);
2813 free(s
->system_storage
.path
);
2814 free(s
->runtime_directory
);
2816 mmap_cache_unref(s
->mmap
);
2821 static const char* const storage_table
[_STORAGE_MAX
] = {
2822 [STORAGE_AUTO
] = "auto",
2823 [STORAGE_VOLATILE
] = "volatile",
2824 [STORAGE_PERSISTENT
] = "persistent",
2825 [STORAGE_NONE
] = "none"
2828 DEFINE_STRING_TABLE_LOOKUP(storage
, Storage
);
2829 DEFINE_CONFIG_PARSE_ENUM(config_parse_storage
, storage
, Storage
, "Failed to parse storage setting");
2831 static const char* const split_mode_table
[_SPLIT_MAX
] = {
2832 [SPLIT_LOGIN
] = "login",
2833 [SPLIT_UID
] = "uid",
2834 [SPLIT_NONE
] = "none",
2837 DEFINE_STRING_TABLE_LOOKUP(split_mode
, SplitMode
);
2838 DEFINE_CONFIG_PARSE_ENUM(config_parse_split_mode
, split_mode
, SplitMode
, "Failed to parse split mode setting");
2840 int config_parse_line_max(
2842 const char *filename
,
2844 const char *section
,
2845 unsigned section_line
,
2852 size_t *sz
= ASSERT_PTR(data
);
2859 if (isempty(rvalue
))
2860 /* Empty assignment means default */
2861 *sz
= DEFAULT_LINE_MAX
;
2865 r
= parse_size(rvalue
, 1024, &v
);
2867 log_syntax(unit
, LOG_WARNING
, filename
, line
, r
, "Failed to parse LineMax= value, ignoring: %s", rvalue
);
2872 /* Why specify 79 here as minimum line length? Simply, because the most common traditional
2873 * terminal size is 80ch, and it might make sense to break one character before the natural
2874 * line break would occur on that. */
2875 log_syntax(unit
, LOG_WARNING
, filename
, line
, 0, "LineMax= too small, clamping to 79: %s", rvalue
);
2877 } else if (v
> (uint64_t) (SSIZE_MAX
-1)) {
2878 /* So, why specify SSIZE_MAX-1 here? Because that's one below the largest size value read()
2879 * can return, and we need one extra byte for the trailing NUL byte. Of course IRL such large
2880 * memory allocations will fail anyway, hence this limit is mostly theoretical anyway, as we'll
2881 * fail much earlier anyway. */
2882 log_syntax(unit
, LOG_WARNING
, filename
, line
, 0, "LineMax= too large, clamping to %" PRIu64
": %s", (uint64_t) (SSIZE_MAX
-1), rvalue
);
2891 int config_parse_compress(
2893 const char *filename
,
2895 const char *section
,
2896 unsigned section_line
,
2903 JournalCompressOptions
* compress
= data
;
2906 if (isempty(rvalue
)) {
2907 compress
->enabled
= true;
2908 compress
->threshold_bytes
= UINT64_MAX
;
2909 } else if (streq(rvalue
, "1")) {
2910 log_syntax(unit
, LOG_WARNING
, filename
, line
, 0,
2911 "Compress= ambiguously specified as 1, enabling compression with default threshold");
2912 compress
->enabled
= true;
2913 } else if (streq(rvalue
, "0")) {
2914 log_syntax(unit
, LOG_WARNING
, filename
, line
, 0,
2915 "Compress= ambiguously specified as 0, disabling compression");
2916 compress
->enabled
= false;
2918 r
= parse_boolean(rvalue
);
2920 r
= parse_size(rvalue
, 1024, &compress
->threshold_bytes
);
2922 log_syntax(unit
, LOG_WARNING
, filename
, line
, r
,
2923 "Failed to parse Compress= value, ignoring: %s", rvalue
);
2925 compress
->enabled
= true;
2927 compress
->enabled
= r
;