mkosi patches up /etc/os-release to add local IDs and fixup certain
issues, so when tests patch /usr/lib/ on the fly, copy to the version in
/etc/ too to avoid test failures when querying
6370s 10/98 systemd:integration-tests / TEST-07-PID1 FAIL 31.03s exit
status 1
6370s 25/98 systemd:integration-tests / TEST-29-PORTABLE FAIL 12.76s
exit status 1
6370s 33/98 systemd:integration-tests / TEST-43-PRIVATEUSER-UNPRIV FAIL
6.57s exit status 1
6370s 37/98 systemd:integration-tests / TEST-50-DISSECT FAIL 16.97s exit
status 1
This is particularly an issue when running these tests on debian unstable,
where mkosi has to fixup os-release to make it valid and avoid further
breakages:
https://github.com/systemd/mkosi/blob/main/mkosi/distributions/debian.py#L234
Should hopefully solve this:
[ 111.084463] systemd[1]: testservice-50k.service: Got notification message from PID 2651: RELOADING=1
[ 111.085980] systemd[1]: testservice-50k.service: Got notification message from PID 2651: MONOTONIC_USEC=111072508
ie, pid1 receives RELOADING=1 and MONOTONIC_USEC= in different messages instead
of a single one, and reload-notify breaks
Follow-up for 3998b30a04
Fixes https://github.com/systemd/systemd/issues/37626
Otherwise, the scope that the nspawn container belonging to may be
removed before the grandchild process of the machined exits and it may
be SIGKILLed.
```
[ 100.829613] systemd-machined[678]: Successfully forked off '(sd-bindmnt)' as PID 2962.
[ 100.833366] systemd-nspawn[2953]: Inner child finished, invoking payload.
[ 100.836111] (sd-bindmnt)[2962]: Skipping PR_SET_MM, as we don't have privileges.
[ 100.836401] (sd-bindmnt)[2962]: Successfully forked off '(sd-bindmnt-inner)' as PID 2964.
[ 100.846498] (sd-bindmnt)[2962]: (sd-bindmnt-inner) terminated by signal KILL.
[ 100.848846] systemd[1]: machine-TEST\x2d13\x2dNSPAWN.machinectl\x2dbind.7ye.scope: cgroup is empty
[ 100.849303] systemd[1]: machine-TEST\x2d13\x2dNSPAWN.machinectl\x2dbind.7ye.scope: Deactivated successfully.
[ 100.849317] systemd[1]: machine-TEST\x2d13\x2dNSPAWN.machinectl\x2dbind.7ye.scope: Changed running -> dead
[ 100.849752] systemd[1]: machine-TEST\x2d13\x2dNSPAWN.machinectl\x2dbind.7ye.scope: Consumed 91ms CPU time, 1.3M memory peak.
[ 100.850399] systemd-machined[678]: (sd-bindmnt) failed with exit status 1.
[ 100.850414] systemd-machined[678]: Child failed.
[ 100.854574] systemd-machined[678]: Failed to mount /tmp/marker-varlink on /tmp/marker-varlink in the namespace of machine 'TEST-13-NSPAWN.machinectl-bind.7ye': Protocol error
```
Hopefully fixes#38434.
- drop unused variables,
- adjust number of partitions, interations, and timeout,
- clear partitions on each test case finished,
- check if unnecessary devlinks are removed,
- several coding style cleanups.
To suppress the following warnings in case check_device_unit() failed e.g.
when the device is already removed:
```
sed: couldn't write 130 items to stdout: Broken pipe
awk: write failure (Broken pipe)
awk: close failed on file "/dev/stdout" (Broken pipe)
```
It seems the failing test in https://github.com/systemd/systemd/issues/37626
is due to MONOTONIC_USEC= being somehow lost. Add a trailing newline when
sending messages with socat, hopefully ensuring it is delivered and read.
- move to TEST-07-PID1, as it is a timer setting,
- rename the timer and service, to emphasize they are for testing
DeferReactivation=,
- use timeout command to wait for the timer being triggered several times,
- stop the timer when not necessary,
- accept 9 seconds as delta, as there are fluctuations.
Fixes the following failure:
```
TEST-74-AUX-UTILS.sh[422]: + last=
TEST-74-AUX-UTILS.sh[422]: + read -r time
TEST-74-AUX-UTILS.sh[422]: + '[' -n '' ']'
TEST-74-AUX-UTILS.sh[422]: + last=1753779616
TEST-74-AUX-UTILS.sh[422]: + read -r time
TEST-74-AUX-UTILS.sh[422]: + '[' -n 1753779616 ']'
TEST-74-AUX-UTILS.sh[422]: + delta=9
TEST-74-AUX-UTILS.sh[422]: + '[' 9 -lt 10 ']'
TEST-74-AUX-UTILS.sh[422]: + echo 'Timer fired too early: 9 < 10'
```
Fixes#38403.
The CI run is failing in the stop command:
```
[ 4841.936906] TEST-71-HOSTNAME.sh[140]: + stop_hostnamed
[ 4841.936906] TEST-71-HOSTNAME.sh[140]: + systemctl stop systemd-hostnamed.service
[ 4845.959747] TEST-71-HOSTNAME.sh[226]: Job for systemd-hostnamed.service canceled.
[ 4846.013286] systemd[1]: TEST-71-HOSTNAME.service: Main process exited, code=exited, status=1/FAILURE
[ 4846.013792] systemd[1]: TEST-71-HOSTNAME.service: Failed with result 'exit-code'.
[ 4846.021821] systemd[1]: Failed to start TEST-71-HOSTNAME.service - TEST-71-HOSTNAME.
```
This happens when we create the stop job, but while we're waiting for
it to finish, something triggers a start of the unit and we lose to competing
start job.
Hopefully fixes#36089.
- use timeout command more,
- use `(! cmd)` rather than `cmd && exit 1`,
- drop unnecessary `|| exit 1`,
- extend timeout to support slow test environment.
Fixes#38395.
Otherwise, the test does not finish until the global timeout is reached.
This is for making the test fail earlier when something spurious happens:
```
[FAILED] Failed to start TEST-23-UNIT-FILE-short-lived.service - Shortlived Unit.
TEST-23-UNIT-FILE.sh[776]: + '[' 0 -eq 0 ']'
TEST-23-UNIT-FILE.sh[776]: + sleep .5
(snip)
58/98 systemd:integration-tests / TEST-23-UNIT-FILE TIMEOUT 1800.52s killed by signal 9 SIGKILL
```
- move scripts from test/units/ to the test specific units directory,
- drop meaningless true from silent-success.service,
- call journalctl from the same bash invocation of echo.
No functional change, just refactoring and preparation for the next
commit.
- wait after kill,
- try --now only once,
- ignore error in reading /proc/$PID/comm when --now is set,
as the process may be already died.
Follow-up for 9e0d0c3fdf.
Hopefully fixes#38352.
For some reasons, kernel or sfdisk once remove the created partitions
and recreated them. And if 'udevadm trigger' triggers devices currently
being removed, the udevd does not receive the triggered events, and the
command stuck.
```
[ 33.150452] TEST-64-UDEV-STORAGE.sh[546]: + sfdisk --wipe=always /dev/md/mdmirpar
[ 33.478336] systemd-udevd[442]: md127: Device is queued (SEQNUM=2163, ACTION=change)
[ 33.480153] kernel: md127: p1 p2 p3
[ 33.483772] systemd-udevd[442]: md127p1: Device is queued (SEQNUM=2164, ACTION=add)
[ 33.483914] systemd-udevd[442]: md127p2: Device is queued (SEQNUM=2165, ACTION=add)
[ 33.484999] systemd-udevd[442]: md127p3: Device is queued (SEQNUM=2166, ACTION=add)
[ 33.485564] systemd-udevd[442]: md127: Received inotify event of watch handle 164.
[ 33.503016] TEST-64-UDEV-STORAGE.sh[546]: + SYSTEMD_LOG_LEVEL=debug
[ 33.503016] TEST-64-UDEV-STORAGE.sh[546]: + timeout 30 udevadm trigger --settle --parent-match /dev/md/mdmirpar
[ 33.485905] systemd-udevd[442]: Successfully forked off '(udev-synth)' as PID 3208.
[ 33.486067] systemd-udevd[442]: md127: Removing watch handle 164.
[ 33.489035] systemd-udevd[442]: md127p1: Device is queued (SEQNUM=2167, ACTION=remove)
[ 33.489048] systemd-udevd[442]: Received inotify event about removal of watch handle 164.
[ 33.489507] systemd-udevd[442]: md127p2: Device is queued (SEQNUM=2168, ACTION=remove)
[ 33.496298] systemd-udevd[442]: md127p3: Device is queued (SEQNUM=2169, ACTION=remove)
[ 33.500628] systemd-udevd[442]: md127: Device is queued (SEQNUM=2170, ACTION=change)
[ 33.502355] systemd-udevd[442]: md127p1: Device is queued (SEQNUM=2171, ACTION=add)
[ 33.509371] TEST-64-UDEV-STORAGE.sh[3211]: md127: Triggered device with action 'change'.
[ 33.509371] TEST-64-UDEV-STORAGE.sh[3211]: md127p1: Triggered device with action 'change'.
[ 33.509371] TEST-64-UDEV-STORAGE.sh[3211]: md127p2: Triggered device with action 'change'.
[ 33.512532] systemd-udevd[442]: md127: Device is queued (SEQNUM=2172, ACTION=change, UUID=a0b75692-08ad-428a-859b-9ef8772874d7)
[ 33.512666] systemd-udevd[442]: md127p1: Device is queued (SEQNUM=2173, ACTION=change, UUID=4cd75a91-aa5b-4678-878c-0420b6c2e1e9)
[ 33.512796] systemd-udevd[442]: md127p2: Device is queued (SEQNUM=2174, ACTION=add)
[ 33.512910] systemd-udevd[442]: md127p3: Device is queued (SEQNUM=2175, ACTION=add)
[ 33.531834] TEST-64-UDEV-STORAGE.sh[3211]: md127: Got uevent without UUID, ignoring: No such file or directory
[ 33.553563] TEST-64-UDEV-STORAGE.sh[3211]: md127p1: Got uevent without UUID, ignoring: No such file or directory
[ 33.561262] TEST-64-UDEV-STORAGE.sh[3211]: md127p2: Got uevent without UUID, ignoring: No such file or directory
[ 33.562468] TEST-64-UDEV-STORAGE.sh[3211]: md127p2: Got uevent without UUID, ignoring: No such file or directory
[ 33.563143] TEST-64-UDEV-STORAGE.sh[3211]: md127p3: Got uevent without UUID, ignoring: No such file or directory
[ 33.564174] TEST-64-UDEV-STORAGE.sh[3211]: md127p1: Got uevent without UUID, ignoring: No such file or directory
[ 33.567614] TEST-64-UDEV-STORAGE.sh[3211]: md127p3: Got uevent without UUID, ignoring: No such file or directory
[ 33.597750] TEST-64-UDEV-STORAGE.sh[3211]: md127: Got uevent without UUID, ignoring: No such file or directory
[ 33.623522] TEST-64-UDEV-STORAGE.sh[3211]: md127p1: Got uevent without UUID, ignoring: No such file or directory
[ 33.676268] TEST-64-UDEV-STORAGE.sh[3211]: md127p3: Got uevent without UUID, ignoring: No such file or directory
[ 33.686088] TEST-64-UDEV-STORAGE.sh[3211]: md127p2: Got uevent without UUID, ignoring: No such file or directory
```
Let's wait for partition devices being actually created, and wait for
all queued events being processed. Then, call 'udevadm trigger'.
When a device is mounted with userspace options such as _netdev, even when the mount event source is
triggered, only /proc/self/mountinfo may be updated, and /run/mount/utab may not be updated yet.
Hence, the mount unit may be created/updated without the userspace options. In that case, the mount
event source will be retriggered when /run/mount/utab is updated, and the mount unit will be updated
again with the userspace options. Typically, the window between the two calls is very short, but when
the mount event source is ratelimited after the first event, processing the second event may be delayed
about 1 secound. Hence, here we need to wait for a while.
By adding a debugging logs in mount_setup_unit(), the userspace mount is
not obtained in the first event, and the second event is delayed by the ratelimit.
```
[ 20.023086] H TEST-10-MOUNT.sh[446]: + mount -t ext4 -o _netdev /dev/loop1p1 /tmp/deptest
[ 20.026255] H kernel: EXT4-fs (loop1p1): mounted filesystem c1fa00ea-2ba8-46b2-9002-2ac997f4cda9 r/w with ordered data mode. Quota mode: none.
[ 20.026537] H TEST-10-MOUNT.sh[446]: + timeout 10 bash -c 'until systemctl -q is-active tmp-deptest.mount; do sleep .1; done'
[ 20.032293] H systemd[1]: tmp-deptest.mount: mount_setup_unit: proc: yes, netdev: no
[ 20.035978] H systemd[1]: Unit blockdev@dev-loop1p1.target has alias blockdev@.target.
[ 20.039765] H systemd[1]: tmp-deptest.mount: Changed dead -> mounted
[ 20.046598] H systemd[1]: Event source 0x7c73093e05e0 (mount-monitor-dispatch) entered rate limit state.
```
Hopefully fixes#32712.
Luca Boccassi
Yu Watanabe
Luca Boccassi
Zbigniew Jędrzejewski-Szmek