1
0
mirror of https://github.com/systemd/systemd.git synced 2024-12-25 01:34:28 +03:00
systemd/test/units/TEST-04-JOURNAL.invocation.sh
Yu Watanabe 22862288c8 test: sync journal after all invocations finished
Otherwise, several messages for the last invocation have not been
stored to journal yet.

Hopefully fixes the following race:
===
[  603.037765] H systemd-run[10503]: Running as unit: invocation-id-test-26448.service; invocation ID: 1a49edeb05a641aaa2def72411134822
[  603.099587] H bash[10504]: invocation 10 1a49edeb05a641aaa2def72411134822
[  603.212069] H systemd[1]: invocation-id-test-26448.service: Deactivated successfully.
[  603.225092] H systemd-run[10503]: Finished with result: success
[  603.225163] H TEST-04-JOURNAL.sh[10506]: + journalctl --list-invocation -u invocation-id-test-26448.service
[  603.225318] H systemd-run[10503]: Main processes terminated with: code=exited, status=0/SUCCESS
[  603.225357] H TEST-04-JOURNAL.sh[10507]: + tee /tmp/tmp.UzSmYamXyg/10
[  603.225357] H TEST-04-JOURNAL.sh[10507]: IDX INVOCATION ID                    FIRST ENTRY                 LAST ENTRY
[  603.225357] H TEST-04-JOURNAL.sh[10507]:  -9 d6efabb546014027b6bd7ee3a78386d6 Wed 2024-08-14 22:12:16 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225357] H TEST-04-JOURNAL.sh[10507]:  -8 3e402b81c28d4a8fa2c5e8e31dffd9ee Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225357] H TEST-04-JOURNAL.sh[10507]:  -7 5ebd0ba07d4f4f52bc84275f55a3ee2e Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225357] H TEST-04-JOURNAL.sh[10507]:  -6 bc53c49d6ce24bb7acd438c3e61cfb23 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225357] H TEST-04-JOURNAL.sh[10507]:  -5 24680907919e4839a75378117bb5a816 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225357] H TEST-04-JOURNAL.sh[10507]:  -4 ec364ed7673c4a1fa22929f95ce7047b Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225357] H TEST-04-JOURNAL.sh[10507]:  -3 2e8a4dea43044d1a9faf922f7a2f3d42 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225357] H TEST-04-JOURNAL.sh[10507]:  -2 ac610b6e6c9c4a29bf8947890685478b Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225357] H TEST-04-JOURNAL.sh[10507]:  -1 9b7d52c3620948f9831e323910f605f5 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225357] H TEST-04-JOURNAL.sh[10507]:   0 1a49edeb05a641aaa2def72411134822 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.225823] H systemd-run[10503]: Service runtime: 174ms
[  603.225866] H TEST-04-JOURNAL.sh[10508]: + journalctl --list-invocation -u invocation-id-test-26448.service --reverse
[  603.226110] H systemd-run[10503]: CPU time consumed: 12ms
[  603.226142] H TEST-04-JOURNAL.sh[10509]: + tee /tmp/tmp.UzSmYamXyg/10-r
[  603.226378] H systemd-run[10503]: Memory peak: 1.4M (swap: 0B)
[  603.230161] H TEST-04-JOURNAL.sh[10509]: IDX INVOCATION ID                    FIRST ENTRY                 LAST ENTRY
[  603.230161] H TEST-04-JOURNAL.sh[10509]:   0 1a49edeb05a641aaa2def72411134822 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:18 UTC
[  603.230161] H TEST-04-JOURNAL.sh[10509]:  -1 9b7d52c3620948f9831e323910f605f5 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.230161] H TEST-04-JOURNAL.sh[10509]:  -2 ac610b6e6c9c4a29bf8947890685478b Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.230161] H TEST-04-JOURNAL.sh[10509]:  -3 2e8a4dea43044d1a9faf922f7a2f3d42 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.230161] H TEST-04-JOURNAL.sh[10509]:  -4 ec364ed7673c4a1fa22929f95ce7047b Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.230161] H TEST-04-JOURNAL.sh[10509]:  -5 24680907919e4839a75378117bb5a816 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.230161] H TEST-04-JOURNAL.sh[10509]:  -6 bc53c49d6ce24bb7acd438c3e61cfb23 Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.230161] H TEST-04-JOURNAL.sh[10509]:  -7 5ebd0ba07d4f4f52bc84275f55a3ee2e Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.230161] H TEST-04-JOURNAL.sh[10509]:  -8 3e402b81c28d4a8fa2c5e8e31dffd9ee Wed 2024-08-14 22:12:17 UTC Wed 2024-08-14 22:12:17 UTC
[  603.230161] H TEST-04-JOURNAL.sh[10509]:  -9 d6efabb546014027b6bd7ee3a78386d6 Wed 2024-08-14 22:12:16 UTC Wed 2024-08-14 22:12:17 UTC
===
2024-08-15 18:52:38 +09:00

