TEST-64-UDEV-STORAGE intermittent fails tracker

[mrc0mmand]

(udevadm) Unknown device "XXX": No such device

Unknown device "/dev/disk/by-id/scsi-360000000000000000e00000000020004": No such device

[   20.914052] testsuite-64.sh[960]: Logging in to [iface: default, target: iqn.2021-09.com.example:iscsi.lvm.test, portal: 127.0.0.1,3260]
[   20.914052] testsuite-64.sh[960]: Login to [iface: default, target: iqn.2021-09.com.example:iscsi.lvm.test, portal: 127.0.0.1,3260] successful.
[   20.914698] testsuite-64.sh[611]: + udevadm settle
[   20.958064] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020002.device: Changed dead -> plugged
[   20.958357] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020002.device: Changed dead -> plugged
[   20.958416] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d2.device: Changed dead -> plugged
[   20.958487] systemd[1]: dev-sdg.device: Changed dead -> plugged
[   20.958543] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:2-block-sdg.device: Changed dead -> plugged
[   20.958598] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=332 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.958652] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=333 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.958703] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=334 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.958763] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=335 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.958850] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=336 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.963663] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020004.device: Changed dead -> plugged
[   20.963753] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d4.device: Changed dead -> plugged
[   20.963857] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020004.device: Changed dead -> plugged
[   20.963916] systemd[1]: dev-sdi.device: Changed dead -> plugged
[   20.963970] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:4-block-sdi.device: Changed dead -> plugged
[   20.964050] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=337 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.964104] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=338 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.964176] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=339 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.964227] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=340 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.964276] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=341 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.969198] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d1.device: Changed dead -> plugged
[   20.969299] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020001.device: Changed dead -> plugged
[   20.969359] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020001.device: Changed dead -> plugged
[   20.969413] systemd[1]: dev-sdf.device: Changed dead -> plugged
[   20.969476] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:1-block-sdf.device: Changed dead -> plugged
[   20.969534] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=342 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.969624] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=343 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.969678] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=344 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.969731] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=345 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.969802] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=346 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.972444] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020003.device: Changed dead -> plugged
[   20.972533] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d3.device: Changed dead -> plugged
[   20.972592] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020003.device: Changed dead -> plugged
[   20.972647] systemd[1]: dev-sdh.device: Changed dead -> plugged
[   20.972711] testsuite-64.sh[611]: + for link in "${expected_symlinks[@]}"
[   20.972711] testsuite-64.sh[611]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-1
[   20.972711] testsuite-64.sh[611]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-1
[   20.972711] testsuite-64.sh[611]: + local ntries=10
[   20.972711] testsuite-64.sh[611]: + local i
[   20.972711] testsuite-64.sh[611]: + (( i = 0 ))
[   20.972711] testsuite-64.sh[611]: + (( i < ntries ))
[   20.972711] testsuite-64.sh[611]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-1
[   20.976686] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:3-block-sdh.device: Changed dead -> plugged
[   20.976816] testsuite-64.sh[611]: + return 0
[   20.976816] testsuite-64.sh[611]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-1
[   20.976816] testsuite-64.sh[611]: + for link in "${expected_symlinks[@]}"
[   20.976816] testsuite-64.sh[611]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-2
[   20.976816] testsuite-64.sh[611]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-2
[   20.976816] testsuite-64.sh[611]: + local ntries=10
[   20.976816] testsuite-64.sh[611]: + local i
[   20.976816] testsuite-64.sh[611]: + (( i = 0 ))
[   20.976816] testsuite-64.sh[611]: + (( i < ntries ))
[   20.976816] testsuite-64.sh[611]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-2
[   20.976816] testsuite-64.sh[611]: + return 0
[   20.976816] testsuite-64.sh[611]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-2
[   20.976816] testsuite-64.sh[611]: + for link in "${expected_symlinks[@]}"
[   20.976816] testsuite-64.sh[611]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-3
[   20.976816] testsuite-64.sh[611]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-3
[   20.976816] testsuite-64.sh[611]: + local ntries=10
[   20.976816] testsuite-64.sh[611]: + local i
[   20.976816] testsuite-64.sh[611]: + (( i = 0 ))
[   20.976816] testsuite-64.sh[611]: + (( i < ntries ))
[   20.976816] testsuite-64.sh[611]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-3
[   20.976816] testsuite-64.sh[611]: + return 0
[   20.976816] testsuite-64.sh[611]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-3
[   20.976816] testsuite-64.sh[611]: + for link in "${expected_symlinks[@]}"
[   20.976816] testsuite-64.sh[611]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-4
[   20.976816] testsuite-64.sh[611]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-4
[   20.976816] testsuite-64.sh[611]: + local ntries=10
[   20.976816] testsuite-64.sh[611]: + local i
[   20.976816] testsuite-64.sh[611]: + (( i = 0 ))
[   20.976816] testsuite-64.sh[611]: + (( i < ntries ))
[   20.976816] testsuite-64.sh[611]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-4
[   20.976816] testsuite-64.sh[611]: + return 0
[   20.976816] testsuite-64.sh[611]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-4
[   20.976816] testsuite-64.sh[611]: + udevadm settle
[   20.991797] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=347 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.991884] testsuite-64.sh[611]: + helper_check_device_symlinks
[   20.992352] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=348 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.992409] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=349 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.992471] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=350 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   20.992532] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=351 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   21.017191] testsuite-64.sh[973]: + set +x
[   21.020029] testsuite-64.sh[973]: /dev/disk/by-label/iscsi_store -> /dev/sdb
[   21.027701] testsuite-64.sh[973]: /dev/disk/by-label/systemd_boot -> /dev/sda1
[   21.034196] testsuite-64.sh[973]: /dev/disk/by-uuid/44b2cf6b-a14b-4bb5-bd22-eb26bd21526c -> /dev/sdb
[   21.040546] testsuite-64.sh[973]: /dev/disk/by-uuid/8d6ddcf9-843c-4f4f-b8d4-680d9f6ce645 -> /dev/sda1
[   21.046871] testsuite-64.sh[973]: /dev/disk/by-partuuid/336dd997-01 -> /dev/sda1
[   21.052901] testsuite-64.sh[973]: /dev/disk/by-partuuid/336dd997-02 -> /dev/sda2
[   21.060489] testsuite-64.sh[973]: /dev/disk/by-id/wwn-0x60000000000000000e00000000020003 -> /dev/sdh
[   21.066900] testsuite-64.sh[973]: /dev/disk/by-id/wwn-0x60000000000000000e00000000020001 -> /dev/sdf
[   21.074507] testsuite-64.sh[973]: /dev/disk/by-id/scsi-360000000000000000e00000000020004 -> /dev/sdi
[   21.079491] testsuite-64.sh[993]: Unknown device "/dev/disk/by-id/scsi-360000000000000000e00000000020004": No such device

Full journal: system.journal.tar.gz

Unknown device "/dev/disk/by-id/wwn-0x60000000000000000e00000000020003": No such device

