test: several fixlets for journal related failures (#38308)

Hopefully fixes #37818, #37143, #38287.
This commit is contained in:
Yu Watanabe
2025-07-25 08:03:08 +09:00
committed by GitHub
7 changed files with 247 additions and 320 deletions

View File

@@ -2290,6 +2290,8 @@ void manager_reopen_journals(Manager *m, const JournalConfig *old) {
(void) manager_system_journal_open(m, /* flush_requested = */ false, /* relinquish_requested = */ false);
/* To make the storage related settings applied, vacuum the storage. */
cache_space_invalidate(&m->system_storage.space);
cache_space_invalidate(&m->runtime_storage.space);
manager_vacuum(m, /* verbose = */ false);
}

View File

@@ -5,6 +5,6 @@ Description=Log filtering unit
Type=oneshot
# If the service finishes extremely fast, journald cannot find the source of the
# stream. Hence, we need to call 'journalctl --sync' before service finishes.
ExecStart=sh -c 'echo "Logging from the service, and ~more~ foo bar"; journalctl --sync'
ExecStart=bash -c 'echo "Logging from the service, and ~more~ foo bar"; journalctl --sync'
SyslogLevel=notice
LogLevelMax=info

View File

@@ -1,316 +0,0 @@
#!/usr/bin/env bash
# SPDX-License-Identifier: LGPL-2.1-or-later
# shellcheck disable=SC2016
set -eux
set -o pipefail
MACHINE_ID="$(</etc/machine-id)"
TEST_MSG_PREFIX="JOURNAL-RELOAD TEST"
SYSLOG_ID="$(systemd-id128 new)"
write_to_journal() {
local rand_val
rand_val=$(head /dev/urandom | tr -dc A-Za-z0-9 | head -c 14)
echo "$TEST_MSG_PREFIX $rand_val" | systemd-cat -t "$SYSLOG_ID"
journalctl --sync
echo "$rand_val"
}
verify_archived_journals() {
local msg="$1"
local journal_path_prefix="$2"
local journal_dir="/$journal_path_prefix/log/journal/$MACHINE_ID"
for journal_file in "$journal_dir"/*; do
filename=$(basename -- "$journal_file")
if [[ "$filename" != "system.journal" ]]; then
if journalctl --file="$journal_file" | grep -q "$msg"; then
echo "Message present in archived journal: $filename"
exit 0
fi
fi
done
exit 1
}
# shellcheck disable=SC2317
verify_journal() {
local msg="$1"
local entry_expected="$2"
local test_name="$3"
local journal_path_prefix="$4"
local path="/$journal_path_prefix/log/journal/$MACHINE_ID/system.journal"
if [ ! -e "$path" ] || ! grep -Fxq "MESSAGE=$TEST_MSG_PREFIX $msg" "$path"; then
if [ "$entry_expected" == true ]; then
echo "$test_name ERROR: Message not present in $journal_path_prefix journal. Checking archived journals..."
if ! verify_archived_journals "$msg" "$journal_path_prefix"; then
echo "$test_name ERROR: Message also not present in archived journals"
cleanup
exit 1
fi
fi
else
if [ "$entry_expected" == false ]; then
echo "$test_name ERROR: Message present in $journal_path_prefix journal"
cleanup
exit 1
fi
fi
}
verify_journals() {
local msg="$1"
local runtime_expected="$2"
local system_expected="$3"
local test_name="$4"
local failed=false
if ! verify_journal "$msg" "$runtime_expected" "$test_name" "run"; then
failed=true
fi
if ! verify_journal "$msg" "$system_expected" "$test_name" "var"; then
failed=true
fi
if [ "$failed" == true ]; then
cleanup
exit 1
fi
}
get_num_archived_journals() {
local journal_path_prefix="$1"
local journal_dir="/$journal_path_prefix/log/journal/$MACHINE_ID/"
num_journal_files=$(find "$journal_dir" -type f -name "*.journal" ! -name "system.journal" | wc -l)
echo "$num_journal_files"
}
cleanup() {
rm /run/systemd/journald.conf.d/reload.conf
journalctl --vacuum-size=1M
systemctl daemon-reload
systemctl reload systemd-journald.service
}
# Start clean slate.
mkdir -p /run/systemd/journald.conf.d
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=persistent
EOF
systemctl daemon-reload
systemctl restart systemd-journald.service
# Add entries in system.
journalctl --flush
rand_val1=$(write_to_journal)
verify_journals "$rand_val1" false true "Confirming test setup after flush."
# Reload journald (persistent->persistent)
systemctl reload systemd-journald.service
# Reload should persist persistent journal.
verify_journals "$rand_val1" false true "Persistent->Persistent System Reload: "
rand_val1=$(write_to_journal)
verify_journals "$rand_val1" false true "Persistent->Persistent System Post-Reload: "
# Add entries in runtime
journalctl --relinquish
rand_val2=$(write_to_journal)
verify_journals "$rand_val2" true false "Confirming test setup after relinquish."
# Reload journald (persistent->persistent)
systemctl reload systemd-journald.service
# System journal entries should stay in system journal, runtime in runtime.
verify_journals "$rand_val1" false true "Persistent->Persistent Runtime Reload 1: "
verify_journals "$rand_val2" true false "Persistent->Persistent Runtime Reload 2: "
# Write new message and confirm it's written to runtime.
rand_val=$(write_to_journal)
verify_journals "$rand_val" true false "Persistent->Persistent New Message After Reload: "
# Flush and confirm that messages are written to system.
journalctl --flush
rand_val=$(write_to_journal)
verify_journals "$rand_val" false true "Persistent->Volatile New Message Before Reload: "
# Test persistent->volatile
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=volatile
EOF
# Confirm old message exists where it was written to (storage->storage).
systemctl reload systemd-journald.service
verify_journals "$rand_val" false true "Persistent->Volatile Reload: "
# Confirm that messages are written to only runtime journal.
rand_val=$(write_to_journal)
verify_journals "$rand_val" true false "Persistent->Volatile New Message After Reload: "
# Test volatile works and logs are NOT getting written to system journal despite flush.
journalctl --flush
rand_val=$(write_to_journal)
verify_journals "$rand_val" true false "Persistent->Volatile New Message After Flush: "
# Test that the new limits (e.g., RuntimeMaxUse) take effect on reload.
# Write 1M of data to runtime journal
max_size=1048656 # (1 * 1024 * 1024) = 1048576, but centos has a different minimum value for some reason.
set +x
dd if=/dev/urandom bs=1M count=5 | base64 | systemd-cat -t "$SYSLOG_ID"
set -x
journalctl --vacuum-size=2M
total_size=$(du -sb "/run/log/journal/$MACHINE_ID" | cut -f1)
if [ "$total_size" -lt "$max_size" ]; then
echo "ERROR: Journal size does not exceed RuntimeMaxUse limit"
cleanup
exit 1
fi
# Reload with RuntimeMaxUse=1M.
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=volatile
RuntimeMaxUse=1M
EOF
# systemctl daemon-reload
systemctl reload systemd-journald.service
sleep 15 # Wait for RuntimeMaxUse change to take effect.
# Confirm that runtime journal size shrunk to <=1M.
total_size=$(du -sb "/run/log/journal/$MACHINE_ID" | cut -f1)
if [ "$total_size" -gt "$max_size" ]; then
echo "ERROR: Journal size exceeds RuntimeMaxUse limit"
cleanup
exit 1
fi
# Prepare for volatile->persistent by getting rid of runtime limit. Otherwise, it will not write.
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=volatile
EOF
systemctl daemon-reload
systemctl reload systemd-journald.service
sleep 15 # Wait for RuntimeMaxUse change to take effect.
journalctl --vacuum-size=1M
sleep 5
rand_val=$(write_to_journal)
verify_journals "$rand_val" true false "Volatile->Persistent New Message Before Reload: "
# Reload volatile->persistent
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=persistent
EOF
systemctl reload systemd-journald.service
# Confirm that previous message is still in runtime journal.
verify_journals "$rand_val" true false "Volatile->Persistent Reload: "
# Confirm that new messages are written to runtime journal.
rand_val=$(write_to_journal)
verify_journals "$rand_val" true false "Volatile->Persistent New Message After Reload: "
# Confirm that flushing writes to system journal.
journalctl --flush
verify_journals "$rand_val" false true "Volatile->Persistent New Message After Flush: "
set +x
dd if=/dev/urandom bs=1M count=5 | base64 | systemd-cat -t "$SYSLOG_ID"
set -x
max_size=$((2 * 1024 * 1024))
total_size=$(du -sb "/var/log/journal/$MACHINE_ID" | cut -f1)
if [ "$total_size" -lt "$max_size" ]; then
echo "ERROR: Journal size does not exceed SystemMaxUse limit"
cleanup
exit 1
fi
# Ensure reloading without limit does not interfere with SystemMaxUse test.
systemctl reload systemd-journald.service
total_size=$(du -sb "/var/log/journal/$MACHINE_ID" | cut -f1)
if [ "$total_size" -lt "$max_size" ]; then
echo "ERROR: Journal size does not exceed SystemMaxUse limit"
cleanup
exit 1
fi
# Write to storage to prepare for SystemMaxFiles test.
journalctl --flush
num_var_journals=$(get_num_archived_journals "var")
limit_var_journals=3
if [ "$num_var_journals" -lt "$limit_var_journals" ]; then
echo "Creating archive files."
for (( i=0; i<=num_var_journals; i++ ))
do
echo "$TEST_MSG_PREFIX" | systemd-cat -t "$SYSLOG_ID"
journalctl --rotate
done
num_var_journals=$(get_num_archived_journals "var")
if [ "$num_var_journals" -lt "$limit_var_journals" ]; then
echo "ERROR: Number of journal files in /var/log/journal/$MACHINE_ID/ is less than $limit_var_journals"
cleanup
exit 1
fi
fi
# Reload with less SystemMaxUse and SystemMaxFiles.
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=persistent
RuntimeMaxUse=2M
SystemMaxUse=2M
SystemMaxFiles=3
EOF
systemctl daemon-reload
systemctl reload systemd-journald.service
# New system journal needs to be created with the new configuration for change to take effect.
journalctl --flush
# Check SystemMaxFiles
num_var_journals=$(get_num_archived_journals "var")
if [ "$num_var_journals" -gt "$limit_var_journals" ]; then
echo "ERROR: Number of journal files in /var/log/journal/$MACHINE_ID/ is greater than $limit_var_journals"
cleanup
exit 1
fi
sleep 15
# Check SystemMaxUse
total_size=$(du -sb "/var/log/journal/$MACHINE_ID" | cut -f1)
if [ "$total_size" -gt "$max_size" ]; then
echo "ERROR: Journal size exceeds SystemMaxUse limit"
cleanup
exit 1
fi
rm /run/systemd/journald.conf.d/reload.conf
journalctl --vacuum-size=1M
systemctl daemon-reload
systemctl reload systemd-journald.service

View File

@@ -0,0 +1,236 @@
#!/usr/bin/env bash
# SPDX-License-Identifier: LGPL-2.1-or-later
# shellcheck disable=SC2016
set -eux
set -o pipefail
# shellcheck source=test/units/util.sh
. "$(dirname "$0")"/util.sh
MACHINE_ID="$(</etc/machine-id)"
SYSLOG_ID="$(systemd-id128 new)"
write_to_journal() {
local service="test-${RANDOM}.service"
systemd-run -q --wait -u "$service" bash -c "echo service=$service invocation=\$INVOCATION_ID; journalctl --sync"
echo "$service"
}
verify_journals() {
local service="${1:?}"
local expected_storage="${2:?}"
local run_expected var_expected
if [[ "$expected_storage" == runtime ]]; then
run_expected=0
var_expected=1
elif [[ "$expected_storage" == persistent ]]; then
run_expected=1
var_expected=0
else
echo "unexpected storage: $expected_storage"
exit 1
fi
assert_rc "$run_expected" journalctl -q -D "/run/log/journal/$MACHINE_ID/" -u "$service" --grep "service=$service"
assert_rc "$var_expected" journalctl -q -D "/var/log/journal/$MACHINE_ID/" -u "$service" --grep "service=$service"
}
get_num_archived_journals() {
local prefix=${1:?}
find "/$prefix/log/journal/$MACHINE_ID/" -type f -name "system@*.journal" | wc -l
}
cleanup() {
set +e
rm -rf /run/systemd/journald.conf.d
systemctl reload systemd-journald.service
}
trap cleanup EXIT ERR INT TERM
mkdir -p /run/systemd/journald.conf.d
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=persistent
EOF
systemctl restart systemd-journald.service
: "Add entries in system."
journalctl --flush
VAL1=$(write_to_journal)
verify_journals "$VAL1" persistent
: "Reload journald (persistent->persistent)"
systemctl reload systemd-journald.service
: "Reload should persist persistent journal."
verify_journals "$VAL1" persistent
: "Add entries in runtime"
journalctl --relinquish
VAL2=$(write_to_journal)
verify_journals "$VAL2" runtime
: "Reload journald after relinquish (persistent->persistent)"
systemctl reload systemd-journald.service
: "System journal entries should stay in system journal, runtime in runtime."
verify_journals "$VAL1" persistent
verify_journals "$VAL2" runtime
: "Write new message and confirm it's written to runtime."
VAL=$(write_to_journal)
verify_journals "$VAL" runtime
: "Flush and confirm that messages are written to system."
journalctl --flush
VAL=$(write_to_journal)
verify_journals "$VAL" persistent
# Test persistent->volatile
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=volatile
EOF
: "Confirm old message exists where it was written to persistent journal."
systemctl reload systemd-journald.service
verify_journals "$VAL" persistent
: "Confirm that new message is written to runtime journal."
VAL=$(write_to_journal)
verify_journals "$VAL" runtime
: "Test volatile works and logs are NOT getting written to system journal despite flush."
journalctl --flush
VAL=$(write_to_journal)
verify_journals "$VAL" runtime
: "Disable compression"
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=volatile
Compress=no
EOF
systemctl reload systemd-journald.service
: "write 2MB of data to runtime journal"
set +x
dd if=/dev/urandom bs=1M count=2 | base64 | systemd-cat -t "$SYSLOG_ID"
set -x
journalctl --sync
journalctl --rotate
ls -l "/run/log/journal/$MACHINE_ID"
max_size=$((1 * 1024 * 1024))
total_size=$(du -sb "/run/log/journal/$MACHINE_ID" | cut -f1)
if (( total_size < max_size )); then
echo "ERROR: runtime journal size is smaller than 1MB."
exit 1
fi
: "Reload with RuntimeMaxUse=1M."
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=volatile
RuntimeMaxUse=1M
EOF
systemctl reload systemd-journald.service
ls -l "/run/log/journal/$MACHINE_ID"
: "Confirm that runtime journal size shrunk to <= 1MB."
total_size=$(du -sb "/run/log/journal/$MACHINE_ID" | cut -f1)
num_archived_journals=$(get_num_archived_journals run)
if (( total_size > max_size )) && (( num_archived_journals > 0 )); then
echo "ERROR: Journal size exceeds RuntimeMaxUse= limit and exists archived journals."
exit 1
fi
: "Write a message to runtime journal"
VAL=$(write_to_journal)
verify_journals "$VAL" runtime
: "Reload volatile->persistent"
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=persistent
EOF
systemctl reload systemd-journald.service
: "Confirm that previous message is still in runtime journal."
verify_journals "$VAL" runtime
: "Confirm that new messages are written to runtime journal."
VAL=$(write_to_journal)
verify_journals "$VAL" runtime
: "Confirm that flushing writes to system journal."
journalctl --flush
verify_journals "$VAL" persistent
: "Disable compression"
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=persistent
Compress=no
EOF
systemctl reload systemd-journald.service
: "Write 2MB of data to volatile journal"
set +x
dd if=/dev/urandom bs=1M count=2 | base64 | systemd-cat -t "$SYSLOG_ID"
set -x
journalctl --sync
max_size=$((1 * 1024 * 1024))
total_size=$(du -sb "/var/log/journal/$MACHINE_ID" | cut -f1)
if (( total_size < max_size )); then
echo "ERROR: volatile journal size is smaller than 1MB."
exit 1
fi
: "Creating archive files."
limit_var_journals=3
for (( i = 0; i < limit_var_journals; i++ )); do
write_to_journal
journalctl --rotate
done
ls -l "/var/log/journal/$MACHINE_ID"
num_archived_journals=$(get_num_archived_journals var)
if (( num_archived_journals < limit_var_journals )); then
echo "ERROR: Number of archived system journal files is ${num_archived_journals} < ${limit_var_journals}."
exit 1
fi
: "Reload with less SystemMaxUse= and SystemMaxFiles=."
cat <<EOF >/run/systemd/journald.conf.d/reload.conf
[Journal]
Storage=persistent
RuntimeMaxUse=2M
SystemMaxUse=1M
SystemMaxFiles=3
EOF
systemctl reload systemd-journald.service
ls -l "/var/log/journal/$MACHINE_ID"
: "Check number of the system journal files"
num_archived_journals=$(get_num_archived_journals var)
if (( num_archived_journals >= limit_var_journals )); then
echo "ERROR: Number of system journal files is ${num_archived_journals} >= ${limit_var_journals}."
exit 1
fi
: "Check the size of the system journal"
total_size=$(du -sb "/var/log/journal/$MACHINE_ID" | cut -f1)
if (( total_size > max_size )) && (( num_archived_journals > 0)); then
echo "ERROR: Journal size exceeds SystemMaxUse limit and there exist archived journals."
exit 1
fi

View File

@@ -14,9 +14,14 @@ systemd-run --wait --uid=nobody \
assert_eq "$(cat /tmp/TEST-07-PID1.prefix-shell.flag)" "a"
rm /tmp/TEST-07-PID1.prefix-shell.flag
# If the service exits too early, journald cannot find the source process of the log message.
# Hence, we cannot use 'journalctl -u' below. Instead, let's use --since=.
journalctl --sync
TS="$(date '+%H:%M:%S')"
systemctl start prefix-shell.service
assert_eq "$(cat /tmp/TEST-07-PID1.prefix-shell.flag)" "YAY!"
journalctl --sync
journalctl -b -u prefix-shell.service --grep "with login shell .*: lvl 101"
journalctl -b -u prefix-shell.service --grep "with normal shell"
journalctl --since "$TS" --grep "with login shell .*: lvl 101"
journalctl --since "$TS" --grep "with normal shell"

View File

@@ -1,4 +1,4 @@
#!/bin/sh
#!/bin/bash
# SPDX-License-Identifier: LGPL-2.1-or-later
mkdir /sys/fs/cgroup/system.slice/delegated-cgroup-filtering.service/the_child