lava-dispatcher, installed at version: 2023.10 start: 0 validate Start time: 2024-11-27 09:58:54.854652+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.20 case: validate
case_id: 4097899
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/37897/tftp-deploy-4d6ikq77/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 2.57 s (2.91 MB/s) end: 1.1.1 http-download (duration 00:00:03) [common] case: http-download
case_id: 4097923
definition: lava
duration: 2.57
extra: ...
level: 1.1.1
namespace: common
result: pass
end: 1.1 download-retry (duration 00:00:03) [common] start: 1.2 download-retry (timeout 00:09:57) [common] start: 1.2.1 http-download (timeout 00:09:57) [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/37897/tftp-deploy-4d6ikq77/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 3.62 s (5.22 MB/s) end: 1.2.1 http-download (duration 00:00:04) [common] case: http-download
case_id: 4097923
definition: lava
duration: 3.62
extra: ...
level: 1.2.1
namespace: common
result: pass
end: 1.2 download-retry (duration 00:00:04) [common] start: 1.3 download-retry (timeout 00:09:54) [common] start: 1.3.1 http-download (timeout 00:09:54) [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/37897/tftp-deploy-4d6ikq77/dtb/hifive-unmatched-a00.dtb total size: 10707 (0 MB) No compression specified progress 100 % (0 MB) 0 MB downloaded in 0.25 s (0.04 MB/s) end: 1.3.1 http-download (duration 00:00:00) [common] case: http-download
case_id: 4097923
definition: lava
duration: 0.25
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:54) [common] start: 1.4.1 http-download (timeout 00:09:54) [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/37897/tftp-deploy-4d6ikq77/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.82 s (4.53 MB/s) end: 1.4.1 http-download (duration 00:00:01) [common] case: http-download
case_id: 4097923
definition: lava
duration: 0.82
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:53) [common] start: 1.5.1 extract-nfsrootfs (timeout 00:09:53) [common] end: 1.5.1 extract-nfsrootfs (duration 00:00:00) [common] start: 1.5.2 lava-overlay (timeout 00:09:53) [common] [common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5 makedir: /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin makedir: /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/tests makedir: /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/results Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-add-keys Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-add-sources Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-background-process-start Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-background-process-stop Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-common-functions Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-echo-ipv4 Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-install-packages Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-installed-packages Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-os-build Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-probe-channel Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-probe-ip Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-target-ip Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-target-mac Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-target-storage Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-test-case Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-test-event Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-test-feedback Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-test-raise Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-test-reference Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-test-runner Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-test-set Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-test-shell Updating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-install-packages (oe) Updating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/bin/lava-installed-packages (oe) Creating /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/environment LAVA metadata - LAVA_JOB_ID=37897 - LAVA_DISPATCHER_IP=192.168.66.1 start: 1.5.2.1 ssh-authorize (timeout 00:09:53) [common] end: 1.5.2.1 ssh-authorize (duration 00:00:00) [common] start: 1.5.2.2 lava-vland-overlay (timeout 00:09:53) [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:53) [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:53) [common] Loading test definitions start: 1.5.2.4.1 inline-repo-action (timeout 00:09:53) [common] Using /lava-37897 at stage 0 uuid=37897_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:53) [common] end: 1.5.2.4.2 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4097927
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:53) [common] end: 1.5.2.4.3 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4097928
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:53) [common] runner path: /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/0/tests/0_dmesg test_uuid 37897_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: 4097929
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:53) [common] Using /lava-37897 at stage 1 uuid=37897_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:53) [common] end: 1.5.2.4.6 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4097927
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:53) [common] end: 1.5.2.4.7 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4097928
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:53) [common] runner path: /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/1/tests/1_bootrr test_uuid 37897_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: 4097929
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/37897/lava-overlay-ovu7odf5/lava-37897/0 for stage 0 - 0_dmesg Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/37897/lava-overlay-ovu7odf5/lava-37897/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:53) [common] end: 1.5.2.5 compress-overlay (duration 00:00:00) [common] start: 1.5.2.6 persistent-nfs-overlay (timeout 00:09:53) [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:53) [common] end: 1.5.3 extract-overlay-ramdisk (duration 00:00:00) [common] start: 1.5.4 extract-modules (timeout 00:09:52) [common] extracting modules file /var/lib/lava/dispatcher/tmp/37897/tftp-deploy-4d6ikq77/modules/modules.tar to /var/lib/lava/dispatcher/tmp/37897/extract-overlay-ramdisk-f0f0ibmi/ramdisk end: 1.5.4 extract-modules (duration 00:00:00) [common] start: 1.5.5 apply-overlay-tftp (timeout 00:09:52) [common] [common] Applying overlay /var/lib/lava/dispatcher/tmp/37897/compress-overlay-_q70_4yh/overlay-1.5.2.5.tar.gz to ramdisk [common] Applying overlay /var/lib/lava/dispatcher/tmp/37897/compress-overlay-_q70_4yh/overlay-1.5.2.5.tar.gz to directory /var/lib/lava/dispatcher/tmp/37897/extract-overlay-ramdisk-f0f0ibmi/ramdisk 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/37897/extract-overlay-ramdisk-f0f0ibmi/ramdisk.cpio containing /var/lib/lava/dispatcher/tmp/37897/extract-overlay-ramdisk-f0f0ibmi/ramdisk >> 86851 blocks Adding RAMdisk u-boot header. mkimage -A riscv -T ramdisk -C none -d /var/lib/lava/dispatcher/tmp/37897/extract-overlay-ramdisk-f0f0ibmi/ramdisk.cpio.gz /var/lib/lava/dispatcher/tmp/37897/extract-overlay-ramdisk-f0f0ibmi/ramdisk.cpio.gz.uboot output: Image Name: output: Created: Wed Nov 27 09:59:10 2024 output: Image Type: RISC-V Linux RAMDisk Image (uncompressed) output: Data Size: 13632393 Bytes = 13312.88 KiB = 13.00 MiB output: Load Address: 00000000 output: Entry Point: 00000000 output: rename /var/lib/lava/dispatcher/tmp/37897/extract-overlay-ramdisk-f0f0ibmi/ramdisk.cpio.gz.uboot to /var/lib/lava/dispatcher/tmp/37897/tftp-deploy-4d6ikq77/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:50) [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:50) [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:10) [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}: 37897/tftp-deploy-4d6ikq77/dtb/hifive-unmatched-a00.dtb - {INITRD}: 37897/tftp-deploy-4d6ikq77/ramdisk/ramdisk.cpio.gz.uboot - {KERNEL_ADDR}: 0x80200000 - {KERNEL}: 37897/tftp-deploy-4d6ikq77/kernel/Image - {LAVA_MAC}: None - {PRESEED_CONFIG}: None - {PRESEED_LOCAL}: None - {RAMDISK_ADDR}: 0x83500000 - {RAMDISK}: 37897/tftp-deploy-4d6ikq77/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 37897/tftp-deploy-4d6ikq77/kernel/Image - tftp 0x83500000 37897/tftp-deploy-4d6ikq77/ramdisk/ramdisk.cpio.gz.uboot - setenv initrd_size ${filesize} - tftp 0x83000000 37897/tftp-deploy-4d6ikq77/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: 4097938
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' >> Accessing Gembird #0 USB device 002 >> Switched outlet 1 off >> Accessing Gembird #0 USB device 002 >> Switched outlet 1 on >> FTDI RELAY: power on >> FTDI RELAY: power off Returned 0 in 8 seconds end: 2.4.1.1 pdu-reboot (duration 00:00:09) [common] case: pdu-reboot
case_id: 4097939
definition: lava
duration: 9.03
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 '^]'. � U-Boot SPL 2023.07.02 (Jul 11 2023 - 15:20:44 +0000) Trying to boot from MMC1 U-Boot 2023.07.02 (Jul 11 2023 - 15:20:44 +0000) CPU: rv64imafdc Model: SiFive HiFive Unmatched A00 DRAM: 16 GiB Core: 28 devices, 19 uclasses, devicetree: separate MMC: spi@10050000:mmc@0: 0 Loading Environment from SPIFlash... SF: Detected is25wp256 with page size 256 Bytes, erase size 4 KiB, total 32 MiB *** Warning - bad CRC, using default environment EEPROM: SiFive PCB EEPROM format v1 Product ID: 0002 (HiFive Unmatched) PCB revision: 3 BOM revision: B BOM variant: 0 Serial number: SF105SZ212500053 Ethernet MAC address: 70:b3:d5:92:fa:8d CRC: 6508cedc In: serial@10010000 Out: serial@10010000 Err: serial@10010000 Model: SiFive HiFive Unmatched A00 Net: eth0: ethernet@10090000 Working FDT set to ff72f7f0 Hit any key to stop autoboot: 2 end: 2.4.2 bootloader-interrupt (duration 00:00:09) [common] start: 2.4.3 bootloader-commands (timeout 00:04:42) [common] Setting prompt string to ['=>'] bootloader-commands: Wait for prompt ['=>'] (timeout 00:04:42)  0 Setting prompt string to ['=>', '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 => setenv autoload no bootloader-commands: Wait for prompt ['=>', '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:42) setenv autoload no setenv initrd_high 0xffffffffffffffff => setenv initrd_high 0xffffffffffffffff bootloader-commands: Wait for prompt ['=>', '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:42) setenv initrd_high 0xffffffffffffffff setenv fdt_high 0xffffffffffffffff => setenv fdt_high 0xffffffffffffffff bootloader-commands: Wait for prompt ['=>', '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:42) setenv fdt_high 0xffffffffffffffff dhcp => dhcp bootloader-commands: Wait for prompt ['=>', '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:41) dhcp ethernet@10090000: PHY present at 0 ethernet@10090000: Starting autonegotiation... ethernet@10090000: Autonegotiation complete ethernet@10090000: link up, 100Mbps full-duplex (lpa: 0xcde1) BOOTP broadcast 1 BOOTP broadcast 2 BOOTP broadcast 3 DHCP client bound to address 192.168.66.16 (1636 ms) setenv serverip 192.168.66.1 => setenv serverip 192.168.66.1 bootloader-commands: Wait for prompt ['=>', '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:37) setenv serverip 192.168.66.1 tftp 0x80200000 37897/tftp-deploy-4d6ikq77/kernel/Image => tftp 0x80200000 37897/tftp-deploy-4d6ikq77/kernel/Image bootloader-commands: Wait for prompt ['=>', '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:37) tftp 0x80200000 37897/tftp-deploy-4d6ikq77/kernel/Image ethernet@10090000: PHY present at 0 ethernet@10090000: Starting autonegotiation... ethernet@10090000: Autonegotiation complete ethernet@10090000: link up, 100Mbps full-duplex (lpa: 0xcde1) Using ethernet@10090000 device TFTP from server 192.168.66.1; our IP address is 192.168.66.16 Filename '37897/tftp-deploy-4d6ikq77/kernel/Image'. Load address: 0x80200000 Loading: *################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# #################################################### 3.7 MiB/s done Bytes transferred = 19845120 (12ed000 hex) tftp 0x83500000 37897/tftp-deploy-4d6ikq77/ramdisk/ramdisk.cpio.gz.uboot => tftp 0x83500000 37897/tftp-deploy-4d6ikq77/ramdisk/ramdisk.cpio.gz.uboot bootloader-commands: Wait for prompt ['=>', '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:28) tftp 0x83500000 37897/tftp-deploy-4d6ikq77/ramdisk/ramdisk.cpio.gz.uboot ethernet@10090000: PHY present at 0 ethernet@10090000: Starting autonegotiation... ethernet@10090000: Autonegotiation complete ethernet@10090000: link up, 100Mbps full-duplex (lpa: 0xcde1) Using ethernet@10090000 device TFTP from server 192.168.66.1; our IP address is 192.168.66.16 Filename '37897/tftp-deploy-4d6ikq77/ramdisk/ramdisk.cpio.gz.uboot'. Load address: 0x83500000 Loading: *################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################### 3.5 MiB/s done Bytes transferred = 13632457 (d003c9 hex) setenv initrd_size ${filesize} => setenv initrd_size ${filesize} bootloader-commands: Wait for prompt ['=>', '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:21) setenv initrd_size ${filesize} tftp 0x83000000 37897/tftp-deploy-4d6ikq77/dtb/hifive-unmatched-a00.dtb => tftp 0x83000000 37897/tftp-deploy-4d6ikq77/dtb/hifive-unmatched-a00.dtb bootloader-commands: Wait for prompt ['=>', '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:21) tftp 0x83000000 37897/tftp-deploy-4d6ikq77/dtb/hifive-unmatched-a00.dtb ethernet@10090000: PHY present at 0 ethernet@10090000: Starting autonegotiation... ethernet@10090000: Autonegotiation complete ethernet@10090000: link up, 100Mbps full-duplex (lpa: 0xcde1) Using ethernet@10090000 device TFTP from server 192.168.66.1; our IP address is 192.168.66.16 Filename '37897/tftp-deploy-4d6ikq77/dtb/hifive-unmatched-a00.dtb'. Load address: 0x83000000 Loading: *# 1.7 MiB/s done Bytes transferred = 10707 (29d3 hex) setenv bootargs '115200 root=/dev/ram0 console_msg_format=syslog earlycon deferred_probe_timeout=60 ip=dhcp' => setenv bootargs '115200 root=/dev/ram0 console_msg_format=syslog earlycon deferred_probe_timeout=60 ip=dhcp' bootloader-commands: Wait for prompt ['=>', '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:17) setenv bootargs '115200 root=/dev/ram0 console_msg_format=syslog earlycon deferred_probe_timeout=60 ip=dhcp' booti 0x80200000 0x83500000 0x83000000 => booti 0x80200000 0x83500000 0x83000000 Setting prompt string to ['Starting kernel', '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'] bootloader-commands: Wait for prompt ['Starting kernel', '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:17) booti 0x80200000 0x83500000 0x83000000 ## Loading init Ramdisk from Legacy Image at 83500000 ... Image Name: Image Type: RISC-V Linux RAMDisk Image (uncompressed) Data Size: 13632393 Bytes = 13 MiB Load Address: 00000000 Entry Point: 00000000 Verifying Checksum ... OK ## Flattened Device Tree blob at 83000000 Booting using the fdt blob at 0x83000000 Working FDT set to 83000000 Using Device Tree in place at 0000000083000000, end 00000000830059d2 Working FDT set to 83000000 Starting kernel ... end: 2.4.3 bootloader-commands (duration 00:00:25) [common] start: 2.4.4 auto-login-action (timeout 00:04:17) [common] Setting prompt string to ['Linux version [0-9]'] Setting prompt string to ['Linux version [0-9]', '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'] auto-login-action: Wait for prompt ['Linux version [0-9]', '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:05:00) start: 2.4.4.1 login-action (timeout 00:04:17) [common] The string '/ #' does not look like a typical prompt and could match status messages instead. Please check the job log files and use a prompt string which matches the actual prompt string more closely. Setting prompt string to [] Setting prompt string to ['-\\[ cut here \\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing'] Using line separator: #'\n'# No login prompt set. Parsing kernel messages ['-\\[ cut here \\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing', '/ #', 'Login timed out', 'Login incorrect'] [login-action] Waiting for messages, (timeout 00:04:17) [ 0.000000] Linux version 6.1.54 (KernelCI@build-j50728-riscv-gcc-10-defconfig-75n2g) (riscv64-linux-gnu-gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2) #1 SMP Tue Sep 19 13:51:25 UTC 2023 [ 0.000000] OF: fdt: Ignoring memory range 0x80000000 - 0x80200000 [ 0.000000] Machine model: SiFive HiFive Unmatched A00 [ 0.000000] earlycon: sifive0 at MMIO 0x0000000010010000 (options '') [ 0.000000] printk: bootconsole [sifive0] enabled [ 0.000000] efi: UEFI not found. [ 0.000000] Zone ranges: [ 0.000000] DMA32 [mem 0x0000000080200000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x000000047fffffff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000080200000-0x000000047fffffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000080200000-0x000000047fffffff] [ 0.000000] SBI specification v1.0 detected [ 0.000000] SBI implementation ID=0x1 Version=0x10002 [ 0.000000] SBI TIME extension detected [ 0.000000] SBI IPI extension detected [ 0.000000] SBI RFENCE extension detected [ 0.000000] SBI SRST extension detected [ 0.000000] SBI HSM extension detected [ 0.000000] CPU with hartid=0 is not available [ 0.000000] CPU with hartid=0 is not available [ 0.000000] CPU with hartid=0 is not available [ 0.000000] riscv: base ISA extensions acdfim [ 0.000000] riscv: ELF capabilities acdfim [ 0.000000] percpu: Embedded 18 pages/cpu s34744 r8192 d30792 u73728 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 4128264 [ 0.000000] Kernel command line: 115200 root=/dev/ram0 console_msg_format=syslog earlycon deferred_probe_timeout=60 ip=dhcp <5>[ 0.000000] Unknown kernel command line parameters \"115200\", will be passed to user space. <6>[ 0.000000] Dentry cache hash table entries: 2097152 (order: 12, 16777216 bytes, linear) <6>[ 0.000000] Inode-cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear) <6>[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off <6>[ 0.000000] software IO TLB: area num 4. <6>[ 0.000000] software IO TLB: mapped [mem 0x00000000fbfff000-0x00000000fffff000] (64MB) <5>[ 0.000000] Virtual kernel memory layout: <5>[ 0.000000] fixmap : 0xffffffc6fea00000 - 0xffffffc6ff000000 (6144 kB) <5>[ 0.000000] pci io : 0xffffffc6ff000000 - 0xffffffc700000000 ( 16 MB) <5>[ 0.000000] vmemmap : 0xffffffc700000000 - 0xffffffc800000000 (4096 MB) <5>[ 0.000000] vmalloc : 0xffffffc800000000 - 0xffffffd800000000 ( 64 GB) <5>[ 0.000000] modules : 0xffffffff01361000 - 0xffffffff80000000 (2028 MB) <5>[ 0.000000] lowmem : 0xffffffd800000000 - 0xffffffdbffe00000 ( 15 GB) <5>[ 0.000000] kernel : 0xffffffff80000000 - 0xffffffffffffffff (2047 MB) <6>[ 0.000000] Memory: 16387904K/16775168K available (7456K kernel code, 4927K rwdata, 4096K rodata, 2164K init, 461K bss, 387264K reserved, 0K cma-reserved) <6>[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 <6>[ 0.000000] rcu: Hierarchical RCU implementation. <6>[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=4. <6>[ 0.000000] rcu: RCU debug extended QS entry/exit. <6>[ 0.000000] Tracing variant of Tasks RCU enabled. <6>[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. <6>[ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 <6>[ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 <6>[ 0.000000] CPU with hartid=0 is not available <4>[ 0.000000] riscv-intc: unable to find hart id for /cpus/cpu@0/interrupt-controller <6>[ 0.000000] riscv-intc: 64 local interrupts mapped <6>[ 0.000000] plic: interrupt-controller@c000000: mapped 69 interrupts with 4 handlers for 9 contexts. <6>[ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention. <6>[ 0.000000] riscv-timer: riscv_timer_init_dt: Registering clocksource cpuid [0] hartid [2] <6>[ 0.000000] clocksource: riscv_clocksource: mask: 0xffffffffffffffff max_cycles: 0x1d854df40, max_idle_ns: 3526361616960 ns <6>[ 0.000003] sched_clock: 64 bits at 1000kHz, resolution 1000ns, wraps every 2199023255500ns <6>[ 0.008823] Console: colour dummy device 80x25 <6>[ 0.013317] printk: console [tty0] enabled <6>[ 0.017631] printk: bootconsole [sifive0] disabled <5>[ 0.000000] Linux version 6.1.54 (KernelCI@build-j50728-riscv-gcc-10-defconfig-75n2g) (riscv64-linux-gnu-gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2) #1 SMP Tue Sep 19 13:51:25 UTC 2023 <4>[ 0.000000] OF: fdt: Ignoring memory range 0x80000000 - 0x80200000 <6>[ 0.000000] Machine model: SiFive HiFive Unmatched A00 <6>[ 0.000000] earlycon: sifive0 at MMIO 0x0000000010010000 (options '') <6>[ 0.000000] printk: bootconsole [sifive0] enabled <6>[ 0.000000] efi: UEFI not found. <6>[ 0.000000] Zone ranges: <6>[ 0.000000] DMA32 [mem 0x0000000080200000-0x00000000ffffffff] <6>[ 0.000000] Normal [mem 0x0000000100000000-0x000000047fffffff] <6>[ 0.000000] Movable zone start for each node <6>[ 0.000000] Early memory node ranges <6>[ 0.000000] node 0: [mem 0x0000000080200000-0x000000047fffffff] <6>[ 0.000000] Initmem setup node 0 [mem 0x0000000080200000-0x000000047fffffff] <6>[ 0.000000] SBI specification v1.0 detected <6>[ 0.000000] SBI implementation ID=0x1 Version=0x10002 <6>[ 0.000000] SBI TIME extension detected <6>[ 0.000000] SBI IPI extension detected <6>[ 0.000000] SBI RFENCE extension detected <6>[ 0.000000] SBI SRST extension detected <6>[ 0.000000] SBI HSM extension detected <6>[ 0.000000] CPU with hartid=0 is not available <6>[ 0.000000] CPU with hartid=0 is not available <6>[ 0.000000] CPU with hartid=0 is not available <6>[ 0.000000] riscv: base ISA extensions acdfim <6>[ 0.000000] riscv: ELF capabilities acdfim <6>[ 0.000000] percpu: Embedded 18 pages/cpu s34744 r8192 d30792 u73728 <6>[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 4128264 <5>[ 0.000000] Kernel command line: 115200 root=/dev/ram0 console_msg_format=syslog earlycon deferred_probe_timeout=60 ip=dhcp <5>[ 0.000000] Unknown kernel command line parameters \"115200\", will be passed to user space. <6>[ 0.000000] Dentry cache hash table entries: 2097152 (order: 12, 16777216 bytes, linear) <6>[ 0.000000] Inode-cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear) <6>[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off <6>[ 0.000000] software IO TLB: area num 4. <6>[ 0.000000] software IO TLB: mapped [mem 0x00000000fbfff000-0x00000000fffff000] (64MB) <5>[ 0.000000] Virtual kernel memory layout: <5>[ 0.000000] fixmap : 0xffffffc6fea00000 - 0xffffffc6ff000000 (6144 kB) <5>[ 0.000000] pci io : 0xffffffc6ff000000 - 0xffffffc700000000 ( 16 MB) <5>[ 0.000000] vmemmap : 0xffffffc700000000 - 0xffffffc800000000 (4096 MB) <5>[ 0.000000] vmalloc : 0xffffffc800000000 - 0xffffffd800000000 ( 64 GB) <5>[ 0.000000] modules : 0xffffffff01361000 - 0xffffffff80000000 (2028 MB) <5>[ 0.000000] lowmem : 0xffffffd800000000 - 0xffffffdbffe00000 ( 15 GB) <5>[ 0.000000] kernel : 0xffffffff80000000 - 0xffffffffffffffff (2047 MB) <6>[ 0.000000] Memory: 16387904K/16775168K available (7456K kernel code, 4927K rwdata, 4096K rodata, 2164K init, 461K bss, 387264K reserved, 0K cma-reserved) <6>[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 <6>[ 0.000000] rcu: Hierarchical RCU implementation. <6>[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=4. <6>[ 0.000000] rcu: RCU debug extended QS entry/exit. <6>[ 0.000000] Tracing variant of Tasks RCU enabled. <6>[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. <6>[ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 <6>[ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 <6>[ 0.000000] CPU with hartid=0 is not available <4>[ 0.000000] riscv-intc: unable to find hart id for /cpus/cpu@0/interrupt-controller <6>[ 0.000000] riscv-intc: 64 local interrupts mapped <6>[ 0.000000] plic: interrupt-controller@c000000: mapped 69 interrupts with 4 handlers for 9 contexts. <6>[ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention. <6>[ 0.000000] riscv-timer: riscv_timer_init_dt: Registering clocksource cpuid [0] hartid [2] <6>[ 0.000000] clocksource: riscv_clocksource: mask: 0xffffffffffffffff max_cycles: 0x1d854df40, max_idle_ns: 3526361616960 ns <6>[ 0.000003] sched_clock: 64 bits at 1000kHz, resolution 1000ns, wraps every 2199023255500ns <6>[ 0.008823] Console: colour dummy device 80x25 <6>[ 0.013317] printk: console [tty0] enabled <6>[ 0.017631] printk: bootconsole [sifive0] disabled <6>[ 0.022729] Calibrating delay loop (skipped), value calculated using timer frequency.. 2.00 BogoMIPS (lpj=4000) <6>[ 0.022754] pid_max: default: 32768 minimum: 301 <6>[ 0.022870] LSM: Security Framework initializing <6>[ 0.023630] Mount-cache hash table entries: 32768 (order: 6, 262144 bytes, linear) <6>[ 0.024322] Mountpoint-cache hash table entries: 32768 (order: 6, 262144 bytes, linear) <6>[ 0.026138] CPU node for /cpus/cpu@0 exist but the possible cpu range is :0-3 <6>[ 0.027534] cblist_init_generic: Setting adjustable number of callback queues. <6>[ 0.027552] cblist_init_generic: Setting shift to 2 and lim to 1. <6>[ 0.027714] riscv: ELF compat mode unsupported <6>[ 0.027722] ASID allocator disabled (0 bits) <6>[ 0.027908] rcu: Hierarchical SRCU implementation. <6>[ 0.027923] rcu: Max phase no-delay instances is 1000. <6>[ 0.028293] EFI services will not be available. <6>[ 0.029001] smp: Bringing up secondary CPUs ... <6>[ 0.032075] smp: Brought up 1 node, 4 CPUs <6>[ 0.036215] devtmpfs: initialized <6>[ 0.039042] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns <6>[ 0.039087] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) <6>[ 0.039479] pinctrl core: initialized pinctrl subsystem <6>[ 0.040493] NET: Registered PF_NETLINK/PF_ROUTE protocol family <6>[ 0.040690] audit: initializing netlink subsys (disabled) <5>[ 0.040959] audit: type=2000 audit(0.028:1): state=initialized audit_enabled=0 res=1 <6>[ 0.041297] cpuidle: using governor menu <6>[ 0.052261] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages <6>[ 0.052288] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page <6>[ 0.053023] iommu: Default domain type: Translated <6>[ 0.053041] iommu: DMA domain TLB invalidation policy: strict mode <5>[ 0.053393] SCSI subsystem initialized <6>[ 0.053807] usbcore: registered new interface driver usbfs <6>[ 0.053861] usbcore: registered new interface driver hub <6>[ 0.053914] usbcore: registered new device driver usb <6>[ 0.054961] vgaarb: loaded <6>[ 0.055121] clocksource: Switched to clocksource riscv_clocksource <6>[ 0.064463] NET: Registered PF_INET protocol family <6>[ 0.071655] IP idents hash table entries: 262144 (order: 9, 2097152 bytes, linear) <6>[ 0.092783] tcp_listen_portaddr_hash hash table entries: 8192 (order: 6, 262144 bytes, linear) <6>[ 0.093822] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) <6>[ 0.093910] TCP established hash table entries: 131072 (order: 8, 1048576 bytes, linear) <6>[ 0.098557] TCP bind hash table entries: 65536 (order: 10, 4194304 bytes, linear) <6>[ 0.116282] TCP: Hash tables configured (established 131072 bind 65536) <6>[ 0.117072] UDP hash table entries: 8192 (order: 7, 786432 bytes, linear) <6>[ 0.120321] UDP-Lite hash table entries: 8192 (order: 7, 786432 bytes, linear) <6>[ 0.123861] NET: Registered PF_UNIX/PF_LOCAL protocol family <6>[ 0.125022] RPC: Registered named UNIX socket transport module. <6>[ 0.125047] RPC: Registered udp transport module. <6>[ 0.125060] RPC: Registered tcp transport module. <6>[ 0.125071] RPC: Registered tcp NFSv4.1 backchannel transport module. <6>[ 0.125093] PCI: CLS 0 bytes, default 64 <6>[ 0.125685] Unpacking initramfs... <6>[ 0.140867] workingset: timestamp_bits=46 max_order=22 bucket_order=0 <5>[ 0.150039] NFS: Registering the id_resolver key type <5>[ 0.150136] Key type id_resolver registered <5>[ 0.150151] Key type id_legacy registered <6>[ 0.150247] nfs4filelayout_init: NFSv4 File Layout Driver Registering... <6>[ 0.150266] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... <6>[ 0.150516] 9p: Installing v9fs 9p2000 file system support <6>[ 0.151015] NET: Registered PF_ALG protocol family <6>[ 0.151098] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250) <6>[ 0.151158] io scheduler mq-deadline registered <6>[ 0.151175] io scheduler kyber registered <6>[ 0.175189] fu740-pcie e00000000.pcie: host bridge /soc/pcie@e00000000 ranges: <6>[ 0.175322] fu740-pcie e00000000.pcie: IO 0x0060080000..0x006008ffff -> 0x0060080000 <6>[ 0.175373] fu740-pcie e00000000.pcie: MEM 0x0060090000..0x007fffffff -> 0x0060090000 <6>[ 0.175402] fu740-pcie e00000000.pcie: MEM 0x2000000000..0x3fffffffff -> 0x2000000000 <6>[ 0.284258] fu740-pcie e00000000.pcie: iATU unroll: enabled <6>[ 0.284320] fu740-pcie e00000000.pcie: iATU regions: 8 ob, 8 ib, align 4K, limit 4096G <6>[ 0.384433] fu740-pcie e00000000.pcie: PCIe Gen.1 x8 link up <6>[ 0.484543] fu740-pcie e00000000.pcie: PCIe Gen.3 x8 link up <6>[ 0.484606] fu740-pcie e00000000.pcie: PCIe Gen.3 x8 link up <6>[ 0.484836] fu740-pcie e00000000.pcie: PCI host bridge to bus 0000:00 <6>[ 0.484865] pci_bus 0000:00: root bus resource [bus 00-ff] <6>[ 0.484889] pci_bus 0000:00: root bus resource [io 0x0000-0xffff] (bus address [0x60080000-0x6008ffff]) <6>[ 0.484911] pci_bus 0000:00: root bus resource [mem 0x60090000-0x7fffffff] <6>[ 0.484928] pci_bus 0000:00: root bus resource [mem 0x2000000000-0x3fffffffff pref] <6>[ 0.484983] pci 0000:00:00.0: [f15e:0000] type 01 class 0x060400 <6>[ 0.485011] pci 0000:00:00.0: reg 0x10: [mem 0x00000000-0x000fffff] <6>[ 0.485033] pci 0000:00:00.0: reg 0x38: [mem 0x00000000-0x0000ffff pref] <6>[ 0.485113] pci 0000:00:00.0: supports D1 <6>[ 0.485128] pci 0000:00:00.0: PME# supported from D0 D1 D3hot <6>[ 0.486009] pci 0000:01:00.0: [1b21:2824] type 01 class 0x060400 <6>[ 0.486107] pci 0000:01:00.0: enabling Extended Tags <6>[ 0.486256] pci 0000:01:00.0: PME# supported from D0 D3hot D3cold <6>[ 0.495198] pci 0000:01:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring <6>[ 0.495434] pci 0000:02:00.0: [1b21:2824] type 01 class 0x060400 <6>[ 0.495530] pci 0000:02:00.0: enabling Extended Tags <6>[ 0.495686] pci 0000:02:00.0: PME# supported from D0 D3hot D3cold <6>[ 0.496054] pci 0000:02:02.0: [1b21:2824] type 01 class 0x060400 <6>[ 0.496148] pci 0000:02:02.0: enabling Extended Tags <6>[ 0.496293] pci 0000:02:02.0: PME# supported from D0 D3hot D3cold <6>[ 0.496581] pci 0000:02:03.0: [1b21:2824] type 01 class 0x060400 <6>[ 0.496675] pci 0000:02:03.0: enabling Extended Tags <6>[ 0.496820] pci 0000:02:03.0: PME# supported from D0 D3hot D3cold <6>[ 0.497129] pci 0000:02:04.0: [1b21:2824] type 01 class 0x060400 <6>[ 0.497225] pci 0000:02:04.0: enabling Extended Tags <6>[ 0.497370] pci 0000:02:04.0: PME# supported from D0 D3hot D3cold <6>[ 0.497734] pci 0000:02:08.0: [1b21:2824] type 01 class 0x060400 <6>[ 0.497830] pci 0000:02:08.0: enabling Extended Tags <6>[ 0.497974] pci 0000:02:08.0: PME# supported from D0 D3hot D3cold <6>[ 0.498651] pci 0000:02:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring <6>[ 0.498686] pci 0000:02:02.0: bridge configuration invalid ([bus 00-00]), reconfiguring <6>[ 0.498715] pci 0000:02:03.0: bridge configuration invalid ([bus 00-00]), reconfiguring <6>[ 0.498744] pci 0000:02:04.0: bridge configuration invalid ([bus 00-00]), reconfiguring <6>[ 0.498772] pci 0000:02:08.0: bridge configuration invalid ([bus 00-00]), reconfiguring <6>[ 0.498956] pci_bus 0000:03: busn_res: [bus 03-ff] end is updated to 03 <6>[ 0.499186] pci 0000:04:00.0: [1b21:1142] type 00 class 0x0c0330 <6>[ 0.499249] pci 0000:04:00.0: reg 0x10: [mem 0x00000000-0x00007fff 64bit] <6>[ 0.499476] pci 0000:04:00.0: PME# supported from D3cold <6>[ 0.511208] pci_bus 0000:04: busn_res: [bus 04-ff] end is updated to 04 <6>[ 0.511470] pci_bus 0000:05: busn_res: [bus 05-ff] end is updated to 05 <6>[ 0.511641] pci_bus 0000:06: busn_res: [bus 06-ff] end is updated to 06 <6>[ 0.511859] pci 0000:07:00.0: [1002:6779] type 00 class 0x030000 <6>[ 0.511920] pci 0000:07:00.0: reg 0x10: [mem 0x00000000-0x0fffffff 64bit pref] <6>[ 0.511963] pci 0000:07:00.0: reg 0x18: [mem 0x00000000-0x0001ffff 64bit] <6>[ 0.511993] pci 0000:07:00.0: reg 0x20: initial BAR value 0x00000000 invalid <6>[ 0.512011] pci 0000:07:00.0: reg 0x20: [io size 0x0100] <6>[ 0.512052] pci 0000:07:00.0: reg 0x30: [mem 0x00000000-0x0001ffff pref] <6>[ 0.512084] pci 0000:07:00.0: enabling Extended Tags <6>[ 0.512231] pci 0000:07:00.0: supports D1 D2 <6>[ 0.512296] pci 0000:07:00.0: 16.000 Gb/s available PCIe bandwidth, limited by 2.5 GT/s PCIe x8 link at 0000:02:08.0 (capable of 32.000 Gb/s with 2.5 GT/s PCIe x16 link) <6>[ 0.512498] pci 0000:07:00.0: vgaarb: setting as boot VGA device <6>[ 0.512517] pci 0000:07:00.0: vgaarb: bridge control possible <6>[ 0.512532] pci 0000:07:00.0: vgaarb: VGA device added: decodes=io+mem,owns=none,locks=none <6>[ 0.512622] pci 0000:07:00.1: [1002:aa98] type 00 class 0x040300 <6>[ 0.512680] pci 0000:07:00.1: reg 0x10: [mem 0x00000000-0x00003fff 64bit] <6>[ 0.512774] pci 0000:07:00.1: enabling Extended Tags <6>[ 0.512906] pci 0000:07:00.1: supports D1 D2 <6>[ 0.523215] pci_bus 0000:07: busn_res: [bus 07-ff] end is updated to 07 <6>[ 0.523264] pci_bus 0000:02: busn_res: [bus 02-ff] end is updated to 07 <6>[ 0.523291] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 07 <6>[ 0.523360] pci 0000:00:00.0: BAR 9: assigned [mem 0x2000000000-0x200fffffff 64bit pref] <6>[ 0.523384] pci 0000:00:00.0: BAR 0: assigned [mem 0x60100000-0x601fffff] <6>[ 0.523404] pci 0000:00:00.0: BAR 8: assigned [mem 0x60200000-0x603fffff] <6>[ 0.523422] pci 0000:00:00.0: BAR 6: assigned [mem 0x60090000-0x6009ffff pref] <6>[ 0.523443] pci 0000:00:00.0: BAR 7: assigned [io 0x1000-0x1fff] <6>[ 0.523465] pci 0000:01:00.0: BAR 9: assigned [mem 0x2000000000-0x200fffffff 64bit pref] <6>[ 0.523486] pci 0000:01:00.0: BAR 8: assigned [mem 0x60200000-0x603fffff] <6>[ 0.523503] pci 0000:01:00.0: BAR 7: assigned [io 0x1000-0x1fff] <6>[ 0.523525] pci 0000:02:08.0: BAR 9: assigned [mem 0x2000000000-0x200fffffff 64bit pref] <6>[ 0.523546] pci 0000:02:02.0: BAR 8: assigned [mem 0x60200000-0x602fffff] <6>[ 0.523564] pci 0000:02:08.0: BAR 8: assigned [mem 0x60300000-0x603fffff] <6>[ 0.523581] pci 0000:02:08.0: BAR 7: assigned [io 0x1000-0x1fff] <6>[ 0.523600] pci 0000:02:00.0: PCI bridge to [bus 03] <6>[ 0.523636] pci 0000:04:00.0: BAR 0: assigned [mem 0x60200000-0x60207fff 64bit] <6>[ 0.523676] pci 0000:02:02.0: PCI bridge to [bus 04] <6>[ 0.523696] pci 0000:02:02.0: bridge window [mem 0x60200000-0x602fffff] <6>[ 0.523724] pci 0000:02:03.0: PCI bridge to [bus 05] <6>[ 0.523755] pci 0000:02:04.0: PCI bridge to [bus 06] <6>[ 0.523791] pci 0000:07:00.0: BAR 0: assigned [mem 0x2000000000-0x200fffffff 64bit pref] <6>[ 0.523831] pci 0000:07:00.0: BAR 2: assigned [mem 0x60300000-0x6031ffff 64bit] <6>[ 0.523869] pci 0000:07:00.0: BAR 6: assigned [mem 0x60320000-0x6033ffff pref] <6>[ 0.523890] pci 0000:07:00.1: BAR 0: assigned [mem 0x60340000-0x60343fff 64bit] <6>[ 0.523928] pci 0000:07:00.0: BAR 4: assigned [io 0x1000-0x10ff] <6>[ 0.523951] pci 0000:02:08.0: PCI bridge to [bus 07] <6>[ 0.523968] pci 0000:02:08.0: bridge window [io 0x1000-0x1fff] <6>[ 0.523988] pci 0000:02:08.0: bridge window [mem 0x60300000-0x603fffff] <6>[ 0.524008] pci 0000:02:08.0: bridge window [mem 0x2000000000-0x200fffffff 64bit pref] <6>[ 0.524034] pci 0000:01:00.0: PCI bridge to [bus 02-07] <6>[ 0.524051] pci 0000:01:00.0: bridge window [io 0x1000-0x1fff] <6>[ 0.524071] pci 0000:01:00.0: bridge window [mem 0x60200000-0x603fffff] <6>[ 0.524090] pci 0000:01:00.0: bridge window [mem 0x2000000000-0x200fffffff 64bit pref] <6>[ 0.524117] pci 0000:00:00.0: PCI bridge to [bus 01-07] <6>[ 0.524132] pci 0000:00:00.0: bridge window [io 0x1000-0x1fff] <6>[ 0.524147] pci 0000:00:00.0: bridge window [mem 0x60200000-0x603fffff] <6>[ 0.524164] pci 0000:00:00.0: bridge window [mem 0x2000000000-0x200fffffff 64bit pref] <6>[ 0.524627] pcieport 0000:00:00.0: PME: Signaling with IRQ 21 <6>[ 0.524789] pcieport 0000:01:00.0: enabling device (0000 -> 0003) <6>[ 0.525382] pcieport 0000:02:02.0: enabling device (0000 -> 0002) <6>[ 0.526452] pcieport 0000:02:08.0: enabling device (0000 -> 0003) <6>[ 0.526768] pci 0000:04:00.0: enabling device (0000 -> 0002) <6>[ 0.526947] pci 0000:07:00.1: D0 power state depends on 0000:07:00.0 <6>[ 0.581975] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled <6>[ 0.583544] 10010000.serial: ttySIF0 at MMIO 0x10010000 (irq = 29, base_baud = 8125000) is a SiFive UART v0 <6>[ 0.978521] Freeing initrd memory: 13308K <6>[ 0.981013] printk: console [ttySIF0] enabled <6>[ 2.117948] 10011000.serial: ttySIF1 at MMIO 0x10011000 (irq = 30, base_baud = 8125000) is a SiFive UART v0 <6>[ 2.137993] loop: module loaded <6>[ 2.141541] sifive_spi 10040000.spi: mapped; irq=31, cs=1 <6>[ 2.147223] sifive_spi 10050000.spi: mapped; irq=32, cs=1 <6>[ 2.154061] macb 10090000.ethernet: Registered clk switch 'sifive-gemgxl-mgmt' <6>[ 2.173022] macb 10090000.ethernet eth0: Cadence GEM rev 0x10070109 at 0x10090000 irq 33 (70:b3:d5:92:fa:8d) <6>[ 2.182517] e1000e: Intel(R) PRO/1000 Network Driver <6>[ 2.187575] e1000e: Copyright(c) 1999 - 2015 Intel Corporation. <6>[ 2.194323] xhci_hcd 0000:04:00.0: xHCI Host Controller <6>[ 2.199244] xhci_hcd 0000:04:00.0: new USB bus registered, assigned bus number 1 <6>[ 2.347626] xhci_hcd 0000:04:00.0: hcc params 0x0200e080 hci version 0x100 quirks 0x0000000010800410 <6>[ 2.357109] xhci_hcd 0000:04:00.0: xHCI Host Controller <6>[ 2.361851] xhci_hcd 0000:04:00.0: new USB bus registered, assigned bus number 2 <6>[ 2.369490] xhci_hcd 0000:04:00.0: Host supports USB 3.0 SuperSpeed <6>[ 2.377498] hub 1-0:1.0: USB hub found <6>[ 2.380793] hub 1-0:1.0: 2 ports detected <6>[ 2.385431] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM. <6>[ 2.393820] hub 2-0:1.0: USB hub found <6>[ 2.397393] hub 2-0:1.0: 2 ports detected <6>[ 2.402341] usbcore: registered new interface driver uas <6>[ 2.407268] usbcore: registered new interface driver usb-storage <6>[ 2.413584] mousedev: PS/2 mouse device common for all mice <6>[ 2.419761] sdhci: Secure Digital Host Controller Interface driver <6>[ 2.425657] sdhci: Copyright(c) Pierre Ossman <6>[ 2.455918] mmc_spi spi1.0: SD/MMC host mmc0, no DMA, no WP, no poweroff <6>[ 2.462194] sdhci-pltfm: SDHCI platform and OF driver helper <6>[ 2.468225] usbcore: registered new interface driver usbhid <6>[ 2.473857] usbhid: USB HID core driver <6>[ 2.478050] riscv-pmu-sbi: SBI PMU extension is available <6>[ 2.483612] riscv-pmu-sbi: 16 firmware and 4 hardware counters <6>[ 2.489663] riscv-pmu-sbi: Perf sampling/filtering is not supported as sscof extension is not available <6>[ 2.500320] NET: Registered PF_INET6 protocol family <6>[ 2.506432] Segment Routing with IPv6 <6>[ 2.509665] In-situ OAM (IOAM) with IPv6 <6>[ 2.513848] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver <6>[ 2.520583] NET: Registered PF_PACKET protocol family <6>[ 2.525447] 9pnet: Installing 9P2000 support <5>[ 2.529841] Key type dns_resolver registered <6>[ 2.538255] debug_vm_pgtable: [debug_vm_pgtable ]: Validating architecture page table helpers <4>[ 2.555571] mmc0: host does not support reading read-only switch, assuming write-enable <6>[ 2.563104] mmc0: new SDHC card on SPI <6>[ 2.568588] mmcblk0: mmc0:0000 SDC 7.47 GiB <4>[ 2.606310] GPT:Primary header thinks Alt. header is not at the end of the disk. <4>[ 2.613234] GPT:13918241 != 15661055 <4>[ 2.617033] GPT:Alternate GPT header not at the end of the disk. <4>[ 2.623288] GPT:13918241 != 15661055 <4>[ 2.627094] GPT: Use GNU Parted to correct GPT errors. <6>[ 2.632523] mmcblk0: p1 p2 p3 p4 <6>[ 2.682911] macb 10090000.ethernet eth0: PHY [10090000.ethernet-ffffffff:00] driver [Microsemi VSC8541 SyncE] (irq=POLL) <6>[ 2.693308] macb 10090000.ethernet eth0: configuring for phy/gmii link mode <6>[ 2.719141] usb 1-2: new high-speed USB device number 2 using xhci_hcd <6>[ 2.966350] hub 1-2:1.0: USB hub found <6>[ 2.969813] hub 1-2:1.0: 4 ports detected <6>[ 3.058574] usb 2-2: new SuperSpeed USB device number 2 using xhci_hcd <6>[ 3.160257] hub 2-2:1.0: USB hub found <6>[ 3.164202] hub 2-2:1.0: 4 ports detected <6>[ 5.768864] macb 10090000.ethernet eth0: Link is Up - 100Mbps/Full - flow control tx <6>[ 5.776158] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready <5>[ 5.803134] Sending DHCP requests ., OK <6>[ 5.822494] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.16 <6>[ 5.830562] IP-Config: Complete: <6>[ 5.834024] device=eth0, hwaddr=70:b3:d5:92:fa:8d, ipaddr=192.168.66.16, mask=255.255.255.0, gw=192.168.66.1 <6>[ 5.844537] host=192.168.66.16, domain=example.org, nis-domain=(none) <6>[ 5.851652] bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath= <6>[ 5.851660] nameserver0=10.1.1.1 <6>[ 5.870583] Freeing unused kernel image (initmem) memory: 2164K <6>[ 5.883197] Run /init as init process Starting syslogd: OK Starting klogd: OK Running sysctl: OK Populating /dev using udev: <30>[ 5.961515] udevd[97]: starting version 3.2.9 <5>[ 9.999132] random: crng init done <27>[ 10.007981] udevd[97]: specified user 'tss' unknown <27>[ 10.012535] udevd[97]: specified group 'tss' unknown <30>[ 10.019403] udevd[99]: starting eudev-3.2.9 <6>[ 13.844210] [drm] radeon kernel modesetting enabled. <6>[ 13.849243] radeon 0000:07:00.0: enabling device (0000 -> 0003) <6>[ 13.855887] [drm] initializing kernel modesetting (CAICOS 0x1002:0x6779 0x1002:0x0000 0x00). <6>[ 14.085047] ATOM BIOS: C26401 <6>[ 14.087687] [drm] GPU not posted. posting now... <6>[ 14.097897] radeon 0000:07:00.0: VRAM: 2048M 0x0000000000000000 - 0x000000007FFFFFFF (2048M used) <6>[ 14.106281] radeon 0000:07:00.0: GTT: 1024M 0x0000000080000000 - 0x00000000BFFFFFFF <6>[ 14.114184] [drm] Detected VRAM RAM=2048M, BAR=256M <6>[ 14.119297] [drm] RAM width 64bits DDR <6>[ 14.123457] [drm] radeon: 2048M of VRAM memory ready <6>[ 14.128511] [drm] radeon: 1024M of GTT memory ready. <6>[ 14.133761] [drm] Loading CAICOS Microcode <4>[ 14.138138] radeon 0000:07:00.0: Direct firmware load for radeon/CAICOS_pfp.bin failed with error -2 <3>[ 14.147456] ni_cp: Failed to load firmware \"radeon/CAICOS_pfp.bin\" <3>[ 14.153869] [drm:evergreen_init [radeon]] *ERROR* Failed to load firmware! <3>[ 14.164762] radeon 0000:07:00.0: Fatal error during GPU init <6>[ 14.170660] [drm] radeon: finishing device. <6>[ 14.182272] [drm] radeon: ttm finalized <4>[ 14.186214] radeon: probe of 0000:07:00.0 failed with error -2 done Saving random seed: OK Starting network: ip: RTNETLINK answers: File exists FAIL Starting dropbear sshd: OK /bin/sh: can't access tty; job control turned off Matched prompt #10: / # case: kernel-messages
case_id: 4097966
definition: lava
duration: 18.32
extra: ...
level: 2.4.4.1
namespace: common
result: pass
Setting prompt string to ['/ #'] end: 2.4.4.1 login-action (duration 00:00:18) [common] case: login-action
case_id: 4097967
definition: lava
duration: 18.32
extra: ...
level: 2.4.4.1
namespace: common
result: pass
end: 2.4.4 auto-login-action (duration 00:00:18) [common] start: 2.4.5 expect-shell-connection (timeout 00:03:58) [common] Setting prompt string to ['/ #'] Forcing a shell prompt, looking for ['/ #'] / # expect-shell-connection: Wait for prompt ['/ #'] (timeout 00:05:00) Waiting using forced prompt support (timeout 00:02:30) end: 2.4.5 expect-shell-connection (duration 00:00:00) [common] start: 2.4.6 export-device-env (timeout 00:03:58) [common] end: 2.4.6 export-device-env (duration 00:00:00) [common] end: 2.4 uboot-commands (duration 00:01:02) [common] end: 2 uboot-action (duration 00:01:02) [common] start: 3 lava-test-retry (timeout 00:01:00) [common] start: 3.1 lava-test-shell (timeout 00:01:00) [common] Using namespace: common # / # # lava-test-shell: Wait for prompt ['/ #'] (timeout 00:01:00) # Using /lava-37897 export SHELL=/bin/sh / # export SHELL=/bin/sh export SHELL=/bin/sh . /lava-37897/environment / # . /lava-37897/environment . /lava-37897/environment /lava-37897/bin/lava-test-runner /lava-37897/0 / # /lava-37897/bin/lava-test-runner /lava-37897/0 Test shell timeout: 10s (minimum of the action and connection timeout) /lava-37897/bin/lava-test-runner /lava-37897/0 + export 'TESTRUN_ID=0_dmesg' + cd /lava-<8>[ 14.834739] <LAVA_SIGNAL_STARTRUN 0_dmesg 37897_1.5.2.4.1> 37897/0/tests/0_dmesg + cat uuid + UUID=37897_1.5.2.4.1 + set +x Received signal: <STARTRUN> 0_dmesg 37897_1.5.2.4.1 Starting test lava.0_dmesg (37897_1.5.2.4.1) Skipping test definition patterns. + KERNELCI_LAVA=y /bin/sh /opt/kernelci/dmesg.sh <8>[ 14.861871] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=crit RESULT=pass UNITS=lines MEASUREMENT=0> Received signal: <TESTCASE> TEST_CASE_ID=crit RESULT=pass UNITS=lines MEASUREMENT=0 case: crit
case_id: 4097968
definition: 0_dmesg
endtc: 930
measurement: 0.0
result: pass
starttc: 930
units: lines
<8>[ 14.887873] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=alert RESULT=pass UNITS=lines MEASUREMENT=0> Received signal: <TESTCASE> TEST_CASE_ID=alert RESULT=pass UNITS=lines MEASUREMENT=0 case: alert
case_id: 4097969
definition: 0_dmesg
endtc: 933
measurement: 0.0
result: pass
starttc: 933
units: lines
<8>[ 14.914079] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=emerg RESULT=pass UNITS=lines MEASUREMENT=0> + set +x <8>[ 14.923003] <LAVA_SIGNAL_ENDRUN 0_dmesg 37897_1.5.2.4.1> <LAVA_TEST_RUNNER EXIT> Received signal: <TESTCASE> TEST_CASE_ID=emerg RESULT=pass UNITS=lines MEASUREMENT=0 case: emerg
case_id: 4097970
definition: 0_dmesg
endtc: 939
measurement: 0.0
result: pass
starttc: 939
units: lines
Received signal: <ENDRUN> 0_dmesg 37897_1.5.2.4.1 Ending use of test pattern. Ending test lava.0_dmesg (37897_1.5.2.4.1), duration 0.08 case: 0_dmesg
case_id: 4097971
definition: lava
duration: 0.08
namespace: common
path: inline/dmesg.yaml
metadata: {'description': 'baseline test plan', 'environment': ['lava-test-shell'], 'format': 'Lava-Test Test Definition 1.0', 'name': 'baseline', 'os': ['debian'], 'scope': ['functional']}
run: {'steps': ['KERNELCI_LAVA=y /bin/sh /opt/kernelci/dmesg.sh']}
result: pass
revision: unspecified
uuid: 37897_1.5.2.4.1
ok: lava_test_shell seems to have completed alert: pass crit: pass emerg: pass end: 3.1 lava-test-shell (duration 00:00:01) [common] end: 3 lava-test-retry (duration 00:00:01) [common] start: 4 lava-test-retry (timeout 00:01:00) [common] start: 4.1 lava-test-shell (timeout 00:01:00) [common] Using namespace: common # # lava-test-shell: Wait for prompt ['/ #'] (timeout 00:01:00) Using /lava-37897 export SHELL=/bin/sh / # #export SHELL=/bin/sh . /lava-37897/environment / # export SHELL=/bin/sh. /lava-37897/environment /lava-37897/bin/lava-test-runner /lava-37897/1 / # . /lava-37897/environment/lava-37897/bin/lava-test-runner /lava-37897/1 Test shell timeout: 10s (minimum of the action and connection timeout) / # /lava-37897/bin/lava-test-runner /lava-37897/1 + export 'TESTRUN_ID=1_bootrr' + cd /lava<8>[ 15.385341] <LAVA_SIGNAL_STARTRUN 1_bootrr 37897_1.5.2.4.5> -37897/1/tests/1_bootrr + cat uuid + UUID=37897_1.5.2.4.5 + set +x Received signal: <STARTRUN> 1_bootrr 37897_1.5.2.4.5 Starting test lava.1_bootrr (37897_1.5.2.4.5) Skipping test definition patterns. + export 'PATH=/opt/bootrr/libexec/bootrr/helpers:/lava-37897/1/../bin:/sbin:/usr/sbin:/bin:/usr/bin' + cd /opt/bootrr/libexec/bootrr + sh helpers/bootrr-auto /lava-37897/1/../bin/lava-test-case <8>[ 15.417735] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=deferred-probe-empty RESULT=pass> Received signal: <TESTCASE> TEST_CASE_ID=deferred-probe-empty RESULT=pass case: deferred-probe-empty
case_id: 4097972
definition: 1_bootrr
endtc: 981
result: pass
starttc: 981
/lava-37897/1/../bin/lava-test-case <8>[ 15.442622] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=all-cpus-are-online RESULT=pass> /lava-37897/1/../bin/lava-test-case Received signal: <TESTCASE> TEST_CASE_ID=all-cpus-are-online RESULT=pass case: all-cpus-are-online
case_id: 4097973
definition: 1_bootrr
endtc: 986
result: pass
starttc: 986
<8>[ 15.458904] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=tpm-chip-is-online RESULT=skip> + set +x Received signal: <TESTCASE> TEST_CASE_ID=tpm-chip-is-online RESULT=skip case: tpm-chip-is-online
case_id: 4097974
definition: 1_bootrr
endtc: 990
result: skip
starttc: 990
<8>[ 15.473804] <LAVA_SIGNAL_ENDRUN 1_bootrr 37897_1.5.2.4.5> Received signal: <ENDRUN> 1_bootrr 37897_1.5.2.4.5 Ending use of test pattern. Ending test lava.1_bootrr (37897_1.5.2.4.5), duration 0.07 case: 1_bootrr
case_id: 4097975
definition: lava
duration: 0.07
namespace: common
path: inline/bootrr.yaml
metadata: {'description': 'baseline test plan', 'environment': ['lava-test-shell'], 'format': 'Lava-Test Test Definition 1.0', 'name': 'baseline', 'os': ['debian'], 'scope': ['functional']}
run: {'steps': ['export PATH=/opt/bootrr/libexec/bootrr/helpers:$PATH', 'cd /opt/bootrr/libexec/bootrr && sh helpers/bootrr-auto']}
result: pass
revision: unspecified
uuid: 37897_1.5.2.4.5
<LAVA_TEST_RUNNER EXIT> ok: lava_test_shell seems to have completed all-cpus-are-online: pass deferred-probe-empty: pass tpm-chip-is-online: skip end: 4.1 lava-test-shell (duration 00:00:01) [common] end: 4 lava-test-retry (duration 00:00:01) [common] start: 5 finalize (timeout 00:08:47) [common] start: 5.1 power-off (timeout 00:00:30) [common] Calling: 'upower.sh' '--atx' 'off' '1' >> Accessing Gembird #0 USB device 002 >> Switched outlet 1 off Returned 0 in 0 seconds end: 5.1 power-off (duration 00:00:01) [common] case: power-off
case_id: 4097976
definition: lava
duration: 0.74
extra: ...
level: 5.1
namespace: common
result: pass
start: 5.2 read-feedback (timeout 00:08:46) [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] end: 5 finalize (duration 00:00:02) [common] Cleaning after the job Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37897/tftp-deploy-4d6ikq77/ramdisk Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37897/tftp-deploy-4d6ikq77/kernel Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37897/tftp-deploy-4d6ikq77/dtb Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37897/tftp-deploy-4d6ikq77/modules Override tmp directory removed at /var/lib/lava/dispatcher/tmp/37897 Root tmp directory removed at /var/lib/lava/dispatcher/tmp/37897 Job finished correctly case: job
case_id: 4097977
definition: lava
result: pass