debcrafters-packages team mailing list archive
-
debcrafters-packages team
-
Mailing list archive
-
Message #03792
[Bug 2116460] [NEW] systemd: TEST-50-DISSECT autopkgtest failure
Public bug reported:
In the current version of systemd, the TEST-50-DISSECT test is failing
with:
3453s 34/95 systemd:integration-tests / TEST-50-DISSECT FAIL 13.66s exit status 1
3453s >>> MSAN_OPTIONS=halt_on_error=1:abort_on_error=1:print_summary=1:print_stacktrace=1 ASAN_OPTIONS=halt_on_error=1:abort_on_error=1:print_summary=1 UBSAN_OPTIONS=halt_on_error=1:abort_on_error=1:print_summary=1:print_stacktrace=1 MESON_TEST_ITERATION=1 MALLOC_PERTURB_=31 /tmp/autopkgtest.qabzQf/build.s2m/src/test/integration-tests/integration-test-wrapper.py --meson-source-dir /tmp/autopkgtest.qabzQf/build.s2m/src --meson-build-dir /var/tmp/integration-tests.h2F3OKYBs0/btrfs/build --name TEST-50-DISSECT --storage volatile --firmware linux-noinitrd --exit-code 123 --coredump-exclude-regex '' --sanitizer-exclude-regex '' --unit TEST-50-DISSECT.service --vm --mkosi /tmp/autopkgtest.qabzQf/autopkgtest_tmp/mkosi/bin/mkosi --
3453s ――――――――――――――――――――――――――――――――――――― ✀ ―――――――――――――――――――――――――――――――――――――
3453s Listing only the last 100 lines from a long log.
3453s [ 10.761729] TEST-50-DISSECT.sh[780]: Uevent not generated! Calling udev_complete internally to avoid process lock-up.
3453s [ 10.762054] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4df4a0 (semid 18) decremented to 1
3453s [ 10.762210] TEST-50-DISSECT.sh[780]: DM create task failed, dm_task errno: -126.
3453s [ 10.762416] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4df4a0 (semid 18) decremented to 0
3453s [ 10.762589] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4df4a0 (semid 18) waiting for zero
3453s [ 10.762772] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4df4a0 (semid 18) destroyed
3453s [ 10.763054] TEST-50-DISSECT.sh[780]: Requesting kernel key cryptsetup:625b20e6-0411-4d1d-b6b1-03f26a9d11bc-4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity (type user) for unlink from thread keyring.
3453s [ 10.763337] TEST-50-DISSECT.sh[780]: Unlinking volume key (id: 553315911) from thread keyring.
3453s [ 10.763543] TEST-50-DISSECT.sh[780]: Validation of dm-verity signature failed via the kernel, trying userspace validation instead: Required key not available
3453s [ 10.763722] TEST-50-DISSECT.sh[780]: Found container virtualization none.
3453s [ 10.764742] TEST-50-DISSECT.sh[780]: Userspace PKCS#7 validation succeeded.
3453s [ 10.764912] TEST-50-DISSECT.sh[780]: Activating volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [keyslot -1] using key.
3453s [ 10.765207] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.765432] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.765621] TEST-50-DISSECT.sh[780]: Verifying VERITY device using hash sha256.
3453s [ 10.765859] TEST-50-DISSECT.sh[780]: Activating VERITY device 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity using hash sha256.
3453s [ 10.766144] TEST-50-DISSECT.sh[780]: Calculated device size is 58000 sectors (RO), offset 0.
3453s [ 10.766353] TEST-50-DISSECT.sh[780]: DM-UUID is CRYPT-VERITY-625b20e604114d1db6b103f26a9d11bc-4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity
3453s [ 10.766535] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) created
3453s [ 10.766670] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) incremented to 1
3453s [ 10.766907] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) incremented to 2
3453s [ 10.767208] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) assigned to CREATE task(0) with flags DISABLE_LIBRARY_FALLBACK (0x20)
3453s [ 10.767454] TEST-50-DISSECT.sh[780]: dm create 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity CRYPT-VERITY-625b20e604114d1db6b103f26a9d11bc-4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush ] [16384] (*1)
3453s [ 10.767643] TEST-50-DISSECT.sh[780]: dm reload (252:0) [ opencount flush readonly securedata ] [16384] (*1)
3453s [ 10.767863] TEST-50-DISSECT.sh[780]: dm resume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush readonly securedata ] [16384] (*1)
3453s [ 10.768124] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: Stacking NODE_ADD (252,0) 0:6 0660 [trust_udev]
3453s [ 10.768337] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: Stacking NODE_READ_AHEAD 256 (flags=1)
3453s [ 10.768543] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) decremented to 1
3453s [ 10.768679] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) waiting for zero
3453s [ 10.842985] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) destroyed
3453s [ 10.843436] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: Skipping NODE_ADD (252,0) 0:6 0660 [trust_udev]
3453s [ 10.843552] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: Processing NODE_READ_AHEAD 256 (flags=1)
3453s [ 10.843722] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity (252:0): read ahead is 256
3453s [ 10.844083] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: retaining kernel read ahead of 256 (requested 256)
3453s [ 10.844308] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.844463] TEST-50-DISSECT.sh[780]: Verity volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity status is V.
3453s [ 10.844671] TEST-50-DISSECT.sh[780]: Probed fstype 'squashfs' on partition /dev/mapper/4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity.
3453s [ 10.844872] TEST-50-DISSECT.sh[780]: Mounting /proc/self/fd/10 (squashfs) on /run/systemd/dissect-root (MS_RDONLY|MS_NODEV "")...
3453s [ 10.846333] TEST-50-DISSECT.sh[780]: Deactivating volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity.
3453s [ 10.846543] TEST-50-DISSECT.sh[780]: Allocating crypt device context by device 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity.
3453s [ 10.846748] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.846950] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.847212] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.847386] TEST-50-DISSECT.sh[780]: dm table 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush securedata ] [16384] (*1)
3453s [ 10.847609] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop0 with direct-io.
3453s [ 10.847754] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.847959] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.848231] TEST-50-DISSECT.sh[780]: Verity volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity status is V.
3453s [ 10.848435] TEST-50-DISSECT.sh[780]: Allocating context for crypt device /dev/loop0.
3453s [ 10.848619] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop0 with direct-io.
3453s [ 10.848865] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.849084] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.849199] TEST-50-DISSECT.sh[780]: dm table 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush securedata ] [16384] (*1)
3453s [ 10.849453] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop0 with direct-io.
3453s [ 10.849636] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.849860] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop7 with direct-io.
3453s [ 10.850096] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.850307] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.850519] TEST-50-DISSECT.sh[780]: Verity volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity status is V.
3453s [ 10.850619] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.850877] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.851098] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.851308] TEST-50-DISSECT.sh[780]: dm table 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush securedata ] [16384] (*1)
3453s [ 10.851434] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop0 with direct-io.
3453s [ 10.851641] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.851883] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.852150] TEST-50-DISSECT.sh[780]: Verity volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity status is V.
3453s [ 10.852268] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.852545] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.852733] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) created
3453s [ 10.852919] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) incremented to 1
3453s [ 10.853165] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) incremented to 2
3453s [ 10.853398] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) assigned to REMOVE task(2) with flags DISABLE_LIBRARY_FALLBACK (0x20)
3453s [ 10.853500] TEST-50-DISSECT.sh[780]: dm remove 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush retryremove deferredremove ] [16384] (*1)
3453s [ 10.853711] TEST-50-DISSECT.sh[780]: Uevent not generated! Calling udev_complete internally to avoid process lock-up.
3453s [ 10.853921] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) decremented to 1
3453s [ 10.854228] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) decremented to 0
3453s [ 10.854428] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) waiting for zero
3453s [ 10.854607] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) destroyed
3453s [ 10.854793] TEST-50-DISSECT.sh[780]: Releasing crypt device /dev/loop7 context.
3453s [ 11.663720] TEST-50-DISSECT.sh[780]: Releasing crypt device /tmp/TEST-50-IMAGES.LGe/minimal_0.verity context.
3453s [ 11.664131] TEST-50-DISSECT.sh[780]: Releasing device-mapper backend.
3453s [ 11.664402] TEST-50-DISSECT.sh[780]: Closing read only fd for /tmp/TEST-50-IMAGES.LGe/minimal_0.verity.
3453s [ 11.664558] TEST-50-DISSECT.sh[780]: Closed loop /dev/loop7 (/tmp/TEST-50-IMAGES.LGe/minimal_0.verity).
3453s [ 11.667335] TEST-50-DISSECT.sh[425]: + echo 'Subtest /usr/lib/systemd/tests/testdata/units/TEST-50-DISSECT.dissect.sh failed'
3453s [ 11.669251] TEST-50-DISSECT.sh[425]: Subtest /usr/lib/systemd/tests/testdata/units/TEST-50-DISSECT.dissect.sh failed
3453s [ 11.669949] TEST-50-DISSECT.sh[425]: + return 1
3453s [ 11.671463] TEST-50-DISSECT.sh[425]: + at_exit
3453s [ 11.671685] TEST-50-DISSECT.sh[425]: + set +e
3453s [ 11.672120] TEST-50-DISSECT.sh[425]: + [[ -z /tmp/TEST-50-IMAGES.LGe ]]
3453s [ 11.672592] TEST-50-DISSECT.sh[835]: ++ find /tmp/TEST-50-IMAGES.LGe -mindepth 1 -maxdepth 1 -type d
3453s [ 11.673310] TEST-50-DISSECT.sh[425]: + read -r dir
3453s [ 11.673543] TEST-50-DISSECT.sh[425]: + rm -rf /tmp/TEST-50-IMAGES.LGe
3453s [FAILED] Failed to start TEST-50-DISSECT.service - TEST-50-DISSECT.
3453s Finishing after writing 60972 entries
3453s No coredumps found.
3453s Test failed, relevant logs can be viewed with:
3453s
3453s journalctl --file /var/tmp/integration-tests.h2F3OKYBs0/btrfs/build/test/journal/TEST-50-DISSECT-1.journal --no-hostname -o short-monotonic -u TEST-50-DISSECT.service -p info
--
Full log: https://autopkgtest.ubuntu.com/results/autopkgtest-
questing/questing/amd64/s/systemd/20250707_194816_0eab9@/log.gz
** Affects: systemd (Ubuntu)
Importance: High
Assignee: Nick Rosbrook (enr0n)
Status: Confirmed
** Tags: dcr-incoming
--
You received this bug notification because you are a member of
Debcrafters packages, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/2116460
Title:
systemd: TEST-50-DISSECT autopkgtest failure
Status in systemd package in Ubuntu:
Confirmed
Bug description:
In the current version of systemd, the TEST-50-DISSECT test is failing
with:
3453s 34/95 systemd:integration-tests / TEST-50-DISSECT FAIL 13.66s exit status 1
3453s >>> MSAN_OPTIONS=halt_on_error=1:abort_on_error=1:print_summary=1:print_stacktrace=1 ASAN_OPTIONS=halt_on_error=1:abort_on_error=1:print_summary=1 UBSAN_OPTIONS=halt_on_error=1:abort_on_error=1:print_summary=1:print_stacktrace=1 MESON_TEST_ITERATION=1 MALLOC_PERTURB_=31 /tmp/autopkgtest.qabzQf/build.s2m/src/test/integration-tests/integration-test-wrapper.py --meson-source-dir /tmp/autopkgtest.qabzQf/build.s2m/src --meson-build-dir /var/tmp/integration-tests.h2F3OKYBs0/btrfs/build --name TEST-50-DISSECT --storage volatile --firmware linux-noinitrd --exit-code 123 --coredump-exclude-regex '' --sanitizer-exclude-regex '' --unit TEST-50-DISSECT.service --vm --mkosi /tmp/autopkgtest.qabzQf/autopkgtest_tmp/mkosi/bin/mkosi --
3453s ――――――――――――――――――――――――――――――――――――― ✀ ―――――――――――――――――――――――――――――――――――――
3453s Listing only the last 100 lines from a long log.
3453s [ 10.761729] TEST-50-DISSECT.sh[780]: Uevent not generated! Calling udev_complete internally to avoid process lock-up.
3453s [ 10.762054] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4df4a0 (semid 18) decremented to 1
3453s [ 10.762210] TEST-50-DISSECT.sh[780]: DM create task failed, dm_task errno: -126.
3453s [ 10.762416] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4df4a0 (semid 18) decremented to 0
3453s [ 10.762589] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4df4a0 (semid 18) waiting for zero
3453s [ 10.762772] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4df4a0 (semid 18) destroyed
3453s [ 10.763054] TEST-50-DISSECT.sh[780]: Requesting kernel key cryptsetup:625b20e6-0411-4d1d-b6b1-03f26a9d11bc-4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity (type user) for unlink from thread keyring.
3453s [ 10.763337] TEST-50-DISSECT.sh[780]: Unlinking volume key (id: 553315911) from thread keyring.
3453s [ 10.763543] TEST-50-DISSECT.sh[780]: Validation of dm-verity signature failed via the kernel, trying userspace validation instead: Required key not available
3453s [ 10.763722] TEST-50-DISSECT.sh[780]: Found container virtualization none.
3453s [ 10.764742] TEST-50-DISSECT.sh[780]: Userspace PKCS#7 validation succeeded.
3453s [ 10.764912] TEST-50-DISSECT.sh[780]: Activating volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [keyslot -1] using key.
3453s [ 10.765207] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.765432] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.765621] TEST-50-DISSECT.sh[780]: Verifying VERITY device using hash sha256.
3453s [ 10.765859] TEST-50-DISSECT.sh[780]: Activating VERITY device 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity using hash sha256.
3453s [ 10.766144] TEST-50-DISSECT.sh[780]: Calculated device size is 58000 sectors (RO), offset 0.
3453s [ 10.766353] TEST-50-DISSECT.sh[780]: DM-UUID is CRYPT-VERITY-625b20e604114d1db6b103f26a9d11bc-4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity
3453s [ 10.766535] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) created
3453s [ 10.766670] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) incremented to 1
3453s [ 10.766907] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) incremented to 2
3453s [ 10.767208] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) assigned to CREATE task(0) with flags DISABLE_LIBRARY_FALLBACK (0x20)
3453s [ 10.767454] TEST-50-DISSECT.sh[780]: dm create 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity CRYPT-VERITY-625b20e604114d1db6b103f26a9d11bc-4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush ] [16384] (*1)
3453s [ 10.767643] TEST-50-DISSECT.sh[780]: dm reload (252:0) [ opencount flush readonly securedata ] [16384] (*1)
3453s [ 10.767863] TEST-50-DISSECT.sh[780]: dm resume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush readonly securedata ] [16384] (*1)
3453s [ 10.768124] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: Stacking NODE_ADD (252,0) 0:6 0660 [trust_udev]
3453s [ 10.768337] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: Stacking NODE_READ_AHEAD 256 (flags=1)
3453s [ 10.768543] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) decremented to 1
3453s [ 10.768679] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) waiting for zero
3453s [ 10.842985] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d3e63 (semid 19) destroyed
3453s [ 10.843436] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: Skipping NODE_ADD (252,0) 0:6 0660 [trust_udev]
3453s [ 10.843552] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: Processing NODE_READ_AHEAD 256 (flags=1)
3453s [ 10.843722] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity (252:0): read ahead is 256
3453s [ 10.844083] TEST-50-DISSECT.sh[780]: 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity: retaining kernel read ahead of 256 (requested 256)
3453s [ 10.844308] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.844463] TEST-50-DISSECT.sh[780]: Verity volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity status is V.
3453s [ 10.844671] TEST-50-DISSECT.sh[780]: Probed fstype 'squashfs' on partition /dev/mapper/4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity.
3453s [ 10.844872] TEST-50-DISSECT.sh[780]: Mounting /proc/self/fd/10 (squashfs) on /run/systemd/dissect-root (MS_RDONLY|MS_NODEV "")...
3453s [ 10.846333] TEST-50-DISSECT.sh[780]: Deactivating volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity.
3453s [ 10.846543] TEST-50-DISSECT.sh[780]: Allocating crypt device context by device 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity.
3453s [ 10.846748] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.846950] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.847212] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.847386] TEST-50-DISSECT.sh[780]: dm table 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush securedata ] [16384] (*1)
3453s [ 10.847609] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop0 with direct-io.
3453s [ 10.847754] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.847959] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.848231] TEST-50-DISSECT.sh[780]: Verity volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity status is V.
3453s [ 10.848435] TEST-50-DISSECT.sh[780]: Allocating context for crypt device /dev/loop0.
3453s [ 10.848619] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop0 with direct-io.
3453s [ 10.848865] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.849084] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.849199] TEST-50-DISSECT.sh[780]: dm table 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush securedata ] [16384] (*1)
3453s [ 10.849453] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop0 with direct-io.
3453s [ 10.849636] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.849860] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop7 with direct-io.
3453s [ 10.850096] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.850307] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.850519] TEST-50-DISSECT.sh[780]: Verity volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity status is V.
3453s [ 10.850619] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.850877] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.851098] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.851308] TEST-50-DISSECT.sh[780]: dm table 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush securedata ] [16384] (*1)
3453s [ 10.851434] TEST-50-DISSECT.sh[780]: Trying to open and read device /dev/loop0 with direct-io.
3453s [ 10.851641] TEST-50-DISSECT.sh[780]: Direct-io is supported and works.
3453s [ 10.851883] TEST-50-DISSECT.sh[780]: dm status 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount noflush ] [16384] (*1)
3453s [ 10.852150] TEST-50-DISSECT.sh[780]: Verity volume 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity status is V.
3453s [ 10.852268] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.852545] TEST-50-DISSECT.sh[780]: dm versions [ opencount flush ] [16384] (*1)
3453s [ 10.852733] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) created
3453s [ 10.852919] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) incremented to 1
3453s [ 10.853165] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) incremented to 2
3453s [ 10.853398] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) assigned to REMOVE task(2) with flags DISABLE_LIBRARY_FALLBACK (0x20)
3453s [ 10.853500] TEST-50-DISSECT.sh[780]: dm remove 4b93597ec52a2cbbdab931253553b4eceae30bd844ea369a390298126bb53aa8-verity [ opencount flush retryremove deferredremove ] [16384] (*1)
3453s [ 10.853711] TEST-50-DISSECT.sh[780]: Uevent not generated! Calling udev_complete internally to avoid process lock-up.
3453s [ 10.853921] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) decremented to 1
3453s [ 10.854228] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) decremented to 0
3453s [ 10.854428] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) waiting for zero
3453s [ 10.854607] TEST-50-DISSECT.sh[780]: Udev cookie 0xd4d6930 (semid 20) destroyed
3453s [ 10.854793] TEST-50-DISSECT.sh[780]: Releasing crypt device /dev/loop7 context.
3453s [ 11.663720] TEST-50-DISSECT.sh[780]: Releasing crypt device /tmp/TEST-50-IMAGES.LGe/minimal_0.verity context.
3453s [ 11.664131] TEST-50-DISSECT.sh[780]: Releasing device-mapper backend.
3453s [ 11.664402] TEST-50-DISSECT.sh[780]: Closing read only fd for /tmp/TEST-50-IMAGES.LGe/minimal_0.verity.
3453s [ 11.664558] TEST-50-DISSECT.sh[780]: Closed loop /dev/loop7 (/tmp/TEST-50-IMAGES.LGe/minimal_0.verity).
3453s [ 11.667335] TEST-50-DISSECT.sh[425]: + echo 'Subtest /usr/lib/systemd/tests/testdata/units/TEST-50-DISSECT.dissect.sh failed'
3453s [ 11.669251] TEST-50-DISSECT.sh[425]: Subtest /usr/lib/systemd/tests/testdata/units/TEST-50-DISSECT.dissect.sh failed
3453s [ 11.669949] TEST-50-DISSECT.sh[425]: + return 1
3453s [ 11.671463] TEST-50-DISSECT.sh[425]: + at_exit
3453s [ 11.671685] TEST-50-DISSECT.sh[425]: + set +e
3453s [ 11.672120] TEST-50-DISSECT.sh[425]: + [[ -z /tmp/TEST-50-IMAGES.LGe ]]
3453s [ 11.672592] TEST-50-DISSECT.sh[835]: ++ find /tmp/TEST-50-IMAGES.LGe -mindepth 1 -maxdepth 1 -type d
3453s [ 11.673310] TEST-50-DISSECT.sh[425]: + read -r dir
3453s [ 11.673543] TEST-50-DISSECT.sh[425]: + rm -rf /tmp/TEST-50-IMAGES.LGe
3453s [FAILED] Failed to start TEST-50-DISSECT.service - TEST-50-DISSECT.
3453s Finishing after writing 60972 entries
3453s No coredumps found.
3453s Test failed, relevant logs can be viewed with:
3453s
3453s journalctl --file /var/tmp/integration-tests.h2F3OKYBs0/btrfs/build/test/journal/TEST-50-DISSECT-1.journal --no-hostname -o short-monotonic -u TEST-50-DISSECT.service -p info
--
Full log: https://autopkgtest.ubuntu.com/results/autopkgtest-
questing/questing/amd64/s/systemd/20250707_194816_0eab9@/log.gz
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/2116460/+subscriptions