[   23.402681] testsuite-64.sh[957]: Login to [iface: default, target: iqn.2021-09.com.example:iscsi.lvm.test, portal: 127.0.0.1,3260] successful.
[   23.404052] testsuite-64.sh[610]: + udevadm settle
[   23.426652] kernel: sd 8:0:0:3: [sdh] Attached SCSI disk
[   23.427469] kernel: sd 8:0:0:4: [sdi] Attached SCSI disk
[   23.469831] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d1.device: Changed dead -> plugged
[   23.398145] kernel: sd 8:0:0:2: [sdg] Attached SCSI disk
[   23.402681] testsuite-64.sh[957]: Logging in to [iface: default, target: iqn.2021-09.com.example:iscsi.lvm.test, portal: 127.0.0.1,3260]
[   23.402681] testsuite-64.sh[957]: Login to [iface: default, target: iqn.2021-09.com.example:iscsi.lvm.test, portal: 127.0.0.1,3260] successful.
[   23.404052] testsuite-64.sh[610]: + udevadm settle
[   23.426652] kernel: sd 8:0:0:3: [sdh] Attached SCSI disk
[   23.427469] kernel: sd 8:0:0:4: [sdi] Attached SCSI disk
[   23.469831] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d1.device: Changed dead -> plugged
[   23.470048] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020001.device: Changed dead -> plugged
[   23.470138] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020001.device: Changed dead -> plugged
[   23.470254] systemd[1]: dev-sdf.device: Changed dead -> plugged
[   23.470357] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:1-block-sdf.device: Changed dead -> plugged
[   23.470442] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=307 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.470523] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=308 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.470602] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=309 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.470687] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=310 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.470766] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=311 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.493045] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020002.device: Changed dead -> plugged
[   23.493218] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020002.device: Changed dead -> plugged
[   23.493306] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d2.device: Changed dead -> plugged
[   23.493408] systemd[1]: dev-sdg.device: Changed dead -> plugged
[   23.493490] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:2-block-sdg.device: Changed dead -> plugged
[   23.493575] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=312 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.493655] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=313 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.493740] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=314 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.493819] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=315 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.493895] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=316 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.501349] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020003.device: Changed dead -> plugged
[   23.501491] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d3.device: Changed dead -> plugged
[   23.501603] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020003.device: Changed dead -> plugged
[   23.501688] systemd[1]: dev-sdh.device: Changed dead -> plugged
[   23.501768] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:3-block-sdh.device: Changed dead -> plugged
[   23.501852] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=317 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.501938] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=318 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.502035] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=319 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.502117] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=320 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.502204] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=321 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.509756] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020004.device: Changed dead -> plugged
[   23.509985] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020004.device: Changed dead -> plugged
[   23.510101] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d4.device: Changed dead -> plugged
[   23.510200] systemd[1]: dev-sdi.device: Changed dead -> plugged
[   23.510283] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:4-block-sdi.device: Changed dead -> plugged
[   23.510378] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=322 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.510458] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=323 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.510537] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=324 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.510614] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=325 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.510692] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=326 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   23.510778] systemd[1]: Added job dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020002.device/nop to transaction.
[   23.510858] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020002.device: Installed new job dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020002.device/nop as 436
[   23.510940] systemd[1]: Added job dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020002.device/nop to transaction.
[   23.511035] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020002.device: Installed new job dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020002.device/nop as 437
[   23.511119] systemd[1]: Added job dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d2.device/nop to transaction.
[   23.511222] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d2.device: Installed new job dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d2.device/nop as 438
[   23.511310] systemd[1]: Added job dev-sdg.device/nop to transaction.
[   23.511388] systemd[1]: dev-sdg.device: Installed new job dev-sdg.device/nop as 439
[   23.511469] systemd[1]: Added job sys-devices-platform-host8-session2-target8:0:0-8:0:0:2-block-sdg.device/nop to transaction.
[   23.511546] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:2-block-sdg.device: Installed new job sys-devices-platform-host8-session2-target8:0:0-8:0:0:2-block-sdg.device/nop as 440
[   23.511651] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dhost8_2dsession2_2dtarget8_3a0_3a0_2d8_3a0_3a0_3a2_2dblock_2dsdg_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=327 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.511732] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dhost8_2dsession2_2dtarget8_3a0_3a0_2d8_3a0_3a0_3a2_2dblock_2dsdg_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=328 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.511811] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dsdg_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=329 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.511898] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dsdg_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=330 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.511977] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2dpath_2dip_5cx2d127_2e0_2e0_2e1_3a3260_5cx2discsi_5cx2diqn_2e2021_5cx2d09_2ecom_2eexample_3aiscsi_2elvm_2etest_5cx2dlun_5cx2d2_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=331 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.512091] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2dpath_2dip_5cx2d127_2e0_2e0_2e1_3a3260_5cx2discsi_5cx2diqn_2e2021_5cx2d09_2ecom_2eexample_3aiscsi_2elvm_2etest_5cx2dlun_5cx2d2_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=332 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.512191] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dscsi_5cx2d360000000000000000e00000000020002_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=333 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.512272] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dscsi_5cx2d360000000000000000e00000000020002_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=334 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.512352] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dwwn_5cx2d0x60000000000000000e00000000020002_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=335 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.512431] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dwwn_5cx2d0x60000000000000000e00000000020002_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=336 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.512523] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=337 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   23.512602] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=338 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   23.512679] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=339 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   23.512757] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=340 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   23.512835] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=341 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   23.512919] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020002.device: Job 437 dev-disk-by\x2did-scsi\x2d360000000000000000e00000000020002.device/nop finished, result=done
[   23.513017] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=342 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   23.513098] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020002.device: Job 436 dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000020002.device/nop finished, result=done
[   23.513189] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=343 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   23.513267] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d2.device: Job 438 dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.lvm.test\x2dlun\x2d2.device/nop finished, result=done
[   23.513358] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=344 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   23.513438] testsuite-64.sh[610]: + for link in "${expected_symlinks[@]}"
[   23.513438] testsuite-64.sh[610]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-1
[   23.513438] testsuite-64.sh[610]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-1
[   23.513438] testsuite-64.sh[610]: + local ntries=10
[   23.513438] testsuite-64.sh[610]: + local i
[   23.513438] testsuite-64.sh[610]: + (( i = 0 ))
[   23.515682] systemd[1]: dev-sdg.device: Job 439 dev-sdg.device/nop finished, result=done
[   23.515770] testsuite-64.sh[610]: + (( i < ntries ))
[   23.515770] testsuite-64.sh[610]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-1
[   23.515770] testsuite-64.sh[610]: + return 0
[   23.515770] testsuite-64.sh[610]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-1
[   23.515770] testsuite-64.sh[610]: + for link in "${expected_symlinks[@]}"
[   23.515770] testsuite-64.sh[610]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-2
[   23.515770] testsuite-64.sh[610]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-2
[   23.515770] testsuite-64.sh[610]: + local ntries=10
[   23.515770] testsuite-64.sh[610]: + local i
[   23.515770] testsuite-64.sh[610]: + (( i = 0 ))
[   23.515770] testsuite-64.sh[610]: + (( i < ntries ))
[   23.515770] testsuite-64.sh[610]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-2
[   23.515770] testsuite-64.sh[610]: + return 0
[   23.515770] testsuite-64.sh[610]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-2
[   23.515770] testsuite-64.sh[610]: + for link in "${expected_symlinks[@]}"
[   23.515770] testsuite-64.sh[610]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-3
[   23.515770] testsuite-64.sh[610]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-3
[   23.515770] testsuite-64.sh[610]: + local ntries=10
[   23.515770] testsuite-64.sh[610]: + local i
[   23.515770] testsuite-64.sh[610]: + (( i = 0 ))
[   23.515770] testsuite-64.sh[610]: + (( i < ntries ))
[   23.515770] testsuite-64.sh[610]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-3
[   23.515770] testsuite-64.sh[610]: + return 0
[   23.515770] testsuite-64.sh[610]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-3
[   23.515770] testsuite-64.sh[610]: + for link in "${expected_symlinks[@]}"
[   23.515770] testsuite-64.sh[610]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-4
[   23.515770] testsuite-64.sh[610]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-4
[   23.515770] testsuite-64.sh[610]: + local ntries=10
[   23.515770] testsuite-64.sh[610]: + local i
[   23.515770] testsuite-64.sh[610]: + (( i = 0 ))
[   23.515770] testsuite-64.sh[610]: + (( i < ntries ))
[   23.515770] testsuite-64.sh[610]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-4
[   23.515770] testsuite-64.sh[610]: + return 0
[   23.515770] testsuite-64.sh[610]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.lvm.test-lun-4
[   23.515770] testsuite-64.sh[610]: + udevadm settle
[   23.530826] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=345 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   23.530923] testsuite-64.sh[610]: + helper_check_device_symlinks
[   23.531528] systemd[1]: sys-devices-platform-host8-session2-target8:0:0-8:0:0:2-block-sdg.device: Job 440 sys-devices-platform-host8-session2-target8:0:0-8:0:0:2-block-sdg.device/nop finished, result=done
[   23.531615] testsuite-64.sh[972]: + set +x
[   23.532406] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=346 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   23.532493] testsuite-64.sh[972]: /dev/disk/by-uuid/9c2349fa-fc73-4333-9399-77f576d77dc5 -> /dev/sdb
[   23.532690] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dhost8_2dsession2_2dtarget8_3a0_3a0_2d8_3a0_3a0_3a2_2dblock_2dsdg_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=347 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.532781] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dhost8_2dsession2_2dtarget8_3a0_3a0_2d8_3a0_3a0_3a2_2dblock_2dsdg_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=348 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.532861] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dsdg_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=349 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.532940] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dsdg_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=350 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.533035] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2dpath_2dip_5cx2d127_2e0_2e0_2e1_3a3260_5cx2discsi_5cx2diqn_2e2021_5cx2d09_2ecom_2eexample_3aiscsi_2elvm_2etest_5cx2dlun_5cx2d2_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=351 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.533124] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2dpath_2dip_5cx2d127_2e0_2e0_2e1_3a3260_5cx2discsi_5cx2diqn_2e2021_5cx2d09_2ecom_2eexample_3aiscsi_2elvm_2etest_5cx2dlun_5cx2d2_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=352 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.533213] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dwwn_5cx2d0x60000000000000000e00000000020002_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=353 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.533293] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dwwn_5cx2d0x60000000000000000e00000000020002_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=354 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.533374] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dscsi_5cx2d360000000000000000e00000000020002_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=355 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.533452] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dscsi_5cx2d360000000000000000e00000000020002_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=356 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   23.542523] testsuite-64.sh[972]: /dev/disk/by-uuid/74f120d7-6edc-41ff-96c3-78967df09a04 -> /dev/sda1
[   23.552595] testsuite-64.sh[972]: /dev/disk/by-partuuid/f5a8dbe1-01 -> /dev/sda1
[   23.562758] testsuite-64.sh[972]: /dev/disk/by-partuuid/f5a8dbe1-02 -> /dev/sda2
[   23.572779] testsuite-64.sh[972]: /dev/disk/by-label/iscsi_store -> /dev/sdb
[   23.582805] testsuite-64.sh[972]: /dev/disk/by-label/systemd_boot -> /dev/sda1
[   23.593187] testsuite-64.sh[972]: /dev/disk/by-id/scsi-360000000000000000e00000000020002 -> /dev/sdg
[   23.603948] testsuite-64.sh[972]: /dev/disk/by-id/wwn-0x60000000000000000e00000000020002 -> /dev/sdg
[   23.614314] testsuite-64.sh[972]: /dev/disk/by-id/wwn-0x60000000000000000e00000000020004 -> /dev/sdi
[   23.624460] testsuite-64.sh[972]: /dev/disk/by-id/wwn-0x60000000000000000e00000000020003 -> /dev/sdh
[   23.632286] testsuite-64.sh[994]: Unknown device "/dev/disk/by-id/wwn-0x60000000000000000e00000000020003": No such device

