lava-dispatcher, installed at version: 2023.10
start: 0 validate
Start time: 2024-08-06 08:45:13.606501+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: 6.33
case: validate
case_id: 4026864
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/35822/tftp-deploy-71pymhzf/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 1.40 s (5.36 MB/s)
end: 1.1.1 http-download (duration 00:00:01) [common]
case: http-download
case_id: 4026877
definition: lava
duration: 1.40
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/35822/tftp-deploy-71pymhzf/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 4.64 s (4.08 MB/s)
end: 1.2.1 http-download (duration 00:00:05) [common]
case: http-download
case_id: 4026877
definition: lava
duration: 4.64
extra: ...
level: 1.2.1
namespace: common
result: pass
end: 1.2 download-retry (duration 00:00:05) [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/35822/tftp-deploy-71pymhzf/dtb/hifive-unmatched-a00.dtb
total size: 10707 (0 MB)
No compression specified
progress 100 % (0 MB)
0 MB downloaded in 0.26 s (0.04 MB/s)
end: 1.3.1 http-download (duration 00:00:00) [common]
case: http-download
case_id: 4026877
definition: lava
duration: 0.27
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/35822/tftp-deploy-71pymhzf/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 1.45 s (2.56 MB/s)
end: 1.4.1 http-download (duration 00:00:01) [common]
case: http-download
case_id: 4026877
definition: lava
duration: 1.46
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:52) [common]
start: 1.5.1 extract-nfsrootfs (timeout 00:09:52) [common]
end: 1.5.1 extract-nfsrootfs (duration 00:00:00) [common]
start: 1.5.2 lava-overlay (timeout 00:09:52) [common]
[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t
makedir: /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin
makedir: /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/tests
makedir: /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/results
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-add-keys
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-add-sources
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-background-process-start
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-background-process-stop
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-common-functions
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-echo-ipv4
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-install-packages
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-installed-packages
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-os-build
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-probe-channel
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-probe-ip
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-target-ip
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-target-mac
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-target-storage
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-test-case
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-test-event
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-test-feedback
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-test-raise
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-test-reference
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-test-runner
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-test-set
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-test-shell
Updating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-install-packages (oe)
Updating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/bin/lava-installed-packages (oe)
Creating /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/environment
LAVA metadata
- LAVA_JOB_ID=35822
- LAVA_DISPATCHER_IP=192.168.66.1
start: 1.5.2.1 ssh-authorize (timeout 00:09:52) [common]
end: 1.5.2.1 ssh-authorize (duration 00:00:00) [common]
start: 1.5.2.2 lava-vland-overlay (timeout 00:09:52) [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:52) [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:52) [common]
Loading test definitions
start: 1.5.2.4.1 inline-repo-action (timeout 00:09:52) [common]
Using /lava-35822 at stage 0
uuid=35822_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:52) [common]
end: 1.5.2.4.2 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 4026881
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:52) [common]
end: 1.5.2.4.3 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 4026882
definition: lava
duration: 0.01
extra: ...
level: 1.5.2.4.3
namespace: common
result: pass
start: 1.5.2.4.4 test-runscript-overlay (timeout 00:09:52) [common]
runner path: /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/0/tests/0_dmesg test_uuid 35822_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: 4026883
definition: lava
duration: 0.01
extra: ...
level: 1.5.2.4.4
namespace: common
result: pass
start: 1.5.2.4.5 inline-repo-action (timeout 00:09:52) [common]
Using /lava-35822 at stage 1
uuid=35822_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:52) [common]
end: 1.5.2.4.6 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 4026881
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:52) [common]
end: 1.5.2.4.7 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 4026882
definition: lava
duration: 0.01
extra: ...
level: 1.5.2.4.7
namespace: common
result: pass
start: 1.5.2.4.8 test-runscript-overlay (timeout 00:09:52) [common]
runner path: /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/1/tests/1_bootrr test_uuid 35822_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: 4026883
definition: lava
duration: 0.01
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/35822/lava-overlay-95xdbp7t/lava-35822/0 for stage 0
- 0_dmesg
Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/35822/lava-overlay-95xdbp7t/lava-35822/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:52) [common]
end: 1.5.2.5 compress-overlay (duration 00:00:00) [common]
start: 1.5.2.6 persistent-nfs-overlay (timeout 00:09:52) [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:52) [common]
end: 1.5.3 extract-overlay-ramdisk (duration 00:00:02) [common]
start: 1.5.4 extract-modules (timeout 00:09:50) [common]
extracting modules file /var/lib/lava/dispatcher/tmp/35822/tftp-deploy-71pymhzf/modules/modules.tar to /var/lib/lava/dispatcher/tmp/35822/extract-overlay-ramdisk-ohae01lf/ramdisk
end: 1.5.4 extract-modules (duration 00:00:00) [common]
start: 1.5.5 apply-overlay-tftp (timeout 00:09:50) [common]
[common] Applying overlay /var/lib/lava/dispatcher/tmp/35822/compress-overlay-4tcbdz15/overlay-1.5.2.5.tar.gz to ramdisk
[common] Applying overlay /var/lib/lava/dispatcher/tmp/35822/compress-overlay-4tcbdz15/overlay-1.5.2.5.tar.gz to directory /var/lib/lava/dispatcher/tmp/35822/extract-overlay-ramdisk-ohae01lf/ramdisk
end: 1.5.5 apply-overlay-tftp (duration 00:00:00) [common]
start: 1.5.6 prepare-kernel (timeout 00:09:50) [common]
start: 1.5.6.1 uboot-prepare-kernel (timeout 00:09:50) [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:50) [common]
end: 1.5.7 configure-preseed-file (duration 00:00:00) [common]
start: 1.5.8 compress-ramdisk (timeout 00:09:50) [common]
Building ramdisk /var/lib/lava/dispatcher/tmp/35822/extract-overlay-ramdisk-ohae01lf/ramdisk.cpio containing /var/lib/lava/dispatcher/tmp/35822/extract-overlay-ramdisk-ohae01lf/ramdisk
>> 86851 blocks
Adding RAMdisk u-boot header.
mkimage -A riscv -T ramdisk -C none -d /var/lib/lava/dispatcher/tmp/35822/extract-overlay-ramdisk-ohae01lf/ramdisk.cpio.gz /var/lib/lava/dispatcher/tmp/35822/extract-overlay-ramdisk-ohae01lf/ramdisk.cpio.gz.uboot
output: Image Name:
output: Created: Tue Aug 6 08:45:37 2024
output: Image Type: RISC-V Linux RAMDisk Image (uncompressed)
output: Data Size: 13644075 Bytes = 13324.29 KiB = 13.01 MiB
output: Load Address: 00000000
output: Entry Point: 00000000
output:
rename /var/lib/lava/dispatcher/tmp/35822/extract-overlay-ramdisk-ohae01lf/ramdisk.cpio.gz.uboot to /var/lib/lava/dispatcher/tmp/35822/tftp-deploy-71pymhzf/ramdisk/ramdisk.cpio.gz.uboot
end: 1.5.8 compress-ramdisk (duration 00:00:08) [common]
end: 1.5 prepare-tftp-overlay (duration 00:00:10) [common]
start: 1.6 lxc-create-udev-rule-action (timeout 00:09:42) [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:42) [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:18) [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}: 35822/tftp-deploy-71pymhzf/dtb/hifive-unmatched-a00.dtb
- {INITRD}: 35822/tftp-deploy-71pymhzf/ramdisk/ramdisk.cpio.gz.uboot
- {KERNEL_ADDR}: 0x80200000
- {KERNEL}: 35822/tftp-deploy-71pymhzf/kernel/Image
- {LAVA_MAC}: None
- {PRESEED_CONFIG}: None
- {PRESEED_LOCAL}: None
- {RAMDISK_ADDR}: 0x83500000
- {RAMDISK}: 35822/tftp-deploy-71pymhzf/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 35822/tftp-deploy-71pymhzf/kernel/Image
- tftp 0x83500000 35822/tftp-deploy-71pymhzf/ramdisk/ramdisk.cpio.gz.uboot
- setenv initrd_size ${filesize}
- tftp 0x83000000 35822/tftp-deploy-71pymhzf/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: 4026891
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 63006'
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: 'upower.sh' '--atx' 'reset' '1'
>> Accessing Gembird #0 USB device 016
>> Switched outlet 1 off
>> Accessing Gembird #0 USB device 016
>> Switched outlet 1 on
>> FTDI RELAY: power on
>> FTDI RELAY: power off
Returned 0 in 12 seconds
end: 2.4.1.1 pdu-reboot (duration 00:00:13) [common]
case: pdu-reboot
case_id: 4026896
definition: lava
duration: 13.02
extra: ...
level: 2.4.1.1
namespace: common
result: pass
end: 2.4.1 reset-device (duration 00:00:13) [common]
start: 2.4.2 bootloader-interrupt (timeout 00:04:43) [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:33) [common]
Setting prompt string to ['=>']
bootloader-commands: Wait for prompt ['=>'] (timeout 00:04:33)
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:33)
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:33)
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:33)
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:33)
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.244 (1201 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:29)
setenv serverip 192.168.66.1
tftp 0x80200000 35822/tftp-deploy-71pymhzf/kernel/Image
=> tftp 0x80200000 35822/tftp-deploy-71pymhzf/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:29)
tftp 0x80200000 35822/tftp-deploy-71pymhzf/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.244
Filename '35822/tftp-deploy-71pymhzf/kernel/Image'.
Load address: 0x80200000
Loading: *#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
####################################################
1.6 MiB/s
done
Bytes transferred = 19845120 (12ed000 hex)
tftp 0x83500000 35822/tftp-deploy-71pymhzf/ramdisk/ramdisk.cpio.gz.uboot
=> tftp 0x83500000 35822/tftp-deploy-71pymhzf/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:15)
tftp 0x83500000 35822/tftp-deploy-71pymhzf/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.244
Filename '35822/tftp-deploy-71pymhzf/ramdisk/ramdisk.cpio.gz.uboot'.
Load address: 0x83500000
Loading: *#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
####################
1.6 MiB/s
done
Bytes transferred = 13644139 (d0316b 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:05)
setenv initrd_size ${filesize}
tftp 0x83000000 35822/tftp-deploy-71pymhzf/dtb/hifive-unmatched-a00.dtb
=> tftp 0x83000000 35822/tftp-deploy-71pymhzf/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:05)
tftp 0x83000000 35822/tftp-deploy-71pymhzf/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.244
Filename '35822/tftp-deploy-71pymhzf/dtb/hifive-unmatched-a00.dtb'.
Load address: 0x83000000
Loading: *#
950.2 KiB/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:02)
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:02)
booti 0x80200000 0x83500000 0x83000000
## Loading init Ramdisk from Legacy Image at 83500000 ...
Image Name:
Image Type: RISC-V Linux RAMDisk Image (uncompressed)
Data Size: 13644075 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:31) [common]
start: 2.4.4 auto-login-action (timeout 00:04:02) [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:02) [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:02)
[ 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: 16387892K/16775168K available (7456K kernel code, 4927K rwdata, 4096K rodata, 2164K init, 461K bss, 387276K 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.000002] sched_clock: 64 bits at 1000kHz, resolution 1000ns, wraps every 2199023255500ns
<6>[ 0.008822] Console: colour dummy device 80x25
<6>[ 0.013317] printk: console [tty0] enabled
<6>[ 0.017630] 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: 16387892K/16775168K available (7456K kernel code, 4927K rwdata, 4096K rodata, 2164K init, 461K bss, 387276K 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.000002] sched_clock: 64 bits at 1000kHz, resolution 1000ns, wraps every 2199023255500ns
<6>[ 0.008822] Console: colour dummy device 80x25
<6>[ 0.013317] printk: console [tty0] enabled
<6>[ 0.017630] printk: bootconsole [sifive0] disabled
<6>[ 0.022726] Calibrating delay loop (skipped), value calculated using timer frequency.. 2.00 BogoMIPS (lpj=4000)
<6>[ 0.022750] pid_max: default: 32768 minimum: 301
<6>[ 0.022866] LSM: Security Framework initializing
<6>[ 0.023623] Mount-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
<6>[ 0.024312] Mountpoint-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
<6>[ 0.026128] CPU node for /cpus/cpu@0 exist but the possible cpu range is :0-3
<6>[ 0.027526] cblist_init_generic: Setting adjustable number of callback queues.
<6>[ 0.027544] cblist_init_generic: Setting shift to 2 and lim to 1.
<6>[ 0.027707] riscv: ELF compat mode unsupported
<6>[ 0.027715] ASID allocator disabled (0 bits)
<6>[ 0.027905] rcu: Hierarchical SRCU implementation.
<6>[ 0.027919] rcu: Max phase no-delay instances is 1000.
<6>[ 0.028287] EFI services will not be available.
<6>[ 0.028989] smp: Bringing up secondary CPUs ...
<6>[ 0.032046] smp: Brought up 1 node, 4 CPUs
<6>[ 0.036178] devtmpfs: initialized
<6>[ 0.039016] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
<6>[ 0.039062] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
<6>[ 0.039458] pinctrl core: initialized pinctrl subsystem
<6>[ 0.040480] NET: Registered PF_NETLINK/PF_ROUTE protocol family
<6>[ 0.040679] audit: initializing netlink subsys (disabled)
<5>[ 0.040939] audit: type=2000 audit(0.028:1): state=initialized audit_enabled=0 res=1
<6>[ 0.041280] cpuidle: using governor menu
<6>[ 0.052269] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
<6>[ 0.052297] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page
<6>[ 0.053034] iommu: Default domain type: Translated
<6>[ 0.053053] iommu: DMA domain TLB invalidation policy: strict mode
<5>[ 0.053406] SCSI subsystem initialized
<6>[ 0.053826] usbcore: registered new interface driver usbfs
<6>[ 0.053878] usbcore: registered new interface driver hub
<6>[ 0.053932] usbcore: registered new device driver usb
<6>[ 0.054979] vgaarb: loaded
<6>[ 0.055142] clocksource: Switched to clocksource riscv_clocksource
<6>[ 0.064450] NET: Registered PF_INET protocol family
<6>[ 0.071640] IP idents hash table entries: 262144 (order: 9, 2097152 bytes, linear)
<6>[ 0.092767] tcp_listen_portaddr_hash hash table entries: 8192 (order: 6, 262144 bytes, linear)
<6>[ 0.093805] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
<6>[ 0.093892] TCP established hash table entries: 131072 (order: 8, 1048576 bytes, linear)
<6>[ 0.098560] TCP bind hash table entries: 65536 (order: 10, 4194304 bytes, linear)
<6>[ 0.116279] TCP: Hash tables configured (established 131072 bind 65536)
<6>[ 0.117068] UDP hash table entries: 8192 (order: 7, 786432 bytes, linear)
<6>[ 0.120317] UDP-Lite hash table entries: 8192 (order: 7, 786432 bytes, linear)
<6>[ 0.123858] NET: Registered PF_UNIX/PF_LOCAL protocol family
<6>[ 0.125025] RPC: Registered named UNIX socket transport module.
<6>[ 0.125051] RPC: Registered udp transport module.
<6>[ 0.125064] RPC: Registered tcp transport module.
<6>[ 0.125075] RPC: Registered tcp NFSv4.1 backchannel transport module.
<6>[ 0.125098] PCI: CLS 0 bytes, default 64
<6>[ 0.125702] Unpacking initramfs...
<6>[ 0.144509] workingset: timestamp_bits=46 max_order=22 bucket_order=0
<5>[ 0.153827] NFS: Registering the id_resolver key type
<5>[ 0.153956] Key type id_resolver registered
<5>[ 0.153972] Key type id_legacy registered
<6>[ 0.154064] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
<6>[ 0.154084] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
<6>[ 0.154349] 9p: Installing v9fs 9p2000 file system support
<6>[ 0.154851] NET: Registered PF_ALG protocol family
<6>[ 0.154934] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
<6>[ 0.154960] io scheduler mq-deadline registered
<6>[ 0.154976] io scheduler kyber registered
<6>[ 0.178980] fu740-pcie e00000000.pcie: host bridge /soc/pcie@e00000000 ranges:
<6>[ 0.179114] fu740-pcie e00000000.pcie: IO 0x0060080000..0x006008ffff -> 0x0060080000
<6>[ 0.179216] fu740-pcie e00000000.pcie: MEM 0x0060090000..0x007fffffff -> 0x0060090000
<6>[ 0.179250] fu740-pcie e00000000.pcie: MEM 0x2000000000..0x3fffffffff -> 0x2000000000
<6>[ 0.288289] fu740-pcie e00000000.pcie: iATU unroll: enabled
<6>[ 0.288351] fu740-pcie e00000000.pcie: iATU regions: 8 ob, 8 ib, align 4K, limit 4096G
<6>[ 0.388464] fu740-pcie e00000000.pcie: PCIe Gen.1 x8 link up
<6>[ 0.488577] fu740-pcie e00000000.pcie: PCIe Gen.3 x8 link up
<6>[ 0.488643] fu740-pcie e00000000.pcie: PCIe Gen.3 x8 link up
<6>[ 0.488887] fu740-pcie e00000000.pcie: PCI host bridge to bus 0000:00
<6>[ 0.488918] pci_bus 0000:00: root bus resource [bus 00-ff]
<6>[ 0.488942] pci_bus 0000:00: root bus resource [io 0x0000-0xffff] (bus address [0x60080000-0x6008ffff])
<6>[ 0.488964] pci_bus 0000:00: root bus resource [mem 0x60090000-0x7fffffff]
<6>[ 0.488981] pci_bus 0000:00: root bus resource [mem 0x2000000000-0x3fffffffff pref]
<6>[ 0.489037] pci 0000:00:00.0: [f15e:0000] type 01 class 0x060400
<6>[ 0.489066] pci 0000:00:00.0: reg 0x10: [mem 0x00000000-0x000fffff]
<6>[ 0.489088] pci 0000:00:00.0: reg 0x38: [mem 0x00000000-0x0000ffff pref]
<6>[ 0.489169] pci 0000:00:00.0: supports D1
<6>[ 0.489184] pci 0000:00:00.0: PME# supported from D0 D1 D3hot
<6>[ 0.490034] pci 0000:01:00.0: [1b21:2824] type 01 class 0x060400
<6>[ 0.490129] pci 0000:01:00.0: enabling Extended Tags
<6>[ 0.490275] pci 0000:01:00.0: PME# supported from D0 D3hot D3cold
<6>[ 0.499246] pci 0000:01:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
<6>[ 0.499491] pci 0000:02:00.0: [1b21:2824] type 01 class 0x060400
<6>[ 0.499588] pci 0000:02:00.0: enabling Extended Tags
<6>[ 0.499745] pci 0000:02:00.0: PME# supported from D0 D3hot D3cold
<6>[ 0.500127] pci 0000:02:02.0: [1b21:2824] type 01 class 0x060400
<6>[ 0.500224] pci 0000:02:02.0: enabling Extended Tags
<6>[ 0.500370] pci 0000:02:02.0: PME# supported from D0 D3hot D3cold
<6>[ 0.500663] pci 0000:02:03.0: [1b21:2824] type 01 class 0x060400
<6>[ 0.500757] pci 0000:02:03.0: enabling Extended Tags
<6>[ 0.500900] pci 0000:02:03.0: PME# supported from D0 D3hot D3cold
<6>[ 0.501211] pci 0000:02:04.0: [1b21:2824] type 01 class 0x060400
<6>[ 0.501305] pci 0000:02:04.0: enabling Extended Tags
<6>[ 0.501450] pci 0000:02:04.0: PME# supported from D0 D3hot D3cold
<6>[ 0.501817] pci 0000:02:08.0: [1b21:2824] type 01 class 0x060400
<6>[ 0.501914] pci 0000:02:08.0: enabling Extended Tags
<6>[ 0.502060] pci 0000:02:08.0: PME# supported from D0 D3hot D3cold
<6>[ 0.502734] pci 0000:02:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
<6>[ 0.502769] pci 0000:02:02.0: bridge configuration invalid ([bus 00-00]), reconfiguring
<6>[ 0.502798] pci 0000:02:03.0: bridge configuration invalid ([bus 00-00]), reconfiguring
<6>[ 0.502827] pci 0000:02:04.0: bridge configuration invalid ([bus 00-00]), reconfiguring
<6>[ 0.502855] pci 0000:02:08.0: bridge configuration invalid ([bus 00-00]), reconfiguring
<6>[ 0.503045] pci_bus 0000:03: busn_res: [bus 03-ff] end is updated to 03
<6>[ 0.503263] pci 0000:04:00.0: [1b21:1142] type 00 class 0x0c0330
<6>[ 0.503327] pci 0000:04:00.0: reg 0x10: [mem 0x00000000-0x00007fff 64bit]
<6>[ 0.503555] pci 0000:04:00.0: PME# supported from D3cold
<6>[ 0.515237] pci_bus 0000:04: busn_res: [bus 04-ff] end is updated to 04
<6>[ 0.515507] pci_bus 0000:05: busn_res: [bus 05-ff] end is updated to 05
<6>[ 0.515681] pci_bus 0000:06: busn_res: [bus 06-ff] end is updated to 06
<6>[ 0.515901] pci 0000:07:00.0: [1002:6779] type 00 class 0x030000
<6>[ 0.515963] pci 0000:07:00.0: reg 0x10: [mem 0x00000000-0x0fffffff 64bit pref]
<6>[ 0.516006] pci 0000:07:00.0: reg 0x18: [mem 0x00000000-0x0001ffff 64bit]
<6>[ 0.516036] pci 0000:07:00.0: reg 0x20: initial BAR value 0x00000000 invalid
<6>[ 0.516054] pci 0000:07:00.0: reg 0x20: [io size 0x0100]
<6>[ 0.516094] pci 0000:07:00.0: reg 0x30: [mem 0x00000000-0x0001ffff pref]
<6>[ 0.516127] pci 0000:07:00.0: enabling Extended Tags
<6>[ 0.516277] pci 0000:07:00.0: supports D1 D2
<6>[ 0.516344] 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.516549] pci 0000:07:00.0: vgaarb: setting as boot VGA device
<6>[ 0.516568] pci 0000:07:00.0: vgaarb: bridge control possible
<6>[ 0.516583] pci 0000:07:00.0: vgaarb: VGA device added: decodes=io+mem,owns=none,locks=none
<6>[ 0.516676] pci 0000:07:00.1: [1002:aa98] type 00 class 0x040300
<6>[ 0.516732] pci 0000:07:00.1: reg 0x10: [mem 0x00000000-0x00003fff 64bit]
<6>[ 0.516827] pci 0000:07:00.1: enabling Extended Tags
<6>[ 0.516959] pci 0000:07:00.1: supports D1 D2
<6>[ 0.527248] pci_bus 0000:07: busn_res: [bus 07-ff] end is updated to 07
<6>[ 0.527299] pci_bus 0000:02: busn_res: [bus 02-ff] end is updated to 07
<6>[ 0.527324] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 07
<6>[ 0.527398] pci 0000:00:00.0: BAR 9: assigned [mem 0x2000000000-0x200fffffff 64bit pref]
<6>[ 0.527423] pci 0000:00:00.0: BAR 0: assigned [mem 0x60100000-0x601fffff]
<6>[ 0.527443] pci 0000:00:00.0: BAR 8: assigned [mem 0x60200000-0x603fffff]
<6>[ 0.527461] pci 0000:00:00.0: BAR 6: assigned [mem 0x60090000-0x6009ffff pref]
<6>[ 0.527483] pci 0000:00:00.0: BAR 7: assigned [io 0x1000-0x1fff]
<6>[ 0.527506] pci 0000:01:00.0: BAR 9: assigned [mem 0x2000000000-0x200fffffff 64bit pref]
<6>[ 0.527527] pci 0000:01:00.0: BAR 8: assigned [mem 0x60200000-0x603fffff]
<6>[ 0.527545] pci 0000:01:00.0: BAR 7: assigned [io 0x1000-0x1fff]
<6>[ 0.527567] pci 0000:02:08.0: BAR 9: assigned [mem 0x2000000000-0x200fffffff 64bit pref]
<6>[ 0.527589] pci 0000:02:02.0: BAR 8: assigned [mem 0x60200000-0x602fffff]
<6>[ 0.527607] pci 0000:02:08.0: BAR 8: assigned [mem 0x60300000-0x603fffff]
<6>[ 0.527624] pci 0000:02:08.0: BAR 7: assigned [io 0x1000-0x1fff]
<6>[ 0.527642] pci 0000:02:00.0: PCI bridge to [bus 03]
<6>[ 0.527679] pci 0000:04:00.0: BAR 0: assigned [mem 0x60200000-0x60207fff 64bit]
<6>[ 0.527719] pci 0000:02:02.0: PCI bridge to [bus 04]
<6>[ 0.527739] pci 0000:02:02.0: bridge window [mem 0x60200000-0x602fffff]
<6>[ 0.527766] pci 0000:02:03.0: PCI bridge to [bus 05]
<6>[ 0.527798] pci 0000:02:04.0: PCI bridge to [bus 06]
<6>[ 0.527833] pci 0000:07:00.0: BAR 0: assigned [mem 0x2000000000-0x200fffffff 64bit pref]
<6>[ 0.527873] pci 0000:07:00.0: BAR 2: assigned [mem 0x60300000-0x6031ffff 64bit]
<6>[ 0.527911] pci 0000:07:00.0: BAR 6: assigned [mem 0x60320000-0x6033ffff pref]
<6>[ 0.527932] pci 0000:07:00.1: BAR 0: assigned [mem 0x60340000-0x60343fff 64bit]
<6>[ 0.527969] pci 0000:07:00.0: BAR 4: assigned [io 0x1000-0x10ff]
<6>[ 0.527993] pci 0000:02:08.0: PCI bridge to [bus 07]
<6>[ 0.528009] pci 0000:02:08.0: bridge window [io 0x1000-0x1fff]
<6>[ 0.528030] pci 0000:02:08.0: bridge window [mem 0x60300000-0x603fffff]
<6>[ 0.528051] pci 0000:02:08.0: bridge window [mem 0x2000000000-0x200fffffff 64bit pref]
<6>[ 0.528077] pci 0000:01:00.0: PCI bridge to [bus 02-07]
<6>[ 0.528094] pci 0000:01:00.0: bridge window [io 0x1000-0x1fff]
<6>[ 0.528114] pci 0000:01:00.0: bridge window [mem 0x60200000-0x603fffff]
<6>[ 0.528133] pci 0000:01:00.0: bridge window [mem 0x2000000000-0x200fffffff 64bit pref]
<6>[ 0.528160] pci 0000:00:00.0: PCI bridge to [bus 01-07]
<6>[ 0.528175] pci 0000:00:00.0: bridge window [io 0x1000-0x1fff]
<6>[ 0.528191] pci 0000:00:00.0: bridge window [mem 0x60200000-0x603fffff]
<6>[ 0.528207] pci 0000:00:00.0: bridge window [mem 0x2000000000-0x200fffffff 64bit pref]
<6>[ 0.528673] pcieport 0000:00:00.0: PME: Signaling with IRQ 21
<6>[ 0.528832] pcieport 0000:01:00.0: enabling device (0000 -> 0003)
<6>[ 0.529403] pcieport 0000:02:02.0: enabling device (0000 -> 0002)
<6>[ 0.530419] pcieport 0000:02:08.0: enabling device (0000 -> 0003)
<6>[ 0.530793] pci 0000:04:00.0: enabling device (0000 -> 0002)
<6>[ 0.530975] pci 0000:07:00.1: D0 power state depends on 0000:07:00.0
<6>[ 0.585242] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
<6>[ 0.586819] 10010000.serial: ttySIF0 at MMIO 0x10010000 (irq = 29, base_baud = 8125000) is a SiFive UART v0
<6>[ 0.976511] Freeing initrd memory: 13320K
<6>[ 0.979936] printk: console [ttySIF0] enabled
<6>[ 2.121026] 10011000.serial: ttySIF1 at MMIO 0x10011000 (irq = 30, base_baud = 8125000) is a SiFive UART v0
<6>[ 2.141102] loop: module loaded
<6>[ 2.144525] sifive_spi 10040000.spi: mapped; irq=31, cs=1
<6>[ 2.150207] sifive_spi 10050000.spi: mapped; irq=32, cs=1
<6>[ 2.157063] macb 10090000.ethernet: Registered clk switch 'sifive-gemgxl-mgmt'
<6>[ 2.176144] macb 10090000.ethernet eth0: Cadence GEM rev 0x10070109 at 0x10090000 irq 33 (70:b3:d5:92:fa:8d)
<6>[ 2.185638] e1000e: Intel(R) PRO/1000 Network Driver
<6>[ 2.190694] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
<6>[ 2.197434] xhci_hcd 0000:04:00.0: xHCI Host Controller
<6>[ 2.202357] xhci_hcd 0000:04:00.0: new USB bus registered, assigned bus number 1
<6>[ 2.350673] xhci_hcd 0000:04:00.0: hcc params 0x0200e080 hci version 0x100 quirks 0x0000000010800410
<6>[ 2.360153] xhci_hcd 0000:04:00.0: xHCI Host Controller
<6>[ 2.364894] xhci_hcd 0000:04:00.0: new USB bus registered, assigned bus number 2
<6>[ 2.372535] xhci_hcd 0000:04:00.0: Host supports USB 3.0 SuperSpeed
<6>[ 2.380574] hub 1-0:1.0: USB hub found
<6>[ 2.383876] hub 1-0:1.0: 2 ports detected
<6>[ 2.388512] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
<6>[ 2.396981] hub 2-0:1.0: USB hub found
<6>[ 2.400456] hub 2-0:1.0: 2 ports detected
<6>[ 2.405481] usbcore: registered new interface driver uas
<6>[ 2.410404] usbcore: registered new interface driver usb-storage
<6>[ 2.416731] mousedev: PS/2 mouse device common for all mice
<6>[ 2.422876] sdhci: Secure Digital Host Controller Interface driver
<6>[ 2.428805] sdhci: Copyright(c) Pierre Ossman
<6>[ 2.459118] mmc_spi spi1.0: SD/MMC host mmc0, no DMA, no WP, no poweroff
<6>[ 2.465394] sdhci-pltfm: SDHCI platform and OF driver helper
<6>[ 2.471425] usbcore: registered new interface driver usbhid
<6>[ 2.477052] usbhid: USB HID core driver
<6>[ 2.481245] riscv-pmu-sbi: SBI PMU extension is available
<6>[ 2.486799] riscv-pmu-sbi: 16 firmware and 4 hardware counters
<6>[ 2.492856] riscv-pmu-sbi: Perf sampling/filtering is not supported as sscof extension is not available
<6>[ 2.503546] NET: Registered PF_INET6 protocol family
<6>[ 2.509821] Segment Routing with IPv6
<6>[ 2.513051] In-situ OAM (IOAM) with IPv6
<6>[ 2.517232] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
<6>[ 2.523925] NET: Registered PF_PACKET protocol family
<6>[ 2.528814] 9pnet: Installing 9P2000 support
<5>[ 2.533204] Key type dns_resolver registered
<6>[ 2.542680] debug_vm_pgtable: [debug_vm_pgtable ]: Validating architecture page table helpers
<4>[ 2.578674] mmc0: host does not support reading read-only switch, assuming write-enable
<6>[ 2.586222] mmc0: new SDHC card on SPI
<6>[ 2.591647] mmcblk0: mmc0:0000 SDC 7.47 GiB
<4>[ 2.629352] GPT:Primary header thinks Alt. header is not at the end of the disk.
<4>[ 2.636271] GPT:13918241 != 15661055
<4>[ 2.640073] GPT:Alternate GPT header not at the end of the disk.
<4>[ 2.646346] GPT:13918241 != 15661055
<4>[ 2.650148] GPT: Use GNU Parted to correct GPT errors.
<6>[ 2.655573] mmcblk0: p1 p2 p3 p4
<6>[ 2.679158] usb 1-2: new high-speed USB device number 2 using xhci_hcd
<6>[ 2.691030] macb 10090000.ethernet eth0: PHY [10090000.ethernet-ffffffff:00] driver [Microsemi VSC8541 SyncE] (irq=POLL)
<6>[ 2.701423] macb 10090000.ethernet eth0: configuring for phy/gmii link mode
<6>[ 2.926364] hub 1-2:1.0: USB hub found
<6>[ 2.929827] hub 1-2:1.0: 4 ports detected
<6>[ 3.018591] usb 2-2: new SuperSpeed USB device number 2 using xhci_hcd
<6>[ 3.120034] hub 2-2:1.0: USB hub found
<6>[ 3.123998] hub 2-2:1.0: 4 ports detected
<6>[ 4.744890] macb 10090000.ethernet eth0: Link is Up - 100Mbps/Full - flow control tx
<6>[ 4.752180] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
<5>[ 4.775262] Sending DHCP requests ., OK
<6>[ 4.794510] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.244
<6>[ 4.802664] IP-Config: Complete:
<6>[ 4.806121] device=eth0, hwaddr=70:b3:d5:92:fa:8d, ipaddr=192.168.66.244, mask=255.255.255.0, gw=192.168.66.1
<6>[ 4.816721] host=192.168.66.244, domain=, nis-domain=(none)
<6>[ 4.822969] bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath=
<6>[ 4.822976] nameserver0=10.1.1.1
<6>[ 4.841939] Freeing unused kernel image (initmem) memory: 2164K
<6>[ 4.855213] Run /init as init process
Starting syslogd: OK
Starting klogd: OK
Running sysctl: OK
Populating /dev using udev: <30>[ 4.934149] udevd[97]: starting version 3.2.9
<5>[ 8.971153] random: crng init done
<27>[ 8.979996] udevd[97]: specified user 'tss' unknown
<27>[ 8.984557] udevd[97]: specified group 'tss' unknown
<30>[ 8.991965] udevd[98]: starting eudev-3.2.9
<6>[ 12.823892] [drm] radeon kernel modesetting enabled.
<6>[ 12.828932] radeon 0000:07:00.0: enabling device (0000 -> 0003)
<6>[ 12.835395] [drm] initializing kernel modesetting (CAICOS 0x1002:0x6779 0x1002:0x0000 0x00).
<6>[ 13.064303] ATOM BIOS: C26401
<6>[ 13.066930] [drm] GPU not posted. posting now...
<6>[ 13.077163] radeon 0000:07:00.0: VRAM: 2048M 0x0000000000000000 - 0x000000007FFFFFFF (2048M used)
<6>[ 13.085550] radeon 0000:07:00.0: GTT: 1024M 0x0000000080000000 - 0x00000000BFFFFFFF
<6>[ 13.093448] [drm] Detected VRAM RAM=2048M, BAR=256M
<6>[ 13.098562] [drm] RAM width 64bits DDR
<6>[ 13.102717] [drm] radeon: 2048M of VRAM memory ready
<6>[ 13.107778] [drm] radeon: 1024M of GTT memory ready.
<6>[ 13.113021] [drm] Loading CAICOS Microcode
<4>[ 13.117398] radeon 0000:07:00.0: Direct firmware load for radeon/CAICOS_pfp.bin failed with error -2
<3>[ 13.126729] ni_cp: Failed to load firmware \"radeon/CAICOS_pfp.bin\"
<3>[ 13.133146] [drm:evergreen_init [radeon]] *ERROR* Failed to load firmware!
<3>[ 13.143572] radeon 0000:07:00.0: Fatal error during GPU init
<6>[ 13.149472] [drm] radeon: finishing device.
<6>[ 13.161081] [drm] radeon: ttm finalized
<4>[ 13.164991] 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: 4026915
definition: lava
duration: 17.28
extra: ...
level: 2.4.4.1
namespace: common
result: pass
Setting prompt string to ['/ #']
end: 2.4.4.1 login-action (duration 00:00:17) [common]
case: login-action
case_id: 4026916
definition: lava
duration: 17.29
extra: ...
level: 2.4.4.1
namespace: common
result: pass
end: 2.4.4 auto-login-action (duration 00:00:17) [common]
start: 2.4.5 expect-shell-connection (timeout 00:03:45) [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:45) [common]
end: 2.4.6 export-device-env (duration 00:00:00) [common]
end: 2.4 uboot-commands (duration 00:01:11) [common]
end: 2 uboot-action (duration 00:01:15) [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-35822
export SHELL=/bin/sh
/ # export SHELL=/bin/sh
export SHELL=/bin/sh
. /lava-35822/environment
/ # . /lava-35822/environment
. /lava-35822/environment
/lava-35822/bin/lava-test-runner /lava-35822/0
/ # /lava-35822/bin/lava-test-runner /lava-35822/0
Test shell timeout: 10s (minimum of the action and connection timeout)
/lava-35822/bin/lava-test-runner /lava-35822/0
+ export 'TESTRUN_ID=0_dmesg'
Received signal: <STARTRUN> 0_dmesg 35822_1.5.2.4.1
Starting test lava.0_dmesg (35822_1.5.2.4.1)
Skipping test definition patterns.
+ cd /lava-<8>[ 13.807784] <LAVA_SIGNAL_STARTRUN 0_dmesg 35822_1.5.2.4.1>
35822/0/tests/0_dmesg
+ cat uuid
+ UUID=35822_1.5.2.4.1
+ set +x
+ KERNELCI_LAVA=y /bin/sh /opt/kernelci/dmesg.sh
<8>[ 13.835108] <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: 4026917
definition: 0_dmesg
endtc: 930
measurement: 0.0
result: pass
starttc: 930
units: lines
<8>[ 13.861568] <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: 4026918
definition: 0_dmesg
endtc: 933
measurement: 0.0
result: pass
starttc: 933
units: lines
<8>[ 13.888142] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=emerg RESULT=pass UNITS=lines MEASUREMENT=0>
+ set +x
Received signal: <TESTCASE> TEST_CASE_ID=emerg RESULT=pass UNITS=lines MEASUREMENT=0
case: emerg
case_id: 4026919
definition: 0_dmesg
endtc: 937
measurement: 0.0
result: pass
starttc: 937
units: lines
<8>[ 13.897070] <LAVA_SIGNAL_ENDRUN 0_dmesg 35822_1.5.2.4.1>
Received signal: <ENDRUN> 0_dmesg 35822_1.5.2.4.1
Ending use of test pattern.
Ending test lava.0_dmesg (35822_1.5.2.4.1), duration 0.10
case: 0_dmesg
case_id: 4026920
definition: lava
duration: 0.10
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: 35822_1.5.2.4.1
<LAVA_TEST_RUNNER EXIT>
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-35822
export SHELL=/bin/sh
export SHELL=/bin/sh
#
. /lava-35822/environment
/ # export SHELL=/bin/sh. /lava-35822/environment
/lava-35822/bin/lava-test-runner /lava-35822/1
/ # . /lava-35822/environment/lava-35822/bin/lava-test-runner /lava-35822/1
Test shell timeout: 10s (minimum of the action and connection timeout)
/ # /lava-35822/bin/lava-test-runner /lava-35822/1
+ export 'TESTRUN_ID=1_bootrr'
+ cd /lava<8>[ 14.363184] <LAVA_SIGNAL_STARTRUN 1_bootrr 35822_1.5.2.4.5>
-35822/1/tests/1_bootrr
+ cat uuid
Received signal: <STARTRUN> 1_bootrr 35822_1.5.2.4.5
Starting test lava.1_bootrr (35822_1.5.2.4.5)
Skipping test definition patterns.
+ UUID=35822_1.5.2.4.5
+ set +x
+ export 'PATH=/opt/bootrr/libexec/bootrr/helpers:/lava-35822/1/../bin:/sbin:/usr/sbin:/bin:/usr/bin'
+ cd /opt/bootrr/libexec/bootrr
+ sh helpers/bootrr-auto
/lava-35822/1/../bin/lava-test-case
<8>[ 14.395091] <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: 4026921
definition: 1_bootrr
endtc: 981
result: pass
starttc: 981
/lava-35822/1/../bin/lava-test-case
Received signal: <TESTCASE> TEST_CASE_ID=all-cpus-are-online RESULT=pass
case: all-cpus-are-online
case_id: 4026922
definition: 1_bootrr
endtc: 984
result: pass
starttc: 984
<8>[ 14.419964] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=all-cpus-are-online RESULT=pass>
/lava-35822/1/../bin/lava-test-case
<8>[ 14.436902] <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: 4026923
definition: 1_bootrr
endtc: 990
result: skip
starttc: 990
<8>[ 14.451703] <LAVA_SIGNAL_ENDRUN 1_bootrr 35822_1.5.2.4.5>
Received signal: <ENDRUN> 1_bootrr 35822_1.5.2.4.5
Ending use of test pattern.
Ending test lava.1_bootrr (35822_1.5.2.4.5), duration 0.08
case: 1_bootrr
case_id: 4026924
definition: lava
duration: 0.09
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: 35822_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:25) [common]
start: 5.1 power-off (timeout 00:00:30) [common]
Calling: 'upower.sh' '--atx' 'off' '1'
>> Accessing Gembird #0 USB device 016
>> Switched outlet 1 off
Returned 0 in 3 seconds
end: 5.1 power-off (duration 00:00:04) [common]
case: power-off
case_id: 4026925
definition: lava
duration: 3.99
extra: ...
level: 5.1
namespace: common
result: pass
start: 5.2 read-feedback (timeout 00:08:21) [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:05) [common]
Cleaning after the job
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35822/tftp-deploy-71pymhzf/ramdisk
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35822/tftp-deploy-71pymhzf/kernel
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35822/tftp-deploy-71pymhzf/dtb
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35822/tftp-deploy-71pymhzf/modules
Override tmp directory removed at /var/lib/lava/dispatcher/tmp/35822
Root tmp directory removed at /var/lib/lava/dispatcher/tmp/35822
Job finished correctly
case: job
case_id: 4026926
definition: lava
result: pass
Please read the triage guidelines for help on debugging failures in the test job, test definitions or in individual test cases.
This section helps test writers to check for actions with a duration which is much shorter than the requested timeout. Reducing these timeouts will allow failures to be identified more quickly.
The graph only shows actions that are longer than 1 second. The full list is anyway available in the table.