test: don't redirect stdout/stderr to console
authorFrantisek Sumsal <frantisek@sumsal.cz>
Tue, 21 Nov 2023 08:37:21 +0000 (09:37 +0100)
committerFrantisek Sumsal <frantisek@sumsal.cz>
Fri, 24 Nov 2023 17:00:07 +0000 (18:00 +0100)
commitfa6f37c04391d0103c95e24813ad345c2d5c4b67
treedcf0c40a615c22eeec60ec5bbbc835d9d0350111
parentc5035a30e290ca602c01e41056225b9475fab399
test: don't redirect stdout/stderr to console

Turns out that redirecting a lot of output to the console can have some
funny effects, like random kernel soft lockups. I spotted this in
various CIs, but it remained almost entirely hidden thanks to
`softlockup_panic=1`, until 1a36d2672f which introduced a couple of
tests that log quite a lot in a short amount of time. This, in
combination with newer kernel version, which, for some reason, seem to
be more susceptible to such soft lockups, made the Arch Linux jobs soft
lockup quite a lot, see [0].

While debugging this I also noticed that runs which don't redirect
stdout/stderr to the console are noticeably faster, e.g.:

    # TEST-71 nspawn + QEMU (KVM), StandardOutput=journal+console
    Elapsed (wall clock) time (h:mm:ss or m:ss): 0:24.64
    # TEST-71 nspawn + QEMU (KVM), StandardOutput=journal
    Elapsed (wall clock) time (h:mm:ss or m:ss): 0:17.95

    # TEST-71 nspawn + QEMU, StandardOutput=journal+console
    Elapsed (wall clock) time (h:mm:ss or m:ss): 2:04.70
    # TEST-71 nspawn + QEMU, StandardOutput=journal
    Elapsed (wall clock) time (h:mm:ss or m:ss): 1:44.48

    # TEST-04 QEMU, StandardOutput=journal+console
    Elapsed (wall clock) time (h:mm:ss or m:ss): 4:22.70
    # TEST-04 QEMU, StandardOutput=console
    Elapsed (wall clock) time (h:mm:ss or m:ss): 5:04.67

Given all this, let's effectively revert ba7abf79a5, and dump the
testsuite-related journal messages only after the test finishes, so they
don't go through the slow console.

Resolves: systemd/systemd-centos-ci#660

[0] https://github.com/systemd/systemd-centos-ci/issues/660
test/test-functions