Full journal: system.journal.tar.gz

Unknown device "/dev/disk/by-id/wwn-0x60000000000000000e00000000010003": No such device

[   22.193733] testsuite-64.sh[773]: Logging in to [iface: default, target: iqn.2021-09.com.example:iscsi.test, portal: 127.0.0.1,3260]
[   22.193733] testsuite-64.sh[773]: Login to [iface: default, target: iqn.2021-09.com.example:iscsi.test, portal: 127.0.0.1,3260] successful.
[   22.194726] testsuite-64.sh[609]: + udevadm settle
[   22.194979] kernel: sd 8:0:0:4: [sdi] Attached SCSI disk
[   22.261544] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d1.device: Changed dead -> plugged
[   22.261763] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010001.device: Changed dead -> plugged
[   22.261851] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010001.device: Changed dead -> plugged
[   22.261935] systemd[1]: dev-sdf.device: Changed dead -> plugged
[   22.262050] systemd[1]: sys-devices-platform-host8-session1-target8:0:0-8:0:0:1-block-sdf.device: Changed dead -> plugged
[   22.262137] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=71 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.262218] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=72 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.262294] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=73 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.262378] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=74 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.262456] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=75 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.277461] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010002.device: Changed dead -> plugged
[   22.277641] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010002.device: Changed dead -> plugged
[   22.277758] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d2.device: Changed dead -> plugged
[   22.277843] systemd[1]: dev-sdg.device: Changed dead -> plugged
[   22.277924] systemd[1]: sys-devices-platform-host8-session1-target8:0:0-8:0:0:2-block-sdg.device: Changed dead -> plugged
[   22.278046] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=76 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.278137] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=77 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.278219] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=78 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.278311] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=79 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.278390] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=80 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.287769] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010003.device: Changed dead -> plugged
[   22.287927] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010003.device: Changed dead -> plugged
[   22.288032] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d3.device: Changed dead -> plugged
[   22.288118] systemd[1]: dev-sdh.device: Changed dead -> plugged
[   22.288199] systemd[1]: sys-devices-platform-host8-session1-target8:0:0-8:0:0:3-block-sdh.device: Changed dead -> plugged
[   22.288289] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=81 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.288376] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=82 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.288454] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=83 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.288532] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=84 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.288621] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=85 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.290108] testsuite-64.sh[609]: + for link in "${expected_symlinks[@]}"
[   22.290108] testsuite-64.sh[609]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-1
[   22.290108] testsuite-64.sh[609]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-1
[   22.290108] testsuite-64.sh[609]: + local ntries=10
[   22.290108] testsuite-64.sh[609]: + local i
[   22.290108] testsuite-64.sh[609]: + (( i = 0 ))
[   22.290108] testsuite-64.sh[609]: + (( i < ntries ))
[   22.290108] testsuite-64.sh[609]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-1
[   22.290108] testsuite-64.sh[609]: + return 0
[   22.290108] testsuite-64.sh[609]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-1
[   22.290108] testsuite-64.sh[609]: + for link in "${expected_symlinks[@]}"
[   22.290108] testsuite-64.sh[609]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-2
[   22.290108] testsuite-64.sh[609]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-2
[   22.290108] testsuite-64.sh[609]: + local ntries=10
[   22.290108] testsuite-64.sh[609]: + local i
[   22.290108] testsuite-64.sh[609]: + (( i = 0 ))
[   22.290108] testsuite-64.sh[609]: + (( i < ntries ))
[   22.290108] testsuite-64.sh[609]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-2
[   22.290108] testsuite-64.sh[609]: + return 0
[   22.290108] testsuite-64.sh[609]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-2
[   22.290108] testsuite-64.sh[609]: + for link in "${expected_symlinks[@]}"
[   22.290108] testsuite-64.sh[609]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-3
[   22.290108] testsuite-64.sh[609]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-3
[   22.290108] testsuite-64.sh[609]: + local ntries=10
[   22.290108] testsuite-64.sh[609]: + local i
[   22.290108] testsuite-64.sh[609]: + (( i = 0 ))
[   22.290108] testsuite-64.sh[609]: + (( i < ntries ))
[   22.290108] testsuite-64.sh[609]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-3
[   22.290108] testsuite-64.sh[609]: + return 0
[   22.290108] testsuite-64.sh[609]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-3
[   22.290108] testsuite-64.sh[609]: + for link in "${expected_symlinks[@]}"
[   22.290108] testsuite-64.sh[609]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-4
[   22.290108] testsuite-64.sh[609]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-4
[   22.290108] testsuite-64.sh[609]: + local ntries=10
[   22.290108] testsuite-64.sh[609]: + local i
[   22.290108] testsuite-64.sh[609]: + (( i = 0 ))
[   22.290108] testsuite-64.sh[609]: + (( i < ntries ))
[   22.290108] testsuite-64.sh[609]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-4
[   22.290108] testsuite-64.sh[609]: + return 0
[   22.290108] testsuite-64.sh[609]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-4
[   22.290108] testsuite-64.sh[609]: + udevadm settle
[   22.309738] testsuite-64.sh[609]: + helper_check_device_symlinks
[   22.310041] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010004.device: Changed dead -> plugged
[   22.310141] testsuite-64.sh[787]: + set +x
[   22.310141] testsuite-64.sh[787]: /dev/disk/by-uuid/231b7109-f41e-4661-8f82-7634d5e52892 -> /dev/sda1
[   22.311483] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010004.device: Changed dead -> plugged
[   22.311580] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d4.device: Changed dead -> plugged
[   22.311665] systemd[1]: dev-sdi.device: Changed dead -> plugged
[   22.311757] systemd[1]: sys-devices-platform-host8-session1-target8:0:0-8:0:0:4-block-sdi.device: Changed dead -> plugged
[   22.311841] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=86 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.311928] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=87 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.312021] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=88 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.312103] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=89 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.312179] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=UnitNew cookie=90 reply_cookie=0 signature=so error-name=n/a error-message=n/a
[   22.312257] systemd[1]: Added job dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d1.device/nop to transaction.
[   22.312346] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d1.device: Installed new job dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d1.device/nop as 410
[   22.312431] systemd[1]: Added job dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010001.device/nop to transaction.
[   22.312507] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010001.device: Installed new job dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010001.device/nop as 411
[   22.312586] systemd[1]: Added job dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010001.device/nop to transaction.
[   22.312662] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010001.device: Installed new job dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010001.device/nop as 412
[   22.312758] systemd[1]: Added job dev-sdf.device/nop to transaction.
[   22.312837] systemd[1]: dev-sdf.device: Installed new job dev-sdf.device/nop as 413
[   22.312916] systemd[1]: Added job sys-devices-platform-host8-session1-target8:0:0-8:0:0:1-block-sdf.device/nop to transaction.
[   22.312992] systemd[1]: sys-devices-platform-host8-session1-target8:0:0-8:0:0:1-block-sdf.device: Installed new job sys-devices-platform-host8-session1-target8:0:0-8:0:0:1-block-sdf.device/nop as 414
[   22.313090] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dhost8_2dsession1_2dtarget8_3a0_3a0_2d8_3a0_3a0_3a1_2dblock_2dsdf_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=91 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313177] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dhost8_2dsession1_2dtarget8_3a0_3a0_2d8_3a0_3a0_3a1_2dblock_2dsdf_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=92 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313254] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dsdf_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=93 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313331] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dsdf_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=94 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313408] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dscsi_5cx2d360000000000000000e00000000010001_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=95 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313494] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dscsi_5cx2d360000000000000000e00000000010001_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=96 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313570] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dwwn_5cx2d0x60000000000000000e00000000010001_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=97 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313648] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dwwn_5cx2d0x60000000000000000e00000000010001_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=98 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313732] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2dpath_2dip_5cx2d127_2e0_2e0_2e1_3a3260_5cx2discsi_5cx2diqn_2e2021_5cx2d09_2ecom_2eexample_3aiscsi_2etest_5cx2dlun_5cx2d1_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=99 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313818] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2dpath_2dip_5cx2d127_2e0_2e0_2e1_3a3260_5cx2discsi_5cx2diqn_2e2021_5cx2d09_2ecom_2eexample_3aiscsi_2etest_5cx2dlun_5cx2d1_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=100 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.313897] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=101 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   22.313973] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=102 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   22.314064] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=103 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   22.314144] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=104 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   22.314230] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=105 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
[   22.314308] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010001.device: Job 412 dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010001.device/nop finished, result=done
[   22.314389] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=106 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   22.314465] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010001.device: Job 411 dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010001.device/nop finished, result=done
[   22.314542] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=107 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   22.314625] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d1.device: Job 410 dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d1.device/nop finished, result=done
[   22.314712] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=108 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   22.314788] systemd[1]: dev-sdf.device: Job 413 dev-sdf.device/nop finished, result=done
[   22.314865] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=109 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   22.315040] systemd[1]: sys-devices-platform-host8-session1-target8:0:0-8:0:0:1-block-sdf.device: Job 414 sys-devices-platform-host8-session1-target8:0:0-8:0:0:1-block-sdf.device/nop finished, result=done
[   22.315125] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=110 reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
[   22.315201] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dhost8_2dsession1_2dtarget8_3a0_3a0_2d8_3a0_3a0_3a1_2dblock_2dsdf_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=111 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.315278] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dplatform_2dhost8_2dsession1_2dtarget8_3a0_3a0_2d8_3a0_3a0_3a1_2dblock_2dsdf_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=112 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.315355] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dsdf_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=113 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.315442] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dsdf_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=114 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.315521] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2dpath_2dip_5cx2d127_2e0_2e0_2e1_3a3260_5cx2discsi_5cx2diqn_2e2021_5cx2d09_2ecom_2eexample_3aiscsi_2etest_5cx2dlun_5cx2d1_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=115 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.315598] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2dpath_2dip_5cx2d127_2e0_2e0_2e1_3a3260_5cx2discsi_5cx2diqn_2e2021_5cx2d09_2ecom_2eexample_3aiscsi_2etest_5cx2dlun_5cx2d1_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=116 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.315675] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dwwn_5cx2d0x60000000000000000e00000000010001_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=117 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.315778] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dwwn_5cx2d0x60000000000000000e00000000010001_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=118 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.315856] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dscsi_5cx2d360000000000000000e00000000010001_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=119 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.315933] systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/dev_2ddisk_2dby_5cx2did_2dscsi_5cx2d360000000000000000e00000000010001_2edevice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=120 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[   22.317874] testsuite-64.sh[787]: /dev/disk/by-label/systemd_boot -> /dev/sda1
[   22.328089] testsuite-64.sh[787]: /dev/disk/by-partuuid/1da349d3-01 -> /dev/sda1
[   22.338197] testsuite-64.sh[787]: /dev/disk/by-partuuid/1da349d3-02 -> /dev/sda2
[   22.348421] testsuite-64.sh[787]: /dev/disk/by-id/wwn-0x60000000000000000e00000000010001 -> /dev/sdf
[   22.358528] testsuite-64.sh[787]: /dev/disk/by-id/scsi-360000000000000000e00000000010001 -> /dev/sdf
[   22.368592] testsuite-64.sh[787]: /dev/disk/by-id/wwn-0x60000000000000000e00000000010004 -> /dev/sdi
[   22.379385] testsuite-64.sh[787]: /dev/disk/by-id/wwn-0x60000000000000000e00000000010003 -> /dev/sdh
[   22.389538] testsuite-64.sh[805]: Unknown device "/dev/disk/by-id/wwn-0x60000000000000000e00000000010003": No such device

