← Back to team overview

debcrafters-packages team mailing list archive

[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