Action timeout for connect-device exceeds Job timeout Action timeout for pdu-reboot exceeds Job timeout Action timeout for reset-device exceeds Job timeout Action timeout for login-action exceeds Job timeout Action timeout for auto-login-action exceeds Job timeout Action timeout for expect-shell-connection exceeds Job timeout Action timeout for overlay-unpack exceeds Job timeout Action timeout for export-device-env exceeds Job timeout Action timeout for minimal-boot exceeds Job timeout lava-dispatcher, installed at version: 2023.10 start: 0 validate Start time: 2024-11-21 13:46:25.833234+00:00 (UTC) Validating that http://download.automotivelinux.org/AGL/release/ricefish/18.0.2/raspberrypi5/deploy/images/raspberrypi5/initramfs-netboot-image-raspberrypi5-20241028040434.ext4.gz exists Validating that http://download.automotivelinux.org/AGL/release/ricefish/18.0.2/raspberrypi5/deploy/images/raspberrypi5/Image exists Validating that http://download.automotivelinux.org/AGL/release/ricefish/18.0.2/raspberrypi5/deploy/images/raspberrypi5/bcm2712-rpi-5-b.dtb exists Validating that http://download.automotivelinux.org/AGL/release/ricefish/18.0.2/raspberrypi5/deploy/images/raspberrypi5/agl-ivi-demo-qt-raspberrypi5-20241028040434.ext4.xz exists validate duration: 0.90 case: validate
case_id: 4089321
definition: lava
result: pass
start: 1 nbd-deploy (timeout 00:10:00) [common] Making protocol call for nbd-deploy using lava-xnbd [nbd-deploy] Checking protocol data for lava-xnbd Get a port from pool Set_port 61966 start: 1.1 download-retry (timeout 00:10:00) [common] start: 1.1.1 http-download (timeout 00:10:00) [common] downloading http://download.automotivelinux.org/AGL/release/ricefish/18.0.2/raspberrypi5/deploy/images/raspberrypi5/initramfs-netboot-image-raspberrypi5-20241028040434.ext4.gz saving as /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/initrd/initramfs-netboot-image-raspberrypi5-20241028040434.ext4 total size: 2153804 (2 MB) Using gunzip to decompress gz progress 1 % (0 MB) progress 6 % (0 MB) progress 12 % (0 MB) progress 18 % (0 MB) progress 24 % (0 MB) progress 30 % (0 MB) progress 36 % (0 MB) progress 41 % (0 MB) progress 47 % (0 MB) progress 53 % (1 MB) progress 59 % (1 MB) progress 65 % (1 MB) progress 71 % (1 MB) progress 76 % (1 MB) progress 82 % (1 MB) progress 88 % (1 MB) progress 94 % (1 MB) progress 100 % (2 MB) 2 MB downloaded in 0.94 s (2.18 MB/s) end: 1.1.1 http-download (duration 00:00:01) [common] case: http-download
case_id: 4089379
definition: lava
duration: 0.94
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 http://download.automotivelinux.org/AGL/release/ricefish/18.0.2/raspberrypi5/deploy/images/raspberrypi5/Image saving as /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/kernel/Image total size: 28887552 (27 MB) No compression specified progress 0 % (0 MB) progress 5 % (1 MB) progress 10 % (2 MB) progress 15 % (4 MB) progress 20 % (5 MB) progress 25 % (6 MB) progress 30 % (8 MB) progress 35 % (9 MB) progress 40 % (11 MB) progress 45 % (12 MB) progress 50 % (13 MB) progress 55 % (15 MB) progress 60 % (16 MB) progress 65 % (17 MB) progress 70 % (19 MB) progress 75 % (20 MB) progress 80 % (22 MB) progress 85 % (23 MB) progress 90 % (24 MB) progress 95 % (26 MB) progress 100 % (27 MB) 27 MB downloaded in 2.10 s (13.14 MB/s) end: 1.2.1 http-download (duration 00:00:02) [common] case: http-download
case_id: 4089379
definition: lava
duration: 2.10
extra: ...
level: 1.2.1
namespace: common
result: pass
end: 1.2 download-retry (duration 00:00:02) [common] start: 1.3 download-retry (timeout 00:09:57) [common] start: 1.3.1 http-download (timeout 00:09:57) [common] downloading http://download.automotivelinux.org/AGL/release/ricefish/18.0.2/raspberrypi5/deploy/images/raspberrypi5/bcm2712-rpi-5-b.dtb saving as /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/dtb/bcm2712-rpi-5-b.dtb total size: 78059 (0 MB) No compression specified progress 41 % (0 MB) progress 83 % (0 MB) progress 100 % (0 MB) 0 MB downloaded in 0.40 s (0.19 MB/s) end: 1.3.1 http-download (duration 00:00:00) [common] case: http-download
case_id: 4089379
definition: lava
duration: 0.40
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:57) [common] start: 1.4.1 http-download (timeout 00:09:57) [common] downloading http://download.automotivelinux.org/AGL/release/ricefish/18.0.2/raspberrypi5/deploy/images/raspberrypi5/agl-ivi-demo-qt-raspberrypi5-20241028040434.ext4.xz saving as /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/nbdroot/agl-ivi-demo-qt-raspberrypi5-20241028040434.ext4 total size: 493866112 (470 MB) Using unxz to decompress xz progress 0 % (0 MB) progress 5 % (23 MB) progress 10 % (47 MB) progress 15 % (70 MB) progress 20 % (94 MB) progress 25 % (117 MB) progress 30 % (141 MB) progress 35 % (164 MB) progress 40 % (188 MB) progress 45 % (211 MB) progress 50 % (235 MB) progress 55 % (259 MB) progress 60 % (282 MB) progress 65 % (306 MB) progress 70 % (329 MB) progress 75 % (353 MB) progress 80 % (376 MB) progress 85 % (400 MB) progress 90 % (423 MB) progress 95 % (447 MB) progress 100 % (470 MB) 470 MB downloaded in 45.61 s (10.33 MB/s) end: 1.4.1 http-download (duration 00:00:46) [common] case: http-download
case_id: 4089379
definition: lava
duration: 45.61
extra: ...
level: 1.4.1
namespace: common
result: pass
end: 1.4 download-retry (duration 00:00:46) [common] start: 1.5 lava-overlay (timeout 00:09:11) [common] [common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr makedir: /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin makedir: /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/tests makedir: /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/results Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-add-keys Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-add-sources Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-background-process-start Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-background-process-stop Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-common-functions Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-echo-ipv4 Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-install-packages Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-installed-packages Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-os-build Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-probe-channel Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-probe-ip Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-target-ip Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-target-mac Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-target-storage Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-test-case Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-test-event Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-test-feedback Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-test-raise Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-test-reference Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-test-runner Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-test-set Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-test-shell Updating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-install-packages (oe) Updating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/bin/lava-installed-packages (oe) Creating /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/environment LAVA metadata - LAVA_JOB_ID=37670 - LAVA_DISPATCHER_IP=192.168.66.1 start: 1.5.1 ssh-authorize (timeout 00:09:11) [common] end: 1.5.1 ssh-authorize (duration 00:00:00) [common] start: 1.5.2 lava-vland-overlay (timeout 00:09:11) [common] skipped lava-vland-overlay end: 1.5.2 lava-vland-overlay (duration 00:00:00) [common] start: 1.5.3 lava-multinode-overlay (timeout 00:09:11) [common] skipped lava-multinode-overlay end: 1.5.3 lava-multinode-overlay (duration 00:00:00) [common] start: 1.5.4 test-definition (timeout 00:09:11) [common] Loading test definitions start: 1.5.4.1 inline-repo-action (timeout 00:09:11) [common] Using /lava-37670 at stage 0 uuid=37670_1.5.4.1 testdef=None end: 1.5.4.1 inline-repo-action (duration 00:00:00) [common] start: 1.5.4.2 test-overlay (timeout 00:09:11) [common] end: 1.5.4.2 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4089383
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.2
namespace: common
result: pass
start: 1.5.4.3 test-install-overlay (timeout 00:09:11) [common] end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4089384
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.3
namespace: common
result: pass
start: 1.5.4.4 test-runscript-overlay (timeout 00:09:11) [common] runner path: /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/0/tests/0_dmesg test_uuid 37670_1.5.4.1 end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4089385
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.4
namespace: common
result: pass
start: 1.5.4.5 inline-repo-action (timeout 00:09:11) [common] Using /lava-37670 at stage 1 uuid=37670_1.5.4.5 testdef=None end: 1.5.4.5 inline-repo-action (duration 00:00:00) [common] start: 1.5.4.6 test-overlay (timeout 00:09:11) [common] end: 1.5.4.6 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4089383
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.6
namespace: common
result: pass
start: 1.5.4.7 test-install-overlay (timeout 00:09:11) [common] end: 1.5.4.7 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4089384
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.7
namespace: common
result: pass
start: 1.5.4.8 test-runscript-overlay (timeout 00:09:11) [common] runner path: /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/1/tests/1_bootrr test_uuid 37670_1.5.4.5 end: 1.5.4.8 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4089385
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.8
namespace: common
result: pass
Creating lava-test-runner.conf files Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/0 for stage 0 - 0_dmesg Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/37670/lava-overlay-hxpxx1lr/lava-37670/1 for stage 1 - 1_bootrr end: 1.5.4 test-definition (duration 00:00:00) [common] start: 1.5.5 compress-overlay (timeout 00:09:11) [common] end: 1.5.5 compress-overlay (duration 00:00:00) [common] start: 1.5.6 persistent-nfs-overlay (timeout 00:09:11) [common] end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common] end: 1.5 lava-overlay (duration 00:00:00) [common] start: 1.6 prepare-kernel (timeout 00:09:11) [common] start: 1.6.1 uboot-prepare-kernel (timeout 00:09:11) [common] end: 1.6.1 uboot-prepare-kernel (duration 00:00:00) [common] end: 1.6 prepare-kernel (duration 00:00:00) [common] start: 1.7 xnbd-server-deploy (timeout 00:09:11) [common] xnbd-server-deploy: starting nbd-server NBD-IP: 192.168.66.1, NBD-PORT: 61966, NBD-ROOT: 37670/nbd-deploy-1bgtg7tt/nbdroot/agl-ivi-demo-qt-raspberrypi5-20241028040434.ext4 nbd-server 61966 /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/nbdroot/agl-ivi-demo-qt-raspberrypi5-20241028040434.ext4 output: output: ** (process:411): WARNING **: 13:47:15.816: Specifying an export on the command line no longer uses the oldstyle protocol. output: xnbd-server-deploy: starting nbd-server done end: 1.7 xnbd-server-deploy (duration 00:00:00) [common] end: 1 nbd-deploy (duration 00:00:49) [common] start: 2 minimal-boot (timeout 00:09:11) [common] start: 2.1 connect-device (timeout 00:09:11) [common] [common] connect-device Connecting to device using 'telnet 127.0.0.1 63007' Setting prompt string to ['lava-test: # '] end: 2.1 connect-device (duration 00:00:00) [common] start: 2.2 reset-device (timeout 00:09:11) [common] start: 2.2.1 pdu-reboot (timeout 00:09:11) [common] Calling: 'upower.sh' '--atx' 'reset' '2' >> Accessing Gembird #0 USB device 002 >> Switched outlet 2 off >> Accessing Gembird #0 USB device 002 >> Switched outlet 2 on >> export LANG='C' >> export LC_ALL='C.UTF-8' >> export PATH='/usr/local/bin:/usr/local/sbin:/bin:/usr/bin:/usr/sbin:/sbin' >> export PWD='/' >> DEBUG: found /var/lib/lava/dispatcher/tmp/bcm2712-rpi-5-b.dtb >> DEBUG: BASETFTP=/var/lib/lava/dispatcher/tmp >> DEBUG: INITRD=/var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/initrd/initramfs-netboot-image-raspberrypi5-20241028040434.ext4 >> /var/lib/lava/dispatcher/tmp/initramfs-netboot-image-raspberrypi5-20241028040434.ext4 >> DEBUG: REL_INITRD=37670/nbd-deploy-1bgtg7tt/initrd/initramfs-netboot-image-raspberrypi5-20241028040434.ext4 /var/lib/lava/dispatcher/tmp/initramfs-netboot-image-raspberrypi5-20241028040434.ext4 >> DEBUG: IMAGE=/var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/kernel/Image >> /var/lib/lava/dispatcher/tmp/37671/tftp-deploy-6b44ad4o/kernel/Image >> /var/lib/lava/dispatcher/tmp/37672/tftp-deploy-2gk2b_se/kernel/Image >> /var/lib/lava/dispatcher/tmp/37669/tftp-deploy-xnnl6zzh/kernel/Image >> DEBUG: REL_IMAGE=37670/nbd-deploy-1bgtg7tt/kernel/Image /var/lib/lava/dispatcher/tmp/37671/tftp-deploy-6b44ad4o/kernel/Image /var/lib/lava/dispatcher/tmp/37672/tftp-deploy-2gk2b_se/kernel/Image /var/lib/lava/dispatcher/tmp/37669/tftp-deploy-xnnl6zzh/kernel/Image >> cp: '/var/lib/lava/dispatcher/tmp/initramfs-netboot-image-raspberrypi5-20241028040434.ext4' and '/var/lib/lava/dispatcher/tmp/initramfs-netboot-image-raspberrypi5-20241028040434.ext4' are the same file >> DEBUG: check LISTEN 0 10 0.0.0.0:61966 0.0.0.0:* users:(("nbd-server",pid=412,fd=3)) >> DEBUG: PID=412 >> NBDPORT=61966 >> >> enable_uart=1 >> kernel 37670/nbd-deploy-1bgtg7tt/kernel/Image /var/lib/lava/dispatcher/tmp/37671/tftp-deploy-6b44ad4o/kernel/Image /var/lib/lava/dispatcher/tmp/37672/tftp-deploy-2gk2b_se/kernel/Image /var/lib/lava/dispatcher/tmp/37669/tftp-deploy-xnnl6zzh/kernel/Image >> initramfs initramfs-netboot-image-raspberrypi5-20241028040434.ext4 >> >> cp: '/var/lib/lava/dispatcher/tmp/bcm2712-rpi-5-b.dtb' and '/var/lib/lava/dispatcher/tmp/bcm2712-rpi-5-b.dtb' are the same file >> DEBUG: found /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/dtb/bcm2712-rpi-5-b.dtb >> DEBUG: BASETFTP=/var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt >> DEBUG: INITRD=/var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/initrd/initramfs-netboot-image-raspberrypi5-20241028040434.ext4 >> DEBUG: REL_INITRD=37670/nbd-deploy-1bgtg7tt/initrd/initramfs-netboot-image-raspberrypi5-20241028040434.ext4 >> DEBUG: IMAGE=/var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/kernel/Image >> DEBUG: REL_IMAGE=37670/nbd-deploy-1bgtg7tt/kernel/Image >> DEBUG: check LISTEN 0 10 0.0.0.0:61966 0.0.0.0:* users:(("nbd-server",pid=412,fd=3)) >> DEBUG: PID=412 >> NBDPORT=61966 >> >> enable_uart=1 >> kernel 37670/nbd-deploy-1bgtg7tt/kernel/Image >> initramfs initramfs-netboot-image-raspberrypi5-20241028040434.ext4 >> Returned 0 in 7 seconds end: 2.2.1 pdu-reboot (duration 00:00:07) [common] case: pdu-reboot
case_id: 4089390
definition: lava
duration: 7.39
extra: ...
level: 2.2.1
namespace: common
result: pass
end: 2.2 reset-device (duration 00:00:07) [common] start: 2.3 auto-login-action (timeout 00:09:04) [common] Setting prompt string to ['Linux version [0-9]'] auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:20:00) Trying 127.0.0.1... Connected to 127.0.0.1. Escape character is '^]'. RPi: BOOTSYS release VERSION:5f2f71fa DATE: 2023/09/25 TIME: 11:44:03 BOOTMODE: 0x06 partition 0 build-ts BUILD_TIMESTAMP=1695638643 serial a18d1bdb boardrev d04170 stc 1605773 AON_RESET: 00000003 PM_RSTS 00001000 RP1_BOOT chip ID: 0x20001927 PM_RSTS: 0x00001000 part 00000000 reset_info 00000000 PMIC reset-event 00000000 rtc 00000001 alarm 00000000 enabled 0 uSD voltage 3.3V Initialising SDRAM 'Micron' 32Gb x2 total-size: 64 Gbit 4267 DDR 4267 1 0 64 152 RP1_BOOT chip ID: 0x20001927 RP1_BOOT chip ID: 0x20001927 RP1_BOOT: fw size 25968 PCI2 init PCI2 reset PCIe scan 00001de4:00000001 RP1_CHIP_INFO 20001927 RPi: BOOTLOADER release VERSION:5f2f71fa DATE: 2023/09/25 TIME: 11:44:03 BOOTMODE: 0x06 partition 0 build-ts BUILD_TIMESTAMP=1695638643 serial a18d1bdb boardrev d04170 stc 4573334 AON_RESET: 00000003 PM_RSTS 00001000 status USB_PD CONFIG 0 41 Boot mode: SD (01) order 24 SD HOST: 200000000 CTL0: 0x00800f00 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 SD HOST: 200000000 CTL0: 0x00800f00 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 EMMC SD retry 1 oc 0 SD HOST: 200000000 CTL0: 0x00800000 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 SD retry 2 oc 0 SD HOST: 200000000 CTL0: 0x00800000 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 SDV1 SD CMD: 0x371a0010 (55) 0x0 0x1fff0001 USB-PD: src-cap PDO object1 0x0a11912c Current 3000 mA Voltage 5000 mV USB-PD: src-cap PDO object2 0x0012d12c Current 3000 mA Voltage 9000 mV USB-PD: src-cap PDO object3 0x0014b12c Current 3000 mA Voltage 15000 mV USB-PD: src-cap PDO object4 0x00164145 Current 3250 mA Voltage 20000 mV Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001) Retry SD 1 SD HOST: 200000000 CTL0: 0x00800000 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 SD HOST: 200000000 CTL0: 0x00800f00 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 EMMC SD retry 1 oc 0 SD HOST: 200000000 CTL0: 0x00800000 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 SD retry 2 oc 0 SD HOST: 200000000 CTL0: 0x00800000 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 SDV1 SD CMD: 0x371a0010 (55) 0x0 0x1fff0001 Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001) Boot mode: USB-MSD (04) order 2 XHCI-STOP xHC0 ver: 272 HCS: 03000440 140000f1 07ff000a HCC: 0240fe6d USBSTS 1 xHC0 ver: 272 HCS: 03000440 140000f1 07ff000a HCC: 0240fe6d xHC0 ports 3 slots 64 intrs 4 XHCI-STOP xHC1 ver: 272 HCS: 03000440 140000f1 07ff000a HCC: 0240fe6d USBSTS 1 xHC1 ver: 272 HCS: 03000440 140000f1 07ff000a HCC: 0240fe6d xHC1 ports 3 slots 64 intrs 4 XHCI-STOP xHC0 ver: 272 HCS: 03000440 140000f1 07ff000a HCC: 0240fe6d USBSTS 0 XHCI-STOP xHC1 ver: 272 HCS: 03000440 140000f1 07ff000a HCC: 0240fe6d USBSTS 0 USB MSD stopped. Timeout: 25 seconds Boot mode: NETWORK (02) order 0 NETWORK: d8:3a:dd:e5:72:37 wait for link TFTP: 192.168.68.1 LINK STATUS: speed: 1000 full duplex Link ready RX: 0 IP: 0 IPV4: 0 MAC: 0 UDP: 0 UDP RECV: 0 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 DHCP src: 70:70:fc:05:68:c7 192.168.66.1 YI_ADDR 192.168.68.231 SI_ADDR 192.168.68.1 OPTIONS:- op: 53 len: 1 DHCP recv OFFER (2) expect OFFER op: 54 len: 4 192.168.66.1 op: 51 len: 4 op: 1 len: 4 255.255.255.0 op: 3 len: 4 192.168.68.1 op: 43 len: 17 DHCP src: 70:70:fc:05:68:c7 192.168.66.1 YI_ADDR 192.168.68.231 SI_ADDR 192.168.68.1 OPTIONS:- op: 53 len: 1 DHCP recv ACK (5) expect ACK op: 54 len: 4 192.168.66.1 op: 51 len: 4 op: 1 len: 4 255.255.255.0 op: 3 len: 4 192.168.68.1 op: 6 len: 4 10.1.1.1 op: 150 len: 4 op: 43 len: 17 op: 15 len: 11 NET 192.168.68.231 255.255.255.0 gw 0.0.0.0 tftp 192.168.68.1 ARP 192.168.68.1 70:70:fc:05:68:c7 NET 192.168.68.231 255.255.255.0 gw 0.0.0.0 tftp 192.168.68.1 RX: 3 IP: 0 IPV4: 2 MAC: 2 UDP: 2 UDP RECV: 2 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 TFTP_GET: 70:70:fc:05:68:c7 192.168.68.1 a18d1bdb/config.txt RX: 3 IP: 0 IPV4: 2 MAC: 2 UDP: 2 UDP RECV: 2 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 TFTP 1: File not found RX: 4 IP: 0 IPV4: 3 MAC: 3 UDP: 3 UDP RECV: 3 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 BMD \"a18d1bdb/config.txt\" not found TFTP_GET: 70:70:fc:05:68:c7 192.168.68.1 config.txt RX: 4 IP: 0 IPV4: 3 MAC: 3 UDP: 3 UDP RECV: 3 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 TFTP: complete 137 RX: 6 IP: 0 IPV4: 5 MAC: 5 UDP: 5 UDP RECV: 5 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 Read config.txt bytes 137 hnd 0x0 TFTP_GET: 70:70:fc:05:68:c7 192.168.68.1 pieeprom.sig RX: 6 IP: 0 IPV4: 5 MAC: 5 UDP: 5 UDP RECV: 5 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 TFTP 1: File not found RX: 7 IP: 0 IPV4: 6 MAC: 6 UDP: 6 UDP RECV: 6 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 Read pieeprom.upd failed usb_max_current_enable default 0 max-current 3000 TFTP_GET: 70:70:fc:05:68:c7 192.168.68.1 bcm2712-rpi-5-b.dtb RX: 7 IP: 0 IPV4: 6 MAC: 6 UDP: 6 UDP RECV: 6 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 TFTP: complete 78059 RX: 62 IP: 0 IPV4: 61 MAC: 61 UDP: 61 UDP RECV: 61 IP_CSUM_ERR: 0 UDP_CSUM_ERR: 0 Read bcm2712-rpi-5-b.dtb bytes 78059 hnd 0x0 dt-match: compatible: raspberrypi,5-model-b match: brcm,bcm2712 dt-match: compatible: brcm,bcm2712 match: brcm,bcm2712 PM_RSTS 00001000 Selecting USB low current limit NOTICE: BL31: v2.6(release):v2.6-239-g2a9ede0bd NOTICE: BL31: Built : 14:26:57, Jun 22 2023 [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x414fd0b1] [ 0.000000] Linux version 6.6.22-v8-16k (oe-user@oe-host) (aarch64-agl-linux-gcc (GCC) 13.3.0, GNU ld (GNU Binutils) 2.42.0.20240716) #1 SMP PREEMPT Thu Oct 24 14:13:42 UTC 2024 [ 0.000000] KASLR enabled [ 0.000000] random: crng init done start: 2.3.1 login-action (timeout 00:07:58) [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'# Waiting for the login prompt 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', 'raspberrypi5:~#', '/ #', 'login:', 'Login incorrect'] [login-action] Waiting for messages, (timeout 00:07:58) [ 0.000000] Machine model: Raspberry Pi 5 Model B Rev 1.0 [ 0.000000] efi: UEFI not found. [ 0.000000] Reserved memory: created CMA memory pool at 0x0000000002000000, size 64 MiB [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool [ 0.000000] OF: reserved mem: 0x0000000002000000..0x0000000005ffffff (65536 KiB) map reusable linux,cma [ 0.000000] OF: reserved mem: 0x0000000000000000..0x000000000007ffff (512 KiB) nomap non-reusable atf@0 [ 0.000000] OF: reserved mem: 0x000000003fd16180..0x000000003fd1627a (0 KiB) nomap non-reusable nvram@0 [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000000000-0x00000000ffffffff] [ 0.000000] DMA32 empty [ 0.000000] Normal [mem 0x0000000100000000-0x00000001ffffffff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000000000-0x000000000007ffff] [ 0.000000] node 0: [mem 0x0000000000080000-0x000000003fbfffff] [ 0.000000] node 0: [mem 0x0000000040000000-0x00000001ffffffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] [ 0.000000] On node 0, zone DMA: 256 pages in unavailable ranges [ 0.000000] psci: probing for conduit method from DT. [ 0.000000] psci: PSCIv1.1 detected in firmware. [ 0.000000] psci: Using standard PSCI v0.2 function IDs [ 0.000000] psci: MIGRATE_INFO_TYPE not supported. [ 0.000000] psci: SMC Calling Convention v1.2 [ 0.000000] percpu: Embedded 14 pages/cpu s184936 r8192 d36248 u229376 [ 0.000000] Detected PIPT I-cache on CPU0 [ 0.000000] CPU features: detected: Virtualization Host Extensions [ 0.000000] CPU features: detected: Hardware dirty bit management [ 0.000000] CPU features: detected: Spectre-v4 [ 0.000000] CPU features: detected: Spectre-BHB [ 0.000000] CPU features: kernel page table isolation forced ON by KASLR [ 0.000000] CPU features: detected: Kernel page table isolation (KPTI) [ 0.000000] alternatives: applying boot alternatives [ 0.000000] Kernel command line: reboot=w coherent_pool=1M 8250.nr_uarts=1 pci=pcie_bus_safe snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbdepth=16 bcm2708_fb.fbswap=1 smsc95xx.macaddr=D8:3A:DD:E5:72:37 vc_mem.mem_base=0x3fc00000 vc_mem.mem_size=0x40000000 console=ttyAMA10,115200n8 rw nbd.server=192.168.68.1 nbd.port=61966 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 ip=dhcp verbose earlyprintk systemd.log_color=false rw [ 0.000000] Unknown kernel command line parameters \"verbose earlyprintk\", will be passed to user space. [ 0.000000] Dentry cache hash table entries: 1048576 (order: 9, 8388608 bytes, linear) [ 0.000000] Inode-cache hash table entries: 524288 (order: 8, 4194304 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 521984 [ 0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off [ 0.000000] software IO TLB: area num 4. [ 0.000000] software IO TLB: mapped [mem 0x00000000fbffc000-0x00000000ffffc000] (64MB) [ 0.000000] Memory: 8159792K/8384512K available (15104K kernel code, 2290K rwdata, 5024K rodata, 5568K init, 1247K bss, 159184K reserved, 65536K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] ftrace: allocating 49047 entries in 48 pages [ 0.000000] ftrace: allocated 48 pages with 2 groups [ 0.000000] trace event string verifier disabled [ 0.000000] rcu: Preemptible hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4. [ 0.000000] Trampoline variant of Tasks RCU enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 [ 0.000000] Root IRQ handler: gic_handle_irq [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention. [ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns [ 0.000000] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns [ 0.000169] Console: colour dummy device 80x25 [ 0.000186] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000) [ 0.000190] pid_max: default: 32768 minimum: 301 [ 0.000214] LSM: initializing lsm=capability,integrity [ 0.000278] Mount-cache hash table entries: 16384 (order: 3, 131072 bytes, linear) [ 0.000301] Mountpoint-cache hash table entries: 16384 (order: 3, 131072 bytes, linear) [ 0.000640] cgroup: Disabling memory control group subsystem [ 0.001024] RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. [ 0.001045] RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. [ 0.001066] RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. [ 0.001121] rcu: Hierarchical SRCU implementation. [ 0.001123] rcu: Max phase no-delay instances is 1000. [ 0.001701] EFI services will not be available. [ 0.001758] smp: Bringing up secondary CPUs ... [ 0.001905] Detected PIPT I-cache on CPU1 [ 0.001947] CPU1: Booted secondary processor 0x0000000100 [0x414fd0b1] [ 0.002118] Detected PIPT I-cache on CPU2 [ 0.002152] CPU2: Booted secondary processor 0x0000000200 [0x414fd0b1] [ 0.002309] Detected PIPT I-cache on CPU3 [ 0.002339] CPU3: Booted secondary processor 0x0000000300 [0x414fd0b1] [ 0.002368] smp: Brought up 1 node, 4 CPUs [ 0.002371] SMP: Total of 4 processors activated. [ 0.002373] CPU features: detected: 32-bit EL0 Support [ 0.002375] CPU features: detected: Data cache clean to the PoU not required for I/D coherence [ 0.002376] CPU features: detected: Common not Private translations [ 0.002378] CPU features: detected: CRC32 instructions [ 0.002380] CPU features: detected: RCpc load-acquire (LDAPR) [ 0.002382] CPU features: detected: LSE atomic instructions [ 0.002384] CPU features: detected: Privileged Access Never [ 0.002385] CPU features: detected: RAS Extension Support [ 0.002387] CPU features: detected: Speculative Store Bypassing Safe (SSBS) [ 0.002419] CPU: All CPU(s) started at EL2 [ 0.002420] alternatives: applying system-wide alternatives [ 0.004246] devtmpfs: initialized [ 0.007026] Enabled cp15_barrier support [ 0.007032] Enabled setend support [ 0.007131] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns [ 0.007136] futex hash table entries: 1024 (order: 2, 65536 bytes, linear) [ 0.007398] pinctrl core: initialized pinctrl subsystem [ 0.007518] DMI not present or invalid. [ 0.007669] NET: Registered PF_NETLINK/PF_ROUTE protocol family [ 0.008224] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations [ 0.008268] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.008314] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.008329] audit: initializing netlink subsys (disabled) [ 0.008378] audit: type=2000 audit(0.008:1): state=initialized audit_enabled=0 res=1 [ 0.008500] thermal_sys: Registered thermal governor 'step_wise' [ 0.008511] cpuidle: using governor menu [ 0.008585] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers. [ 0.008612] ASID allocator initialised with 32768 entries [ 0.008918] Serial: AMBA PL011 UART driver [ 0.009686] bcm2835-mbox 107c013880.mailbox: mailbox enabled [ 0.009876] 107d001000.serial: ttyAMA10 at MMIO 0x107d001000 (irq = 15, base_baud = 0) is a PL011 rev2 [ 0.009886] printk: console [ttyAMA10] enabled [ 0.766719] raspberrypi-firmware soc:firmware: Attached to firmware from 2023-09-25T10:44:03, variant start_cd [ 0.780770] raspberrypi-firmware soc:firmware: Firmware hash is 5f2f71fa00000000000000000000000000000000 [ 0.796434] Modules: 2G module region forced by RANDOMIZE_MODULE_REGION_FULL [ 0.803514] Modules: 0 pages in range for non-PLT usage [ 0.803515] Modules: 129224 pages in range for PLT usage [ 0.813313] bcm2835-dma 1000010000.dma: DMA legacy API manager, dmachans=0x1 [ 0.826099] iommu: Default domain type: Translated [ 0.830910] iommu: DMA domain TLB invalidation policy: strict mode [ 0.837214] SCSI subsystem initialized [ 0.841004] usbcore: registered new interface driver usbfs [ 0.846513] usbcore: registered new interface driver hub [ 0.851850] usbcore: registered new device driver usb [ 0.857012] pps_core: LinuxPPS API ver. 1 registered [ 0.861993] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <[email protected]> [ 0.871163] PTP clock support registered [ 0.875144] Advanced Linux Sound Architecture Driver Initialized. [ 0.881494] vgaarb: loaded [ 0.884316] clocksource: Switched to clocksource arch_sys_counter [ 0.890549] VFS: Disk quotas dquot_6.6.0 [ 0.900325] VFS: Dquot-cache hash table entries: 2048 (order 0, 16384 bytes) [ 0.907426] FS-Cache: Loaded [ 0.910342] CacheFiles: Loaded [ 0.914900] NET: Registered PF_INET protocol family [ 0.919946] IP idents hash table entries: 131072 (order: 6, 1048576 bytes, linear) [ 0.929916] tcp_listen_portaddr_hash hash table entries: 4096 (order: 2, 65536 bytes, linear) [ 0.938528] Table-perturb hash table entries: 65536 (order: 4, 262144 bytes, linear) [ 0.946304] TCP established hash table entries: 65536 (order: 5, 524288 bytes, linear) [ 0.954520] TCP bind hash table entries: 65536 (order: 7, 2097152 bytes, linear) [ 0.963647] TCP: Hash tables configured (established 65536 bind 65536) [ 0.970340] MPTCP token hash table entries: 8192 (order: 3, 196608 bytes, linear) [ 0.977980] UDP hash table entries: 4096 (order: 3, 131072 bytes, linear) [ 0.984890] UDP-Lite hash table entries: 4096 (order: 3, 131072 bytes, linear) [ 0.992283] NET: Registered PF_UNIX/PF_LOCAL protocol family [ 0.998091] RPC: Registered named UNIX socket transport module. [ 1.004033] RPC: Registered udp transport module. [ 1.008749] RPC: Registered tcp transport module. [ 1.013468] RPC: Registered tcp-with-tls transport module. [ 1.018970] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.025440] PCI: CLS 0 bytes, default 64 [ 1.029531] Trying to unpack rootfs image as initramfs... [ 1.034984] rootfs image is not initramfs (invalid magic at start of compressed archive); looks like an initrd [ 1.045065] kvm [1]: IPA Size Limit: 40 bits [ 1.049434] kvm [1]: GICV region size/alignment is unsafe, using trapping (reduced performance) [ 1.058315] kvm [1]: vgic interrupt IRQ9 [ 1.062360] kvm [1]: VHE mode initialized successfully [ 1.065628] Freeing initrd memory: 12288K [ 1.098432] Initialise system trusted keyrings [ 1.102959] workingset: timestamp_bits=46 max_order=19 bucket_order=0 [ 1.109440] zbud: loaded [ 1.112145] NFS: Registering the id_resolver key type [ 1.117218] Key type id_resolver registered [ 1.121412] Key type id_legacy registered [ 1.125435] nfs4filelayout_init: NFSv4 File Layout Driver Registering... [ 1.132161] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... [ 1.139629] F2FS not supported on PAGE_SIZE(16384) != 4096 [ 1.145192] NET: Registered PF_ALG protocol family [ 1.150000] Key type asymmetric registered [ 1.154106] Asymmetric key parser 'x509' registered [ 1.159013] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245) [ 1.166471] io scheduler mq-deadline registered [ 1.171016] io scheduler kyber registered [ 1.175042] io scheduler bfq registered [ 1.179109] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d503000, parent irq: 27) [ 1.186859] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d508380, parent irq: 28) [ 1.194596] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d508400, parent irq: 29) [ 1.202342] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d517b00, parent irq: 30) [ 1.212094] bcm2708_fb soc:fb: Unable to determine number of FBs. Disabling driver. [ 1.219794] bcm2708_fb: probe of soc:fb failed with error -2 [ 1.256701] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled [ 1.263391] 107d50c000.serial: ttyS0 at MMIO 0x107d50c000 (irq = 32, base_baud = 6000000) is a Broadcom BCM7271 UART [ 1.274015] serial serial0: tty port ttyS0 registered [ 1.279361] iproc-rng200 107d208000.rng: hwrng registered [ 1.284826] vc-mem: phys_addr:0x00000000 mem_base=0x3fc00000 mem_size:0x40000000(1024 MiB) [ 1.293354] bcm2712-iommu-cache 1000005b00.iommuc: bcm2712_iommu_cache_probe [ 1.302824] brd: module loaded [ 1.307204] loop: module loaded [ 1.315659] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver [ 1.323105] Loading iSCSI transport class v2.0-870. [ 1.328837] usbcore: registered new device driver r8152-cfgselector [ 1.335134] usbcore: registered new interface driver r8152 [ 1.340644] usbcore: registered new interface driver lan78xx [ 1.346384] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) [ 1.352307] usbcore: registered new interface driver uas [ 1.357647] usbcore: registered new interface driver usb-storage [ 1.363700] usbcore: registered new interface driver usbserial_generic [ 1.370258] usbserial: USB Serial support registered for generic [ 1.376290] usbcore: registered new interface driver cp210x [ 1.381884] usbserial: USB Serial support registered for cp210x [ 1.387911] mousedev: PS/2 mouse device common for all mice [ 1.401304] rpi-rtc soc:rpi_rtc: registered as rtc0 [ 1.407661] rpi-rtc soc:rpi_rtc: setting system clock to 1970-01-01T00:01:08 UTC (68) [ 1.415572] usbcore: registered new interface driver i2c-tiny-usb [ 1.421985] bcm2835-wdt bcm2835-wdt: Poweroff handler already present! [ 1.428540] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer [ 1.437368] sdhci: Secure Digital Host Controller Interface driver [ 1.443577] sdhci: Copyright(c) Pierre Ossman [ 1.447968] sdhci-pltfm: SDHCI platform and OF driver helper [ 1.453777] ledtrig-cpu: registered to indicate activity on CPUs [ 1.459828] SMCCC: SOC_ID: ARCH_SOC_ID not implemented, skipping .... [ 1.466298] hid: raw HID events driver (C) Jiri Kosina [ 1.471480] usbcore: registered new interface driver usbhid [ 1.477070] usbhid: USB HID core driver [ 1.481118] hw perfevents: enabled with armv8_cortex_a76 PMU driver, 7 counters available [ 1.489421] usbcore: registered new interface driver snd-usb-audio [ 1.495726] NET: Registered PF_PACKET protocol family [ 1.500814] Key type dns_resolver registered [ 1.508475] registered taskstats version 1 [ 1.512632] Loading compiled-in X.509 certificates [ 1.519152] Key type .fscrypt registered [ 1.523085] Key type fscrypt-provisioning registered [ 1.528637] brcm-pcie 1000120000.pcie: host bridge /axi/pcie@120000 ranges: [ 1.535893] brcm-pcie 1000120000.pcie: No bus range found for /axi/pcie@120000, using [bus 00-ff] [ 1.544984] brcm-pcie 1000120000.pcie: MEM 0x1f00000000..0x1ffffffffb -> 0x0000000000 [ 1.553284] brcm-pcie 1000120000.pcie: MEM 0x1c00000000..0x1effffffff -> 0x0400000000 [ 1.561583] brcm-pcie 1000120000.pcie: IB MEM 0x1f00000000..0x1f003fffff -> 0x0000000000 [ 1.569880] brcm-pcie 1000120000.pcie: IB MEM 0x0000000000..0x0fffffffff -> 0x1000000000 [ 1.579349] brcm-pcie 1000120000.pcie: Forcing gen 2 [ 1.584566] brcm-pcie 1000120000.pcie: PCI host bridge to bus 0000:00 [ 1.591030] pci_bus 0000:00: root bus resource [bus 00-ff] [ 1.596535] pci_bus 0000:00: root bus resource [mem 0x1f00000000-0x1ffffffffb] (bus address [0x00000000-0xfffffffb]) [ 1.607104] pci_bus 0000:00: root bus resource [mem 0x1c00000000-0x1effffffff pref] (bus address [0x400000000-0x6ffffffff]) [ 1.618289] pci 0000:00:00.0: [14e4:2712] type 01 class 0x060400 [ 1.624335] pci 0000:00:00.0: PME# supported from D0 D3hot [ 1.630404] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring [ 1.744318] brcm-pcie 1000120000.pcie: link up, 5.0 GT/s PCIe x4 (!SSC) [ 1.750971] pci 0000:01:00.0: [1de4:0001] type 00 class 0x020000 [ 1.757008] pci 0000:01:00.0: reg 0x10: [mem 0xffffc000-0xffffffff] [ 1.763300] pci 0000:01:00.0: reg 0x14: [mem 0xffc00000-0xffffffff] [ 1.769592] pci 0000:01:00.0: reg 0x18: [mem 0xffff0000-0xffffffff] [ 1.775939] pci 0000:01:00.0: supports D1 [ 1.779957] pci 0000:01:00.0: PME# supported from D0 D1 D3hot D3cold [ 1.796322] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01 [ 1.802964] pci 0000:00:00.0: BAR 8: assigned [mem 0x1f00000000-0x1f005fffff] [ 1.810127] pci 0000:01:00.0: BAR 1: assigned [mem 0x1f00000000-0x1f003fffff] [ 1.817289] pci 0000:01:00.0: BAR 2: assigned [mem 0x1f00400000-0x1f0040ffff] [ 1.824452] pci 0000:01:00.0: BAR 0: assigned [mem 0x1f00410000-0x1f00413fff] [ 1.831614] pci 0000:00:00.0: PCI bridge to [bus 01] [ 1.836593] pci 0000:00:00.0: bridge window [mem 0x1f00000000-0x1f005fffff] [ 1.843755] pci 0000:00:00.0: Max Payload Size set to 256/ 512 (was 128), Max Read Rq 512 [ 1.852231] pci 0000:01:00.0: Max Payload Size set to 256/ 256 (was 128), Max Read Rq 512 [ 1.860751] pcieport 0000:00:00.0: enabling device (0000 -> 0002) [ 1.866893] pcieport 0000:00:00.0: PME: Signaling with IRQ 37 [ 1.872696] pcieport 0000:00:00.0: AER: enabled with IRQ 37 [ 1.878337] rp1 0000:01:00.0: bar0 len 0x4000, start 0x1f00410000, end 0x1f00413fff, flags, 0x40200 [ 1.887420] rp1 0000:01:00.0: bar1 len 0x400000, start 0x1f00000000, end 0x1f003fffff, flags, 0x40200 [ 1.896681] rp1 0000:01:00.0: enabling device (0000 -> 0002) [ 1.903083] rp1 0000:01:00.0: chip_id 0x20001927 [ 1.930309] macb 1f00100000.ethernet eth0: Cadence GEM rev 0x00070109 at 0x1f00100000 irq 105 (d8:3a:dd:e5:72:37) [ 1.943579] dw_axi_dmac_platform 1f00188000.dma: DesignWare AXI DMA Controller, 8 channels [ 1.952084] xhci-hcd xhci-hcd.0: xHCI Host Controller [ 1.957157] xhci-hcd xhci-hcd.0: new USB bus registered, assigned bus number 1 [ 1.964840] xhci-hcd xhci-hcd.0: hcc params 0x0240fe6d hci version 0x110 quirks 0x0000008000000810 [ 1.973838] xhci-hcd xhci-hcd.0: irq 130, io mem 0x1f00200000 [ 1.979664] xhci-hcd xhci-hcd.0: xHCI Host Controller [ 1.984731] xhci-hcd xhci-hcd.0: new USB bus registered, assigned bus number 2 [ 1.991981] xhci-hcd xhci-hcd.0: Host supports USB 3.0 SuperSpeed [ 1.998129] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06 [ 2.006427] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 2.013679] usb usb1: Product: xHCI Host Controller [ 2.018570] usb usb1: Manufacturer: Linux 6.6.22-v8-16k xhci-hcd [ 2.024596] usb usb1: SerialNumber: xhci-hcd.0 [ 2.029139] hub 1-0:1.0: USB hub found [ 2.032907] hub 1-0:1.0: 2 ports detected [ 2.037017] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.06 [ 2.045314] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 2.052563] usb usb2: Product: xHCI Host Controller [ 2.057454] usb usb2: Manufacturer: Linux 6.6.22-v8-16k xhci-hcd [ 2.063548] usb usb2: SerialNumber: xhci-hcd.0 [ 2.068077] hub 2-0:1.0: USB hub found [ 2.071842] hub 2-0:1.0: 1 port detected [ 2.075969] xhci-hcd xhci-hcd.1: xHCI Host Controller [ 2.081148] xhci-hcd xhci-hcd.1: new USB bus registered, assigned bus number 3 [ 2.088826] xhci-hcd xhci-hcd.1: hcc params 0x0240fe6d hci version 0x110 quirks 0x0000008000000810 [ 2.097922] xhci-hcd xhci-hcd.1: irq 135, io mem 0x1f00300000 [ 2.103740] xhci-hcd xhci-hcd.1: xHCI Host Controller [ 2.108807] xhci-hcd xhci-hcd.1: new USB bus registered, assigned bus number 4 [ 2.116152] xhci-hcd xhci-hcd.1: Host supports USB 3.0 SuperSpeed [ 2.122291] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06 [ 2.130683] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 2.137931] usb usb3: Product: xHCI Host Controller [ 2.142821] usb usb3: Manufacturer: Linux 6.6.22-v8-16k xhci-hcd [ 2.148943] usb usb3: SerialNumber: xhci-hcd.1 [ 2.153458] hub 3-0:1.0: USB hub found [ 2.157225] hub 3-0:1.0: 2 ports detected [ 2.161328] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.06 [ 2.169723] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 2.176992] usb usb4: Product: xHCI Host Controller [ 2.181884] usb usb4: Manufacturer: Linux 6.6.22-v8-16k xhci-hcd [ 2.188057] usb usb4: SerialNumber: xhci-hcd.1 [ 2.192580] hub 4-0:1.0: USB hub found [ 2.196346] hub 4-0:1.0: 1 port detected [ 2.200925] bcm2712-iommu 1000005100.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774 [ 2.209193] platform 1000800000.codec: bcm2712_iommu_probe_device: MMU 1000005100.iommu [ 2.217426] platform 1000800000.codec: bcm2712_iommu_device_group: MMU 1000005100.iommu [ 2.225483] platform 1000800000.codec: Adding to iommu group 0 [ 2.231340] platform 1000880000.pisp_be: bcm2712_iommu_probe_device: MMU 1000005100.iommu [ 2.239736] platform 1000880000.pisp_be: bcm2712_iommu_device_group: MMU 1000005100.iommu [ 2.247957] platform 1000880000.pisp_be: Adding to iommu group 0 [ 2.254185] platform 1000800000.codec: bcm2712_iommu_attach_dev: MMU 1000005100.iommu [ 2.262044] platform 1000880000.pisp_be: bcm2712_iommu_attach_dev: MMU 1000005100.iommu [ 2.270265] bcm2712-iommu 1000005100.iommu: bcm2712_iommu_probe: Success [ 2.277263] bcm2712-iommu 1000005200.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774 [ 2.285711] bcm2712-iommu 1000005200.iommu: bcm2712_iommu_probe: Success [ 2.292674] bcm2712-iommu 1000005280.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774 [ 2.301131] bcm2712-iommu 1000005280.iommu: bcm2712_iommu_probe: Success [ 2.308328] sdhci-brcmstb 1000fff000.mmc: Got CD GPIO [ 2.308354] mmc1: CQHCI version 5.10 [ 2.313471] mmc0: CQHCI version 5.10 [ 2.317232] of_cfs_init [ 2.323038] of_cfs_init: OK [ 2.356615] mmc0: SDHCI controller on 1000fff000.mmc [1000fff000.mmc] using ADMA 64-bit [ 2.508859] mmc1: SDHCI controller on 1001100000.mmc [1001100000.mmc] using ADMA 64-bit [ 2.526286] macb 1f00100000.ethernet eth0: PHY [1f00100000.ethernet-ffffffff:01] driver [Broadcom BCM54213PE] (irq=POLL) [ 2.537206] macb 1f00100000.ethernet eth0: configuring for phy/rgmii-id link mode [ 2.547413] pps pps0: new PPS source ptp0 [ 2.549342] mmc1: new ultra high speed DDR50 SDIO card at address 0001 [ 2.558019] macb 1f00100000.ethernet: gem-ptp-timer ptp clock registered. [ 5.605444] macb 1f00100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off [ 5.632317] Sending DHCP requests ., OK [ 5.656169] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.68.231 [ 5.664121] IP-Config: Complete: [ 5.667354] device=eth0, hwaddr=d8:3a:dd:e5:72:37, ipaddr=192.168.68.231, mask=255.255.255.0, gw=192.168.68.1 [ 5.677747] host=192.168.68.231, domain=example.org, nis-domain=(none) [ 5.684734] bootserver=192.168.68.1, rootserver=192.168.68.1, rootpath= [ 5.684736] nameserver0=10.1.1.1 [ 5.695572] clk: Disabling unused clocks [ 5.708863] ALSA device list: [ 5.711835] No soundcards found. [ 5.715649] uart-pl011 107d001000.serial: no DMA platform data [ 5.721516] Waiting 7 sec before mounting root device... [ 12.836343] RAMDISK: ext2 filesystem found at block 0 [ 12.841414] RAMDISK: Loading 12288KiB [1 disk] into ram disk... |/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\ [ 12.851368] |/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\done. [ 13.008068] EXT4-fs (ram0): mounted filesystem d291e3c8-a47c-4bba-b248-a917c9104949 r/w with ordered data mode. Quota mode: none. [ 13.019804] VFS: Mounted root (ext4 filesystem) on device 1:0. [ 13.025679] devtmpfs: mounted [ 13.032091] Freeing unused kernel memory: 5568K [ 13.040387] Run /sbin/init as init process ________________________________________________________________________________ ___ ________ _ __ __ __ __ / | / ____/ / / | / /__ / /_/ /_ ____ ____ / /_ / /| |/ / __/ / ______ / |/ / _ \/ __/ __ \/ __ \/ __ \/ __/ / ___ / /_/ / /___ /_____/ / /| / __/ /_/ /_/ / /_/ / /_/ / /_ /_/ |_\____/_____/ /_/ |_/\___/\__/_.___/\____/\____/\__/ ________________________________________________________________________________ /sbin/init[1]: starting initrd script /sbin/init[1]: mounting FS: proc /proc /sb[ 13.100645] nbd0: detected capacity change from 0 to 8962048 in/init[1]: mounting FS: sysfs /sys /sbin/init[1]: mounting FS: devtmpfs /dev /sbin/init[1]: /dev (devtmpfs) already mounted /sbin/init[1]: mounting FS: devpts /dev/pts /sbin/init[1]: mounting FS: tmpfs /dev/shm /sbin/init[1]: mounting FS: tmpfs /tmp /sbin/init[1]: mounting FS: tmpfs /run /sbin/init[1]: NBD parameters: device /dev/nbd0, server 192.168.68.1:61966 /sbin/init[1]: Starting NBD client /sbin/init[1]: NBD client successfully started [ 14.219810] EXT4-fs (nbd0): mounted filesystem 47966b53-c54b-46c5-a736-dd34e4b9c216 r/w with ordered data mode. Quota mode: none. /sbin/init[1]: Moving /dev to new rootfs /sbin/init[1]: Moving /proc to new rootfs /sbin/init[1]: Moving /sys to new rootfs /sbin/init[1]: Moving /tmp to new rootfs /sbin/init[1]: Moving /run to new rootfs /sbin/init[1]: Switching to new rootfs /sbin/init[1]: find_active_interface: first active interface is eth0 /sbin/init[1]: Adjusting Connman command line. Will be: 'connmand -r -n -I eth0,enp2s0,enp3s0,end0,enp0s2,enp0s1 ' /sbin/init[1]: Unmounting /tmp and /run /sbin/init[1]: Exec'ing systemd ________________________________________________________________________________ ___ ________ ____ __ _ / | / ____/ / / __ )____ ____ / /_(_)___ ____ _ / /| |/ / __/ / / __ / __ \/ __ \/ __/ / __ \/ __ `/ / ___ / /_/ / /___ / /_/ / /_/ / /_/ / /_/ / / / / /_/ / _ _ _ /_/ |_\____/_____/ /_____/\____/\____/\__/_/_/ /_/\__, / (_) (_) (_) _____________________________________________________/____/_____________________ [ 15.438164] systemd[1]: System time before build time, advancing clock. [ 15.601649] NET: Registered PF_INET6 protocol family [ 15.607120] Segment Routing with IPv6 [ 15.610806] In-situ OAM (IOAM) with IPv6 [ 15.725460] systemd[1]: systemd 255.4^ running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA -SMACK +SECCOMP -GCRYPT -GNUTLS -OPENSSL +ACL +BLKID -CURL -ELFUTILS -FIDO2 -IDN2 -IDN +IPTC +KMOD -LIBCRYPTSETUP +LIBFDISK -PCRE2 -PWQUALITY -P11KIT -QRENCODE -TPM2 -BZIP2 -LZ4 -XZ -ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified) [ 15.757439] systemd[1]: Detected architecture arm64. Welcome to Automotive Grade Linux 18.0.2 (ricefish)! [ 15.796308] systemd[1]: Hostname set to <raspberrypi5>. [ 15.825756] systemd[1]: Initializing machine ID from random generator. [ 16.367050] systemd[1]: Queued start job for default target Graphical Interface. [ 16.413119] systemd[1]: Created slice Slice /system/getty. [ OK ] Created slice Slice /system/getty. [ 16.432640] systemd[1]: Created slice Slice /system/modprobe. [ OK ] Created slice Slice /system/modprobe. [ 16.452609] systemd[1]: Created slice Slice /system/serial-getty. [ OK ] Created slice Slice /system/serial-getty. [ 16.472615] systemd[1]: Created slice Slice /system/wireplumber. [ OK ] Created slice Slice /system/wireplumber. [ 16.492502] systemd[1]: Created slice User and Session Slice. [ OK ] Created slice User and Session Slice. [ 16.512407] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 16.536381] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ 16.556352] systemd[1]: Expecting device /sys/devices/platform/gpu/graphics/fb0... Expecting device /sys/devices/platform/gpu/graphics/fb0... [ 16.576375] systemd[1]: Reached target Host and Network Name Lookups. [ OK ] Reached target Host and Network Name Lookups. [ 16.596340] systemd[1]: Reached target Path Units. [ OK ] Reached target Path Units. [ 16.612351] systemd[1]: Reached target Remote File Systems. [ OK ] Reached target Remote File Systems. [ 16.628345] systemd[1]: Reached target Slice Units. [ OK ] Reached target Slice Units. [ 16.644350] systemd[1]: Reached target Swaps. [ OK ] Reached target Swaps. [ 16.663575] systemd[1]: Listening on Process Core Dump Socket. [ OK ] Listening on Process Core Dump Socket. [ 16.680414] systemd[1]: Listening on initctl Compatibility Named Pipe. [ OK ] Listening on initctl Compatibility Named Pipe. [ 16.700604] systemd[1]: Listening on Journal Audit Socket. [ OK ] Listening on Journal Audit Socket. [ 16.716468] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 16.736485] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 16.752514] systemd[1]: Listening on Network Service Netlink Socket. [ OK ] Listening on Network Service Netlink Socket. [ 16.772492] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 16.788444] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 16.804453] systemd[1]: Listening on User Database Manager Socket. [ OK ] Listening on User Database Manager Socket. [ 16.824477] systemd[1]: Huge Pages File System was skipped because of an unmet condition check (ConditionPathExists=/sys/kernel/mm/hugepages). [ 16.856434] systemd[1]: Mounting POSIX Message Queue File System... Mounting POSIX Message Queue File System... [ 16.877190] systemd[1]: Mounting Kernel Debug File System... Mounting Kernel Debug Fi[ 16.883863] systemd[1]: Mounting Kernel Trace File System... le System... Mounting Kernel Trace File System... [ 16.914675] systemd[1]: Mounting Temporary Directory /tmp... Mounting Temporary Direc[ 16.921740] systemd[1]: Starting Create List of Static Device Nodes... tory /tmp... Starting Create List of [ 16.941599] systemd[1]: Starting Load Kernel Module configfs... Static Device Nodes... Starting Load Kernel Mod[ 16.961543] systemd[1]: Starting Load Kernel Module drm... ule configfs... Starting Load Kernel Mod[ 16.981578] systemd[1]: Starting Load Kernel Module fuse... ule drm... Starting Load Kernel Mod[ 17.001542] systemd[1]: Starting SELinux autorelabel service loading... ule fuse... Starting SELinux autorel[ 17.021455] systemd[1]: Starting SELinux init for /dev service loading... abel service loading... [ 17.039225] fuse: init (API version 7.39) Starting SELinux init for /dev service loading... [ 17.056436] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/). [ 17.070649] systemd[1]: Starting Journal Service... Starting Journal Service... [ 17.089897] systemd[1]: Starting Load Kernel Modules... Starting Load Kernel Mod[ 17.104488] systemd[1]: Generate network units from Kernel command line was skipped because of an unmet condition check (ConditionKernelCommandLine=!nbd.server). ules... [ 17.122653] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root an[ 17.133354] systemd[1]: Starting Coldplug All udev Devices... d Kernel File Systems... Starting Coldplug All udev Devic[ 17.154706] systemd[1]: Mounted POSIX Message Queue File System. es... [ OK ] Mounted POSIX Message Queue File System. [ 17.188923] systemd[1]: Mounted Kernel Debug File System. [ OK ] Mounted Kernel Debug File System[ 17.196420] EXT4-fs (nbd0): re-mounted 47966b53-c54b-46c5-a736-dd34e4b9c216 r/w. Quota mode: none. . [ 17.217172] systemd[1]: Mounted Kernel Trace File System. [ OK ] Mounted Kernel Trace File System. [ 17.236569] systemd[1]: Mounted Temporary Directory /tmp. [ 17.241940] systemd-journald[197]: Collecting audit messages is enabled. [ OK ] Mounted Temporary Directory /tmp. [ 17.264679] systemd[1]: Finished Create List of Static Device Nodes. [ OK ] Finished Create List of Static Device Nodes. [ 17.278991] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. [ 17.290349] snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored [ 17.330606] audit: type=1130 audit(1725908514.887:2): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=kmod-static-nodes comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 17.330854] systemd[1]: Started Journal Service. [ OK ] Started Journal Service. [ 17.368492] audit: type=1130 audit(1725908514.927:3): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-journald comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished Load Kernel Module configfs. [ 17.400377] audit: type=1130 audit(1725908514.959:4): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@configfs comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 17.419332] audit: type=1131 audit(1725908514.959:5): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@configfs comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished Load Kernel Module drm. [ 17.452366] audit: type=1130 audit(1725908515.011:6): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@drm comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 17.470883] audit: type=1131 audit(1725908515.011:7): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@drm comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished Load Kernel Module fuse. [ 17.500353] audit: type=1130 audit(1725908515.059:8): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@fuse comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 17.518954] audit: type=1131 audit(1725908515.059:9): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@fuse comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished SELinux autorelabel service loading. [ 17.552354] audit: type=1130 audit(1725908515.111:10): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=selinux-autorelabel comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 17.571566] audit: type=1131 audit(1725908515.111:11): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=selinux-autorelabel comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished SELinux init for /dev service loading. [ OK ] Finished Load Kernel Modules. [ OK ] Finished Remount Root and Kernel File Systems. [ OK ] Finished Coldplug All udev Devices. Mounting FUSE Control File System... Mounting Kernel Configuration File System... Starting Flush Journal to Persistent Storage... Starting Apply Kernel Variables... [ 17.741454] systemd-journald[197]: Received client request to flush runtime journal. Starting Create Static Device Nodes in /dev gracefully... [ OK ] Mounted FUSE Control File System. [ OK ] Mounted Kernel Configuration File System. [ OK ] Finished Flush Journal to Persistent Storage. [ OK ] Finished Apply Kernel Variables. [ OK ] Finished Create Static Device Nodes in /dev gracefully. Starting Create System Users... Starting User Database Manager... [ OK ] Started User Database Manager. [ OK ] Finished Create System Users. Starting Create Static Device Nodes in /dev... [ OK ] Finished Create Static Device Nodes in /dev. [ OK ] Reached target Preparation for Local File Systems. Mounting /var/volatile... Starting Rule-based Manager for Device Events and Files... [ OK ] Mounted /var/volatile. Starting Load/Save OS Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting SELinux resolv.conf relabeling... Starting SELinux init service loading... Starting Create Volatile Files and Directories... [ OK ] Finished Load/Save OS Random Seed. [ OK ] Finished SELinux init service loading. Starting Generated file SELinux relabeling... [ OK ] Finished SELinux resolv.conf relabeling. [ OK ] Finished Create Volatile Files and Directories. Starting Load Audit Rules... Starting Rebuild Journal Catalog... [ OK ] Finished Generated file SELinux relabeling. [ OK ] Finished Rebuild Journal Catalog. [ OK ] Finished Load Audit Rules. Starting Security Audit Logging Service... [ OK ] Started Rule-based Manager for Device Events and Files. [ OK ] Started Security Audit Logging Service. Starting Record System Boot/Shutdown in UTMP... Starting Virtual Console Setup... [ 18.981701] input: pwr_button as /devices/platform/pwr_button/input/input0 [ OK ] Finished Record System Boot/Shutdown in UTMP. [ 19.064927] rpi-gpiomem 107d508500.gpiomem: window base 0x107d508500 size 0x00000040 [ 19.072943] rpi-gpiomem 107d508500.gpiomem: initialised 1 regions as /dev/gpiomem1 [ 19.080711] rpi-gpiomem 107d517c00.gpiomem: window base 0x107d517c00 size 0x00000040 [ 19.088565] rpi-gpiomem 107d517c00.gpiomem: initialised 1 regions as /dev/gpiomem2 [ 19.096204] rpi-gpiomem 107d504100.gpiomem: window base 0x107d504100 size 0x00000020 [ 19.104013] rpi-gpiomem 107d504100.gpiomem: initialised 1 regions as /dev/gpiomem3 [ 19.111673] rpi-gpiomem 107d510700.gpiomem: window base 0x107d510700 size 0x00000020 [ 19.119583] rpi-gpiomem 107d510700.gpiomem: initialised 1 regions as /dev/gpiomem4 [ 19.127306] rpi-gpiomem 1f000d0000.gpiomem: window base 0x1f000d0000 size 0x00030000 [ 19.128722] macb 1f00100000.ethernet end0: renamed from eth0 (while UP) [ 19.135160] rpi-gpiomem 1f000d0000.gpiomem: initialised 1 regions as /dev/gpiomem0 [ 19.249932] mc: Linux media interface: v0.10 [ 19.339440] videodev: Linux video capture interface: v2.00 [ OK ] Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. [ 19.430516] Bluetooth: Core ver 2.22 [ 19.434179] NET: Registered PF_BLUETOOTH protocol family [ 19.439539] Bluetooth: HCI device and connection manager initialized [ 19.445960] Bluetooth: HCI socket layer initialized [ 19.450896] Bluetooth: L2CAP socket layer initialized [ 19.456010] Bluetooth: SCO socket layer initialized [ 19.467991] pispbe 1000880000.pisp_be: bcm2712_iommu_of_xlate: MMU 1000005100.iommu [ 19.478084] cfg80211: Loading compiled-in X.509 certificates for regulatory database [ 19.478417] rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. [ 19.479096] pispbe 1000880000.pisp_be: pispbe_probe: HW version: 0x02252700 [ 19.479105] pispbe 1000880000.pisp_be: pispbe_probe: BatchStatus: 0x00000000 [ 19.479107] pispbe 1000880000.pisp_be: pispbe_probe: Status: 0x00000000 [ 19.479109] pispbe 1000880000.pisp_be: Register nodes for group 0 [ 19.479204] pispbe 1000880000.pisp_be: input device node registered as /dev/video20 [ 19.479241] pispbe 1000880000.pisp_be: tdn_input device node registered as /dev/video21 [ 19.479267] pispbe 1000880000.pisp_be: stitch_input device node registered as /dev/video22 [ 19.479314] pispbe 1000880000.pisp_be: hog_output device node registered as /dev/video23 [ 19.479340] pispbe 1000880000.pisp_be: output0 device node registered as /dev/video24 [ 19.479370] pispbe 1000880000.pisp_be: output1 device node registered as /dev/video25 [ 19.479395] pispbe 1000880000.pisp_be: tdn_output device node registered as /dev/video26 [ 19.479431] pispbe 1000880000.pisp_be: stitch_output device node registered as /dev/video27 [ 19.479457] pispbe 1000880000.pisp_be: config device node registered as /dev/video28 [ 19.479733] pispbe 1000880000.pisp_be: Register nodes for group 1 [ 19.479770] pispbe 1000880000.pisp_be: input device node registered as /dev/video29 [ 19.479814] pispbe 1000880000.pisp_be: tdn_input device node registered as /dev/video30 [ 19.479844] pispbe 1000880000.pisp_be: stitch_input device node registered as /dev/video31 [ 19.479873] pispbe 1000880000.pisp_be: hog_output device node registered as /dev/video32 [ 19.479908] pispbe 1000880000.pisp_be: output0 device node registered as /dev/video33 [ 19.479934] pispbe 1000880000.pisp_be: output1 device node registered as /dev/video34 [ 19.479960] pispbe 1000880000.pisp_be: tdn_output device node registered as /dev/video35 [ 19.479995] pispbe 1000880000.pisp_be: stitch_output device node registered as /dev/video36 [ 19.480037] pispbe 1000880000.pisp_be: config device node registered as /dev/video37 [ 19.502844] Loaded X.509 cert '[email protected]: 577e021cb980e0e820821ba7b54b4961b8b4fadf' [ 19.503056] Loaded X.509 cert '[email protected]: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' [ 19.503200] Bluetooth: HCI UART driver ver 2.3 [ 19.503204] Bluetooth: HCI UART protocol H4 registered [ 19.503206] Bluetooth: HCI UART protocol BCSP registered [ 19.503228] Bluetooth: HCI UART protocol Three-wire (H5) registered [ 19.503358] hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator [ 19.503398] hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator [ 19.504379] Bluetooth: HCI UART protocol Broadcom registered [ 19.523486] rpivid 1000800000.codec: bcm2712_iommu_of_xlate: MMU 1000005100.iommu [ 19.533872] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' [ 19.540377] rpivid 1000800000.codec: Device registered as /dev/video19 [ 19.547764] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Starting Load/Save RF Kill Switc[ 19.790625] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 h Status... [ 19.801186] cfg80211: failed to load regulatory.db [ OK ] Started Load/Save RF Kill Switch Status. [ OK ] Finished Virtual Console Setup. [ 19.832292] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 [ 19.841107] usbcore: registered new interface driver brcmfmac [ 19.847947] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,5-model-b.bin failed with error -2 [ 19.856746] Bluetooth: hci0: BCM: chip id 107 [ 19.864241] Bluetooth: hci0: BCM: features 0x2f [ 19.869930] Bluetooth: hci0: BCM4345C0 [ 19.873729] Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 [ 19.911577] Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch [ OK ] Created slice Slice /system/bthelper. Starting SELinux resolv.conf relabeling... Starting SELinux autorelabel service loading... Starting SELinux init service loading... Starting SELinux init for /dev service loading... Starting Network Name Resolution... [ OK ] Finished SELinux resolv.conf relabeling. [ OK ] Finished SELinux autorelabel service loading. [ OK ] Finished SELinux init service loading. [ OK ] Finished SELinux init for /dev service l[ 20.111668] brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob available (err=-2) oading. [ 20.121360] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Aug 29 2023 01:47:08 version 7.45.265 (28bca26 CY) FWID 01-b677b91b [ OK ] Started Network Name Resolution. [ 20.596932] Bluetooth: hci0: BCM: features 0x2f [ 20.602834] Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+-0190 [ 20.609047] Bluetooth: hci0: BCM4345C0 (003.001.025) build 0382 [ 20.615277] Bluetooth: hci0: BCM: Using default device address (43:45:c0:00:1f:ac) [* ] (1 of 2) A start job is running for…namic Linker Cache (2s / no limit) M[K[** ] (1 of 2) A start job is running for…namic Linker Cache (3s / no limit) M[K[*** ] (1 of 2) A start job is running for…namic Linker Cache (3s / no limit) M[K[ *** ] (2 of 2) A start job is running for…m/gpu/graphics/fb0 (7s / 1min 30s) M[K[ *** ] (2 of 2) A start job is running for…m/gpu/graphics/fb0 (8s / 1min 30s) M[K[ ***] (2 of 2) A start job is running for…m/gpu/graphics/fb0 (8s / 1min 30s) M[K[ **] (1 of 2) A start job is running for…namic Linker Cache (5s / no limit) M[K[ OK ] Finished Rebuild Dynamic Linker Cache. [K Starting Update is Completed... [ OK ] Finished Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timer Units. [ OK ] Listening on agl-compositor, a Wayl…ositor, as a systemd user service. [ OK ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Listening on GPS (Global Positioning System) Daemon Sockets. [ OK ] Listening on mpd.socket. Starting PipeWire Multimedia System Manager Socket... Starting PipeWire Multimedia System Socket... Starting sshd.socket... [ OK ] Listening on PipeWire Multimedia System Manager Socket. [ OK ] Listening on PipeWire Multimedia System Socket. [ OK ] Listening on sshd.socket. [ OK ] Reached target Socket Units. [ OK ] Reached target Basic System. Starting CAN interface helper... Starting D-Bus System Message Bus... Starting Raspberry Pi bluetooth helper... Starting IPv6 Packet Filtering Framework... Starting IPv4 Packet Filtering Framework... Starting Telephony service... [ OK ] Started PipeWire Multimedia Service. Starting Authorization Manager... Starting User Login Management... Starting Disk Manager... [ OK ] Started Multimedia Service Session Manager (audio). [ OK ] Started Multimedia Service Session Manager (bluetooth). [ OK ] Started Multimedia Service Session Manager (policy). [ OK ] Started Multimedia Service Session Manager (video-capture). Starting OpenSSH Key Generation... [ OK ] Finished IPv6 Packet Filtering Framework. [ 26.167902] CAN device driver interface [ OK ] Finished Raspberry Pi bluetooth helper. [ OK ] Finished IPv4 Packet Filtering Framework. [ OK ] Reached target Preparation for Network. [ 26.219114] vcan: Virtual CAN interface driver Starting Bluetooth service... Starting Network Configuration... [ OK ] Finished CAN interface helper. [ OK ] Started User Login Management. [ OK ] Started Network Configuration. [ OK ] Started D-Bus System Message Bus. Starting Connection service... [ OK ] Started Telephony service. [ OK ] Started Bluetooth service. [ OK ] Reached target Bluetooth Support. [ 27.986612] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 [ 27.991991] Bluetooth: BNEP filters: protocol multicast [ 27.997272] Bluetooth: BNEP socket layer initialized [ 28.004082] Bluetooth: MGMT ver 1.22 Starting Hostname Service... [ OK ] Started Hostname Service. [ 28.337416] Bluetooth: RFCOMM TTY layer initialized [ 28.342435] Bluetooth: RFCOMM socket layer initialized [ 28.347874] Bluetooth: RFCOMM ver 1.11 [ OK ] Started Connection service. [ OK ] Reached target Network. [ OK ] Started agl-service-radio.service. Starting Avahi mDNS/DNS-SD Stack... [ OK ] Started Eclipse KUKSA.va[ 28.513189] pipewire[479]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set l databroker. [ OK ] Started agl-service-audiomixer.service. [ OK ] Started agl-service-hvac.service. Starting agl-vss-helper.service... [ OK ] Started Eclipse KUKSA.val DBC feeder. Starting Permit User Sessions... [ OK ] Started Avahi mDNS/DNS-SD Stack. [ OK ] Finished Permit User Sessions. Starting AGL compositor... [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyAMA10. [ OK ] Reached target Login Prompts. Starting WPA supplicant... Starting Load/Save RF Kill Switch Status... [ OK ] Started Load/Save RF Kill Switch Status. [ OK ] Started WPA supplicant. [ OK ] Created slice User Slice of UID 1001. Starting User Runtime Directory /run/user/1001... [ OK ] Finished User Runtime Directory /run/user/1001. Starting User Manager for UID 1001... [ 31.469302] can: controller area network core [ 31.473796] NET: Registered PF_CAN protocol family [ 31.504145] can: raw protocol [ OK ] Started Authorization Manager. Starting applaunchd.service... [ OK ] Started Disk Manager. [ OK ] Started Automount Disk Manager. [ OK ] Started User Manager for UID 1001. [ OK ] Finished OpenSSH Key Generation. [ OK ] Started Session c1 of User agl-driver. [ OK ] Started applaunchd.service. [FAILED] Failed to start AGL compositor. See 'systemctl status agl-compositor.service' for details. [DEPEND] Dependency failed for homescreen.service. [DEPEND] Dependency failed for launcher.service. Automotive Grade Linux 18.0.2 raspberrypi5 ttyAMA10 Matched prompt #12: login: case: kernel-messages
case_id: 4089421
definition: lava
duration: 34.82
extra: ...
level: 2.3.1
namespace: common
result: pass
Sending username root root raspberrypi5 login: root Setting prompt string to ['raspberrypi5:~#', '/ #'] login-action: Wait for prompt ['raspberrypi5:~#', '/ #', 'Login incorrect', 'Login timed out'] (timeout 00:07:23) root Setting prompt string to ['raspberrypi5:~#', '/ #'] end: 2.3.1 login-action (duration 00:00:38) [common] case: login-action
case_id: 4089422
definition: lava
duration: 38.29
extra: ...
level: 2.3.1
namespace: common
result: pass
end: 2.3 auto-login-action (duration 00:01:44) [common] start: 2.4 expect-shell-connection (timeout 00:07:20) [common] Setting prompt string to ['raspberrypi5:~#', '/ #'] Forcing a shell prompt, looking for ['raspberrypi5:~#', '/ #'] 7[r[999;999H[6nroot@raspberrypi5:~# expect-shell-connection: Wait for prompt ['raspberrypi5:~#', '/ #'] (timeout 00:20:00) Waiting using forced prompt support (timeout 00:10:00) end: 2.4 expect-shell-connection (duration 00:00:00) [common] start: 2.5 overlay-unpack (timeout 00:07:20) [common] rm overlay-1.5.5.tar.gz root@raspberrypi5:~# rm overlay-1.5.5.tar.gz rm overlay-1.5.5.tar.gz rm: cannot remove 'overlay-1.5.5.tar.gz': No such file or directory wget http://192.168.66.1/tmp/37670/compress-overlay-edci8j23/overlay-1.5.5.tar.gz root@raspberrypi5:~# wget http://192.168.66.1/tmp/37670/compress-overlay-edci8j23/overlay-1.5.5.tar.gz wget http://192.168.66.1/tmp/37670/compress-overlay-edci8j233/overlay-1.5.5.tar.gz Connecting to 192.168.66.1 (192.168.66.1:80) saving to 'overlay-1.5.5.tar.gz' overlay-1.5.5.tar.gz 100% |********************************| 8050 0:00:00 ETA 'overlay-1.5.5.tar.gz' saved tar -C / -xvpf overlay-1.5.5.tar.gz root@raspberrypi5:~# tar -C / -xvpf overlay-1.5.5.tar.gz tar -C / -xvpf overlay-1.5.5.tar.gz x lava-37670/ x lava-37670/0/ x lava-37670/0/lava-test-runner.conf x lava-37670/0/tests/ x lava-37670/0/tests/0_dmesg/ x lava-37670/0/tests/0_dmesg/inline/ x lava-37670/0/tests/0_dmesg/inline/dmesg.yaml x lava-37670/0/tests/0_dmesg/run.sh x lava-37670/0/tests/0_dmesg/testdef.yaml x lava-37670/0/tests/0_dmesg/testdef_metadata x lava-37670/0/tests/0_dmesg/uuid x lava-37670/1/ x lava-37670/1/lava-test-runner.conf x lava-37670/1/tests/ x lava-37670/1/tests/1_bootrr/ x lava-37670/1/tests/1_bootrr/inline/ x lava-37670/1/tests/1_bootrr/inline/bootrr.yaml x lava-37670/1/tests/1_bootrr/run.sh x lava-37670/1/tests/1_bootrr/testdef.yaml x lava-37670/1/tests/1_bootrr/testdef_metadata x lava-37670/1/tests/1_bootrr/uuid x lava-37670/bin/ x lava-37670/bin/lava-add-keys x lava-37670/bin/lava-add-sources x lava-37670/bin/lava-background-process-start x lava-37670/bin/lava-background-process-stop x lava-37670/bin/lava-common-functions x lava-37670/bin/lava-echo-ipv4 x lava-37670/bin/lava-install-packages x lava-37670/bin/lava-installed-packages x lava-37670/bin/lava-os-build x lava-37670/bin/lava-probe-channel x lava-37670/bin/lava-probe-ip x lava-37670/bin/lava-target-ip x lava-37670/bin/lava-target-mac x lava-37670/bin/lava-target-storage x lava-37670/bin/lava-test-case x lava-37670/bin/lava-test-event x lava-37670/bin/lava-test-feedback x lava-37670/bin/lava-test-raise x lava-37670/bin/lava-test-reference x lava-37670/bin/lava-test-runner x lava-37670/bin/lava-test-set x lava-37670/bin/lava-test-shell x lava-37670/environment x lava-37670/lava x lava-37670/lava.pub x lava-37670/results/ x lava-37670/tests/ end: 2.5 overlay-unpack (duration 00:00:01) [common] start: 2.6 export-device-env (timeout 00:07:19) [common] end: 2.6 export-device-env (duration 00:00:00) [common] end: 2 minimal-boot (duration 00:01:52) [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 # root@raspberrypi5:~# # lava-test-shell: Wait for prompt ['raspberrypi5:~#', '/ #'] (timeout 00:01:00) # Using /lava-37670 export SHELL=/bin/sh root@raspberrypi5:~# export SHELL=/bin/sh export SHELL=/bin/sh . /lava-37670/environment root@raspberrypi5:~# . /lava-37670/environment . /lava-37670/environment /lava-37670/bin/lava-test-runner /lava-37670/0 root@raspberrypi5:~# /lava-37670/bin/lava-test-runner /lava-37670/0 Test shell timeout: 10s (minimum of the action and connection timeout) /lava-37670/bin/lava-test-runner /lava-37670/0 + export TESTRUN_ID=0_dmesg + TESTRUN_ID=0_dmesg + cd /lava-37670/0/tests/0_dmesg ++ cat uuid + UUID=37670_1.5.4.1 + set +x <LAVA_SIGNAL_STARTRUN 0_dmesg 37670_1.5.4.1> + for level in warn err + dmesg --level=warn --notime -x -k + for level in warn err + dmesg --level=err --notime -x -k + for level in crit alert emerg + dmesg --level=crit --notime -x -k + test -s dmesg.crit + res=pass ++ cat dmesg.crit ++ wc -l + count=0 Received signal: <STARTRUN> 0_dmesg 37670_1.5.4.1 Starting test lava.0_dmesg (37670_1.5.4.1) Skipping test definition patterns. + lava-test-case crit --result pass --measurement 0 --units lines <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=crit RESULT=pass UNITS=lines MEASUREMENT=0> + for level in crit alert emerg + dmesg --level=alert --notime -x -k + test -s dmesg.alert + res=pass ++ cat dmesg.alert ++ wc -l + count=0 + lava-test-case alert --result pass --measurement 0 --units lines <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=alert RESULT=pass UNITS=lines MEASUREMENT=0> + for level in crit alert emerg + dmesg --level=emerg --notime -x -k Received signal: <TESTCASE> TEST_CASE_ID=crit RESULT=pass UNITS=lines MEASUREMENT=0 case: crit
case_id: 4089423
definition: 0_dmesg
endtc: 1333
measurement: 0.0
result: pass
starttc: 1333
units: lines
Received signal: <TESTCASE> TEST_CASE_ID=alert RESULT=pass UNITS=lines MEASUREMENT=0 case: alert
case_id: 4089424
definition: 0_dmesg
endtc: 1335
measurement: 0.0
result: pass
starttc: 1335
units: lines
+ test -s dmesg.emerg + res=pass ++ cat dmesg.emerg ++ wc -l + count=0 + lava-test-case emerg --result pass --measurement 0 --units lines <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=emerg RESULT=pass UNITS=lines MEASUREMENT=0> + cat dmesg.emerg dmesg.alert dmesg.crit dmesg.err dmesg.warn kern :err : bcm2708_fb soc:fb: Unable to determine number of FBs. Disabling driver. kern :warn : F2FS not supported on PAGE_SIZE(16384) != 4096 kern :warn : bcm2708_fb: probe of soc:fb failed with error -2 Received signal: <TESTCASE> TEST_CASE_ID=emerg RESULT=pass UNITS=lines MEASUREMENT=0 case: emerg
case_id: 4089425
definition: 0_dmesg
endtc: 1348
measurement: 0.0
result: pass
starttc: 1348
units: lines
+ set +x <LAVA_SIGNAL_ENDRUN 0_dmesg 37670_1.5.4.1> <LAVA_TEST_RUNNER EXIT> Received signal: <ENDRUN> 0_dmesg 37670_1.5.4.1 Ending use of test pattern. Ending test lava.0_dmesg (37670_1.5.4.1), duration 0.10 case: 0_dmesg
case_id: 4089426
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': ['for level in warn err; do\n dmesg --level=$level --notime -x -k > dmesg.$level\ndone\n', 'for level in crit alert emerg; do\n dmesg --level=$level --notime -x -k > dmesg.$level\n test -s dmesg.$level && res=fail || res=pass\n count=$(cat dmesg.$level | wc -l)\n lava-test-case $level \\\n --result $res \\\n --measurement $count \\\n --units lines\ndone\n', 'cat dmesg.emerg dmesg.alert dmesg.crit dmesg.err dmesg.warn']}
result: pass
revision: unspecified
uuid: 37670_1.5.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 # root@raspberrypi5:~# # lava-test-shell: Wait for prompt ['raspberrypi5:~#', '/ #'] (timeout 00:01:00) Using /lava-37670 export SHELL=/bin/sh export SHELL=/bin/sh # . /lava-37670/environment root@raspberrypi5:~# export SHELL=/bin/sh. /lava-37670/environment /lava-37670/bin/lava-test-runner /lava-37670/1 root@raspberrypi5:~# . /lava-37670/environment/lava-37670/bin/lava-test-runner /lava-37670/1 Test shell timeout: 10s (minimum of the action and connection timeout) root@raspberrypi5:~# /lava-37670/bin/lava-test-runner /lava-37670/1 + export TESTRUN_ID=1_bootrr + TESTRUN_ID=1[ 40.185034] <LAVA_SIGNAL_STARTRUN 1_bootrr 37670_1.5.4.5> _bootrr + cd /lava-37670/1/tests/[ 40.193439] <LAVA_SIGNAL_ENDRUN 1_bootrr 37670_1.5.4.5> 1_bootrr ++ cat uuid + UUID=37670_1.5.4.5 + set +x + export PATH=/opt/bootrr/helpers:/lava-37670/1/../bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin + PATH=/opt/bootrr/helpers:/lava-37670/1/../bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin Received signal: <STARTRUN> 1_bootrr 37670_1.5.4.5 Starting test lava.1_bootrr (37670_1.5.4.5) Skipping test definition patterns. Received signal: <ENDRUN> 1_bootrr 37670_1.5.4.5 Ending use of test pattern. Ending test lava.1_bootrr (37670_1.5.4.5), duration 0.00 case: 1_bootrr
case_id: 4089427
definition: lava
duration: 0.00
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/helpers:$PATH', 'cd /opt/bootrr && sh helpers/bootrr-auto']}
result: pass
revision: unspecified
uuid: 37670_1.5.4.5
+ cd /opt/bootrr /lava-37670/1/tests/1_bootrr/run.sh: line 15: cd: /opt/bootrr: No such file or directory + set +x <LAVA_TEST_RUNNER EXIT> ok: lava_test_shell seems to have completed 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:07:18) [common] start: 5.1 power-off (timeout 00:00:30) [common] Calling: 'upower.sh' '--atx' 'off' '2' >> Accessing Gembird #0 USB device 002 >> Switched outlet 2 off Returned 0 in 1 seconds end: 5.1 power-off (duration 00:00:01) [common] case: power-off
case_id: 4089428
definition: lava
duration: 1.14
extra: ...
level: 5.1
namespace: common
result: pass
start: 5.2 read-feedback (timeout 00:07:17) [common] Listened to connection for namespace 'common' for up to 1s Finalising connection for namespace 'common' Disconnecting from shell: Finalise root@raspberrypi5:~# end: 5.2 read-feedback (duration 00:00:01) [common] lava-xnbd cleanup clean NBD port 61966 end: 5 finalize (duration 00:00:02) [common] Cleaning after the job Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/initrd Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/kernel Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/dtb Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37670/nbd-deploy-1bgtg7tt/nbdroot Override tmp directory removed at /var/lib/lava/dispatcher/tmp/37670 Root tmp directory removed at /var/lib/lava/dispatcher/tmp/37670 Job finished correctly case: job
case_id: 4089429
definition: lava
result: pass