Full journal: system.journal.tar.gz

[mrc0mmand]

@yuwata I managed to weed out a couple of races thanks to the debug logging, but this one boggles my mind:

[   20.012332] kernel: sd 8:0:0:4: [sdi] Write cache: enabled, read cache: enabled, supports DPO and FUA
[   20.012463] kernel: sd 8:0:0:4: Attached scsi generic sg9 type 0
[   20.021279] kernel: sd 8:0:0:2: [sdg] Attached SCSI disk
[   20.025904] kernel: sd 8:0:0:3: [sdh] Attached SCSI disk
[   20.027322] kernel: sd 8:0:0:4: [sdi] Attached SCSI disk
[   20.042630] systemd-udevd[566]: host8: SEQNUM=1873 blocked by SEQNUM=1870
[   20.042791] testsuite-64.sh[780]: Logging in to [iface: default, target: iqn.2021-09.com.example:iscsi.test, portal: 127.0.0.1,3260]
[   20.042791] testsuite-64.sh[780]: Login to [iface: default, target: iqn.2021-09.com.example:iscsi.test, portal: 127.0.0.1,3260] successful.
[   20.044345] systemd-udevd[775]: iscsi_q_8: Device processed (SEQNUM=1869, ACTION=add)
[   20.044427] testsuite-64.sh[609]: + udevadm settle
...
[   20.098727] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_SCSI=1'
[   20.098860] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_VENDOR=IET'
[   20.098946] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_VENDOR_ENC=IET\x20\x20\x20\x20\x20'
[   20.099034] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_MODEL=VIRTUAL-DISK'
[   20.099106] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_MODEL_ENC=VIRTUAL-DISK\x20\x20\x20\x20'
[   20.099185] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_REVISION=0001'
[   20.099255] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_TYPE=disk'
[   20.099325] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_SERIAL=360000000000000000e00000000010004'
[   20.099429] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_SERIAL_SHORT=60000000000000000e00000000010004'
[   20.099510] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_WWN=0x6000000000000000'
[   20.099581] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_WWN_VENDOR_EXTENSION=0x0e00000000010004'
[   20.099695] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_WWN_WITH_EXTENSION=0x60000000000000000e00000000010004'
[   20.099766] systemd-udevd[787]: sdi: 'scsi_id --export --whitelisted -d /dev/sdi'(out) 'ID_SCSI_SERIAL=                              beaf14'
[   20.099868] systemd-udevd[787]: sdi: Process 'scsi_id --export --whitelisted -d /dev/sdi' succeeded.
[   20.099942] systemd-udevd[787]: sdi: /usr/lib/udev/rules.d/60-persistent-storage.rules:68 LINK 'disk/by-id/scsi-360000000000000000e00000000010004'
[   20.100051] systemd-udevd[787]: sdi: /usr/lib/udev/rules.d/60-persistent-storage.rules:90 Importing properties from results of builtin command 'path_id'
[   20.100134] systemd-udevd[787]: sdi: /usr/lib/udev/rules.d/60-persistent-storage.rules:92 LINK 'disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-4'
[   20.100205] systemd-udevd[787]: sdi: /usr/lib/udev/rules.d/60-persistent-storage.rules:110 Importing properties from results of builtin command 'blkid'
[   20.100274] systemd-udevd[787]: sdi: Probe /dev/sdi with raid and offset=0
...
[   20.102910] systemd-udevd[787]: sdi: /usr/lib/udev/rules.d/60-persistent-storage.rules:117 LINK 'disk/by-id/wwn-0x60000000000000000e00000000010004'
[   20.102987] systemd-udevd[787]: sdi: Setting permissions /dev/sdi, uid=0, gid=6, mode=0660
[   20.103087] systemd-udevd[787]: sdi: Handling device node '/dev/sdi', devnum=b8:128
...
[   20.115070] systemd[1]: dev-disk-by\x2did-wwn\x2d0x60000000000000000e00000000010004.device: Changed dead -> plugged
[   20.115143] systemd[1]: dev-disk-by\x2did-scsi\x2d360000000000000000e00000000010004.device: Changed dead -> plugged
[   20.115212] systemd[1]: dev-disk-by\x2dpath-ip\x2d127.0.0.1:3260\x2discsi\x2diqn.2021\x2d09.com.example:iscsi.test\x2dlun\x2d4.device: Changed dead -> plugged
[   20.115281] systemd[1]: dev-sdi.device: Changed dead -> plugged
...
[   20.132354] testsuite-64.sh[609]: + for link in "${expected_symlinks[@]}"
[   20.132354] testsuite-64.sh[609]: + helper_wait_for_dev /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-4
[   20.132354] testsuite-64.sh[609]: + local dev=/dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-4
[   20.132354] testsuite-64.sh[609]: + local ntries=10
[   20.132354] testsuite-64.sh[609]: + local i
[   20.132354] testsuite-64.sh[609]: + (( i = 0 ))
[   20.132354] testsuite-64.sh[609]: + (( i < ntries ))
[   20.132354] testsuite-64.sh[609]: + test '!' -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-4
[   20.132354] testsuite-64.sh[609]: + return 0
[   20.132354] testsuite-64.sh[609]: + test -e /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2021-09.com.example:iscsi.test-lun-4
[   20.132354] testsuite-64.sh[609]: + udevadm settle
[   20.178397] systemd-udevd[566]: Received udev control message (PING)
[   20.183560] testsuite-64.sh[609]: + helper_check_device_symlinks
[   20.183905] testsuite-64.sh[797]: + set +x
[   20.187366] testsuite-64.sh[797]: /dev/disk/by-label/systemd_boot -> /dev/sda1
[   20.195090] testsuite-64.sh[797]: /dev/disk/by-partuuid/dfd2db7f-01 -> /dev/sda1
[   20.202466] testsuite-64.sh[797]: /dev/disk/by-partuuid/dfd2db7f-02 -> /dev/sda2
[   20.208814] testsuite-64.sh[797]: /dev/disk/by-uuid/de28bc39-a6c4-4a8e-a993-39b18fd2ee20 -> /dev/sda1
[   20.214966] testsuite-64.sh[797]: /dev/disk/by-id/wwn-0x60000000000000000e00000000010003 -> /dev/sdh
[   20.221314] testsuite-64.sh[797]: /dev/disk/by-id/scsi-360000000000000000e00000000010003 -> /dev/sdh
[   20.227498] testsuite-64.sh[797]: /dev/disk/by-id/scsi-360000000000000000e00000000010004 -> /dev/sdi
[   20.232351] testsuite-64.sh[813]: Unknown device "/dev/disk/by-id/scsi-360000000000000000e00000000010004": No such device
...

