diff --git a/src/journal/journald-stream.c b/src/journal/journald-stream.c index 3f6116aa0a8..75552667dad 100644 --- a/src/journal/journald-stream.c +++ b/src/journal/journald-stream.c @@ -123,15 +123,27 @@ static int stdout_stream_save(StdoutStream *s) { if (!s->state_file) { struct stat st; + uint64_t cookie; r = fstat(s->fd, &st); if (r < 0) return log_ratelimit_warning_errno(errno, JOURNAL_LOG_RATELIMIT, "Failed to stat connected stream: %m"); - /* We use device and inode numbers as identifier for the stream */ - r = asprintf(&s->state_file, "%s/streams/%lu:%lu", s->manager->runtime_directory, (unsigned long) st.st_dev, (unsigned long) st.st_ino); + /* Identify the stream by device, inode and socket cookie: socket inode numbers are 32-bit + * and get reused, the cookie never is. Device and inode come first so that older versions + * can still parse the name. */ + r = socket_get_cookie(s->fd, &cookie); if (r < 0) + return log_ratelimit_warning_errno(r, JOURNAL_LOG_RATELIMIT, + "Failed to get cookie of connected stream: %m"); + + s->state_file = asprintf_safe("%s/streams/%lu:%lu:%" PRIu64, + s->manager->runtime_directory, + (unsigned long) st.st_dev, + (unsigned long) st.st_ino, + cookie); + if (!s->state_file) return log_oom(); } @@ -833,6 +845,56 @@ static int stdout_stream_restore(Manager *m, const char *fname, int fd) { return 0; } +static int restore_stream_from_file(Manager *m, DIR *d, const char *path, const char *fname, FDSet *fds, bool with_cookie) { + unsigned long st_dev, st_ino; + uint64_t cookie = 0; + int fd, n, r; + + assert(m); + assert(d); + assert(path); + assert(fname); + /* fds may be NULL if no stream fds were passed in, in which case all state files are removed */ + + /* Older versions named state files without the socket cookie, see stdout_stream_save() */ + n = sscanf(fname, "%lu:%lu:%" SCNu64, &st_dev, &st_ino, &cookie); + if (n != (with_cookie ? 3 : 2)) + return 0; + + FDSET_FOREACH(fd, fds) { + struct stat st; + + if (fstat(fd, &st) < 0) + return log_error_errno(errno, "Failed to stat %s: %m", fname); + + if (!S_ISSOCK(st.st_mode) || st.st_dev != st_dev || st.st_ino != st_ino) + continue; + + /* Socket inode numbers are reused, so match the cookie too if we have one */ + if (with_cookie) { + uint64_t c; + + if (socket_get_cookie(fd, &c) < 0 || c != cookie) + continue; + } + + fdset_remove(fds, fd); + + r = stdout_stream_restore(m, fname, fd); + if (r < 0) + safe_close(fd); + + return 0; + } + + /* No file descriptor? Then let's delete the state file */ + log_debug("Cannot restore stream file %s", fname); + if (unlinkat(dirfd(d), fname, 0) < 0) + log_warning_errno(errno, "Failed to remove %s/%s: %m", path, fname); + + return 0; +} + int manager_restore_streams(Manager *m, FDSet *fds) { _cleanup_closedir_ DIR *d = NULL; const char *path; @@ -847,39 +909,21 @@ int manager_restore_streams(Manager *m, FDSet *fds) { return log_warning_errno(errno, "Failed to enumerate %s: %m", path); } + /* Restore streams from state files with socket cookie first, so that state files named without + * cookie can only take the fds that are left over: socket inode numbers are reused, and the fd of + * a stream with a state file of its own has to stay with that stream. */ FOREACH_DIRENT(de, d, goto fail) { - unsigned long st_dev, st_ino; - bool found = false; - int fd; - - if (sscanf(de->d_name, "%lu:%lu", &st_dev, &st_ino) != 2) - continue; - - FDSET_FOREACH(fd, fds) { - struct stat st; - - if (fstat(fd, &st) < 0) - return log_error_errno(errno, "Failed to stat %s: %m", de->d_name); - - if (S_ISSOCK(st.st_mode) && st.st_dev == st_dev && st.st_ino == st_ino) { - found = true; - break; - } - } - - if (!found) { - /* No file descriptor? Then let's delete the state file */ - log_debug("Cannot restore stream file %s", de->d_name); - if (unlinkat(dirfd(d), de->d_name, 0) < 0) - log_warning_errno(errno, "Failed to remove %s/%s: %m", path, de->d_name); - continue; - } - - fdset_remove(fds, fd); - - r = stdout_stream_restore(m, de->d_name, fd); + r = restore_stream_from_file(m, d, path, de->d_name, fds, /* with_cookie= */ true); if (r < 0) - safe_close(fd); + return r; + } + + rewinddir(d); + + FOREACH_DIRENT(de, d, goto fail) { + r = restore_stream_from_file(m, d, path, de->d_name, fds, /* with_cookie= */ false); + if (r < 0) + return r; } return 0; diff --git a/test/units/TEST-04-JOURNAL.stream-restore.sh b/test/units/TEST-04-JOURNAL.stream-restore.sh new file mode 100755 index 00000000000..2ba222cfaed --- /dev/null +++ b/test/units/TEST-04-JOURNAL.stream-restore.sh @@ -0,0 +1,108 @@ +#!/usr/bin/env bash +# SPDX-License-Identifier: LGPL-2.1-or-later +set -eux +set -o pipefail + +# Check that stdout streams are restored from the right state file on journald restart: state files include +# the socket cookie, state files named without it by older versions are still used, and state files of other +# streams with the same inode number, with or without cookie, are not used. + +STREAMS=/run/systemd/journal/streams + +start_logger() { + local id="${1:?}" + + systemd-run --unit="$id.service" -p SyslogIdentifier="$id" \ + bash -c "i=0; while :; do echo \"$id \$((i++))\"; sleep .2; done" +} + +# Print the state file of the stream with the given identifier, once PID 1 has the stream in its fd store +state_file_of() { + local id="${1:?}" + local f ino + + f="$(timeout 30 bash -c "until grep -lx 'IDENTIFIER=$id' $STREAMS/* 2>/dev/null; do sleep .2; done")" + [[ "$(wc -l <<<"$f")" -eq 1 ]] + + ino="$(basename "$f" | cut -d: -f2)" + for _ in {1..150}; do + if find /proc/1/fd -lname "socket:\[$ino\]" | grep . >/dev/null; then + echo "$f" + return 0 + fi + sleep .2 + done + + return 1 +} + +# Restart journald and wait until new lines matching the given journalctl arguments are logged +restart_and_wait_for_logs() { + local cursor + + # Reset the start-limit counters, as we're going to restart journald a couple of times + systemctl reset-failed systemd-journald.service + systemctl restart systemd-journald + journalctl --sync + cursor="$(journalctl -q "$@" -n 1 -o export | sed -n 's/^__CURSOR=//p')" + [[ -n "$cursor" ]] + + for _ in {1..150}; do + journalctl --sync + if journalctl -q "$@" --after-cursor="$cursor" | grep .; then + return 0 + fi + sleep .2 + done + + return 1 +} + +at_exit() { + systemctl stop stream-restore-cookie.service \ + stream-restore-legacy.service \ + stream-restore-other.service \ + stream-restore-legacy-other.service || : + systemctl reset-failed systemd-journald.service || : +} + +trap at_exit EXIT + +# State files include the socket cookie, and the stream is restored from them with its identifier +start_logger stream-restore-cookie +F="$(state_file_of stream-restore-cookie)" +[[ "$(basename "$F")" =~ ^[0-9]+:[0-9]+:[0-9]+$ ]] +restart_and_wait_for_logs -t stream-restore-cookie +[[ -e "$F" ]] +systemctl stop stream-restore-cookie.service + +# A state file named without cookie, as written by older versions, is used and left as it is +start_logger stream-restore-legacy +F="$(state_file_of stream-restore-legacy)" +mv "$F" "${F%:*}" +restart_and_wait_for_logs -t stream-restore-legacy +grep -x IDENTIFIER=stream-restore-legacy "${F%:*}" +[[ ! -e "$F" ]] +systemctl stop stream-restore-legacy.service + +# A state file with the same inode number but another cookie, i.e. of another stream after the inode number +# was reused, is not used for the stream and removed +start_logger stream-restore-other +F="$(state_file_of stream-restore-other)" +sed 's/^IDENTIFIER=.*/IDENTIFIER=stream-restore-other-bogus/' "$F" >"${F%:*}:1" +restart_and_wait_for_logs -t stream-restore-other +[[ ! -e "${F%:*}:1" ]] +[[ -e "$F" ]] +[[ -z "$(journalctl -q -t stream-restore-other-bogus)" ]] +systemctl stop stream-restore-other.service + +# A state file without cookie with the same inode number, e.g. of a stream from before the upgrade, does not +# take the fd of a stream that has a state file with cookie, and is removed +start_logger stream-restore-legacy-other +F="$(state_file_of stream-restore-legacy-other)" +sed 's/^IDENTIFIER=.*/IDENTIFIER=stream-restore-legacy-other-bogus/' "$F" >"${F%:*}" +restart_and_wait_for_logs -t stream-restore-legacy-other +[[ ! -e "${F%:*}" ]] +[[ -e "$F" ]] +[[ -z "$(journalctl -q -t stream-restore-legacy-other-bogus)" ]] +systemctl stop stream-restore-legacy-other.service