lava-dispatcher, installed at version: 2023.10 start: 0 validate Start time: 2024-05-29 11:32:49.709769+00:00 (UTC) Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/images/rootfs/buildroot/kci-2019.02-11-g17e793fa4728/arm64/base/rootfs.cpio.gz?raw=true exists Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/Image?raw=true exists Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/dtbs/broadcom/bcm2711-rpi-4-b.dtb?raw=true exists Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/modules.tar.xz?raw=true exists validate duration: 5.85 case: validate
case_id: 3987292
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/kci-2019.02-11-g17e793fa4728/arm64/base/rootfs.cpio.gz?raw=true saving as /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/ramdisk/rootfs.cpio.gz total size: 4192947 (3 MB) progress 0 % (0 MB) progress 5 % (0 MB) progress 10 % (0 MB) progress 15 % (0 MB) progress 20 % (0 MB) progress 25 % (1 MB) progress 30 % (1 MB) progress 35 % (1 MB) progress 40 % (1 MB) progress 45 % (1 MB) progress 50 % (2 MB) progress 55 % (2 MB) progress 60 % (2 MB) progress 65 % (2 MB) progress 70 % (2 MB) progress 75 % (3 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.61 s (6.53 MB/s) end: 1.1.1 http-download (duration 00:00:01) [common] case: http-download
case_id: 3987296
definition: lava
duration: 0.62
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-5.6.y/v5.6.12/arm64/defconfig/gcc-8/Image?raw=true saving as /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/kernel/Image total size: 27247104 (25 MB) No compression specified progress 0 % (0 MB) progress 5 % (1 MB) progress 10 % (2 MB) progress 15 % (3 MB) progress 20 % (5 MB) progress 25 % (6 MB) progress 30 % (7 MB) progress 35 % (9 MB) progress 40 % (10 MB) progress 45 % (11 MB) progress 50 % (13 MB) progress 55 % (14 MB) progress 60 % (15 MB) progress 65 % (16 MB) progress 70 % (18 MB) progress 75 % (19 MB) progress 80 % (20 MB) progress 85 % (22 MB) progress 90 % (23 MB) progress 95 % (24 MB) progress 100 % (25 MB) 25 MB downloaded in 2.86 s (9.07 MB/s) end: 1.2.1 http-download (duration 00:00:03) [common] case: http-download
case_id: 3987296
definition: lava
duration: 2.87
extra: ...
level: 1.2.1
namespace: common
result: pass
end: 1.2 download-retry (duration 00:00:03) [common] start: 1.3 download-retry (timeout 00:09:57) [common] start: 1.3.1 http-download (timeout 00:09:57) [common] downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/dtbs/broadcom/bcm2711-rpi-4-b.dtb?raw=true saving as /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/dtb/bcm2711-rpi-4-b.dtb total size: 22210 (0 MB) No compression specified progress 100 % (0 MB) 0 MB downloaded in 0.21 s (0.10 MB/s) end: 1.3.1 http-download (duration 00:00:00) [common] case: http-download
case_id: 3987296
definition: lava
duration: 0.22
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:56) [common] start: 1.4.1 http-download (timeout 00:09:56) [common] downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/modules.tar.xz?raw=true saving as /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/modules/modules.tar total size: 6392588 (6 MB) Using unxz to decompress xz progress 0 % (0 MB) progress 5 % (0 MB) progress 10 % (0 MB) progress 15 % (0 MB) progress 20 % (1 MB) progress 25 % (1 MB) progress 30 % (1 MB) progress 35 % (2 MB) progress 40 % (2 MB) progress 45 % (2 MB) progress 50 % (3 MB) progress 55 % (3 MB) progress 60 % (3 MB) progress 65 % (3 MB) progress 70 % (4 MB) progress 75 % (4 MB) progress 80 % (4 MB) progress 85 % (5 MB) progress 90 % (5 MB) progress 95 % (5 MB) progress 100 % (6 MB) 6 MB downloaded in 1.82 s (3.35 MB/s) end: 1.4.1 http-download (duration 00:00:02) [common] case: http-download
case_id: 3987296
definition: lava
duration: 1.82
extra: ...
level: 1.4.1
namespace: common
result: pass
end: 1.4 download-retry (duration 00:00:02) [common] start: 1.5 prepare-tftp-overlay (timeout 00:09:54) [common] start: 1.5.1 extract-nfsrootfs (timeout 00:09:54) [common] end: 1.5.1 extract-nfsrootfs (duration 00:00:00) [common] start: 1.5.2 lava-overlay (timeout 00:09:54) [common] [common] skipped lava-overlay - no test action. end: 1.5.2 lava-overlay (duration 00:00:00) [common] start: 1.5.3 extract-overlay-ramdisk (timeout 00:09:54) [common] end: 1.5.3 extract-overlay-ramdisk (duration 00:00:01) [common] start: 1.5.4 extract-modules (timeout 00:09:54) [common] extracting modules file /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/modules/modules.tar to /var/lib/lava/dispatcher/tmp/34537/extract-overlay-ramdisk-6r4wf5pz/ramdisk end: 1.5.4 extract-modules (duration 00:00:01) [common] start: 1.5.5 apply-overlay-tftp (timeout 00:09:52) [common] end: 1.5.5 apply-overlay-tftp (duration 00:00:00) [common] start: 1.5.6 prepare-kernel (timeout 00:09:52) [common] start: 1.5.6.1 uboot-prepare-kernel (timeout 00:09:52) [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:52) [common] end: 1.5.7 configure-preseed-file (duration 00:00:00) [common] start: 1.5.8 compress-ramdisk (timeout 00:09:52) [common] Building ramdisk /var/lib/lava/dispatcher/tmp/34537/extract-overlay-ramdisk-6r4wf5pz/ramdisk.cpio containing /var/lib/lava/dispatcher/tmp/34537/extract-overlay-ramdisk-6r4wf5pz/ramdisk >> 90939 blocks Adding RAMdisk u-boot header. mkimage -A arm64 -T ramdisk -C none -d /var/lib/lava/dispatcher/tmp/34537/extract-overlay-ramdisk-6r4wf5pz/ramdisk.cpio.gz /var/lib/lava/dispatcher/tmp/34537/extract-overlay-ramdisk-6r4wf5pz/ramdisk.cpio.gz.uboot output: Image Name: output: Created: Wed May 29 11:33:11 2024 output: Image Type: AArch64 Linux RAMDisk Image (uncompressed) output: Data Size: 13781365 Bytes = 13458.36 KiB = 13.14 MiB output: Load Address: 00000000 output: Entry Point: 00000000 output: rename /var/lib/lava/dispatcher/tmp/34537/extract-overlay-ramdisk-6r4wf5pz/ramdisk.cpio.gz.uboot to /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/ramdisk/ramdisk.cpio.gz.uboot end: 1.5.8 compress-ramdisk (duration 00:00:09) [common] end: 1.5 prepare-tftp-overlay (duration 00:00:11) [common] start: 1.6 lxc-create-udev-rule-action (timeout 00:09:43) [common] No LXC device requested end: 1.6 lxc-create-udev-rule-action (duration 00:00:00) [common] Checking files for TFTP limit of 4294967296 bytes. end: 1 tftp-deploy (duration 00:00:17) [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 0x00080000 0x02700000 0x02400000 - {DTB_ADDR}: 0x02400000 - {DTB}: 34537/tftp-deploy-lficdcsd/dtb/bcm2711-rpi-4-b.dtb - {INITRD}: 34537/tftp-deploy-lficdcsd/ramdisk/ramdisk.cpio.gz.uboot - {KERNEL_ADDR}: 0x00080000 - {KERNEL}: 34537/tftp-deploy-lficdcsd/kernel/Image - {LAVA_MAC}: None - {PRESEED_CONFIG}: None - {PRESEED_LOCAL}: None - {RAMDISK_ADDR}: 0x02700000 - {RAMDISK}: 34537/tftp-deploy-lficdcsd/ramdisk/ramdisk.cpio.gz.uboot - {ROOT_PART}: None - {ROOT}: None - {SERVER_IP}: 172.18.0.2 - {TEE_ADDR}: 0x83000000 - {TEE}: None Parsed boot commands: - setenv autoload no - setenv initrd_high 0xffffffff - setenv fdt_high 0xffffffff - dhcp - setenv serverip 172.18.0.2 - tftp 0x00080000 34537/tftp-deploy-lficdcsd/kernel/Image - tftp 0x02700000 34537/tftp-deploy-lficdcsd/ramdisk/ramdisk.cpio.gz.uboot - setenv initrd_size ${filesize} - tftp 0x02400000 34537/tftp-deploy-lficdcsd/dtb/bcm2711-rpi-4-b.dtb - setenv bootargs 'console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp' - fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000 0x02400000 end: 2.2 bootloader-overlay (duration 00:00:00) [common] case: bootloader-overlay
case_id: 3987301
definition: lava
duration: 0.01
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 63003' Setting prompt string to ['lava-test: # '] end: 2.3 connect-device (duration 00:00:04) [common] start: 2.4 uboot-commands (timeout 00:04:56) [common] start: 2.4.1 reset-device (timeout 00:04:56) [common] start: 2.4.1.1 pdu-reboot (timeout 00:04:56) [common] Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '7' >> Success >> Success Returned 0 in 6 seconds end: 2.4.1.1 pdu-reboot (duration 00:00:06) [common] case: pdu-reboot
case_id: 3987304
definition: lava
duration: 6.22
extra: ...
level: 2.4.1.1
namespace: common
result: pass
end: 2.4.1 reset-device (duration 00:00:06) [common] start: 2.4.2 bootloader-interrupt (timeout 00:04:50) [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 '^]'. U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200) DRAM: 3.9 GiB RPI 4 Model B (0xc03111) MMC: emmc2@7e340000: 0, mmcnr@7e300000: 1 Loading Environment from FAT... *** Warning - bad CRC, using default environment In: serial Out: serial Err: serial Net: eth0: genet@7d580000 starting USB... No working controllers found c end: 2.4.2 bootloader-interrupt (duration 00:00:10) [common] start: 2.4.3 bootloader-commands (timeout 00:04:39) [common] Setting prompt string to ['U-Boot>'] bootloader-commands: Wait for prompt ['U-Boot>'] (timeout 00:04:39) Hit any key to stop autoboot: 2  0 Setting prompt string to ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] setenv autoload no U-Boot> setenv autoload no bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:39) setenv autoload no setenv initrd_high 0xffffffff U-Boot> setenv initrd_high 0xffffffff bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:39) setenv initrd_high 0xffffffff setenv fdt_high 0xffffffff U-Boot> setenv fdt_high 0xffffffff bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:39) setenv fdt_high 0xffffffff dhcp U-Boot> dhcp bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:39) dhcp genet@7d580000 Waiting for PHY auto negotiation to complete....... done BOOTP broadcast 1 BOOTP broadcast 2 BOOTP broadcast 3 DHCP client bound to address 192.168.66.241 (1283 ms) setenv serverip 172.18.0.2 U-Boot> setenv serverip 172.18.0.2 bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:34) setenv serverip 172.18.0.2 tftp 0x00080000 34537/tftp-deploy-lficdcsd/kernel/Image U-Boot> tftp 0x00080000 34537/tftp-deploy-lficdcsd/kernel/Image bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:34) tftp 0x00080000 34537/tftp-deploy-lficdcsd/kernel/Image Using genet@7d580000 device TFTP from server 172.18.0.2; our IP address is 192.168.66.241; sending through gateway 192.168.66.1 Filename '34537/tftp-deploy-lficdcsd/kernel/Image'. Load address: 0x80000 Loading: *T T T T T T T T T T Retry count exceeded; starting again matched a bootloader error message: 'Retry count exceeded' (4) end: 2.4.3 bootloader-commands (duration 00:01:00) [common] case: bootloader-commands
case_id: 3987311
definition: lava
duration: 60.21
extra: ...
level: 2.4.3
namespace: common
result: fail
matched a bootloader error message: 'Retry count exceeded' (4) end: 2.4 uboot-commands (duration 00:01:17) [common] case: uboot-commands
case_id: 3987312
definition: lava
duration: 76.76
extra: ...
level: 2.4
namespace: common
result: fail
uboot-action failed: 1 of 1 attempts. 'matched a bootloader error message: 'Retry count exceeded' (4)' matched a bootloader error message: 'Retry count exceeded' (4) end: 2 uboot-action (duration 00:01:21) [common] case: uboot-action
case_id: 3987313
definition: lava
duration: 80.79
extra: ...
level: 2
namespace: common
result: fail
Cleaning after the job Cleaning up download directory: /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/ramdisk Cleaning up download directory: /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/kernel Cleaning up download directory: /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/dtb Cleaning up download directory: /var/lib/lava/dispatcher/tmp/34537/tftp-deploy-lficdcsd/modules start: 3.1 power-off (timeout 00:00:30) [common] Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '7' >> Success Returned 0 in 3 seconds end: 3.1 power-off (duration 00:00:04) [common] case: power-off
case_id: 3987314
definition: lava
duration: 3.59
extra: ...
level: 3.1
namespace: common
result: pass
start: 3.2 read-feedback (timeout 00:09:56) [common] Listened to connection for namespace 'common' for up to 1s Finalising connection for namespace 'common' Disconnecting from shell: Finalise U-Boot> � end: 3.2 read-feedback (duration 00:00:01) [common] Override tmp directory removed at /var/lib/lava/dispatcher/tmp/34537 Root tmp directory removed at /var/lib/lava/dispatcher/tmp/34537 InfrastructureError: The Infrastructure is not working correctly. Please report this error to LAVA admins. case: job
case_id: 3987315
definition: lava
error_msg: matched a bootloader error message: 'Retry count exceeded' (4)
error_type: Infrastructure
result: fail