The last line is from udevadm info (

systemd/test/units/testsuite-64.sh

Lines 35 to 40 in d874a13

	# Check if the symlink points to the correct device in /dev
	dev="/dev/$(udevadm info -q name "$link")"
	if [[ "$target" != "$dev" ]]; then
	echo >&2 "ERROR: symlink '$link' points to '$target' but '$dev' was expected"
	return 1
	fi

). It's really weird that the symlinks were created by udev and are valid, but udevadm claims the device doesn't exist?

Full log (CentOS 8): system.journal.tar.gz

Recent hit: 2021-11-25 (https://jenkins-systemd.apps.ocp.ci.centos.org/job/upstream-centos8/4688/artifact//systemd-centos-ci/index.html)

[mrc0mmand]

Another intermittent fail, this time spotted a couple of times on Arch:

[    8.872841] kernel: BTRFS: device label btrfs_root devid 1 transid 6 /dev/disk/by-id/ata-foobar_deadbeefbtrfs0 scanned by mkfs.btrfs (339)
[    8.747079] testsuite-64.sh[339]: btrfs-progs v5.15
[    8.747079] testsuite-64.sh[339]: See http://btrfs.wiki.kernel.org for more information.
[    8.747079] testsuite-64.sh[339]: Performing full device TRIM /dev/disk/by-id/ata-foobar_deadbeefbtrfs0 (350.00MiB) ...
[    8.747079] testsuite-64.sh[339]: NOTE: several default settings have changed in version 5.15, please make sure
[    8.747079] testsuite-64.sh[339]:       this does not affect your deployments:
[    8.747079] testsuite-64.sh[339]:       - DUP for metadata (-m dup)
[    8.747079] testsuite-64.sh[339]:       - enabled no-holes (-O no-holes)
[    8.747079] testsuite-64.sh[339]:       - enabled free-space-tree (-R free-space-tree)
[    8.747079] testsuite-64.sh[339]: Label:              btrfs_root
[    8.747079] testsuite-64.sh[339]: UUID:               deadbeef-dead-dead-beef-000000000000
[    8.747079] testsuite-64.sh[339]: Node size:          16384
[    8.747079] testsuite-64.sh[339]: Sector size:        4096
[    8.747079] testsuite-64.sh[339]: Filesystem size:    350.00MiB
[    8.747079] testsuite-64.sh[339]: Block group profiles:
[    8.747079] testsuite-64.sh[339]:   Data:             single            8.00MiB
[    8.747079] testsuite-64.sh[339]:   Metadata:         DUP              32.00MiB
[    8.747079] testsuite-64.sh[339]:   System:           DUP               8.00MiB
[    8.747079] testsuite-64.sh[339]: SSD detected:       no
[    8.747079] testsuite-64.sh[339]: Zoned device:       no
[    8.747079] testsuite-64.sh[339]: Incompat features:  extref, skinny-metadata, no-holes
[    8.747079] testsuite-64.sh[339]: Runtime features:   free-space-tree
[    8.747079] testsuite-64.sh[339]: Checksum:           crc32c
[    8.747079] testsuite-64.sh[339]: Number of devices:  1
[    8.747079] testsuite-64.sh[339]: Devices:
[    8.747079] testsuite-64.sh[339]:    ID        SIZE  PATH
[    8.747079] testsuite-64.sh[339]:     1   350.00MiB  /dev/disk/by-id/ata-foobar_deadbeefbtrfs0
[    8.880587] testsuite-64.sh[272]: + udevadm settle
[    8.885454] systemd-udevd[298]: btrfs-control: /usr/lib/udev/rules.d/50-udev-default.rules:81 GROUP 995
[    8.885578] systemd-udevd[298]: btrfs-control: Setting permissions /dev/btrfs-control, uid=0, gid=995, mode=0660
[    8.885664] systemd-udevd[298]: btrfs-control: Handling device node '/dev/btrfs-control', devnum=c10:234
[    8.885747] systemd-udevd[298]: btrfs-control: sd-device: Created empty file '/run/udev/data/c10:234' for '/devices/virtual/misc/btrfs-control'
[    8.885832] systemd-udevd[298]: btrfs-control: Failed to get watch handle, ignoring: No such file or directory
[    8.886046] systemd-udevd[298]: btrfs-control: Device processed (SEQNUM=2232, ACTION=add)
[    8.886131] systemd-udevd[298]: btrfs-control: sd-device-monitor: Passed 193 byte to netlink monitor
[    8.886213] systemd-udevd[223]: Received udev control message (PING)
[    8.894753] testsuite-64.sh[272]: + btrfs filesystem show
[    9.089967] kernel: floppy0: disk absent or changed during operation
[    9.089976] kernel: blk_update_request: I/O error, dev fd0, sector 0 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0
[    9.090276] kernel: floppy0: disk absent or changed during operation
[    9.090280] kernel: blk_update_request: I/O error, dev fd0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    9.090286] kernel: Buffer I/O error on dev fd0, logical block 0, async page read
[    9.050843] testsuite-64.sh[347]: Label: 'btrfs_root'  uuid: deadbeef-dead-dead-beef-000000000000
[    9.050843] testsuite-64.sh[347]:         Total devices 1 FS bytes used 144.00KiB
[    9.050843] testsuite-64.sh[347]:         devid    1 size 350.00MiB used 88.00MiB path /dev/sda
[    9.069193] testsuite-64.sh[272]: + test -e /dev/disk/by-uuid/deadbeef-dead-dead-beef-000000000000
[    9.075650] systemd[1]: testsuite-64.service: Main process exited, code=exited, status=1/FAILURE
[    9.076024] systemd[1]: testsuite-64.service: Failed with result 'exit-code'.
[    9.087407] systemd[1]: Failed to start TEST-64-UDEV.

