lava-dispatcher, installed at version: 2023.10 start: 0 validate Start time: 2024-12-06 09:53:19.462453+00:00 (UTC) Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/images/rootfs/buildroot/buildroot-baseline/20230623.0/riscv/rootfs.cpio.gz?raw=true exists Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/kernel/Image?raw=true exists Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/dtbs/sifive/hifive-unmatched-a00.dtb?raw=true exists Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/modules.tar.xz?raw=true exists validate duration: 5.18 case: validate
case_id: 4107644
definition: lava
result: pass
start: 1 tftp-deploy (timeout 00:10:00) [common] start: 1.1 download-retry (timeout 00:10:00) [common] start: 1.1.1 http-download (timeout 00:10:00) [common] Not decompressing ramdisk as can be used compressed. downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/images/rootfs/buildroot/buildroot-baseline/20230623.0/riscv/rootfs.cpio.gz?raw=true saving as /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/ramdisk/rootfs.cpio.gz total size: 7844224 (7 MB) progress 0 % (0 MB) progress 5 % (0 MB) progress 10 % (0 MB) progress 15 % (1 MB) progress 20 % (1 MB) progress 25 % (1 MB) progress 30 % (2 MB) progress 35 % (2 MB) progress 40 % (3 MB) progress 45 % (3 MB) progress 50 % (3 MB) progress 55 % (4 MB) progress 60 % (4 MB) progress 65 % (4 MB) progress 70 % (5 MB) progress 75 % (5 MB) progress 80 % (6 MB) progress 85 % (6 MB) progress 90 % (6 MB) progress 95 % (7 MB) progress 100 % (7 MB) 7 MB downloaded in 0.63 s (11.78 MB/s) end: 1.1.1 http-download (duration 00:00:01) [common] case: http-download
case_id: 4107648
definition: lava
duration: 0.64
extra: ...
level: 1.1.1
namespace: common
result: pass
end: 1.1 download-retry (duration 00:00:01) [common] start: 1.2 download-retry (timeout 00:09:59) [common] start: 1.2.1 http-download (timeout 00:09:59) [common] downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/kernel/Image?raw=true saving as /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/kernel/Image total size: 19845120 (18 MB) No compression specified progress 0 % (0 MB) progress 5 % (0 MB) progress 10 % (1 MB) progress 15 % (2 MB) progress 20 % (3 MB) progress 25 % (4 MB) progress 30 % (5 MB) progress 35 % (6 MB) progress 40 % (7 MB) progress 45 % (8 MB) progress 50 % (9 MB) progress 55 % (10 MB) progress 60 % (11 MB) progress 65 % (12 MB) progress 70 % (13 MB) progress 75 % (14 MB) progress 80 % (15 MB) progress 85 % (16 MB) progress 90 % (17 MB) progress 95 % (18 MB) progress 100 % (18 MB) 18 MB downloaded in 1.62 s (11.71 MB/s) end: 1.2.1 http-download (duration 00:00:02) [common] case: http-download
case_id: 4107648
definition: lava
duration: 1.62
extra: ...
level: 1.2.1
namespace: common
result: pass
end: 1.2 download-retry (duration 00:00:02) [common] start: 1.3 download-retry (timeout 00:09:58) [common] start: 1.3.1 http-download (timeout 00:09:58) [common] downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/dtbs/sifive/hifive-unmatched-a00.dtb?raw=true saving as /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/dtb/hifive-unmatched-a00.dtb total size: 10707 (0 MB) No compression specified progress 100 % (0 MB) 0 MB downloaded in 0.21 s (0.05 MB/s) end: 1.3.1 http-download (duration 00:00:00) [common] case: http-download
case_id: 4107648
definition: lava
duration: 0.21
extra: ...
level: 1.3.1
namespace: common
result: pass
end: 1.3 download-retry (duration 00:00:00) [common] start: 1.4 download-retry (timeout 00:09:58) [common] start: 1.4.1 http-download (timeout 00:09:58) [common] downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/modules.tar.xz?raw=true saving as /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/modules/modules.tar total size: 3892756 (3 MB) Using unxz to decompress xz progress 0 % (0 MB) progress 5 % (0 MB) progress 10 % (0 MB) progress 15 % (0 MB) progress 20 % (0 MB) progress 25 % (0 MB) progress 30 % (1 MB) progress 35 % (1 MB) progress 40 % (1 MB) progress 45 % (1 MB) progress 50 % (1 MB) progress 55 % (2 MB) progress 60 % (2 MB) progress 65 % (2 MB) progress 70 % (2 MB) progress 75 % (2 MB) progress 80 % (3 MB) progress 85 % (3 MB) progress 90 % (3 MB) progress 95 % (3 MB) progress 100 % (3 MB) 3 MB downloaded in 0.58 s (6.44 MB/s) end: 1.4.1 http-download (duration 00:00:01) [common] case: http-download
case_id: 4107648
definition: lava
duration: 0.58
extra: ...
level: 1.4.1
namespace: common
result: pass
end: 1.4 download-retry (duration 00:00:01) [common] start: 1.5 prepare-tftp-overlay (timeout 00:09:57) [common] start: 1.5.1 extract-nfsrootfs (timeout 00:09:57) [common] end: 1.5.1 extract-nfsrootfs (duration 00:00:00) [common] start: 1.5.2 lava-overlay (timeout 00:09:57) [common] [common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj makedir: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin makedir: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/tests makedir: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/results Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-add-keys Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-add-sources Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-background-process-start Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-background-process-stop Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-common-functions Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-echo-ipv4 Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-install-packages Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-installed-packages Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-os-build Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-probe-channel Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-probe-ip Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-target-ip Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-target-mac Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-target-storage Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-case Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-event Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-feedback Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-raise Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-reference Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-runner Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-set Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-shell Updating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-install-packages (oe) Updating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-installed-packages (oe) Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/environment LAVA metadata - LAVA_JOB_ID=38167 - LAVA_DISPATCHER_IP=192.168.66.1 start: 1.5.2.1 ssh-authorize (timeout 00:09:57) [common] end: 1.5.2.1 ssh-authorize (duration 00:00:00) [common] start: 1.5.2.2 lava-vland-overlay (timeout 00:09:57) [common] skipped lava-vland-overlay end: 1.5.2.2 lava-vland-overlay (duration 00:00:00) [common] start: 1.5.2.3 lava-multinode-overlay (timeout 00:09:57) [common] skipped lava-multinode-overlay end: 1.5.2.3 lava-multinode-overlay (duration 00:00:00) [common] start: 1.5.2.4 test-definition (timeout 00:09:57) [common] Loading test definitions start: 1.5.2.4.1 inline-repo-action (timeout 00:09:57) [common] Using /lava-38167 at stage 0 uuid=38167_1.5.2.4.1 testdef=None end: 1.5.2.4.1 inline-repo-action (duration 00:00:00) [common] start: 1.5.2.4.2 test-overlay (timeout 00:09:57) [common] end: 1.5.2.4.2 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4107652
definition: lava
duration: 0.00
extra: ...
level: 1.5.2.4.2
namespace: common
result: pass
start: 1.5.2.4.3 test-install-overlay (timeout 00:09:57) [common] end: 1.5.2.4.3 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4107653
definition: lava
duration: 0.00
extra: ...
level: 1.5.2.4.3
namespace: common
result: pass
start: 1.5.2.4.4 test-runscript-overlay (timeout 00:09:57) [common] runner path: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/0/tests/0_dmesg test_uuid 38167_1.5.2.4.1 end: 1.5.2.4.4 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4107654
definition: lava
duration: 0.00
extra: ...
level: 1.5.2.4.4
namespace: common
result: pass
start: 1.5.2.4.5 inline-repo-action (timeout 00:09:57) [common] Using /lava-38167 at stage 1 uuid=38167_1.5.2.4.5 testdef=None end: 1.5.2.4.5 inline-repo-action (duration 00:00:00) [common] start: 1.5.2.4.6 test-overlay (timeout 00:09:57) [common] end: 1.5.2.4.6 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4107652
definition: lava
duration: 0.00
extra: ...
level: 1.5.2.4.6
namespace: common
result: pass
start: 1.5.2.4.7 test-install-overlay (timeout 00:09:57) [common] end: 1.5.2.4.7 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4107653
definition: lava
duration: 0.00
extra: ...
level: 1.5.2.4.7
namespace: common
result: pass
start: 1.5.2.4.8 test-runscript-overlay (timeout 00:09:57) [common] runner path: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/1/tests/1_bootrr test_uuid 38167_1.5.2.4.5 end: 1.5.2.4.8 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4107654
definition: lava
duration: 0.00
extra: ...
level: 1.5.2.4.8
namespace: common
result: pass
Creating lava-test-runner.conf files Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/0 for stage 0 - 0_dmesg Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/1 for stage 1 - 1_bootrr end: 1.5.2.4 test-definition (duration 00:00:00) [common] start: 1.5.2.5 compress-overlay (timeout 00:09:57) [common] end: 1.5.2.5 compress-overlay (duration 00:00:00) [common] start: 1.5.2.6 persistent-nfs-overlay (timeout 00:09:57) [common] end: 1.5.2.6 persistent-nfs-overlay (duration 00:00:00) [common] end: 1.5.2 lava-overlay (duration 00:00:00) [common] start: 1.5.3 extract-overlay-ramdisk (timeout 00:09:57) [common] end: 1.5.3 extract-overlay-ramdisk (duration 00:00:00) [common] start: 1.5.4 extract-modules (timeout 00:09:57) [common] extracting modules file /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/modules/modules.tar to /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk end: 1.5.4 extract-modules (duration 00:00:00) [common] start: 1.5.5 apply-overlay-tftp (timeout 00:09:56) [common] [common] Applying overlay /var/lib/lava/dispatcher/tmp/38167/compress-overlay-d6oze46s/overlay-1.5.2.5.tar.gz to ramdisk [common] Applying overlay /var/lib/lava/dispatcher/tmp/38167/compress-overlay-d6oze46s/overlay-1.5.2.5.tar.gz to directory /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk end: 1.5.5 apply-overlay-tftp (duration 00:00:00) [common] start: 1.5.6 prepare-kernel (timeout 00:09:56) [common] start: 1.5.6.1 uboot-prepare-kernel (timeout 00:09:56) [common] end: 1.5.6.1 uboot-prepare-kernel (duration 00:00:00) [common] end: 1.5.6 prepare-kernel (duration 00:00:00) [common] start: 1.5.7 configure-preseed-file (timeout 00:09:56) [common] end: 1.5.7 configure-preseed-file (duration 00:00:00) [common] start: 1.5.8 compress-ramdisk (timeout 00:09:56) [common] Building ramdisk /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk.cpio containing /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk >> 86851 blocks Adding RAMdisk u-boot header. mkimage -A riscv -T ramdisk -C none -d /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk.cpio.gz /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk.cpio.gz.uboot output: Image Name: output: Created: Fri Dec 6 09:53:30 2024 output: Image Type: RISC-V Linux RAMDisk Image (uncompressed) output: Data Size: 13631840 Bytes = 13312.34 KiB = 13.00 MiB output: Load Address: 00000000 output: Entry Point: 00000000 output: rename /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk.cpio.gz.uboot to /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/ramdisk/ramdisk.cpio.gz.uboot end: 1.5.8 compress-ramdisk (duration 00:00:03) [common] end: 1.5 prepare-tftp-overlay (duration 00:00:03) [common] start: 1.6 lxc-create-udev-rule-action (timeout 00:09:54) [common] No LXC device requested end: 1.6 lxc-create-udev-rule-action (duration 00:00:00) [common] start: 1.7 deploy-device-env (timeout 00:09:54) [common] end: 1.7 deploy-device-env (duration 00:00:00) [common] Checking files for TFTP limit of 4294967296 bytes. end: 1 tftp-deploy (duration 00:00:06) [common] start: 2 uboot-action (timeout 00:05:00) [common] start: 2.1 uboot-from-media (timeout 00:05:00) [common] end: 2.1 uboot-from-media (duration 00:00:00) [common] start: 2.2 bootloader-overlay (timeout 00:05:00) [common] substitutions: - {BOOTX}: booti 0x80200000 0x83500000 0x83000000 - {DTB_ADDR}: 0x83000000 - {DTB}: 38167/tftp-deploy-jdlmucrc/dtb/hifive-unmatched-a00.dtb - {INITRD}: 38167/tftp-deploy-jdlmucrc/ramdisk/ramdisk.cpio.gz.uboot - {KERNEL_ADDR}: 0x80200000 - {KERNEL}: 38167/tftp-deploy-jdlmucrc/kernel/Image - {LAVA_MAC}: None - {PRESEED_CONFIG}: None - {PRESEED_LOCAL}: None - {RAMDISK_ADDR}: 0x83500000 - {RAMDISK}: 38167/tftp-deploy-jdlmucrc/ramdisk/ramdisk.cpio.gz.uboot - {ROOT_PART}: None - {ROOT}: None - {SERVER_IP}: 192.168.66.1 - {TEE_ADDR}: 0x83000000 - {TEE}: None Parsed boot commands: - setenv autoload no - setenv initrd_high 0xffffffffffffffff - setenv fdt_high 0xffffffffffffffff - dhcp - setenv serverip 192.168.66.1 - tftp 0x80200000 38167/tftp-deploy-jdlmucrc/kernel/Image - tftp 0x83500000 38167/tftp-deploy-jdlmucrc/ramdisk/ramdisk.cpio.gz.uboot - setenv initrd_size ${filesize} - tftp 0x83000000 38167/tftp-deploy-jdlmucrc/dtb/hifive-unmatched-a00.dtb - setenv bootargs '115200 root=/dev/ram0 console_msg_format=syslog earlycon deferred_probe_timeout=60 ip=dhcp' - booti 0x80200000 0x83500000 0x83000000 end: 2.2 bootloader-overlay (duration 00:00:00) [common] case: bootloader-overlay
case_id: 4107660
definition: lava
duration: 0.00
extra: ...
level: 2.2
namespace: common
result: pass
start: 2.3 connect-device (timeout 00:05:00) [common] [common] connect-device Connecting to device using 'telnet 127.0.0.1 63006' Setting prompt string to ['lava-test: # '] end: 2.3 connect-device (duration 00:00:00) [common] start: 2.4 uboot-commands (timeout 00:05:00) [common] start: 2.4.1 reset-device (timeout 00:05:00) [common] start: 2.4.1.1 pdu-reboot (timeout 00:05:00) [common] Calling: 'upower.sh' '--atx' 'reset' '1' >> No GEMBIRD SiS-PM found. Check USB connections, please! >> No GEMBIRD SiS-PM found. Check USB connections, please! >> FTDI RELAY: power on >> FTDI RELAY: power off Returned 0 in 9 seconds end: 2.4.1.1 pdu-reboot (duration 00:00:09) [common] case: pdu-reboot
case_id: 4107666
definition: lava
duration: 9.14
extra: ...
level: 2.4.1.1
namespace: common
result: pass
end: 2.4.1 reset-device (duration 00:00:09) [common] start: 2.4.2 bootloader-interrupt (timeout 00:04:51) [common] Setting prompt string to ['Hit any key to stop autoboot'] bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:05:00) Trying 127.0.0.1... Connected to 127.0.0.1. Escape character is '^]'. bootloader-interrupt timed out after 291 seconds end: 2.4.2 bootloader-interrupt (duration 00:04:51) [common] case: bootloader-interrupt
case_id: 4107685
definition: lava
duration: 291.00
extra: ...
level: 2.4.2
namespace: common
result: fail
bootloader-interrupt timed out after 291 seconds end: 2.4 uboot-commands (duration 00:05:00) [common] case: uboot-commands
case_id: 4107686
definition: lava
duration: 300.14
extra: ...
level: 2.4
namespace: common
result: fail
uboot-action failed: 1 of 1 attempts. 'bootloader-interrupt timed out after 291 seconds' bootloader-interrupt timed out after 291 seconds end: 2 uboot-action (duration 00:05:00) [common] case: uboot-action
case_id: 4107687
definition: lava
duration: 300.15
extra: ...
level: 2
namespace: common
result: fail
Cleaning after the job Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/ramdisk Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/kernel Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/dtb Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/modules start: 5.1 power-off (timeout 00:00:30) [common] Calling: 'upower.sh' '--atx' 'off' '1' >> No GEMBIRD SiS-PM found. Check USB connections, please! Returned 0 in 1 seconds end: 5.1 power-off (duration 00:00:01) [common] case: power-off
case_id: 4107688
definition: lava
duration: 1.14
extra: ...
level: 5.1
namespace: common
result: pass
start: 5.2 read-feedback (timeout 00:09:59) [common] Listened to connection for namespace 'common' for up to 1s Finalising connection for namespace 'common' Disconnecting from shell: Finalise end: 5.2 read-feedback (duration 00:00:01) [common] Override tmp directory removed at /var/lib/lava/dispatcher/tmp/38167 Root tmp directory removed at /var/lib/lava/dispatcher/tmp/38167 InfrastructureError: The Infrastructure is not working correctly. Please report this error to LAVA admins. case: job
case_id: 4107689
definition: lava
error_msg: bootloader-interrupt timed out after 291 seconds
error_type: Infrastructure
result: fail