72 lines
3.3 KiB
Bash
Executable File

#!/usr/bin/env bash
# SPDX-License-Identifier: LGPL-2.1-or-later
# shellcheck disable=SC2002
set -eux
set -o pipefail
# shellcheck source=test/units/util.sh
. "$(dirname "$0")"/util.sh
SERVICE_NAME=invocation-id-test-"$RANDOM".service
TMP_DIR=$(mktemp -d)
# FIXME: if the maximum log level of PID1 is debug, then journal entries of
# service stdout will not contain _SYSTEMD_INVOCATION_ID field.
SAVED_LOG_LEVEL=$(systemctl log-level)
systemctl log-level info
# Note, if the service exits extremely fast, journald cannot find the source of the
# stream. Hence, we need to call 'journalctl --sync' before service exits.
for i in {1..10}; do
systemd-run --wait -u "$SERVICE_NAME" bash -c "echo invocation ${i} \$INVOCATION_ID; journalctl --sync"
done
# Sync journal again here to ensure the following message is stored to journal.
# systemd[1]: invocation-id-test-26448.service: Deactivated successfully.
journalctl --sync
journalctl --list-invocation -u "$SERVICE_NAME" | tee "$TMP_DIR"/10
journalctl --list-invocation -u "$SERVICE_NAME" --reverse | tee "$TMP_DIR"/10-r
journalctl --list-invocation -u "$SERVICE_NAME" -n +10 | tee "$TMP_DIR"/p10
journalctl --list-invocation -u "$SERVICE_NAME" -n +10 --reverse | tee "$TMP_DIR"/p10-r
journalctl --list-invocation -u "$SERVICE_NAME" -n 5 | tee "$TMP_DIR"/5
journalctl --list-invocation -u "$SERVICE_NAME" -n 5 --reverse | tee "$TMP_DIR"/5-r
journalctl --list-invocation -u "$SERVICE_NAME" -n +5 | tee "$TMP_DIR"/p5
journalctl --list-invocation -u "$SERVICE_NAME" -n +5 --reverse | tee "$TMP_DIR"/p5-r
[[ $(cat "$TMP_DIR"/10 | wc -l) == 11 ]]
[[ $(cat "$TMP_DIR"/10-r | wc -l) == 11 ]]
[[ $(cat "$TMP_DIR"/p10 | wc -l) == 11 ]]
[[ $(cat "$TMP_DIR"/p10-r | wc -l) == 11 ]]
[[ $(cat "$TMP_DIR"/5 | wc -l) == 6 ]]
[[ $(cat "$TMP_DIR"/5-r | wc -l) == 6 ]]
[[ $(cat "$TMP_DIR"/p5 | wc -l) == 6 ]]
[[ $(cat "$TMP_DIR"/p5-r | wc -l) == 6 ]]
diff <(tail -n 10 "$TMP_DIR"/10 | tac) <(tail -n 10 "$TMP_DIR"/10-r)
diff <(tail -n 5 "$TMP_DIR"/10) <(tail -n 5 "$TMP_DIR"/5)
diff <(tail -n 5 "$TMP_DIR"/10 | tac) <(tail -n 5 "$TMP_DIR"/5-r)
diff <(tail -n 10 "$TMP_DIR"/p10 | tac) <(tail -n 10 "$TMP_DIR"/p10-r)
diff <(tail -n 10 "$TMP_DIR"/p10 | head -n 5) <(tail -n 5 "$TMP_DIR"/p5)
diff <(tail -n 10 "$TMP_DIR"/p10 | head -n 5 | tac) <(tail -n 5 "$TMP_DIR"/p5-r)
tail -n 10 "$TMP_DIR"/10 |
while read -r idx invocation _; do
i="$(( idx + 10 ))"
assert_in "invocation ${i} ${invocation}" "$(journalctl --no-hostname -n 1 -t bash --invocation="${i}" -u "$SERVICE_NAME")"
assert_in "invocation ${i} ${invocation}" "$(journalctl --no-hostname -n 1 -t bash --invocation="${idx}" -u "$SERVICE_NAME")"
assert_in "invocation ${i} ${invocation}" "$(journalctl --no-hostname -n 1 -t bash --invocation="${invocation}")"
done
tail -n 10 "$TMP_DIR"/p10 |
while read -r i invocation _; do
idx="$(( i - 10 ))"
assert_in "invocation ${i} ${invocation}" "$(journalctl --no-hostname -n 1 -t bash --invocation="${i}" -u "$SERVICE_NAME")"
assert_in "invocation ${i} ${invocation}" "$(journalctl --no-hostname -n 1 -t bash --invocation="${idx}" -u "$SERVICE_NAME")"
assert_in "invocation ${i} ${invocation}" "$(journalctl --no-hostname -n 1 -t bash --invocation="${invocation}")"
done
# Restore the log level.
systemctl log-level "$SAVED_LOG_LEVEL"