Full log (Arch Linux): system.journal.tar.gz

Recent hit: 2022-01-10 (https://jenkins-systemd.apps.ocp.ci.centos.org/job/upstream-vagrant-archlinux/9438/artifact//systemd-centos-ci/index.html)

[mrc0mmand]

Looking at the second issue (btrfs related), there's a common denominator:

[    7.647977] H testsuite-64.sh[354]: btrfs-progs v5.15.1
[    7.647977] H testsuite-64.sh[354]: See http://btrfs.wiki.kernel.org for more information.
[    7.647977] H testsuite-64.sh[354]: Performing full device TRIM /dev/disk/by-id/ata-foobar_deadbeefbtrfs0 (350.00MiB) ...
[    7.647977] H testsuite-64.sh[354]: NOTE: several default settings have changed in version 5.15, please make sure
[    7.647977] H testsuite-64.sh[354]:       this does not affect your deployments:
[    7.647977] H testsuite-64.sh[354]:       - DUP for metadata (-m dup)
[    7.647977] H testsuite-64.sh[354]:       - enabled no-holes (-O no-holes)
[    7.647977] H testsuite-64.sh[354]:       - enabled free-space-tree (-R free-space-tree)
[    7.647977] H testsuite-64.sh[354]: Label:              btrfs_root
[    7.647977] H testsuite-64.sh[354]: UUID:               deadbeef-dead-dead-beef-000000000000
[    7.647977] H testsuite-64.sh[354]: Node size:          16384
[    7.647977] H testsuite-64.sh[354]: Sector size:        4096
[    7.647977] H testsuite-64.sh[354]: Filesystem size:    350.00MiB
[    7.647977] H testsuite-64.sh[354]: Block group profiles:
[    7.647977] H testsuite-64.sh[354]:   Data:             single            8.00MiB
[    7.647977] H testsuite-64.sh[354]:   Metadata:         DUP              32.00MiB
[    7.647977] H testsuite-64.sh[354]:   System:           DUP               8.00MiB
[    7.647977] H testsuite-64.sh[354]: SSD detected:       no
[    7.647977] H testsuite-64.sh[354]: Zoned device:       no
[    7.647977] H testsuite-64.sh[354]: Incompat features:  extref, skinny-metadata, no-holes
[    7.647977] H testsuite-64.sh[354]: Runtime features:   free-space-tree
[    7.647977] H testsuite-64.sh[354]: Checksum:           crc32c
[    7.647977] H testsuite-64.sh[354]: Number of devices:  1
[    7.647977] H testsuite-64.sh[354]: Devices:
[    7.647977] H testsuite-64.sh[354]:    ID        SIZE  PATH
[    7.647977] H testsuite-64.sh[354]:     1   350.00MiB  /dev/disk/by-id/ata-foobar_deadbeefbtrfs0
[    7.771673] H kernel: Btrfs loaded, crc32c=crc32c-intel, zoned=yes, fsverity=yes
[    7.774173] H kernel: BTRFS: device label btrfs_root devid 1 transid 6 /dev/disk/by-id/ata-foobar_deadbeefbtrfs0 scanned by mkfs.btrfs (354)
[    7.889478] H kernel: floppy0: disk absent or changed during operation
[    7.889487] H kernel: blk_update_request: I/O error, dev fd0, sector 0 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0
[    7.891069] H kernel: floppy0: disk absent or changed during operation
[    7.891077] H kernel: blk_update_request: I/O error, dev fd0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[    7.891100] H kernel: Buffer I/O error on dev fd0, logical block 0, async page read
[    7.827743] H systemd-udevd[355]: btrfs-control: Failed to get watch handle, ignoring: No such file or directory
[    7.827845] H testsuite-64.sh[293]: + udevadm settle
[    7.827845] H testsuite-64.sh[293]: + btrfs filesystem show
[    7.838013] H systemd-udevd[355]: btrfs-control: Device processed (SEQNUM=2270, ACTION=add)
[    7.838635] H systemd-udevd[355]: btrfs-control: sd-device-monitor: Passed 193 byte to netlink monitor
[    7.838722] H systemd-udevd[244]: Received udev control message (PING)
[    7.907095] H testsuite-64.sh[365]: Label: 'btrfs_root'  uuid: deadbeef-dead-dead-beef-000000000000
[    7.907095] H testsuite-64.sh[365]:         Total devices 1 FS bytes used 144.00KiB
[    7.907095] H testsuite-64.sh[365]:         devid    1 size 350.00MiB used 88.00MiB path /dev/sda
[    7.927485] H testsuite-64.sh[293]: + test -e /dev/disk/by-uuid/deadbeef-dead-dead-beef-000000000000
[    7.934343] H systemd[1]: systemd-journald.service: Received EPOLLHUP on stored fd 59 (stored), closing.
[    7.934465] H systemd[1]: Received SIGCHLD from PID 293 (bash).
[    7.934527] H systemd[1]: Child 293 (bash) died (code=exited, status=1/FAILURE)
[    7.934595] H systemd[1]: testsuite-64.service: Child 293 belongs to testsuite-64.service.
[    7.934655] H systemd[1]: testsuite-64.service: Main process exited, code=exited, status=1/FAILURE
[    7.934755] H systemd[1]: testsuite-64.service: Failed with result 'exit-code'.

[   10.373467] H testsuite-64.sh[360]: btrfs-progs v5.16
[   10.373467] H testsuite-64.sh[360]: See http://btrfs.wiki.kernel.org for more information.
[   10.373467] H testsuite-64.sh[360]: Performing full device TRIM /dev/disk/by-id/ata-foobar_deadbeefbtrfs0 (350.00MiB) ...
[   10.373467] H testsuite-64.sh[360]: NOTE: several default settings have changed in version 5.15, please make sure
[   10.373467] H testsuite-64.sh[360]:       this does not affect your deployments:
[   10.373467] H testsuite-64.sh[360]:       - DUP for metadata (-m dup)
[   10.373467] H testsuite-64.sh[360]:       - enabled no-holes (-O no-holes)
[   10.373467] H testsuite-64.sh[360]:       - enabled free-space-tree (-R free-space-tree)
[   10.373467] H testsuite-64.sh[360]: Label:              btrfs_root
[   10.373467] H testsuite-64.sh[360]: UUID:               deadbeef-dead-dead-beef-000000000000
[   10.373467] H testsuite-64.sh[360]: Node size:          16384
[   10.373467] H testsuite-64.sh[360]: Sector size:        4096
[   10.373467] H testsuite-64.sh[360]: Filesystem size:    350.00MiB
[   10.373467] H testsuite-64.sh[360]: Block group profiles:
[   10.373467] H testsuite-64.sh[360]:   Data:             single            8.00MiB
[   10.373467] H testsuite-64.sh[360]:   Metadata:         DUP              32.00MiB
[   10.373467] H testsuite-64.sh[360]:   System:           DUP               8.00MiB
[   10.373467] H testsuite-64.sh[360]: SSD detected:       no
[   10.373467] H testsuite-64.sh[360]: Zoned device:       no
[   10.373467] H testsuite-64.sh[360]: Incompat features:  extref, skinny-metadata, no-holes
[   10.373467] H testsuite-64.sh[360]: Runtime features:   free-space-tree
[   10.373467] H testsuite-64.sh[360]: Checksum:           crc32c
[   10.373467] H testsuite-64.sh[360]: Number of devices:  1
[   10.373467] H testsuite-64.sh[360]: Devices:
[   10.373467] H testsuite-64.sh[360]:    ID        SIZE  PATH
[   10.373467] H testsuite-64.sh[360]:     1   350.00MiB  /dev/disk/by-id/ata-foobar_deadbeefbtrfs0
[   10.493632] H kernel: BTRFS: device label btrfs_root devid 1 transid 6 /dev/disk/by-id/ata-foobar_deadbeefbtrfs0 scanned by mkfs.btrfs (360)
[   10.501311] H systemd-udevd[247]: Received udev control message (PING)
[   10.501450] H testsuite-64.sh[296]: + udevadm settle
[   10.501450] H testsuite-64.sh[296]: + btrfs filesystem show
[   10.684619] H kernel: floppy0: disk absent or changed during operation
[   10.684628] H kernel: I/O error, dev fd0, sector 0 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0
[   10.684910] H kernel: floppy0: disk absent or changed during operation
[   10.684915] H kernel: I/O error, dev fd0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[   10.684920] H kernel: Buffer I/O error on dev fd0, logical block 0, async page read
[   10.645457] H testsuite-64.sh[370]: Label: 'btrfs_root'  uuid: deadbeef-dead-dead-beef-000000000000
[   10.645457] H testsuite-64.sh[370]:         Total devices 1 FS bytes used 144.00KiB
[   10.645457] H testsuite-64.sh[370]:         devid    1 size 350.00MiB used 88.00MiB path /dev/sda
[   10.661882] H testsuite-64.sh[296]: + test -e /dev/disk/by-uuid/deadbeef-dead-dead-beef-000000000000
[   10.669185] H systemd[1]: Received SIGCHLD from PID 296 (bash).
[   10.669500] H systemd[1]: Child 296 (bash) died (code=exited, status=1/FAILURE)
[   10.669586] H systemd[1]: testsuite-64.service: Child 296 belongs to testsuite-64.service.
[   10.669672] H systemd[1]: testsuite-64.service: Main process exited, code=exited, status=1/FAILURE
[   10.669772] H systemd[1]: testsuite-64.service: Failed with result 'exit-code'.

In all failed runs I've seen so far there always was the "floppy0" error after udevadm settle. Just for completeness, here's an excerpt from a successful run:

[    2.686512] H kernel: BTRFS: device label btrfs_root devid 1 transid 5 /dev/disk/by-id/ata-foobar_deadbeefbtrfs0 scanned by mkfs.btrfs (666)
[    2.680000] H systemd-udevd[568]: Failed to create sd_device object from watch handle, ignoring: No such file or directory
[    2.680117] H testsuite-64.sh[666]: btrfs-progs v5.14.2
[    2.680117] H testsuite-64.sh[666]: See http://btrfs.wiki.kernel.org for more information.
[    2.680117] H testsuite-64.sh[666]: Performing full device TRIM /dev/disk/by-id/ata-foobar_deadbeefbtrfs0 (350.00MiB) ...
[    2.680117] H testsuite-64.sh[666]: Label:              btrfs_root
[    2.680117] H testsuite-64.sh[666]: UUID:               deadbeef-dead-dead-beef-000000000000
[    2.680117] H testsuite-64.sh[666]: Node size:          16384
[    2.680117] H testsuite-64.sh[666]: Sector size:        4096
[    2.680117] H testsuite-64.sh[666]: Filesystem size:    350.00MiB
[    2.680117] H testsuite-64.sh[666]: Block group profiles:
[    2.680117] H testsuite-64.sh[666]:   Data:             single            8.00MiB
[    2.680117] H testsuite-64.sh[666]:   Metadata:         DUP              32.00MiB
[    2.680117] H testsuite-64.sh[666]:   System:           DUP               8.00MiB
[    2.680117] H testsuite-64.sh[666]: SSD detected:       no
[    2.680117] H testsuite-64.sh[666]: Zoned device:       no
[    2.680117] H testsuite-64.sh[666]: Incompat features:  extref, skinny-metadata
[    2.680117] H testsuite-64.sh[666]: Runtime features:
[    2.680117] H testsuite-64.sh[666]: Checksum:           crc32c
[    2.680117] H testsuite-64.sh[666]: Number of devices:  1
[    2.680117] H testsuite-64.sh[666]: Devices:
[    2.680117] H testsuite-64.sh[666]:    ID        SIZE  PATH
[    2.680117] H testsuite-64.sh[666]:     1   350.00MiB  /dev/disk/by-id/ata-foobar_deadbeefbtrfs0
[    2.697976] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:54 Importing properties from results of 'ata_id --export /dev/sda'
[    2.698104] H testsuite-64.sh[598]: + udevadm settle
[    2.698639] H systemd-udevd[608]: sda: Starting 'ata_id --export /dev/sda'
[    2.698742] H systemd-udevd[608]: Successfully forked off '(spawn)' as PID 668.
[    2.698826] H systemd-udevd[568]: Received udev control message (PING)
[    2.698929] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA=1'
[    2.699019] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_TYPE=disk'
[    2.699097] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_BUS=ata'
[    2.699178] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_MODEL=foobar'
[    2.699256] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_MODEL_ENC=foobar\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20'
[    2.699335] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_REVISION=2.5+'
[    2.699411] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_SERIAL=foobar_deadbeefbtrfs0'
[    2.699488] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_SERIAL_SHORT=deadbeefbtrfs0'
[    2.699564] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_WRITE_CACHE=1'
[    2.699645] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_WRITE_CACHE_ENABLED=1'
[    2.699730] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_FEATURE_SET_SMART=1'
[    2.699810] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_FEATURE_SET_SMART_ENABLED=1'
[    2.699912] H systemd-udevd[608]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_SATA=1'
[    2.699995] H systemd-udevd[608]: sda: Process 'ata_id --export /dev/sda' succeeded.
[    2.700072] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:68 LINK 'disk/by-id/ata-foobar_deadbeefbtrfs0'
[    2.700155] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:90 Importing properties from results of builtin command 'path_id'
[    2.700235] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:92 LINK 'disk/by-path/pci-0000:00:03.0-ata-1.0'
[    2.700311] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:95 LINK 'disk/by-path/pci-0000:00:03.0-ata-1'
[    2.700389] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:110 Importing properties from results of builtin command 'blkid'
[    2.700466] H systemd-udevd[608]: sda: Probe /dev/sda with raid and offset=0
[    2.700543] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:113 LINK 'disk/by-uuid/deadbeef-dead-dead-beef-000000000000'
[    2.700635] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:114 LINK 'disk/by-label/btrfs_root'
[    2.700717] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/64-btrfs.rules:9 Importing properties from results of builtin command 'btrfs ready /dev/sda'
[    2.700804] H systemd-udevd[608]: sda: /usr/lib/udev/rules.d/64-btrfs.rules:15 RUN '/usr/bin/udevadm trigger -s block -p ID_BTRFS_READY=0'
[    2.700904] H systemd-udevd[608]: sda: Handling device node '/dev/sda', devnum=b8:0
[    2.700991] H systemd-udevd[608]: sda: /run/udev/links/disk\x2fby-label\x2fbtrfs_root is modified, but its timestamp is not changed, updating timestamp after 10ms.
[    2.704435] H systemd-udevd[608]: sda: /run/udev/links/disk\x2fby-uuid\x2fdeadbeef-dead-dead-beef-000000000000 is modified, but its timestamp is not changed, updating timestamp after 10ms.
[    2.714783] H systemd-udevd[608]: sda: sd-device: Created db file '/run/udev/data/b8:0' for '/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda'
[    2.714961] H systemd-udevd[608]: sda: Running command "/usr/bin/udevadm trigger -s block -p ID_BTRFS_READY=0"
[    2.715056] H systemd-udevd[608]: sda: Starting '/usr/bin/udevadm trigger -s block -p ID_BTRFS_READY=0'
[    2.715136] H systemd-udevd[608]: Successfully forked off '(spawn)' as PID 670.
[    2.722399] H systemd-udevd[608]: sda: Process '/usr/bin/udevadm trigger -s block -p ID_BTRFS_READY=0' succeeded.
[    2.722540] H systemd-udevd[608]: sda: Adding watch on '/dev/sda'
[    2.722625] H systemd-udevd[608]: sda: Device processed (SEQNUM=2458, ACTION=change)
[    2.722712] H systemd-udevd[608]: sda: sd-device-monitor: Passed 1366 byte to netlink monitor
[    2.722938] H systemd[1]: dev-disk-by\x2dpath-pci\x2d0000:00:03.0\x2data\x2d1.0.device: Installed new job dev-disk-by\x2dpath-pci\x2d0000:00:03.0\x2data\x2d1.0.device/nop as 316
[    2.723037] H systemd[1]: dev-disk-by\x2did-ata\x2dfoobar_deadbeefbtrfs0.device: Installed new job dev-disk-by\x2did-ata\x2dfoobar_deadbeefbtrfs0.device/nop as 317
[    2.723124] H systemd[1]: dev-disk-by\x2dpath-pci\x2d0000:00:03.0\x2data\x2d1.device: Installed new job dev-disk-by\x2dpath-pci\x2d0000:00:03.0\x2data\x2d1.device/nop as 318
[    2.723206] H systemd[1]: dev-sda.device: Installed new job dev-sda.device/nop as 319
[    2.723284] H systemd[1]: sys-devices-pci0000:00-0000:00:03.0-ata1-host0-target0:0:0-0:0:0:0-block-sda.device: Installed new job sys-devices-pci0000:00-0000:00:03.0-ata1-host0-target0:0:0-0:0:0:0-block-sda.device/nop as 320
[    2.724483] H systemd[1]: dev-disk-by\x2duuid-deadbeef\x2ddead\x2ddead\x2dbeef\x2d000000000000.device: Changed dead -> plugged
[    2.724645] H systemd[1]: dev-disk-by\x2dlabel-btrfs_root.device: Changed dead -> plugged

I'm inclined to drop the /dev/floppy0 device from the test VMs to see if it helps, but I'm still not sure if this is a kernel issue our a udev one (or whether it's an issue at all).

@yuwata any thoughts?

[yuwata]

@mrc0mmand Sorry for late response. For the second issue (btrfs), it seems udevadm settle is called too earlier. Like other places, I guess we should call helper_wait_for_dev() for the device(s).

[yuwata]

Full log (CentOS 8): system.journal.tar.gz

Is the file broken?? I cannot open it with journalctl --file.

[mrc0mmand]

Journal file system.journal has unknown incompatible flags 0x10
Failed to open journal file system.journal: Protocol not supported

hmm, interesting. Let me look into that.

[mrc0mmand]

Not sure what happened but that journal is indeed corrupted. Thankfully, I managed to find another one with the same issue: system.journal.tar.gz

[yuwata]

Ouch, the btrfs related issue is not fully fixed.
https://jenkins-systemd.apps.ocp.ci.centos.org/job/upstream-vagrant-archlinux/9599/artifact//systemd-centos-ci/index.html

[yuwata]

It seems blkid udev builtin command could not obtain filesystem UUID and label.

Jan 20 01:50:47 H systemd-udevd[244]: sda: Inotify event: 8 for /dev/sda
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/power/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/holders/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/mq/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/mq/0/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/mq/0/cpu3/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/mq/0/cpu1/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/mq/0/cpu2/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/mq/0/cpu0/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/queue/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/queue/iosched/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/integrity/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/trace/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda/slaves/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[244]: sda: device is closed, synthesising 'change' on /sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda
Jan 20 01:50:47 H systemd-udevd[244]: sda: Device is queued (SEQNUM=2262, ACTION=change)
Jan 20 01:50:47 H systemd-udevd[244]: sda: Device ready for processing (SEQNUM=2262, ACTION=change)
Jan 20 01:50:47 H systemd-udevd[244]: Successfully forked off 'n/a' as PID 356.
Jan 20 01:50:47 H systemd-udevd[244]: sda: Worker [356] is forked for processing SEQNUM=2262.
Jan 20 01:50:47 H systemd-udevd[356]: sda: Processing device (SEQNUM=2262, ACTION=change)
Jan 20 01:50:47 H systemd-udevd[356]: sda: Removing watch
Jan 20 01:50:47 H systemd-udevd[356]: sd-device: the uevent file "/sys/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[356]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:54 Importing properties from results of 'ata_id --export /dev/sda'
Jan 20 01:50:47 H systemd-udevd[356]: sda: Starting 'ata_id --export /dev/sda'
Jan 20 01:50:47 H systemd-udevd[356]: Successfully forked off '(spawn)' as PID 357.
Jan 20 01:50:47 H systemd-udevd[244]: Failed to create sd_device object from watch handle, ignoring: No such file or directory
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA=1'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_TYPE=disk'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_BUS=ata'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_MODEL=foobar'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_MODEL_ENC=foobar\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20\x20'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_REVISION=2.5+'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_SERIAL=foobar_deadbeefbtrfs0'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_SERIAL_SHORT=deadbeefbtrfs0'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_WRITE_CACHE=1'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_WRITE_CACHE_ENABLED=1'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_FEATURE_SET_SMART=1'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_FEATURE_SET_SMART_ENABLED=1'
Jan 20 01:50:47 H systemd-udevd[356]: sda: 'ata_id --export /dev/sda'(out) 'ID_ATA_SATA=1'
Jan 20 01:50:47 H systemd-udevd[356]: sda: Process 'ata_id --export /dev/sda' succeeded.
Jan 20 01:50:47 H systemd-udevd[356]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:68 LINK 'disk/by-id/ata-foobar_deadbeefbtrfs0'
Jan 20 01:50:47 H systemd-udevd[356]: sd-device: the uevent file "/sys/devices/uevent" does not exist.
Jan 20 01:50:47 H systemd-udevd[356]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:90 Importing properties from results of builtin command 'path_id'
Jan 20 01:50:47 H systemd-udevd[356]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:92 LINK 'disk/by-path/pci-0000:00:03.0-ata-1.0'
Jan 20 01:50:47 H systemd-udevd[356]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:95 LINK 'disk/by-path/pci-0000:00:03.0-ata-1'
Jan 20 01:50:47 H systemd-udevd[356]: sda: /usr/lib/udev/rules.d/60-persistent-storage.rules:110 Importing properties from results of builtin command 'blkid'
Jan 20 01:50:47 H systemd-udevd[356]: sda: Probe /dev/sda with raid and offset=0
Jan 20 01:50:47 H systemd-udevd[356]: sda: Handling device node '/dev/sda', devnum=b8:0
Jan 20 01:50:47 H systemd-udevd[356]: sda: sd-device: Created db file '/run/udev/data/b8:0' for '/devices/pci0000:00/0000:00:03.0/ata1/host0/target0:0:0/0:0:0:0/block/sda'
Jan 20 01:50:47 H systemd-udevd[356]: sda: Adding watch on '/dev/sda'
Jan 20 01:50:47 H systemd-udevd[356]: sda: Device processed (SEQNUM=2262, ACTION=change)

[mrc0mmand]

Ouch, the btrfs related issue is not fully fixed. https://jenkins-systemd.apps.ocp.ci.centos.org/job/upstream-vagrant-archlinux/9599/artifact//systemd-centos-ci/index.html

Yeah, TEST-64 seems to be now angrier than usual, probably sensing we're trying to silence it. Is there anything I could do to obtain some useful data for further debugging?

[yuwata]

I have not checked the rate of failure in the test, but if it increased, then I hope we are now closer to investigate the root cause of the issue :-p

Now, I am suspecting the behavior of blkid. Does it correctly detect btrfs filesystem even if btrfs module is not loaded yet? As you may observed, some (not sure if all) failure logs show that udev's blkid builtin command is triggered before btrfs kernel module is loaded. cc @karelzak

[karelzak]

Now, I am suspecting the behavior of blkid. Does it correctly detect btrfs filesystem even if btrfs module is not loaded yet? As you may observed, some (not sure if all) failure logs show that udev's blkid builtin command is triggered before btrfs kernel module is loaded. cc @karelzak

libblkid works without any interaction with kernel modules; it looks up for magic strings at the block device, so all it needs from kernel is seek() and read() :-)