From: Yu Watanabe <watanabe.yu+github@gmail.com>
Date: Sat, 1 Jun 2024 06:54:44 +0000 (+0900)
Subject: test: sync journal in short-living services
X-Git-Tag: v256-rc4~49^2~2
X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=7faf8987edaec4f160c4daa455721dab8f2261d4;p=thirdparty%2Fsystemd.git

test: sync journal in short-living services

This also adjusts LogLevelMax=.

Hopefully, this makes the test much stabler.
---

diff --git a/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/delegated-cgroup-filtering.service b/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/delegated-cgroup-filtering.service
index a12b12ac4a6..7ecd35816da 100644
--- a/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/delegated-cgroup-filtering.service
+++ b/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/delegated-cgroup-filtering.service
@@ -6,3 +6,4 @@ Type=oneshot
 ExecStart=/usr/lib/systemd/tests/testdata/units/delegated_cgroup_filtering_payload.sh
 Delegate=yes
 SyslogLevel=notice
+LogLevelMax=info
diff --git a/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/logs-filtering.service b/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/logs-filtering.service
index a5aba1859c8..4c430058cf1 100644
--- a/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/logs-filtering.service
+++ b/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/logs-filtering.service
@@ -3,5 +3,9 @@ Description=Log filtering unit
 
 [Service]
 Type=oneshot
-ExecStart=sh -c 'echo "Logging from the service, and ~more~ foo bar" && sleep 2'
+ExecStart=sh -c 'echo "Logging from the service, and ~more~ foo bar"'
+# 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=journalctl --sync
 SyslogLevel=notice
+LogLevelMax=info
diff --git a/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/silent-success.service b/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/silent-success.service
index 3d83f87fe07..d4541afa888 100644
--- a/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/silent-success.service
+++ b/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/silent-success.service
@@ -3,5 +3,9 @@
 Description=Silent successful service
 
 [Service]
+Type=oneshot
 LogLevelMax=notice
 ExecStart=/bin/true
+# 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=journalctl --sync
diff --git a/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/verbose-success.service b/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/verbose-success.service
index f4a86fd2b22..004693b282c 100644
--- a/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/verbose-success.service
+++ b/test/TEST-04-JOURNAL/TEST-04-JOURNAL.units/verbose-success.service
@@ -4,8 +4,10 @@ Description=Verbose successful service
 
 [Service]
 Type=oneshot
-# Sleep so that the cgroup is still there when journald processes the log message which is required for
-# journald to add the expected fields to the log message.
-ExecStart=sleep 2
 ExecStart=echo success
-ExecStart=sleep 2
+# 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=journalctl --sync
+# Suppress debugging logs from PID1 or sd-executor. Otherwise, the client context
+# may be outdated when the stream from 'echo' command in the above comes.
+LogLevelMax=info
diff --git a/test/units/TEST-04-JOURNAL.LogFilterPatterns.sh b/test/units/TEST-04-JOURNAL.LogFilterPatterns.sh
index dfa9652ee29..04062bd76f7 100755
--- a/test/units/TEST-04-JOURNAL.LogFilterPatterns.sh
+++ b/test/units/TEST-04-JOURNAL.LogFilterPatterns.sh
@@ -20,9 +20,9 @@ run_service_and_fetch_logs() {
     local unit="${1:?}"
     local start
 
+    journalctl --sync
     start="$(date '+%Y-%m-%d %T.%6N')"
     systemctl start "$unit"
-    journalctl --sync
     journalctl -q -u "$unit" -S "$start" -p notice
 }
 
diff --git a/test/units/TEST-04-JOURNAL.journal.sh b/test/units/TEST-04-JOURNAL.journal.sh
index bb4f66d2c89..bd9f8a5e820 100755
--- a/test/units/TEST-04-JOURNAL.journal.sh
+++ b/test/units/TEST-04-JOURNAL.journal.sh
@@ -104,12 +104,10 @@ diff /tmp/expected /tmp/output
 
 # test that LogLevelMax can also suppress logging about services, not only by services
 systemctl start silent-success
-journalctl --sync
 [[ -z "$(journalctl -b -q -u silent-success.service)" ]]
 
 # Test syslog identifiers exclusion
 systemctl start verbose-success.service
-journalctl --sync
 [[ -n "$(journalctl -b -q -u verbose-success.service -t systemd)" ]]
 [[ -n "$(journalctl -b -q -u verbose-success.service -t echo)" ]]
 [[ -n "$(journalctl -b -q -u verbose-success.service -T systemd)" ]]
@@ -262,8 +260,8 @@ UNIT_NAME="test-cursor-$RANDOM.service"
 CURSOR_FILE="$(mktemp)"
 # Generate some messages we can match against
 journalctl --cursor-file="$CURSOR_FILE" -n1
-systemd-run --unit="$UNIT_NAME" --wait --service-type=exec bash -ec "sleep 2; set -x; echo hello; echo world; set +x; sleep 2"
-journalctl --sync
+systemd-run --unit="$UNIT_NAME" --wait --service-type=exec -p LogLevelMax=info \
+            bash -ec "set -x; echo hello; echo world; set +x; journalctl --sync"
 # --after-cursor= + --unit=
 # The format of the "Starting ..." message depends on StatusUnitFormat=, so match only the beginning
 # which should be enough in this case