storage: x86_64::storage::openvmm_openhcl_linux_x64_storvsp_dynamic_add_disk fails #3107
Description
This looks like guest slowness. 7/8 disks appear (sdb-sdh), while the last one (sdi) is detected by the guest kernel (I see it in dmesg) but doesn't show up in /sys where we probe for it (and thus also not in /dev which we print just for debugging). We retry for 30 secs but it's still not there. It could be some weird interaction between the guest driver and storvsp where it detects it (thus prints in dmesg) but can't do some other required operation and thus it's not appearing in /sys.
Full log: log.txt
dmesg shows all 8 disks as detected:
2026-03-23T17:31:34.2011744Z [ petri] 2026-03-23T17:25:21.596376Z WARN tests::x86_64::storage: Attempt 1/10: Failed to get device paths: command failed: exit code 1. Retrying in 3 seconds...
2026-03-23T17:31:34.2012078Z [ petri] 2026-03-23T17:25:21.598047Z INFO pipette: 64.914966300s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sleep", args: ["3"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2012367Z [ linux] [ 94.410009] scsi 1:0:0:0: Direct-Access OpenVMM Disk 1.0 PQ: 0 ANSI: 5
2026-03-23T17:31:34.2012623Z [ openhcl] [128.150793] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2012942Z [ openhcl] [128.241231] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2013348Z [ linux] [ 95.313555] sd 1:0:0:0: Attached scsi generic sg1 type 0
2026-03-23T17:31:34.2013548Z [ linux] [ 95.315213] sd 1:0:0:0: [sdb] 262144 512-byte logical blocks: (134 MB/128 MiB)
2026-03-23T17:31:34.2013746Z [ linux] [ 95.448551] sd 1:0:0:0: [sdb] 4096-byte physical blocks
2026-03-23T17:31:34.2013927Z [ linux] [ 95.495681] sd 1:0:0:0: [sdb] Write Protect is off
2026-03-23T17:31:34.2014118Z [ linux] [ 95.495739] scsi 1:0:0:1: Direct-Access OpenVMM Disk 1.0 PQ: 0 ANSI: 5
2026-03-23T17:31:34.2014389Z [ linux] [ 95.624260] sd 1:0:0:0: [sdb] Mode Sense: 0f 00 10 00
2026-03-23T17:31:34.2014593Z [ linux] [ 95.669641] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, supports DPO and FUA
2026-03-23T17:31:34.2014838Z [ openhcl] [128.979393] scsidisk: DEBUG scsi_error disk=[5c, b, 9d, b5, a3, 2e, dc, 47, b2, b0, f5, 7a, 28, 92, 1c, 80] error=unsupported vpd page code: 185 op=INQUIRY
2026-03-23T17:31:34.2015123Z [ openhcl] [129.011389] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2015425Z [ openhcl] [129.045105] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2015665Z [ linux] [ 95.901538] sd 1:0:0:0: [sdb] Attached SCSI disk
2026-03-23T17:31:34.2015862Z [ linux] [ 95.993455] scsi 1:0:0:1: Attached scsi generic sg2 type 0
2026-03-23T17:31:34.2016060Z [ linux] [ 95.995482] sd 1:0:0:1: [sdc] 264192 512-byte logical blocks: (135 MB/129 MiB)
2026-03-23T17:31:34.2016252Z [ linux] [ 96.129938] sd 1:0:0:1: [sdc] 4096-byte physical blocks
2026-03-23T17:31:34.2016445Z [ linux] [ 96.176240] scsi 1:0:0:2: Direct-Access OpenVMM Disk 1.0 PQ: 0 ANSI: 5
2026-03-23T17:31:34.2016635Z [ linux] [ 96.177252] sd 1:0:0:1: [sdc] Write Protect is off
2026-03-23T17:31:34.2016813Z [ linux] [ 96.329287] sd 1:0:0:1: [sdc] Mode Sense: 0f 00 10 00
2026-03-23T17:31:34.2017077Z [ linux] [ 96.428178] sd 1:0:0:1: [sdc] Write cache: enabled, read cache: enabled, supports DPO and FUA
2026-03-23T17:31:34.2017320Z [ openhcl] [129.734652] scsidisk: DEBUG scsi_error disk=[56, 59, b2, b, d, 0, 45, 49, 97, 77, 9a, 56, 16, 7b, 37, 11] error=unsupported vpd page code: 185 op=INQUIRY
2026-03-23T17:31:34.2017614Z [ openhcl] [129.771443] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2017915Z [ openhcl] [129.805743] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2018154Z [ linux] [ 96.662907] sd 1:0:0:1: [sdc] Attached SCSI disk
2026-03-23T17:31:34.2018335Z [ linux] [ 96.755558] sd 1:0:0:2: Attached scsi generic sg3 type 0
2026-03-23T17:31:34.2018529Z [ linux] [ 96.757441] sd 1:0:0:2: [sdd] 266240 512-byte logical blocks: (136 MB/130 MiB)
2026-03-23T17:31:34.2018728Z [ linux] [ 96.890488] sd 1:0:0:2: [sdd] 4096-byte physical blocks
2026-03-23T17:31:34.2018918Z [ linux] [ 96.937255] scsi 1:0:0:3: Direct-Access OpenVMM Disk 1.0 PQ: 0 ANSI: 5
2026-03-23T17:31:34.2019107Z [ linux] [ 96.938119] sd 1:0:0:2: [sdd] Write Protect is off
2026-03-23T17:31:34.2019285Z [ linux] [ 97.081112] sd 1:0:0:2: [sdd] Mode Sense: 0f 00 10 00
2026-03-23T17:31:34.2019482Z [ linux] [ 97.126742] sd 1:0:0:2: [sdd] Write cache: enabled, read cache: enabled, supports DPO and FUA
2026-03-23T17:31:34.2019723Z [ openhcl] [130.428988] scsidisk: DEBUG scsi_error disk=[37, c5, bb, bf, 8a, 74, 56, 46, af, 17, 61, f4, 3c, d8, 4d, 1f] error=unsupported vpd page code: 185 op=INQUIRY
2026-03-23T17:31:34.2019982Z [ petri] 2026-03-23T17:25:24.601898Z INFO pipette: 67.918718800s DEBUG pipette::execute: process exited pid=516 status=Normal(0)
2026-03-23T17:31:34.2020236Z [ petri] 2026-03-23T17:25:24.602177Z INFO pipette_client::shell: command stdout out=""
2026-03-23T17:31:34.2020456Z [ petri] 2026-03-23T17:25:24.602308Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2020717Z [ openhcl] [130.513733] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2021121Z [ petri] 2026-03-23T17:25:24.644895Z INFO pipette: 67.921224100s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -ld /sys/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2021449Z [ petri] 2026-03-23T17:25:24.652498Z INFO pipette: 67.969815000s DEBUG pipette::execute: process exited pid=521 status=Normal(0)
2026-03-23T17:31:34.2022155Z [ petri] 2026-03-23T17:25:24.652906Z INFO pipette_client::shell: command stdout out="lrwxrwxrwx 1 root root 0 Mar 23 17:24 /sys/block/sda -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/27b553e8-8b39-411b-a55f-839971a7884f/host0/target0:0:0/0:0:0:1/block/sda\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdb -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdc -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdd -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd\n"
2026-03-23T17:31:34.2022813Z [ petri] 2026-03-23T17:25:24.653121Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2023519Z [ petri] 2026-03-23T17:25:24.653253Z INFO tests::utils: All disks all_disks="lrwxrwxrwx 1 root root 0 Mar 23 17:24 /sys/block/sda -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/27b553e8-8b39-411b-a55f-839971a7884f/host0/target0:0:0/0:0:0:1/block/sda\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdb -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdc -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdd -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd"
2026-03-23T17:31:34.2024297Z [ petri] 2026-03-23T17:25:24.655070Z INFO pipette: 67.972174900s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:0/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2024663Z [ petri] 2026-03-23T17:25:24.662692Z INFO pipette: 67.980110500s DEBUG pipette::execute: process exited pid=526 status=Normal(0)
2026-03-23T17:31:34.2024955Z [ petri] 2026-03-23T17:25:24.663083Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\n"
2026-03-23T17:31:34.2025221Z [ petri] 2026-03-23T17:25:24.663218Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2025533Z [ petri] 2026-03-23T17:25:24.664993Z INFO pipette: 67.982136800s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdb/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2025858Z [ petri] 2026-03-23T17:25:24.668720Z INFO pipette: 67.986341000s DEBUG pipette::execute: process exited pid=531 status=Normal(0)
2026-03-23T17:31:34.2026100Z [ petri] 2026-03-23T17:25:24.669247Z INFO pipette_client::shell: command stdout out="262144\n"
2026-03-23T17:31:34.2026378Z [ petri] 2026-03-23T17:25:24.669374Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2026725Z [ petri] 2026-03-23T17:25:24.671096Z INFO pipette: 67.988023600s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:1/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2027108Z [ petri] 2026-03-23T17:25:24.678907Z INFO pipette: 67.996278500s DEBUG pipette::execute: process exited pid=536 status=Normal(0)
2026-03-23T17:31:34.2027555Z [ petri] 2026-03-23T17:25:24.679135Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\n"
2026-03-23T17:31:34.2027824Z [ petri] 2026-03-23T17:25:24.679269Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2028125Z [ petri] 2026-03-23T17:25:24.680723Z INFO pipette: 67.998022700s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdc/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2028476Z [ openhcl] [130.555752] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2028756Z [ petri] 2026-03-23T17:25:24.684959Z INFO pipette: 68.002492000s DEBUG pipette::execute: process exited pid=541 status=Normal(0)
2026-03-23T17:31:34.2029073Z [ petri] 2026-03-23T17:25:24.685359Z INFO pipette_client::shell: command stdout out="264192\n"
2026-03-23T17:31:34.2029294Z [ petri] 2026-03-23T17:25:24.685476Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2029641Z [ petri] 2026-03-23T17:25:24.687136Z INFO pipette: 68.004145300s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:2/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2030008Z [ petri] 2026-03-23T17:25:24.706857Z INFO pipette: 68.024210800s DEBUG pipette::execute: process exited pid=546 status=Normal(0)
2026-03-23T17:31:34.2030298Z [ petri] 2026-03-23T17:25:24.707639Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd\n"
2026-03-23T17:31:34.2030724Z [ petri] 2026-03-23T17:25:24.707786Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2030937Z [ linux] [ 97.421379] sd 1:0:0:3: [sde] 268288 512-byte logical blocks: (137 MB/131 MiB)
2026-03-23T17:31:34.2031134Z [ linux] [ 97.444059] sd 1:0:0:3: Attached scsi generic sg4 type 0
2026-03-23T17:31:34.2031434Z [ petri] 2026-03-23T17:25:24.817792Z INFO pipette: 68.026820300s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdd/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2031760Z [ petri] 2026-03-23T17:25:24.837769Z INFO pipette: 68.153315500s DEBUG pipette::execute: process exited pid=551 status=Normal(0)
2026-03-23T17:31:34.2032002Z [ petri] 2026-03-23T17:25:24.840371Z INFO pipette_client::shell: command stdout out="266240\n"
2026-03-23T17:31:34.2032226Z [ petri] 2026-03-23T17:25:24.840497Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2032568Z [ petri] 2026-03-23T17:25:24.847646Z INFO pipette: 68.162290600s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:3/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2032985Z [ linux] [ 97.479522] sd 1:0:0:3: [sde] 4096-byte physical blocks
2026-03-23T17:31:34.2033209Z [ petri] 2026-03-23T17:25:24.864538Z INFO pipette: 68.181800100s DEBUG pipette::execute: process exited pid=556 status=Normal(1)
2026-03-23T17:31:34.2033447Z [ petri] 2026-03-23T17:25:24.864759Z INFO pipette_client::shell: command stdout out=""
2026-03-23T17:31:34.2033728Z [ petri] 2026-03-23T17:25:24.864858Z INFO pipette_client::shell: command stderr err="ls: /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:3/block/sd*: No such file or directory\n"
2026-03-23T17:31:34.2034044Z [ petri] 2026-03-23T17:25:24.865017Z WARN tests::x86_64::storage: Attempt 2/10: Failed to get device paths: command failed: exit code 1. Retrying in 3 seconds...
2026-03-23T17:31:34.2034384Z [ petri] 2026-03-23T17:25:24.866677Z INFO pipette: 68.183531000s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sleep", args: ["3"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2034670Z [ linux] [ 97.645401] scsi 1:0:0:4: Direct-Access OpenVMM Disk 1.0 PQ: 0 ANSI: 5
2026-03-23T17:31:34.2034860Z [ linux] [ 97.647166] sd 1:0:0:2: [sdd] Attached SCSI disk
2026-03-23T17:31:34.2035036Z [ linux] [ 97.754752] sd 1:0:0:3: [sde] Write Protect is off
2026-03-23T17:31:34.2035272Z [ linux] [ 97.857084] sd 1:0:0:3: [sde] Mode Sense: 0f 00 10 00
2026-03-23T17:31:34.2035469Z [ linux] [ 98.013594] sd 1:0:0:3: [sde] Write cache: enabled, read cache: enabled, supports DPO and FUA
2026-03-23T17:31:34.2035711Z [ openvmm] 134.455336500s DEBUG hyperv_ic::timesync: sent time sample time=2026-03-23T17:25:25.5495433Z ref_time=0x4fd72bdf
2026-03-23T17:31:34.2035983Z [ openhcl] [131.451460] scsidisk: DEBUG scsi_error disk=[f7, cc, 9b, 4d, 8d, 2c, 63, 44, af, a2, 98, be, 66, b9, 71, a] error=unsupported vpd page code: 185 op=INQUIRY
2026-03-23T17:31:34.2036264Z [ openhcl] [131.485778] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2036565Z [ openhcl] [131.517406] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2036807Z [ linux] [ 98.371743] sd 1:0:0:3: [sde] Attached SCSI disk
2026-03-23T17:31:34.2036998Z [ linux] [ 98.376398] sd 1:0:0:4: [sdf] 270336 512-byte logical blocks: (138 MB/132 MiB)
2026-03-23T17:31:34.2037197Z [ linux] [ 98.494966] sd 1:0:0:4: [sdf] 4096-byte physical blocks
2026-03-23T17:31:34.2037380Z [ linux] [ 98.495043] sd 1:0:0:4: Attached scsi generic sg5 type 0
2026-03-23T17:31:34.2037562Z [ linux] [ 98.536543] sd 1:0:0:4: [sdf] Write Protect is off
2026-03-23T17:31:34.2037740Z [ linux] [ 98.646222] sd 1:0:0:4: [sdf] Mode Sense: 0f 00 10 00
2026-03-23T17:31:34.2037928Z [ linux] [ 98.686851] scsi 1:0:0:5: Direct-Access OpenVMM Disk 1.0 PQ: 0 ANSI: 5
2026-03-23T17:31:34.2038138Z [ linux] [ 98.688197] sd 1:0:0:4: [sdf] Write cache: enabled, read cache: enabled, supports DPO and FUA
2026-03-23T17:31:34.2038378Z [ openhcl] [132.159512] scsidisk: DEBUG scsi_error disk=[f3, f6, b3, d3, 64, c8, 71, 42, be, 6c, 1b, aa, c0, af, 19, 76] error=unsupported vpd page code: 185 op=INQUIRY
2026-03-23T17:31:34.2038666Z [ openhcl] [132.322391] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2038960Z [ linux] [ 99.142880] sd 1:0:0:4: [sdf] Attached SCSI disk
2026-03-23T17:31:34.2039201Z [ openhcl] [132.446775] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2039442Z [ linux] [ 99.509187] sd 1:0:0:5: Attached scsi generic sg6 type 0
2026-03-23T17:31:34.2039637Z [ linux] [ 99.510852] sd 1:0:0:5: [sdg] 272384 512-byte logical blocks: (139 MB/133 MiB)
2026-03-23T17:31:34.2039827Z [ linux] [ 99.628217] sd 1:0:0:5: [sdg] 4096-byte physical blocks
2026-03-23T17:31:34.2040024Z [ linux] [ 99.675627] scsi 1:0:0:6: Direct-Access OpenVMM Disk 1.0 PQ: 0 ANSI: 5
2026-03-23T17:31:34.2040218Z [ linux] [ 99.676184] sd 1:0:0:5: [sdg] Write Protect is off
2026-03-23T17:31:34.2040396Z [ linux] [ 99.826836] sd 1:0:0:5: [sdg] Mode Sense: 0f 00 10 00
2026-03-23T17:31:34.2040595Z [ linux] [ 99.984674] sd 1:0:0:5: [sdg] Write cache: enabled, read cache: enabled, supports DPO and FUA
2026-03-23T17:31:34.2040835Z [ openhcl] [133.338625] scsidisk: DEBUG scsi_error disk=[2, 57, b7, 1a, 3c, 45, d4, 4b, 8e, 8a, 8c, 9a, cc, 9a, 14, 85] error=unsupported vpd page code: 185 op=INQUIRY
2026-03-23T17:31:34.2041115Z [ openhcl] [133.399012] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2041416Z [ openhcl] [133.487436] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2041726Z [ linux] [ 100.404175] sd 1:0:0:5: [sdg] Attached SCSI disk
2026-03-23T17:31:34.2041907Z [ linux] [ 100.492039] sd 1:0:0:6: Attached scsi generic sg7 type 0
2026-03-23T17:31:34.2042107Z [ linux] [ 100.493447] sd 1:0:0:6: [sdh] 274432 512-byte logical blocks: (141 MB/134 MiB)
2026-03-23T17:31:34.2042342Z [ petri] 2026-03-23T17:25:27.893162Z INFO pipette: 71.210125300s DEBUG pipette::execute: process exited pid=561 status=Normal(0)
2026-03-23T17:31:34.2042581Z [ petri] 2026-03-23T17:25:27.893467Z INFO pipette_client::shell: command stdout out=""
2026-03-23T17:31:34.2042798Z [ petri] 2026-03-23T17:25:27.893645Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2043106Z [ petri] 2026-03-23T17:25:27.919403Z INFO pipette: 71.213416600s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -ld /sys/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2043404Z [ linux] [ 100.623231] sd 1:0:0:6: [sdh] 4096-byte physical blocks
2026-03-23T17:31:34.2043597Z [ linux] [ 100.667466] scsi 1:0:0:7: Direct-Access OpenVMM Disk 1.0 PQ: 0 ANSI: 5
2026-03-23T17:31:34.2043788Z [ linux] [ 100.668378] sd 1:0:0:6: [sdh] Write Protect is off
2026-03-23T17:31:34.2044007Z [ petri] 2026-03-23T17:25:28.094829Z INFO pipette: 71.410402300s DEBUG pipette::execute: process exited pid=566 status=Normal(0)
2026-03-23T17:31:34.2045176Z [ petri] 2026-03-23T17:25:28.095117Z INFO pipette_client::shell: command stdout out="lrwxrwxrwx 1 root root 0 Mar 23 17:24 /sys/block/sda -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/27b553e8-8b39-411b-a55f-839971a7884f/host0/target0:0:0/0:0:0:1/block/sda\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdb -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdc -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdd -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sde -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:3/block/sde\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdf -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:4/block/sdf\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdg -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:5/block/sdg\n"
2026-03-23T17:31:34.2046258Z [ petri] 2026-03-23T17:25:28.095400Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2047242Z [ petri] 2026-03-23T17:25:28.095515Z INFO tests::utils: All disks all_disks="lrwxrwxrwx 1 root root 0 Mar 23 17:24 /sys/block/sda -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/27b553e8-8b39-411b-a55f-839971a7884f/host0/target0:0:0/0:0:0:1/block/sda\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdb -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdc -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdd -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sde -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:3/block/sde\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdf -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:4/block/sdf\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdg -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:5/block/sdg"
2026-03-23T17:31:34.2048525Z [ petri] 2026-03-23T17:25:28.102448Z INFO pipette: 71.415774300s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:0/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2048853Z [ linux] [ 100.823602] sd 1:0:0:6: [sdh] Mode Sense: 0f 00 10 00
2026-03-23T17:31:34.2049078Z [ petri] 2026-03-23T17:25:28.138299Z INFO pipette: 71.455148900s DEBUG pipette::execute: process exited pid=571 status=Normal(0)
2026-03-23T17:31:34.2049369Z [ petri] 2026-03-23T17:25:28.138534Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\n"
2026-03-23T17:31:34.2049650Z [ petri] 2026-03-23T17:25:28.138670Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2049951Z [ petri] 2026-03-23T17:25:28.148569Z INFO pipette: 71.458341000s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdb/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2050275Z [ petri] 2026-03-23T17:25:28.161023Z INFO pipette: 71.478323600s DEBUG pipette::execute: process exited pid=576 status=Normal(0)
2026-03-23T17:31:34.2050584Z [ petri] 2026-03-23T17:25:28.161303Z INFO pipette_client::shell: command stdout out="262144\n"
2026-03-23T17:31:34.2050806Z [ petri] 2026-03-23T17:25:28.161433Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2051151Z [ petri] 2026-03-23T17:25:28.163650Z INFO pipette: 71.480617400s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:1/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2051523Z [ petri] 2026-03-23T17:25:28.192059Z INFO pipette: 71.509491800s DEBUG pipette::execute: process exited pid=581 status=Normal(0)
2026-03-23T17:31:34.2051818Z [ petri] 2026-03-23T17:25:28.192983Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\n"
2026-03-23T17:31:34.2052087Z [ petri] 2026-03-23T17:25:28.193133Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2052389Z [ petri] 2026-03-23T17:25:28.199065Z INFO pipette: 71.515175800s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdc/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2052697Z [ linux] [ 100.869192] sd 1:0:0:6: [sdh] Write cache: enabled, read cache: enabled, supports DPO and FUA
2026-03-23T17:31:34.2052937Z [ petri] 2026-03-23T17:25:28.213858Z INFO pipette: 71.531137900s DEBUG pipette::execute: process exited pid=586 status=Normal(0)
2026-03-23T17:31:34.2053271Z [ petri] 2026-03-23T17:25:28.214123Z INFO pipette_client::shell: command stdout out="264192\n"
2026-03-23T17:31:34.2053494Z [ petri] 2026-03-23T17:25:28.214244Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2053839Z [ petri] 2026-03-23T17:25:28.216049Z INFO pipette: 71.532919900s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:2/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2054203Z [ petri] 2026-03-23T17:25:28.221971Z INFO pipette: 71.539387100s DEBUG pipette::execute: process exited pid=591 status=Normal(0)
2026-03-23T17:31:34.2054495Z [ petri] 2026-03-23T17:25:28.222187Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd\n"
2026-03-23T17:31:34.2054763Z [ petri] 2026-03-23T17:25:28.222305Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2055064Z [ petri] 2026-03-23T17:25:28.224085Z INFO pipette: 71.541026800s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdd/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2055390Z [ petri] 2026-03-23T17:25:28.227110Z INFO pipette: 71.544572300s DEBUG pipette::execute: process exited pid=596 status=Normal(0)
2026-03-23T17:31:34.2055634Z [ petri] 2026-03-23T17:25:28.227410Z INFO pipette_client::shell: command stdout out="266240\n"
2026-03-23T17:31:34.2055856Z [ petri] 2026-03-23T17:25:28.227519Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2056197Z [ petri] 2026-03-23T17:25:28.229137Z INFO pipette: 71.546110100s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:3/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2056612Z [ petri] 2026-03-23T17:25:28.233649Z INFO pipette: 71.550786400s DEBUG pipette::execute: process exited pid=601 status=Normal(0)
2026-03-23T17:31:34.2056907Z [ petri] 2026-03-23T17:25:28.233875Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:3/block/sde\n"
2026-03-23T17:31:34.2057173Z [ petri] 2026-03-23T17:25:28.234005Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2057474Z [ petri] 2026-03-23T17:25:28.235695Z INFO pipette: 71.552669200s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sde/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2057795Z [ petri] 2026-03-23T17:25:28.237752Z INFO pipette: 71.555225600s DEBUG pipette::execute: process exited pid=606 status=Normal(0)
2026-03-23T17:31:34.2058041Z [ petri] 2026-03-23T17:25:28.238009Z INFO pipette_client::shell: command stdout out="268288\n"
2026-03-23T17:31:34.2058263Z [ petri] 2026-03-23T17:25:28.238151Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2058608Z [ petri] 2026-03-23T17:25:28.239768Z INFO pipette: 71.556694400s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:4/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2058966Z [ petri] 2026-03-23T17:25:28.243747Z INFO pipette: 71.561098200s DEBUG pipette::execute: process exited pid=611 status=Normal(0)
2026-03-23T17:31:34.2059316Z [ petri] 2026-03-23T17:25:28.243973Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:4/block/sdf\n"
2026-03-23T17:31:34.2059593Z [ petri] 2026-03-23T17:25:28.244105Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2059893Z [ petri] 2026-03-23T17:25:28.245900Z INFO pipette: 71.562872100s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdf/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2060216Z [ petri] 2026-03-23T17:25:28.248185Z INFO pipette: 71.565464200s DEBUG pipette::execute: process exited pid=616 status=Normal(0)
2026-03-23T17:31:34.2060456Z [ petri] 2026-03-23T17:25:28.248401Z INFO pipette_client::shell: command stdout out="270336\n"
2026-03-23T17:31:34.2060678Z [ petri] 2026-03-23T17:25:28.248556Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2061026Z [ petri] 2026-03-23T17:25:28.250296Z INFO pipette: 71.567240800s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:5/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2061389Z [ petri] 2026-03-23T17:25:28.254406Z INFO pipette: 71.571723300s DEBUG pipette::execute: process exited pid=621 status=Normal(0)
2026-03-23T17:31:34.2061676Z [ petri] 2026-03-23T17:25:28.254665Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:5/block/sdg\n"
2026-03-23T17:31:34.2062028Z [ petri] 2026-03-23T17:25:28.254800Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2062426Z [ petri] 2026-03-23T17:25:28.256301Z INFO pipette: 71.573353000s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdg/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2062831Z [ petri] 2026-03-23T17:25:28.258716Z INFO pipette: 71.576139300s DEBUG pipette::execute: process exited pid=626 status=Normal(0)
2026-03-23T17:31:34.2063073Z [ petri] 2026-03-23T17:25:28.259019Z INFO pipette_client::shell: command stdout out="272384\n"
2026-03-23T17:31:34.2063301Z [ petri] 2026-03-23T17:25:28.259142Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2063646Z [ petri] 2026-03-23T17:25:28.260797Z INFO pipette: 71.577666400s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:6/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2064007Z [ petri] 2026-03-23T17:25:28.268608Z INFO pipette: 71.586051400s DEBUG pipette::execute: process exited pid=631 status=Normal(0)
2026-03-23T17:31:34.2064309Z [ petri] 2026-03-23T17:25:28.268828Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:6/block/sdh\n"
2026-03-23T17:31:34.2064575Z [ petri] 2026-03-23T17:25:28.268929Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2064876Z [ petri] 2026-03-23T17:25:28.270765Z INFO pipette: 71.587711100s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdh/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2065200Z [ petri] 2026-03-23T17:25:28.273273Z INFO pipette: 71.590767700s DEBUG pipette::execute: process exited pid=636 status=Normal(0)
2026-03-23T17:31:34.2065651Z [ petri] 2026-03-23T17:25:28.273761Z INFO pipette_client::shell: command stdout out="274432\n"
2026-03-23T17:31:34.2065872Z [ petri] 2026-03-23T17:25:28.273878Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2066219Z [ petri] 2026-03-23T17:25:28.275668Z INFO pipette: 71.592458600s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:7/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2066580Z [ petri] 2026-03-23T17:25:28.281424Z INFO pipette: 71.598818100s DEBUG pipette::execute: process exited pid=641 status=Normal(1)
2026-03-23T17:31:34.2066823Z [ petri] 2026-03-23T17:25:28.281651Z INFO pipette_client::shell: command stdout out=""
2026-03-23T17:31:34.2067104Z [ petri] 2026-03-23T17:25:28.281770Z INFO pipette_client::shell: command stderr err="ls: /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:7/block/sd*: No such file or directory\n"
2026-03-23T17:31:34.2067424Z [ petri] 2026-03-23T17:25:28.281971Z WARN tests::x86_64::storage: Attempt 3/10: Failed to get device paths: command failed: exit code 1. Retrying in 3 seconds...
2026-03-23T17:31:34.2067756Z [ petri] 2026-03-23T17:25:28.283545Z INFO pipette: 71.600528200s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sleep", args: ["3"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2068072Z [ openhcl] [134.226204] scsidisk: DEBUG scsi_error disk=[c8, c1, 1b, ed, ad, 45, 74, 40, 82, 79, 19, 95, 98, e1, 24, 67] error=unsupported vpd page code: 185 op=INQUIRY
2026-03-23T17:31:34.2068362Z [ openhcl] [134.269839] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2068666Z [ openhcl] [134.303087] scsidisk::inquiry: DEBUG handle_vpd_block_limits unmap properties max_lba_count=0xffffffff max_block_descriptor_count=0x1000 optimal_unmap_granularity=0x1
2026-03-23T17:31:34.2069012Z [ linux] [ 101.154814] sd 1:0:0:6: [sdh] Attached SCSI disk
2026-03-23T17:31:34.2069197Z [ linux] [ 101.249053] sd 1:0:0:7: Attached scsi generic sg8 type 0
2026-03-23T17:31:34.2069392Z [ linux] [ 101.250984] sd 1:0:0:7: [sdi] 276480 512-byte logical blocks: (142 MB/135 MiB)
2026-03-23T17:31:34.2069590Z [ linux] [ 101.374780] sd 1:0:0:7: [sdi] 4096-byte physical blocks
2026-03-23T17:31:34.2069768Z [ linux] [ 101.419976] sd 1:0:0:7: [sdi] Write Protect is off
2026-03-23T17:31:34.2069950Z [ linux] [ 101.462993] sd 1:0:0:7: [sdi] Mode Sense: 0f 00 10 00
2026-03-23T17:31:34.2070150Z [ linux] [ 101.505941] sd 1:0:0:7: [sdi] Write cache: enabled, read cache: enabled, supports DPO and FUA
2026-03-23T17:31:34.2070391Z [ openhcl] [134.803321] scsidisk: DEBUG scsi_error disk=[ef, 52, a8, 52, d9, fb, 72, 45, b6, 79, 71, b6, 1f, 2d, e7, 2f] error=unsupported vpd page code: 185 op=INQUIRY
2026-03-23T17:31:34.2070610Z [ linux] [ 101.664993] sd 1:0:0:7: [sdi] Attached SCSI disk
2026-03-23T17:31:34.2070831Z [ openvmm] 139.455570000s DEBUG hyperv_ic::timesync: sent time sample time=2026-03-23T17:25:30.5498127Z ref_time=0x52d2266d
2026-03-23T17:31:34.2071061Z [ linux] [ 103.270876] sd 1:0:0:7: [sdi] Synchronizing SCSI cache
2026-03-23T17:31:34.2071248Z [ openvmm] 139.533551700s DEBUG nvme::namespace: flush nsid=0x25
2026-03-23T17:31:34.2071474Z [ petri] 2026-03-23T17:25:31.287638Z INFO pipette: 74.604683300s DEBUG pipette::execute: process exited pid=646 status=Normal(0)
2026-03-23T17:31:34.2071769Z [ petri] 2026-03-23T17:25:31.287951Z INFO pipette_client::shell: command stdout out=""
2026-03-23T17:31:34.2071986Z [ petri] 2026-03-23T17:25:31.288077Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2072290Z [ petri] 2026-03-23T17:25:31.290150Z INFO pipette: 74.606868100s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -ld /sys/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2072620Z [ petri] 2026-03-23T17:25:31.297367Z INFO pipette: 74.614304900s DEBUG pipette::execute: process exited pid=651 status=Normal(0)
2026-03-23T17:31:34.2073744Z [ petri] 2026-03-23T17:25:31.297682Z INFO pipette_client::shell: command stdout out="lrwxrwxrwx 1 root root 0 Mar 23 17:24 /sys/block/sda -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/27b553e8-8b39-411b-a55f-839971a7884f/host0/target0:0:0/0:0:0:1/block/sda\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdb -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdc -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdd -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sde -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:3/block/sde\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdf -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:4/block/sdf\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdg -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:5/block/sdg\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdh -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:6/block/sdh\n"
2026-03-23T17:31:34.2075213Z [ petri] 2026-03-23T17:25:31.297982Z INFO pipette_client::shell: command stderr err=""
Logs from last attempt to find disks:
2026-03-23T17:31:34.2224490Z [ petri] 2026-03-23T17:25:46.985724Z WARN tests::x86_64::storage: Attempt 9/10: Failed to get device paths: command failed: exit code 1. Retrying in 3 seconds...
2026-03-23T17:31:34.2224825Z [ petri] 2026-03-23T17:25:46.987437Z INFO pipette: 90.304340400s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sleep", args: ["3"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2225155Z [ petri] 2026-03-23T17:25:49.991025Z INFO pipette: 93.308204900s DEBUG pipette::execute: process exited pid=1156 status=Normal(0)
2026-03-23T17:31:34.2225394Z [ petri] 2026-03-23T17:25:49.991391Z INFO pipette_client::shell: command stdout out=""
2026-03-23T17:31:34.2225615Z [ petri] 2026-03-23T17:25:49.991536Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2225924Z [ petri] 2026-03-23T17:25:49.993655Z INFO pipette: 93.310392300s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -ld /sys/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2226307Z [ petri] 2026-03-23T17:25:49.999905Z INFO pipette: 93.317263700s DEBUG pipette::execute: process exited pid=1161 status=Normal(0)
2026-03-23T17:31:34.2227427Z [ petri] 2026-03-23T17:25:50.000216Z INFO pipette_client::shell: command stdout out="lrwxrwxrwx 1 root root 0 Mar 23 17:24 /sys/block/sda -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/27b553e8-8b39-411b-a55f-839971a7884f/host0/target0:0:0/0:0:0:1/block/sda\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdb -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdc -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdd -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sde -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:3/block/sde\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdf -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:4/block/sdf\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdg -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:5/block/sdg\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdh -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:6/block/sdh\n"
2026-03-23T17:31:34.2228512Z [ petri] 2026-03-23T17:25:50.000521Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2229604Z [ petri] 2026-03-23T17:25:50.000656Z INFO tests::utils: All disks all_disks="lrwxrwxrwx 1 root root 0 Mar 23 17:24 /sys/block/sda -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/27b553e8-8b39-411b-a55f-839971a7884f/host0/target0:0:0/0:0:0:1/block/sda\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdb -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdc -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdd -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sde -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:3/block/sde\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdf -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:4/block/sdf\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdg -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:5/block/sdg\nlrwxrwxrwx 1 root root 0 Mar 23 17:25 /sys/block/sdh -> ../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:6/block/sdh"
2026-03-23T17:31:34.2230861Z [ petri] 2026-03-23T17:25:50.003018Z INFO pipette: 93.319394200s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:0/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2231275Z [ petri] 2026-03-23T17:25:50.009696Z INFO pipette: 93.327063400s DEBUG pipette::execute: process exited pid=1166 status=Normal(0)
2026-03-23T17:31:34.2231578Z [ petri] 2026-03-23T17:25:50.010094Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:0/block/sdb\n"
2026-03-23T17:31:34.2231851Z [ petri] 2026-03-23T17:25:50.010236Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2232157Z [ petri] 2026-03-23T17:25:50.012346Z INFO pipette: 93.329140900s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdb/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2232481Z [ petri] 2026-03-23T17:25:50.015928Z INFO pipette: 93.333053100s DEBUG pipette::execute: process exited pid=1171 status=Normal(0)
2026-03-23T17:31:34.2232738Z [ petri] 2026-03-23T17:25:50.016199Z INFO pipette_client::shell: command stdout out="262144\n"
2026-03-23T17:31:34.2232966Z [ petri] 2026-03-23T17:25:50.016339Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2233315Z [ petri] 2026-03-23T17:25:50.018752Z INFO pipette: 93.335172600s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:1/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2233677Z [ petri] 2026-03-23T17:25:50.025893Z INFO pipette: 93.343364600s DEBUG pipette::execute: process exited pid=1176 status=Normal(0)
2026-03-23T17:31:34.2233971Z [ petri] 2026-03-23T17:25:50.026302Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:1/block/sdc\n"
2026-03-23T17:31:34.2234254Z [ petri] 2026-03-23T17:25:50.026438Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2234558Z [ petri] 2026-03-23T17:25:50.028197Z INFO pipette: 93.345114600s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdc/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2234933Z [ petri] 2026-03-23T17:25:50.031584Z INFO pipette: 93.348891400s DEBUG pipette::execute: process exited pid=1181 status=Normal(0)
2026-03-23T17:31:34.2235178Z [ petri] 2026-03-23T17:25:50.031992Z INFO pipette_client::shell: command stdout out="264192\n"
2026-03-23T17:31:34.2235402Z [ petri] 2026-03-23T17:25:50.032111Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2235756Z [ petri] 2026-03-23T17:25:50.033807Z INFO pipette: 93.350577400s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:2/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2236290Z [ petri] 2026-03-23T17:25:50.038498Z INFO pipette: 93.356008600s DEBUG pipette::execute: process exited pid=1186 status=Normal(0)
2026-03-23T17:31:34.2236584Z [ petri] 2026-03-23T17:25:50.039049Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:2/block/sdd\n"
2026-03-23T17:31:34.2236855Z [ petri] 2026-03-23T17:25:50.039185Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2237163Z [ petri] 2026-03-23T17:25:50.041243Z INFO pipette: 93.358014400s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdd/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2237614Z [ petri] 2026-03-23T17:25:50.043957Z INFO pipette: 93.361145300s DEBUG pipette::execute: process exited pid=1191 status=Normal(0)
2026-03-23T17:31:34.2237862Z [ petri] 2026-03-23T17:25:50.044193Z INFO pipette_client::shell: command stdout out="266240\n"
2026-03-23T17:31:34.2238085Z [ petri] 2026-03-23T17:25:50.044316Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2238431Z [ petri] 2026-03-23T17:25:50.045870Z INFO pipette: 93.362833200s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:3/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2238805Z [ petri] 2026-03-23T17:25:50.052776Z INFO pipette: 93.370207400s DEBUG pipette::execute: process exited pid=1196 status=Normal(0)
2026-03-23T17:31:34.2239099Z [ petri] 2026-03-23T17:25:50.053160Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:3/block/sde\n"
2026-03-23T17:31:34.2239505Z [ petri] 2026-03-23T17:25:50.053286Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2239811Z [ petri] 2026-03-23T17:25:50.054923Z INFO pipette: 93.371834400s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sde/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2240142Z [ petri] 2026-03-23T17:25:50.058136Z INFO pipette: 93.375579200s DEBUG pipette::execute: process exited pid=1201 status=Normal(0)
2026-03-23T17:31:34.2240388Z [ petri] 2026-03-23T17:25:50.058596Z INFO pipette_client::shell: command stdout out="268288\n"
2026-03-23T17:31:34.2240645Z [ petri] 2026-03-23T17:25:50.058755Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2241280Z [ petri] 2026-03-23T17:25:50.060376Z INFO pipette: 93.377338900s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:4/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2242161Z [ petri] 2026-03-23T17:25:50.065786Z INFO pipette: 93.383061400s DEBUG pipette::execute: process exited pid=1206 status=Normal(0)
2026-03-23T17:31:34.2242737Z [ petri] 2026-03-23T17:25:50.066171Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:4/block/sdf\n"
2026-03-23T17:31:34.2243259Z [ petri] 2026-03-23T17:25:50.066300Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2243844Z [ petri] 2026-03-23T17:25:50.068015Z INFO pipette: 93.384896400s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdf/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2244272Z [ petri] 2026-03-23T17:25:50.070864Z INFO pipette: 93.388111600s DEBUG pipette::execute: process exited pid=1211 status=Normal(0)
2026-03-23T17:31:34.2244517Z [ petri] 2026-03-23T17:25:50.071160Z INFO pipette_client::shell: command stdout out="270336\n"
2026-03-23T17:31:34.2244749Z [ petri] 2026-03-23T17:25:50.071287Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2245098Z [ petri] 2026-03-23T17:25:50.073296Z INFO pipette: 93.390048200s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:5/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2245618Z [ petri] 2026-03-23T17:25:50.078319Z INFO pipette: 93.395617300s DEBUG pipette::execute: process exited pid=1216 status=Normal(0)
2026-03-23T17:31:34.2245913Z [ petri] 2026-03-23T17:25:50.078524Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:5/block/sdg\n"
2026-03-23T17:31:34.2246188Z [ petri] 2026-03-23T17:25:50.078676Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2246489Z [ petri] 2026-03-23T17:25:50.081178Z INFO pipette: 93.398116800s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdg/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2246815Z [ petri] 2026-03-23T17:25:50.084435Z INFO pipette: 93.401785800s DEBUG pipette::execute: process exited pid=1221 status=Normal(0)
2026-03-23T17:31:34.2247061Z [ petri] 2026-03-23T17:25:50.084710Z INFO pipette_client::shell: command stdout out="272384\n"
2026-03-23T17:31:34.2247285Z [ petri] 2026-03-23T17:25:50.084837Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2247629Z [ petri] 2026-03-23T17:25:50.086508Z INFO pipette: 93.403382700s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:6/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2248004Z [ petri] 2026-03-23T17:25:50.093106Z INFO pipette: 93.410424200s DEBUG pipette::execute: process exited pid=1226 status=Normal(0)
2026-03-23T17:31:34.2248296Z [ petri] 2026-03-23T17:25:50.093606Z INFO pipette_client::shell: command stdout out="/sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host1/target1:0:0/1:0:0:6/block/sdh\n"
2026-03-23T17:31:34.2248565Z [ petri] 2026-03-23T17:25:50.093737Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2248958Z [ petri] 2026-03-23T17:25:50.095544Z INFO pipette: 93.412455800s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "cat", args: ["/sys/block/sdh/size"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2249293Z [ petri] 2026-03-23T17:25:50.098882Z INFO pipette: 93.416134500s DEBUG pipette::execute: process exited pid=1231 status=Normal(0)
2026-03-23T17:31:34.2249537Z [ petri] 2026-03-23T17:25:50.099064Z INFO pipette_client::shell: command stdout out="274432\n"
2026-03-23T17:31:34.2249758Z [ petri] 2026-03-23T17:25:50.099157Z INFO pipette_client::shell: command stderr err=""
2026-03-23T17:31:34.2250104Z [ petri] 2026-03-23T17:25:50.100767Z INFO pipette: 93.417708600s DEBUG pipette::execute: execute request request=ExecuteRequest { program: "sh", args: ["-c", "ls -d /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:7/block/sd*"], current_dir: Some("/"), stdin: true, stdout: true, stderr: true, env: [], clear_env: false }
2026-03-23T17:31:34.2250477Z [ petri] 2026-03-23T17:25:50.107296Z INFO pipette: 93.424713500s DEBUG pipette::execute: process exited pid=1236 status=Normal(1)
2026-03-23T17:31:34.2250716Z [ petri] 2026-03-23T17:25:50.107687Z INFO pipette_client::shell: command stdout out=""
2026-03-23T17:31:34.2250996Z [ petri] 2026-03-23T17:25:50.107802Z INFO pipette_client::shell: command stderr err="ls: /sys/bus/vmbus/devices/63dadc0e-4c9b-451b-b1be-c93aabe8fae1/host*/target*/*:0:0:7/block/sd*: No such file or directory\n"
2026-03-23T17:31:34.2251401Z [ petri] 2026-03-23T17:25:50.109841Z INFO mesh-point-to-point: mesh_remote::point_to_point: close time.busy=212ms time.idle=93.4s node=N-a41be9d538cb666338b136985a783abb
2026-03-23T17:31:34.2251707Z [ petri] 2026-03-23T17:25:50.110221Z ERROR mesh_channel_core::mpsc: channel closed due to error error=node failure error.sources=[local mesh failure, mesh is shutting down]
2026-03-23T17:31:34.2252013Z [ petri] 2026-03-23T17:25:50.110574Z ERROR petri::tracing: test failed error=Failed to get device paths after 10 attempts: command failed: exit code 1
2026-03-23T17:31:34.2252214Z FAILED