lava-dispatcher, installed at version: 2023.01 start: 0 validate Start time: 2023-03-09 06:26:12.769150+00:00 (UTC) Validating that http://download.automotivelinux.org/AGL/upload/ci/28560/2/bbe/initramfs-netboot-image-bbe.ext4.gz exists Validating that http://download.automotivelinux.org/AGL/upload/ci/28560/2/bbe/zImage exists Validating that http://download.automotivelinux.org/AGL/upload/ci/28560/2/bbe/am335x-sancloud-bbe.dtb exists Validating that http://download.automotivelinux.org/AGL/upload/ci/28560/2/bbe/agl-telematics-demo-platform-bbe.ext4.xz exists validate duration: 0.88 case: validate
case_id: 3885698
definition: lava
result: pass
start: 1 nbd-deploy (timeout 01:30: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 01:30:00) [common] start: 1.1.1 http-download (timeout 01:30:00) [common] downloading http://download.automotivelinux.org/AGL/upload/ci/28560/2/bbe/initramfs-netboot-image-bbe.ext4.gz saving as /var/lib/lava/dispatcher/tmp/32194/nbd-deploy-4b7psuvy/initrd/initramfs-netboot-image-bbe.ext4.gz total size: 1677796 (1MB) No compression specified progress 1% (0MB) progress 7% (0MB) progress 13% (0MB) progress 19% (0MB) progress 25% (0MB) progress 31% (0MB) progress 37% (0MB) progress 42% (0MB) progress 48% (0MB) progress 54% (0MB) progress 60% (0MB) progress 66% (1MB) progress 72% (1MB) progress 78% (1MB) progress 83% (1MB) progress 89% (1MB) progress 95% (1MB) progress 100% (1MB) 1MB downloaded in 0.90s (1.79MB/s) end: 1.1.1 http-download (duration 00:00:01) [common] case: http-download
case_id: 3885702
definition: lava
duration: 0.90
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 01:29:59) [common] start: 1.2.1 http-download (timeout 01:29:59) [common] downloading http://download.automotivelinux.org/AGL/upload/ci/28560/2/bbe/zImage saving as /var/lib/lava/dispatcher/tmp/32194/nbd-deploy-4b7psuvy/kernel/zImage total size: 4736736 (4MB) No compression specified progress 0% (0MB) progress 5% (0MB) progress 10% (0MB) progress 15% (0MB) progress 20% (0MB) progress 25% (1MB) progress 30% (1MB) progress 35% (1MB) progress 40% (1MB) progress 45% (2MB) progress 50% (2MB) progress 55% (2MB) progress 60% (2MB) progress 65% (2MB) progress 70% (3MB) progress 75% (3MB) progress 80% (3MB) progress 85% (3MB) progress 90% (4MB) progress 95% (4MB) progress 100% (4MB) 4MB downloaded in 1.69s (2.67MB/s) end: 1.2.1 http-download (duration 00:00:02) [common] case: http-download
case_id: 3885702
definition: lava
duration: 1.70
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 01:29:57) [common] start: 1.3.1 http-download (timeout 01:29:57) [common] downloading http://download.automotivelinux.org/AGL/upload/ci/28560/2/bbe/am335x-sancloud-bbe.dtb saving as /var/lib/lava/dispatcher/tmp/32194/nbd-deploy-4b7psuvy/dtb/am335x-sancloud-bbe.dtb total size: 93513 (0MB) No compression specified progress 35% (0MB) progress 70% (0MB) progress 100% (0MB) 0MB downloaded in 0.41s (0.21MB/s) end: 1.3.1 http-download (duration 00:00:00) [common] case: http-download
case_id: 3885702
definition: lava
duration: 0.42
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 01:29:57) [common] start: 1.4.1 http-download (timeout 01:29:57) [common] downloading http://download.automotivelinux.org/AGL/upload/ci/28560/2/bbe/agl-telematics-demo-platform-bbe.ext4.xz saving as /var/lib/lava/dispatcher/tmp/32194/nbd-deploy-4b7psuvy/nbdroot/agl-telematics-demo-platform-bbe.ext4 total size: 246913200 (235MB) Using unxz to decompress xz progress 0% (0MB) progress 5% (11MB) progress 10% (23MB) progress 15% (35MB) progress 20% (47MB) progress 25% (58MB) progress 30% (70MB) progress 35% (82MB) progress 40% (94MB) progress 45% (105MB) progress 50% (117MB) progress 55% (129MB) progress 60% (141MB) progress 65% (153MB) progress 70% (164MB) progress 75% (176MB) progress 80% (188MB) progress 85% (200MB) progress 90% (211MB) progress 95% (223MB) progress 100% (235MB) 235MB downloaded in 108.60s (2.17MB/s) end: 1.4.1 http-download (duration 00:01:49) [common] case: http-download
case_id: 3885702
definition: lava
duration: 108.60
extra: ...
level: 1.4.1
namespace: common
result: pass
end: 1.4 download-retry (duration 00:01:49) [common] start: 1.5 lava-overlay (timeout 01:28:08) [common] [common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto makedir: /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin makedir: /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/tests makedir: /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/results Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-add-keys Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-add-sources Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-background-process-start Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-background-process-stop Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-common-functions Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-echo-ipv4 Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-install-packages Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-installed-packages Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-os-build Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-probe-channel Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-probe-ip Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-target-ip Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-target-mac Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-target-storage Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-test-case Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-test-event Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-test-feedback Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-test-raise Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-test-reference Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-test-runner Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-test-set Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-test-shell Updating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-install-packages (oe) Updating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/bin/lava-installed-packages (oe) Creating /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/environment LAVA metadata - LAVA_JOB_ID=32194 - LAVA_DISPATCHER_IP=192.168.66.1 start: 1.5.1 ssh-authorize (timeout 01:28:08) [common] end: 1.5.1 ssh-authorize (duration 00:00:00) [common] start: 1.5.2 lava-vland-overlay (timeout 01:28:08) [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 01:28:08) [common] skipped lava-multinode-overlay end: 1.5.3 lava-multinode-overlay (duration 00:00:00) [common] start: 1.5.4 test-definition (timeout 01:28:08) [common] Loading test definitions start: 1.5.4.1 git-repo-action (timeout 01:28:08) [common] Using /lava-32194 at stage 0 Fetching tests from https://github.com/duerpei/yan_test.git Running '/usr/bin/git clone --depth=1 https://github.com/duerpei/yan_test.git /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/0/tests/0_check_disk_space' Removing '.git' directory in /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/0/tests/0_check_disk_space Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/0/tests/0_check_disk_space/./check_space.yaml uuid=32194_1.5.4.1 testdef=None end: 1.5.4.1 git-repo-action (duration 00:00:01) [common] case: git-repo-action
case_id: 3885703
definition: lava
duration: 0.84
extra: ...
level: 1.5.4.1
namespace: common
result: pass
start: 1.5.4.2 test-overlay (timeout 01:28:07) [common] end: 1.5.4.2 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 3885704
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.2
namespace: common
result: pass
start: 1.5.4.3 test-install-overlay (timeout 01:28:07) [common] end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 3885705
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.3
namespace: common
result: pass
start: 1.5.4.4 test-runscript-overlay (timeout 01:28:07) [common] runner path: /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/0/tests/0_check_disk_space test_uuid 32194_1.5.4.1 end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 3885706
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.4
namespace: common
result: pass
Creating lava-test-runner.conf files Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/32194/lava-overlay-gaccwlto/lava-32194/0 for stage 0 - 0_check_disk_space end: 1.5.4 test-definition (duration 00:00:01) [common] start: 1.5.5 compress-overlay (timeout 01:28:07) [common] end: 1.5.5 compress-overlay (duration 00:00:00) [common] start: 1.5.6 persistent-nfs-overlay (timeout 01:28:07) [common] end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common] end: 1.5 lava-overlay (duration 00:00:01) [common] start: 1.6 prepare-kernel (timeout 01:28:07) [common] start: 1.6.1 uboot-prepare-kernel (timeout 01:28:07) [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 01:28:07) [common] xnbd-server-deploy: starting nbd-server NBD-IP: 192.168.66.1, NBD-PORT: 61966, NBD-ROOT: 32194/nbd-deploy-4b7psuvy/nbdroot/agl-telematics-demo-platform-bbe.ext4 nbd-server 61966 /var/lib/lava/dispatcher/tmp/32194/nbd-deploy-4b7psuvy/nbdroot/agl-telematics-demo-platform-bbe.ext4 output: output: ** (process:4624): WARNING **: 06:28:06.301: 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:01:53) [common] start: 2 uboot-action (timeout 00:20:00) [common] start: 2.1 uboot-from-media (timeout 00:20:00) [common] end: 2.1 uboot-from-media (duration 00:00:00) [common] start: 2.2 bootloader-overlay (timeout 00:20:00) [common] substitutions: - {BOOTX}: bootz 0x82000000 0x83000000:${initrd_size} 0x88000000 - {DTB_ADDR}: 0x88000000 - {DTB}: 32194/nbd-deploy-4b7psuvy/dtb/am335x-sancloud-bbe.dtb - {INITRD}: 32194/nbd-deploy-4b7psuvy/initrd/initramfs-netboot-image-bbe.ext4.gz - {KERNEL_ADDR}: 0x82000000 - {KERNEL}: 32194/nbd-deploy-4b7psuvy/kernel/zImage - {LAVA_MAC}: None - {NBDSERVERIP}: 192.168.66.1 - {NBDSERVERPORT}: 61966 - {PRESEED_CONFIG}: None - {PRESEED_LOCAL}: None - {RAMDISK_ADDR}: 0x83000000 - {RAMDISK}: 32194/nbd-deploy-4b7psuvy/initrd/initramfs-netboot-image-bbe.ext4.gz - {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 0xffffffff - setenv fdt_high 0xffffffff - dhcp - setenv serverip 192.168.66.1 - tftp 0x82000000 32194/nbd-deploy-4b7psuvy/kernel/zImage - tftp 0x83000000 32194/nbd-deploy-4b7psuvy/initrd/initramfs-netboot-image-bbe.ext4.gz - setenv initrd_size ${filesize} - tftp 0x88000000 32194/nbd-deploy-4b7psuvy/dtb/am335x-sancloud-bbe.dtb - setenv bootargs 'console=ttyO0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61966 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw' - bootz 0x82000000 0x83000000:${initrd_size} 0x88000000 end: 2.2 bootloader-overlay (duration 00:00:00) [common] case: bootloader-overlay
case_id: 3885707
definition: lava
duration: 0.02
extra: ...
level: 2.2
namespace: common
result: pass
start: 2.3 connect-device (timeout 00:20:00) [common] [common] connect-device Connecting to device using 'telnet 127.0.0.1 63005' Setting prompt string to ['lava-test: # '] end: 2.3 connect-device (duration 00:00:03) [common] start: 2.4 uboot-commands (timeout 00:19:57) [common] start: 2.4.1 reset-device (timeout 00:19:57) [common] start: 2.4.1.1 pdu-reboot (timeout 00:19:57) [common] Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '4' >> Success >> Success Returned 0 in 4 seconds end: 2.4.1.1 pdu-reboot (duration 00:00:05) [common] case: pdu-reboot
case_id: 3885708
definition: lava
duration: 4.63
extra: ...
level: 2.4.1.1
namespace: common
result: pass
end: 2.4.1 reset-device (duration 00:00:05) [common] start: 2.4.2 bootloader-interrupt (timeout 00:19:52) [common] Setting prompt string to ['Press SPACE to abort autoboot'] bootloader-interrupt: Wait for prompt ['Press SPACE to abort autoboot'] (timeout 00:20:00) Trying 127.0.0.1... Connected to 127.0.0.1. Escape character is '^]'. U-Boot SPL 2019.04-00002-g07d5700e21 (Mar 06 2020 - 11:24:55 -0600) Trying to boot from MMC1 Loading Environment from EXT4... OK U-Boot 2019.04-00002-g07d5700e21 (Mar 06 2020 - 11:24:55 -0600), Build: jenkins-github_Bootloader-Builder-137 CPU : AM335X-GP rev 2.1 I2C: ready DRAM: 1 GiB No match for driver 'omap_hsmmc' No match for driver 'omap_hsmmc' Some drivers were not found Reset Source: Power-on reset has occurred. RTC 32KCLK Source: External. MMC: OMAP SD/MMC: 0, OMAP SD/MMC: 1 Loading Environment from EXT4... OK Board: BeagleBone Black Model: SanCloud BeagleBone Enhanced BeagleBone Black: Model: SanCloud BeagleBone Enhanced: BeagleBone: cape eeprom: i2c_probe: 0x54: BeagleBone: cape eeprom: i2c_probe: 0x55: BeagleBone: cape eeprom: i2c_probe: 0x56: BeagleBone: cape eeprom: i2c_probe: 0x57: Net: eth0: RGMII MODE cpsw, usb_ether Press SPACE to abort autoboot in 5 seconds end: 2.4.2 bootloader-interrupt (duration 00:00:02) [common] start: 2.4.3 bootloader-commands (timeout 00:19:50) [common] Setting prompt string to ['=>'] bootloader-commands: Wait for prompt ['=>'] (timeout 00:19:50) Hit any key to stop autoboot 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'] Sending with 10 millisecond of delay 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:19:44) setenv autoload no Sending with 10 millisecond of delay setenv initrd_high 0xffffffff => setenv initrd_high 0xffffffff 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:19:43) setenv initrd_high 0xffffffff Sending with 10 millisecond of delay setenv fdt_high 0xffffffff => setenv fdt_high 0xffffffff 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:19:41) setenv fdt_high 0xffffffff Sending with 10 millisecond of delay 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:19:41) dhcp link up on port 0, speed 1000, full duplex BOOTP broadcast 1 BOOTP broadcast 2 BOOTP broadcast 3 DHCP client bound to address 192.168.66.235 (1034 ms) Sending with 10 millisecond of delay 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:19:38) setenv serverip 192.168.66.1 Sending with 10 millisecond of delay tftp 0x82000000 32194/nbd-deploy-4b7psuvy/kernel/zImage => tftp 0x82000000 32194/nbd-deploy-4b7psuvy/kernel/zImage 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:19:34) tftp 0x82000000 32194/nbd-deploy-4b7psuvy/kernel/zImage link up on port 0, speed 1000, full duplex Using cpsw device TFTP from server 192.168.66.1; our IP address is 192.168.66.235 Filename '32194/nbd-deploy-4b7psuvy/kernel/zImage'. Load address: 0x82000000 Loading: *################################################################# ################################################################# ################################################################# ################################################################# ############################################################### 2.6 MiB/s done Bytes transferred = 4736736 (4846e0 hex) Sending with 10 millisecond of delay tftp 0x83000000 32194/nbd-deploy-4b7psuvy/initrd/initramfs-netboot-image-bbe.ext4.gz => tftp 0x83000000 32194/nbd-deploy-4b7psuvy/initrd/initramfs-netboot-image-bbe.ext4.gz 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:19:27) tftp 0x83000000 32194/nbd-deploy-4b7psuvy/initrd/initramfs-netboot-image-bbe.ext4.gz link up on port 0, speed 1000, full duplex Using cpsw device TFTP from server 192.168.66.1; our IP address is 192.168.66.235 Filename '32194/nbd-deploy-4b7psuvy/initrd/initramfs-netboot-image-bbe.ext4.gz'. Load address: 0x83000000 Loading: *################################################################# ################################################## 2.6 MiB/s done Bytes transferred = 1677796 (1999e4 hex) Sending with 10 millisecond of delay 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:19:25) setenv initrd_size ${filesize} Sending with 10 millisecond of delay tftp 0x88000000 32194/nbd-deploy-4b7psuvy/dtb/am335x-sancloud-bbe.dtb => tftp 0x88000000 32194/nbd-deploy-4b7psuvy/dtb/am335x-sancloud-bbe.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:19:21) tftp 0x88000000 32194/nbd-deploy-4b7psuvy/dtb/am335x-sancloud-bbe.dtb link up on port 0, speed 1000, full duplex Using cpsw device TFTP from server 192.168.66.1; our IP address is 192.168.66.235 Filename '32194/nbd-deploy-4b7psuvy/dtb/am335x-sancloud-bbe.dtb'. Load address: 0x88000000 Loading: *####### 2.2 MiB/s done Bytes transferred = 93513 (16d49 hex) Sending with 10 millisecond of delay setenv bootargs 'console=ttyO0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61966 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw' => setenv bootargs 'console=ttyO0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61966 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw' 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:19:06) setenv bootargs 'console=ttyO0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61966 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw' Sending with 10 millisecond of delay bootz 0x82000000 0x83000000:${initrd_size} 0x88000000 => bootz 0x82000000 0x83000000:${initrd_size} 0x88000000 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:19:02) bootz 0x82000000 0x83000000:${initrd_size} 0x88000000 ## Flattened Device Tree blob at 88000000 Booting using the fdt blob at 0x88000000 Using Device Tree in place at 88000000, end 88019d48 Starting kernel ... end: 2.4.3 bootloader-commands (duration 00:00:48) [common] start: 2.4.4 auto-login-action (timeout 00:19: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:20:00) [ 0.000000] Booting Linux on physical CPU 0x0 start: 2.4.4.1 login-action (timeout 00:18: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 ['-\\[ 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', 'root@bbe:~', 'bbe:~#', '/ #', 'login:', 'Login incorrect'] [login-action] Waiting for messages, (timeout 00:18:58) [ 0.000000] Linux version 5.10.100-sc1 (oe-user@oe-host) (arm-agl-linux-gnueabi-gcc (GCC) 11.3.0, GNU ld (GNU Binutils) 2.38.20220708) #1 PREEMPT Mon Jan 30 17:33:20 UTC 2023 [ 0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), cr=10c5387d [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache [ 0.000000] OF: fdt: Machine model: SanCloud BeagleBone Enhanced [ 0.000000] Memory policy: Data cache writeback [ 0.000000] cma: Reserved 256 MiB at 0xb0000000 [ 0.000000] Zone ranges: [ 0.000000] Normal [mem 0x0000000080000000-0x00000000afefffff] [ 0.000000] HighMem [mem 0x00000000aff00000-0x00000000bfffffff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000080000000-0x00000000afefffff] [ 0.000000] node 0: [mem 0x00000000b0000000-0x00000000bfffffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000080000000-0x00000000bfffffff] [ 0.000000] CPU: All CPU(s) started in SVC mode. [ 0.000000] AM335X ES2.1 (sgx neon) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 260162 [ 0.000000] Kernel command line: console=ttyO0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61966 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off [ 0.000000] Memory: 756276K/1047552K available (10240K kernel code, 1180K rwdata, 3432K rodata, 1024K init, 602K bss, 29132K reserved, 262144K cma-reserved, 0K highmem) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 [ 0.000000] rcu: Preemptible hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] Trampoline variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 [ 0.000000] IRQ: Found an INTC at 0x(ptrval) (revision 5.0) with 128 interrupts [ 0.000000] random: get_random_bytes called from start_kernel+0x370/0x544 with crng_init=0 [ 0.000000] TI gptimer clocksource: always-on /ocp/interconnect@44c00000/segment@200000/target-module@31000 [ 0.000010] sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 89478484971ns [ 0.000027] clocksource: dmtimer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns [ 0.000320] TI gptimer clockevent: 24000000 Hz at /ocp/interconnect@48000000/segment@0/target-module@40000 [ 0.001258] Console: colour dummy device 80x30 [ 0.001296] WARNING: Your 'console=ttyO0' has been replaced by 'ttyS0' Matched prompt #6: WARNING: Setting prompt string to ['end trace[^\\r]*\\r', 'root@bbe:~', 'bbe:~#', '/ #', 'login:', 'Login incorrect'] [ 0.001304] This ensures that you still see kernel messages. Please [ 0.001309] update your kernel commandline. [ 0.001368] Calibrating delay loop... 996.14 BogoMIPS (lpj=4980736) [ 0.090393] pid_max: default: 32768 minimum: 301 [ 0.090553] LSM: Security Framework initializing [ 0.090615] SELinux: Initializing. [ 0.090706] LSM support for eBPF active [ 0.090880] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) [ 0.090900] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) [ 0.091835] CPU: Testing write buffer coherency: ok [ 0.091911] CPU0: Spectre v2: using BPIALL workaround [ 0.092831] Setting up static identity map for 0x80100000 - 0x80100060 [ 0.092974] rcu: Hierarchical SRCU implementation. [ 0.093651] devtmpfs: initialized [ 0.106350] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 3 [ 0.106616] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.106640] futex hash table entries: 256 (order: -1, 3072 bytes, linear) [ 0.124449] pinctrl core: initialized pinctrl subsystem [ 0.125721] NET: Registered protocol family 16 [ 0.127859] DMA: preallocated 256 KiB pool for atomic coherent allocations [ 0.145905] l3-aon-clkctrl:0000:0: failed to disable [ 0.146409] audit: initializing netlink subsys (disabled) [ 0.147427] thermal_sys: Registered thermal governor 'fair_share' [ 0.147440] thermal_sys: Registered thermal governor 'bang_bang' [ 0.147455] thermal_sys: Registered thermal governor 'step_wise' [ 0.147462] thermal_sys: Registered thermal governor 'user_space' [ 0.147812] cpuidle: using governor ladder [ 0.147853] cpuidle: using governor menu [ 0.160456] audit: type=2000 audit(0.140:1): state=initialized audit_enabled=0 res=1 [ 1.169471] hw-breakpoint: debug architecture 0x4 unsupported. [ 1.187903] Kprobes globally optimized [ 1.193347] iommu: Default domain type: Translated [ 1.195403] usbcore: registered new interface driver usbfs [ 1.195472] usbcore: registered new interface driver hub [ 1.195527] usbcore: registered new device driver usb [ 1.195989] pps_core: LinuxPPS API ver. 1 registered [ 1.196001] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <[email protected]> [ 1.196026] PTP clock support registered [ 1.196629] Advanced Linux Sound Architecture Driver Initialized. [ 1.197991] clocksource: Switched to clocksource dmtimer [ 1.832280] NET: Registered protocol family 2 [ 1.832562] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 1.833779] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear) [ 1.833815] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) [ 1.833886] TCP bind hash table entries: 8192 (order: 3, 32768 bytes, linear) [ 1.833953] TCP: Hash tables configured (established 8192 bind 8192) [ 1.834097] UDP hash table entries: 512 (order: 1, 8192 bytes, linear) [ 1.834126] UDP-Lite hash table entries: 512 (order: 1, 8192 bytes, linear) [ 1.834247] NET: Registered protocol family 1 [ 1.834787] RPC: Registered named UNIX socket transport module. [ 1.834803] RPC: Registered udp transport module. [ 1.834810] RPC: Registered tcp transport module. [ 1.834817] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.835388] Trying to unpack rootfs image as initramfs... [ 1.835917] rootfs image is not initramfs (no cpio magic); looks like an initrd [ 1.845846] Freeing initrd memory: 1640K [ 1.846431] hw perfevents: enabled with armv7_cortex_a8 PMU driver, 5 counters available [ 1.847948] Initialise system trusted keyrings [ 1.848454] workingset: timestamp_bits=14 max_order=18 bucket_order=4 [ 1.852704] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ 1.853515] NFS: Registering the id_resolver key type [ 1.853572] Key type id_resolver registered [ 1.853581] Key type id_legacy registered [ 1.854525] NET: Registered protocol family 38 [ 1.854549] Key type asymmetric registered [ 1.854559] Asymmetric key parser 'x509' registered [ 1.854635] bounce: pool size: 64 pages [ 1.854693] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 1.854705] io scheduler mq-deadline registered [ 1.854713] io scheduler kyber registered [ 2.311940] debugfs: Directory '49000000.dma' with parent 'dmaengine' already present! [ 2.311988] edma 49000000.dma: TI EDMA DMA engine driver [ 2.330699] pinctrl-single 44e10800.pinmux: 142 pins, size 568 [ 2.339596] Serial: 8250/16550 driver, 6 ports, IRQ sharing enabled [ 2.343069] 44e09000.serial: ttyS0 at MMIO 0x44e09000 (irq = 20, base_baud = 3000000) is a 8250 [ 2.489137] random: fast init done [ 3.045426] printk: console [ttyS0] enabled [ 3.053085] omap_rng 48310000.rng: Random Number Generator ver. 20 [ 3.059621] random: crng init done [ 3.081653] brd: module loaded [ 3.092628] loop: module loaded [ 3.198091] davinci_mdio 4a101000.mdio: davinci mdio revision 1.6, bus freq 1000000 [ 3.208392] davinci_mdio 4a101000.mdio: phy[0]: device 4a101000.mdio:00, driver Qualcomm Atheros AR8035 [ 3.218551] cpsw-switch 4a100000.switch: initialized cpsw ale version 1.4 [ 3.225380] cpsw-switch 4a100000.switch: ALE Table size 1024 [ 3.231313] cpsw-switch 4a100000.switch: cpts: overflow check period 500 (jiffies) [ 3.238964] cpsw-switch 4a100000.switch: CPTS: ref_clk_freq:250000000 calc_mult:2147483648 calc_shift:29 error:0 nsec/sec [ 3.250085] cpsw-switch 4a100000.switch: Detected MACID = 04:79:b7:f0:e8:bf [ 3.258074] cpsw-switch 4a100000.switch: initialized (regs 0x4a100000, pool size 256) hw_ver:0019010C 1.12 (0) [ 3.269404] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 3.275970] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 3.282442] usbcore: registered new interface driver usbserial_generic [ 3.289056] usbserial: USB Serial support registered for generic [ 3.295115] usbcore: registered new interface driver cp210x [ 3.300745] usbserial: USB Serial support registered for cp210x [ 3.308620] omap_rtc 44e3e000.rtc: registered as rtc0 [ 3.313737] omap_rtc 44e3e000.rtc: setting system clock to 2000-01-01T00:00:00 UTC (946684800) [ 3.322788] i2c /dev entries driver [ 3.326385] usbcore: registered new interface driver i2c-tiny-usb [ 3.334490] cpuidle: enable-method property 'ti,am3352' found operations [ 3.341953] sdhci: Secure Digital Host Controller Interface driver [ 3.348205] sdhci: Copyright(c) Pierre Ossman [ 3.353539] sdhci-pltfm: SDHCI platform and OF driver helper [ 3.361314] sdhci-omap 481d8000.mmc: supply vqmmc not found, using dummy regulator [ 3.369876] ledtrig-cpu: registered to indicate activity on CPUs [ 3.389266] usbcore: registered new interface driver usbhid [ 3.394878] usbhid: USB HID core driver [ 3.408288] remoteproc remoteproc0: wkup_m3 is available [ 3.415336] usbcore: registered new interface driver snd-usb-audio [ 3.427371] NET: Registered protocol family 17 [ 3.432838] Key type dns_resolver registered [ 3.437273] omap_voltage_late_init: Voltage driver support not added [ 3.444541] Loading compiled-in X.509 certificates [ 3.456620] mmc1: SDHCI controller on 481d8000.mmc [481d8000.mmc] using External DMA [ 3.475330] OMAP GPIO hardware version 0.1 [ 3.482235] at24 0-0050: supply vcc not found, using dummy regulator [ 3.518184] at24 0-0050: 32768 byte 24c256 EEPROM, writable, 1 bytes/write [ 3.526761] usb251xb 0-002c: supply vdd not found, using dummy regulator [ 3.534450] usb251xb 0-002c: configuring block 0 failed: -121 [ 3.540306] usb251xb 0-002c: Failed to connect hub (-121) [ 3.546021] usb251xb: probe of 0-002c failed with error -121 [ 3.552628] mmc1: new high speed MMC card at address 0001 [ 3.558352] omap_i2c 44e0b000.i2c: bus 0 rev0.11 at 400 kHz [ 3.565653] mmcblk1: mmc1:0001 Q2J54A 3.64 GiB [ 3.571532] mmcblk1boot0: mmc1:0001 Q2J54A partition 1 2.00 MiB [ 3.577759] mmcblk1boot1: mmc1:0001 Q2J54A partition 2 2.00 MiB [ 3.584819] at24 2-0054: supply vcc not found, using dummy regulator [ 3.591930] mmcblk1rpmb: mmc1:0001 Q2J54A partition 3 512 KiB, chardev (245:0) [ 3.622100] at24 2-0055: supply vcc not found, using dummy regulator [ 3.660903] at24 2-0056: supply vcc not found, using dummy regulator [ 3.691240] at24 2-0057: supply vcc not found, using dummy regulator [ 3.731205] omap_i2c 4819c000.i2c: bus 2 rev0.11 at 100 kHz [ 3.744433] remoteproc remoteproc1: 4a334000.pru is available [ 3.751625] remoteproc remoteproc2: 4a338000.pru is available [ 3.761128] omap_gpio 44e07000.gpio: Could not set line 6 debounce to 200000 microseconds (-22) [ 3.771463] tda998x 0-0070: Error -121 writing to cec:0xff [ 3.777014] sdhci-omap 48060000.mmc: Got CD GPIO [ 3.781715] tda998x 0-0070: set_page 000a err -121 [ 3.787215] sdhci-omap 48060000.mmc: supply vqmmc not found, using dummy regulator [ 3.847504] mmc0: SDHCI controller on 48060000.mmc [48060000.mmc] using External DMA [ 3.855475] tda998x 0-0070: set_page 000a err -121 [ 3.893568] mmc0: new high speed SDHC card at address 5048 [ 3.899898] mmcblk0: mmc0:5048 SD16G 14.4 GiB [ 3.906633] mmcblk0: p1 [ 3.928090] tda998x 0-0070: set_page 0001 err -121 [ 3.932971] tda998x 0-0070: set_page 0001 err -121 [ 3.937831] tda998x 0-0070: set_page 0200 err -121 [ 3.942733] tda998x 0-0070: set_page 0201 err -121 [ 3.947593] tda998x 0-0070: set_page 0202 err -121 [ 3.952493] tda998x 0-0070: set_page 0203 err -121 [ 3.957351] tda998x 0-0070: set_page 0204 err -121 [ 3.962238] tda998x 0-0070: set_page 0205 err -121 [ 3.967096] tda998x 0-0070: set_page 020e err -121 [ 3.971975] tda998x 0-0070: set_page 0211 err -121 [ 3.976833] tda998x 0-0070: set_page 0207 err -121 [ 3.981704] tda998x 0-0070: set_page 0208 err -121 [ 3.986561] tda998x 0-0070: set_page 0209 err -121 [ 3.991430] tda998x 0-0070: set_page 020a err -121 [ 3.996287] tda998x 0-0070: set_page 0206 err -121 [ 4.001156] tda998x 0-0070: set_page 0027 err -121 [ 4.006015] tda998x 0-0070: set_page 0000 err -121 [ 4.010838] tda998x 0-0070: failed to read version: -121 [ 4.016247] tda998x: probe of 0-0070 failed with error -121 [ 4.024143] cpsw-switch 4a100000.switch: starting ndev. mode: dual_mac [ 4.110595] Qualcomm Atheros AR8035 4a101000.mdio:00: attached PHY driver [Qualcomm Atheros AR8035] (mii_bus:phy_addr=4a101000.mdio:00, irq=POLL) [ 7.289317] cpsw-switch 4a100000.switch eth0: Link is Up - 1Gbps/Full - flow control off [ 7.327995] Sending DHCP requests .., OK [ 10.311995] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.235 [ 10.319974] IP-Config: Complete: [ 10.323219] device=eth0, hwaddr=04:79:b7:f0:e8:bf, ipaddr=192.168.66.235, mask=255.255.255.0, gw=192.168.66.1 [ 10.333621] host=192.168.66.235, domain=, nis-domain=(none) [ 10.339660] bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath= [ 10.339666] nameserver0=10.1.1.1 [ 10.350076] ALSA device list: [ 10.353068] No soundcards found. [ 10.356871] Waiting 7 sec before mounting root device... [ 17.768228] RAMDISK: gzip image found at block 0 [ 17.969245] EXT4-fs (ram0): mounted filesystem with ordered data mode. Opts: (null) [ 17.977052] VFS: Mounted root (ext4 filesystem) on device 1:0. [ 17.983328] devtmpfs: mounted [ 17.987972] Freeing unused kernel memory: 1024K [ 17.993206] Run /sbin/init as init process ________________________________________________________________________________ ___ ________ _ __ __ __ __ / | / ____/ / / | / /__ / /_/ /_ ____ ____ / /_ / /| |/ / __/ / ______ / |/ / _ \/ __/ __ \/ __ \/ __ \/ __/ / ___ / /_/ / /___ /_____/ / /| / __/ /_/ /_/ / /_/ / /_/ / /_ /_/ |_\____/_____/ /_/ |_/\___/\__/_.___/\____/\____/\__/ ________________________________________________________________________________ /sbin/init[1]: starting initrd script /sbin/init[1]: mounting FS: proc /proc /sbin/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.66.1:61966 /sbin/init[1]: Starting NBD client /sbin/init[1]: NBD client successfully started [ 18.290667] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) /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' /sbin/init[1]: Unmounting /tmp and /run /sbin/init[1]: Exec'ing systemd ________________________________________________________________________________ ___ ________ ____ __ _ / | / ____/ / / __ )____ ____ / /_(_)___ ____ _ / /| |/ / __/ / / __ / __ \/ __ \/ __/ / __ \/ __ `/ / ___ / /_/ / /___ / /_/ / /_/ / /_/ / /_/ / / / / /_/ / _ _ _ /_/ |_\____/_____/ /_____/\____/\____/\__/_/_/ /_/\__, / (_) (_) (_) _____________________________________________________/____/_____________________ [ 19.666391] SELinux: Class rpmsg_socket not defined in policy. [ 19.672493] SELinux: the above unknown classes and permissions will be allowed [ 19.692612] SELinux: policy capability network_peer_controls=1 [ 19.698753] SELinux: policy capability open_perms=1 [ 19.703741] SELinux: policy capability extended_socket_class=1 [ 19.709733] SELinux: policy capability always_check_network=0 [ 19.715590] SELinux: policy capability cgroup_seclabel=1 [ 19.721040] SELinux: policy capability nnp_nosuid_transition=1 [ 19.726982] SELinux: policy capability genfs_seclabel_symlinks=0 [ 19.828155] audit: type=1403 audit(946684817.010:2): auid=4294967295 ses=4294967295 lsm=selinux res=1 [ 19.861279] systemd[1]: Successfully loaded SELinux policy in 570.158ms. [ 20.051920] systemd[1]: System time before build time, advancing clock. [ 20.218238] audit: type=1400 audit(1675100000.160:3): avc: denied { confidentiality } for pid=1 comm=\"systemd\" lockdown_reason=\"use of tracefs\" scontext=system_u:system_r:init_t:s0 tcontext=system_u:system_r:init_t:s0 tclass=lockdown permissive=1 [ 20.241451] NET: Registered protocol family 10 [ 20.250728] Segment Routing with IPv6 [ 20.582324] systemd[1]: Relabelled /dev, /dev/shm, /run, /sys/fs/cgroup in 246.200ms. [ 20.647605] systemd[1]: systemd 250.5+ 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 -BZIP2 -LZ4 -XZ -ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=hybrid) [ 20.680018] systemd[1]: Detected architecture arm. Welcome to Automotive Grade Linux 15.90.0+snapshot-65dafea22018052fe7b2e17e6e4d7eb754224d38 (pike)! [ 20.760923] systemd[1]: Hostname set to <bbe>. [ 20.785073] systemd[1]: Initializing machine ID from random generator. [ 21.939482] systemd[1]: Queued start job for default target Multi-User System. [ 22.004188] systemd[1]: Created slice Slice /system/getty. [ OK ] Created slice Slice /system/getty. [ 22.042646] systemd[1]: Created slice Slice /system/modprobe. [ OK ] Created slice Slice /system/modprobe. [ 22.082501] systemd[1]: Created slice Slice /system/serial-getty. [ OK ] Created slice Slice /system/serial-getty. [ 22.121852] systemd[1]: Created slice User and Session Slice. [ OK ] Created slice User and Session Slice. [ 22.160385] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 22.200232] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ 22.238885] systemd[1]: Reached target Host and Network Name Lookups. [ OK ] Reached target Host and Network Name Lookups. [ 22.278323] systemd[1]: Reached target Path Units. [ OK ] Reached target Path Units. [ 22.308401] systemd[1]: Reached target Remote File Systems. [ OK ] Reached target Remote File Systems. [ 22.348273] systemd[1]: Reached target Slice Units. [ OK ] Reached target Slice Units. [ 22.378409] systemd[1]: Reached target Swaps. [ OK ] Reached target Swaps. [ 22.426990] systemd[1]: Listening on Process Core Dump Socket. [ OK ] Listening on Process Core Dump Socket. [ 22.460499] systemd[1]: Listening on initctl Compatibility Named Pipe. [ OK ] Listening on initctl Compatibility Named Pipe. [ 22.502068] systemd[1]: Listening on Journal Audit Socket. [ OK ] Listening on Journal Audit Socket. [ 22.545485] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 22.581471] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 22.621268] systemd[1]: Listening on Network Service Netlink Socket. [ OK ] Listening on Network Service Netlink Socket. [ 22.667466] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 22.700572] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 22.743315] systemd[1]: Listening on User Database Manager Socket. [ OK ] Listening on User Database Manager Socket. [ 22.779622] systemd[1]: Huge Pages File System was skipped because of a failed condition check (ConditionPathExists=/sys/kernel/mm/hugepages). [ 22.805213] systemd[1]: Mounting POSIX Message Queue File System... Mounting POSIX Message Queue File System... [ 22.861634] systemd[1]: Mounting Kernel Debug File System... Mounting Kernel Debug File System... [ 22.893488] systemd[1]: Mounting Kernel Trace File System... Mounting Kernel Trace File System... [ 22.952583] systemd[1]: Mounting Temporary Directory /tmp... Mounting Temporary Directory /tmp... [ 23.010569] systemd[1]: Starting Create List of Static Device Nodes... Starting Create List of Static Device Nodes... [ 23.045604] systemd[1]: Starting Load Kernel Module configfs... Starting Load Kernel Module configfs... [ 23.109637] systemd[1]: Starting Load Kernel Module drm... Starting Load Kernel Module drm... [ 23.161352] systemd[1]: Starting Load Kernel Module fuse... Starting Load Kernel Module fuse... [ 23.202923] systemd[1]: Starting SELinux autorelabel service loading... [ 23.217276] fuse: init (API version 7.32) Starting SELinux autorelabel service loading... [ 23.287080] systemd[1]: Starting SELinux init for /dev service loading... Starting SELinux init for /dev service loading... [ 23.327209] systemd[1]: File System Check on Root Device was skipped because of a failed condition check (ConditionPathIsReadWrite=!/). [ 23.439003] systemd[1]: Starting Journal Service... Starting Journal Service... [ 23.483696] systemd[1]: Load Kernel Modules was skipped because all trigger condition checks failed. [ 23.552358] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... [ 23.667533] systemd[1]: Starting Apply Kernel Variables... Starting Apply Kernel Variables... [ 23.816288] EXT4-fs (nbd0): re-mounted. Opts: (null) [ 23.844925] systemd[1]: Starting Coldplug All udev Devices... Starting Coldplug All udev Devices... [ 23.972014] audit: type=1400 audit(1675100003.910:4): avc: denied { read } for pid=155 comm=\"systemd-journal\" name=\"machine-id\" dev=\"nbd0\" ino=140 scontext=system_u:system_r:syslogd_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=file permissive=1 [ 24.054599] systemd[1]: Mounted POSIX Message Queue File System. [ OK ] Mounted POSIX Message Queue File System.[ 24.111221] audit: type=1400 audit(1675100003.950:5): avc: denied { open } for pid=155 comm=\"systemd-journal\" path=\"/etc/machine-id\" dev=\"nbd0\" ino=140 scontext=system_u:system_r:syslogd_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=file permissive=1 [ 24.170273] systemd[1]: Mounted Kernel Debug File System. [ OK ] Mounted Kernel Debug File System. [ 24.209691] systemd[1]: Mounted Kernel Trace File System. [ OK ] Mounted Kernel Trace File System. [ 24.238602] systemd[1]: Mounted Temporary Directory /tmp. [ OK ] Mounted Temporary Directory /tmp. [ 24.278823] systemd[1]: Finished Create List of Static Device Nodes. [ OK ] Finished Create List of Static Device Nodes. [ 24.309533] audit: type=1130 audit(1675100004.250:6): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=kmod-static-nodes comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 24.334721] systemd[1]: [email protected]: Deactivated successfully. [ 24.380420] systemd[1]: Finished Load Kernel Module configfs. [ OK ] Finished Load Kernel Module configfs. [ 24.421319] systemd[1]: [email protected]: Deactivated successfully. [ 24.428636] audit: type=1130 audit(1675100004.360:7): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@configfs comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 24.480508] systemd[1]: Finished Load Kernel Module drm. [ OK ] Finished Load Kernel Module drm. [ 24.501401] systemd[1]: [email protected]: Deactivated successfully. [ 24.519136] audit: type=1131 audit(1675100004.360:8): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@configfs comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 24.568507] systemd[1]: Finished Load Kernel Module fuse. [ OK ] Finished Load Kernel Module fuse. [ 24.593171] systemd[1]: selinux-autorelabel.service: Deactivated successfully. [ 24.628233] audit: type=1130 audit(1675100004.440:9): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@drm comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 24.670796] systemd[1]: Finished SELinux autorelabel service loading. [ OK ] Finished SELinux autorelabel service loading. [ 24.712073] systemd[1]: Finished Remount Root and Kernel File Systems. [ 24.748537] audit: type=1131 audit(1675100004.440:10): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@drm comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished Remount Root and Kernel File Systems. [ 24.802415] systemd[1]: Finished Apply Kernel Variables. [ OK ] Finished Apply Kernel Variables. [ 24.837776] audit: type=1130 audit(1675100004.530:11): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@fuse comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 24.901628] systemd[1]: Mounting FUSE Control File System... Mounting FUSE Control File System... [ 24.948511] audit: type=1131 audit(1675100004.530:12): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@fuse comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 24.999269] systemd[1]: Mounting Kernel Configuration File System... Mounting Kernel Configuration File System... [ 25.040744] audit: type=1130 audit(1675100004.650:13): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=selinux-autorelabel comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 25.066300] systemd[1]: Rebuild Hardware Database was skipped because all trigger condition checks failed. [ 25.109040] systemd[1]: Platform Persistent Storage Archival was skipped because of a failed condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). [ 25.148241] audit: type=1131 audit(1675100004.650:14): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=selinux-autorelabel comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 25.202293] systemd[1]: Starting Create System Users... Starting Create System Users... [ 25.239428] audit: type=1130 audit(1675100004.740:15): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-remount-fs comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 25.358250] audit: type=1130 audit(1675100004.800:16): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-sysctl comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 25.385426] systemd[1]: selinux-labeldev.service: Deactivated successfully. [ 25.440609] systemd[1]: Finished SELinux init for /dev service loading. [ OK ] Finished SELinux init for /dev service loading. [ 25.468291] audit: type=1400 audit(1675100005.360:17): avc: denied { getattr } for pid=174 comm=\"systemd-sysuser\" name=\"/\" dev=\"tmpfs\" ino=1 scontext=system_u:system_r:systemd_sysusers_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=filesystem permissive=1 [ 25.494174] systemd[1]: Mounted FUSE Control File System. [ OK ] Mounted FUSE Control File System. [ 25.559643] systemd[1]: Mounted Kernel Configuration File System. [ OK ] Mounted Kernel Configuration File System. [ 25.579343] audit: type=1400 audit(1675100005.360:18): avc: denied { search } for pid=174 comm=\"systemd-sysuser\" name=\"/\" dev=\"tmpfs\" ino=1 scontext=system_u:system_r:systemd_sysusers_t:s0 tcontext=system_u:object_r:cgroup_t:s0 tclass=dir permissive=1 [ 25.675785] audit: type=1400 audit(1675100005.360:18): avc: denied { getattr } for pid=174 comm=\"systemd-sysuser\" name=\"/\" dev=\"cgroup2\" ino=1 scontext=system_u:system_r:systemd_sysusers_t:s0 tcontext=system_u:object_r:cgroup_t:s0 tclass=filesystem permissive=1 [ 25.767215] audit: type=1130 audit(1675100005.430:19): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=selinux-labeldev comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 25.827005] systemd[1]: Finished Create System Users. [ OK ] Finished Create System Users. [ 25.858349] audit: type=1131 audit(1675100005.430:20): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=selinux-labeldev comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 25.912577] systemd[1]: Starting Create Static Device Nodes in /dev... Starting Create Static Device Nodes in /dev... [ 26.261370] systemd[1]: Started Journal Service. [ OK ] Started Journal Service. Starting Flush Journal to Persistent Storage... [ OK ] Finished Create Static Device Nodes in /dev. [ OK ] Reached target Preparation for Local File Systems. Mounting /var/volatile... [ 26.559202] systemd-journald[155]: Received client request to flush runtime journal. Starting Rule-based Manager for Device Events and Files... [ OK ] Finished Flush Journal to Persistent Storage. [ OK ] Mounted /var/volatile. Starting Load/Save 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 Random Seed. [ OK ] Finished SELinux init service loading. Starting Generated file SELinux relabeling... [ OK ] Finished SELinux resolv.conf relabeling. [ OK ] Started Rule-based Manager for Device Events and Files. [ OK ] Finished Rebuild Dynamic Linker Cache. [ 32.123930] inv-mpu6050-i2c 0-0068: mounting matrix not found: using identity... [ 32.148289] tps65217-pmic: Failed to locate of_node [id: -1] [ 32.154333] tps65217-bl: Failed to locate of_node [id: -1] [ 32.209217] st-press-i2c 0-005c: supply vdd not found, using dummy regulator [ 32.216613] st-press-i2c 0-005c: supply vddio not found, using dummy regulator [ 32.274248] inv-mpu6050-i2c 0-0068: supply vdd not found, using dummy regulator [ 32.323501] omap_wdt: OMAP Watchdog Timer Rev 0x01: initial timeout 60 sec [ 32.348554] tps65217 0-0024: TPS65217 ID 0xe version 1.2 [ 32.361626] inv-mpu6050-i2c 0-0068: supply vddio not found, using dummy regulator [ 32.390475] iio iio:device1: failed to read Who-Am-I register. [ 32.396740] st-press-i2c: probe of 0-005c failed with error -121 [ 32.573609] inv-mpu6050-i2c: probe of 0-0068 failed with error -121 [ 32.945921] am335x-phy-driver 47401300.usb-phy: supply vcc not found, using dummy regulator [ 33.331531] am335x-phy-driver 47401b00.usb-phy: supply vcc not found, using dummy regulator [ 33.459374] davinci-mcasp 48038000.mcasp: IRQ common not found [ 33.539359] musb-hdrc musb-hdrc.1: MUSB HDRC host driver [ 33.544754] musb-hdrc musb-hdrc.1: new USB bus registered, assigned bus number 1 [ 33.708544] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10 [ 33.716870] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 33.892020] usb usb1: Product: MUSB HDRC host driver [ 33.926411] usb usb1: Manufacturer: Linux 5.10.100-sc1 musb-hcd [ 34.028441] usb usb1: SerialNumber: musb-hdrc.1 [ 34.056047] hub 1-0:1.0: USB hub found [ 34.068330] hub 1-0:1.0: 1 port detected [ 34.568181] usb 1-1: new high-speed USB device number 2 using musb-hdrc [ 34.788632] usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3 [ 34.796875] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 34.895352] omap-sham 53100000.sham: hw accel on OMAP rev 4.3 [ 34.903348] omap-aes 53500000.aes: OMAP AES hw accel rev: 3.2 [ 35.019190] hub 1-1:1.0: USB hub found [ 35.038165] omap-aes 53500000.aes: will run requests pump with realtime priority [ 35.045703] omap-sham 53100000.sham: will run requests pump with realtime priority [ 35.083730] hub 1-1:1.0: 4 ports detected [ 35.197852] pvrsrvkm: loading out-of-tree module taints kernel. [ 35.421613] [drm] Initialized pvr 1.17.4948957 20110701 for 56000000.gpu on minor 0 [ 36.481981] kauditd_printk_skb: 17 callbacks suppressed [ 36.481994] audit: type=1334 audit(1675100016.420:36): prog-id=7 op=LOAD [ 36.578972] audit: type=1334 audit(1675100016.440:37): prog-id=8 op=LOAD [ 36.645175] audit: type=1334 audit(1675100016.440:38): prog-id=3 op=UNLOAD [ 36.729389] audit: type=1334 audit(1675100016.440:39): prog-id=4 op=UNLOAD [ 36.813241] audit: type=1334 audit(1675100016.500:40): prog-id=9 op=LOAD [ OK ] Finished Coldplug All udev Devices. [ 36.889288] audit: type=1334 audit(1675100016.500:41): prog-id=10 op=LOAD [ OK ] Finished Create Volatile Files and Directories. [ 36.975763] audit: type=1334 audit(1675100016.500:42): prog-id=5 op=UNLOAD [ OK ] Finished Generated file SELinux relabeling. [ 37.046312] audit: type=1334 audit(1675100016.500:43): prog-id=6 op=UNLOAD [ 37.113681] audit: type=1130 audit(1675100016.820:44): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-udev-trigger comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 37.339431] audit: type=1130 audit(1675100016.870:45): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-tmpfiles-setup comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 37.882456] tps6521x_pwrbutton tps65217-pwrbutton: DMA mask not set [ 37.903908] tps65217-charger tps65217-charger: DMA mask not set [ 37.949169] input: tps65217_pwrbutton as /devices/platform/ocp/44c00000.interconnect/44c00000.interconnect:segment@200000/44e0b000.target-module/44e0b000.i2c/i2c-0/0-0024/tps65217-pwrbutton/input/input0 [ 37.978401] genirq: Flags mismatch irq 74. 00002000 (tps65217-charger) vs. 00002000 (vbus) [ 38.028556] tps65217-charger tps65217-charger: Unable to register irq 74 err -16 [ 38.118685] tps65217-charger: probe of tps65217-charger failed with error -16 [ OK ] Reached target Hardware activated USB gadget. [ OK ] Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Starting Security Auditing Service... Starting Rebuild Journal Catalog... Starting Wait for udev To Complete Device Initialization... [ OK ] Finished Rebuild Journal Catalog. [ OK ] Finished Wait for udev To Complete Device Initialization. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Update is Completed... [ OK ] Started Security Auditing Service. Starting Record System Boot/Shutdown in UTMP... [ OK ] Finished Update is Completed. [ OK ] Finished Record System Boot/Shutdown in UTMP. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timer Units. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Listening on GPS (Global Positioning System) Daemon Sockets. Starting sshd.socket... [ OK ] Listening on sshd.socket. [ OK ] Reached target Socket Units. [ OK ] Reached target Basic System. Starting D-Bus System Message Bus... Starting IPv6 Packet Filtering Framework... Starting IPv4 Packet Filtering Framework... Starting Telephony service... Starting User Login Management... Starting OpenSSH Key Generation... [ OK ] Started D-Bus System Message Bus. [ OK ] Finished IPv6 Packet Filtering Framework. [ 41.759084] Bluetooth: Core ver 2.22 [ OK ] Finished IPv4 Packet Filtering Framework.[ 41.788730] NET: Registered protocol family 31 [ OK ] Reached target Preparation for Network.[ 41.829646] Bluetooth: HCI device and connection manager initialized [ 41.878317] Bluetooth: HCI socket layer initialized [ 41.883246] Bluetooth: L2CAP socket layer initialized Starting Connection service... [ 41.958420] Bluetooth: SCO socket layer initialized Starting Network Configuration... [ OK ] Started Telephony service. [ OK ] Started Connection service. Starting WPA supplicant... Starting Hostname Service... [ OK ] Started User Login Management. [ OK ] Started WPA supplicant. [ 44.381123] cfg80211: Loading compiled-in X.509 certificates for regulatory database [ 44.470818] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' [ 44.493244] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 [ 44.525727] cfg80211: failed to load regulatory.db [ OK ] Started Network Configuration. [ OK ] Reached target Network. Starting Permit User Sessions... [ OK ] Finished Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Reached target Multi-User System. Starting Record Runlevel Change in UTMP... [ OK ] Finished Record Runlevel Change in UTMP. [ OK ] Started Hostname Service. Automotive Grade Linux 15.90.0+snapshot-65dafea22018052fe7b2e17e6e4d7eb754224d38 bbe ttyS0 Unable to match end of the kernel message case: kernel-messages
case_id: 3885709
definition: lava
duration: 49.08
extra: ...
level: 2.4.4.1
namespace: common
result: pass
Sending username root Sending with 10 millisecond of delay root bbe login: root Setting prompt string to ['root@bbe:~', 'bbe:~#', '/ #'] login-action: Wait for prompt ['root@bbe:~', 'bbe:~#', '/ #', 'Login incorrect', 'Login timed out'] (timeout 00:18:08) root Setting prompt string to ['root@bbe:~', 'bbe:~#', '/ #'] end: 2.4.4.1 login-action (duration 00:00:57) [common] case: login-action
case_id: 3885710
definition: lava
duration: 56.63
extra: ...
level: 2.4.4.1
namespace: common
result: pass
end: 2.4.4 auto-login-action (duration 00:01:01) [common] start: 2.4.5 expect-shell-connection (timeout 00:18:01) [common] Setting prompt string to ['root@bbe:~', 'bbe:~#', '/ #'] Forcing a shell prompt, looking for ['root@bbe:~', 'bbe:~#', '/ #'] 7[r[999;999H[6nroot@bbe:~# expect-shell-connection: Wait for prompt ['root@bbe:~', 'bbe:~#', '/ #'] (timeout 00:20:00) Waiting using forced prompt support (timeout 00:10:00) end: 2.4.5 expect-shell-connection (duration 00:00:00) [common] start: 2.4.6 overlay-unpack (timeout 00:18:01) [common] Sending with 10 millisecond of delay rm overlay-1.5.5.tar.gz root@bbe:~# 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 Sending with 10 millisecond of delay wget http://192.168.66.1/tmp/32194/compress-overlay-iubj79vr/overlay-1.5.5.tar.gz root@bbe:~# wget http://192.168.66.1/tmp/32194/compress-overlay-iubj79vr/overlay-1.5.5.tar.gz wget http://192.168.66.1/tmp/32194/compress-overlay-iubj79vr/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% |********************************| 7730 0:00:00 ETA 'overlay-1.5.5.tar.gz' saved Sending with 10 millisecond of delay tar -C / -xvpf overlay-1.5.5.tar.gz root@bbe:~# tar -C / -xvpf overlay-1.5.5.tar.gz tar -C / -xvpf overlay-1.5.5.tar.gz x lava-32194/ x lava-32194/0/ x lava-32194/0/lava-test-runner.conf x lava-32194/0/tests/ x lava-32194/0/tests/0_check_disk_space/ x lava-32194/0/tests/0_check_disk_space/README x lava-32194/0/tests/0_check_disk_space/check_space.sh x lava-32194/0/tests/0_check_disk_space/check_space.yaml x lava-32194/0/tests/0_check_disk_space/run.sh x lava-32194/0/tests/0_check_disk_space/testdef.yaml x lava-32194/0/tests/0_check_disk_space/testdef_metadata x lava-32194/0/tests/0_check_disk_space/uuid x lava-32194/bin/ x lava-32194/bin/lava-add-keys x lava-32194/bin/lava-add-sources x lava-32194/bin/lava-background-process-start x lava-32194/bin/lava-background-process-stop x lava-32194/bin/lava-common-functions x lava-32194/bin/lava-echo-ipv4 x lava-32194/bin/lava-install-packages x lava-32194/bin/lava-installed-packages x lava-32194/bin/lava-os-build x lava-32194/bin/lava-probe-channel x lava-32194/bin/lava-probe-ip x lava-32194/bin/lava-target-ip x lava-32194/bin/lava-target-mac x lava-32194/bin/lava-target-storage x lava-32194/bin/lava-test-case x lava-32194/bin/lava-test-event x lava-32194/bin/lava-test-feedback x lava-32194/bin/lava-test-raise x lava-32194/bin/lava-test-reference x lava-32194/bin/lava-test-runner x lava-32194/bin/lava-test-set x lava-32194/bin/lava-test-shell x lava-32194/environment x lava-32194/lava x lava-32194/lava.pub x lava-32194/results/ x lava-32194/tests/ end: 2.4.6 overlay-unpack (duration 00:00:09) [common] start: 2.4.7 export-device-env (timeout 00:17:52) [common] end: 2.4.7 export-device-env (duration 00:00:00) [common] end: 2.4 uboot-commands (duration 00:02:05) [common] end: 2 uboot-action (duration 00:02:08) [common] start: 3 lava-test-retry (timeout 00:15:00) [common] start: 3.1 lava-test-shell (timeout 00:15:00) [common] Using namespace: common # root@bbe:~# # lava-test-shell: Wait for prompt ['root@bbe:~', 'bbe:~#', '/ #'] (timeout 00:15:00) # Using /lava-32194 export SHELL=/bin/sh root@bbe:~# export SHELL=/bin/sh export SHELL=/bin/sh . /lava-32194/environment root@bbe:~# . /lava-32194/environment . /lava-32194/environment /lava-32194/bin/lava-test-runner /lava-32194/0 root@bbe:~# /lava-32194/bin/lava-test-runner /lava-32194/0 Test shell timeout: 900s (minimum of the action and connection timeout) /lava-32194/bin/lava-test-runner /lava-32194/0 + export TESTRUN_ID=0_check_disk_space + TESTRUN_ID=0_check_disk_space + cd /lava-32194/0/tests/0_check_disk_space ++ cat uuid + UUID=32194_1.5.4.1 + set +x <LAVA_SIGNAL_STARTRUN 0_check_disk_space 32194_1.5.4.1> + ./check_space.sh Space info in /usr: Received signal: <STARTRUN> 0_check_disk_space 32194_1.5.4.1 Starting test lava.0_check_disk_space (32194_1.5.4.1) Skipping test definition patterns. Filesystem Size Used Avail Use% Mounted on /dev/nbd0 2.4G 1.6G 710M 69% / Space info in /var/run Filesystem Size Used Avail Use% Mounted on tmpfs 200M 9.0M 191M 5% /run + set +x <LAVA_SIGNAL_ENDRUN 0_check_disk_space 32194_1.5.4.1> <LAVA_TEST_RUNNER EXIT> Received signal: <ENDRUN> 0_check_disk_space 32194_1.5.4.1 Ending use of test pattern. Ending test lava.0_check_disk_space (32194_1.5.4.1), duration 0.05 case: 0_check_disk_space
case_id: 3885711
commit_id: e4513698c438fef88cabd871178580a0c36ed5ce
definition: lava
duration: 0.06
namespace: common
path: ./check_space.yaml
repository: https://github.com/duerpei/yan_test.git
result: pass
revision: unspecified
uuid: 32194_1.5.4.1
ok: lava_test_shell seems to have completed end: 3.1 lava-test-shell (duration 00:00:01) [common] end: 3 lava-test-retry (duration 00:00:01) [common] start: 4 finalize (timeout 00:30:00) [common] start: 4.1 power-off (timeout 00:00:10) [common] Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '4' >> Success Returned 0 in 3 seconds end: 4.1 power-off (duration 00:00:04) [common] case: power-off
case_id: 3885712
definition: lava
duration: 3.55
extra: ...
level: 4.1
namespace: common
result: pass
start: 4.2 read-feedback (timeout 00:29:56) [common] Listened to connection for namespace 'common' for up to 1s Listened to connection for namespace 'common' for up to 1s Finalising connection for namespace 'common' Disconnecting from shell: Finalise root@bbe:~# [ end: 4.2 read-feedback (duration 00:00:01) [common] lava-xnbd cleanup clean NBD port 61966 end: 4 finalize (duration 00:00:08) [common] Cleaning after the job Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32194/nbd-deploy-4b7psuvy/initrd Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32194/nbd-deploy-4b7psuvy/kernel Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32194/nbd-deploy-4b7psuvy/dtb Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32194/nbd-deploy-4b7psuvy/nbdroot Override tmp directory removed at /var/lib/lava/dispatcher/tmp/32194 Root tmp directory removed at /var/lib/lava/dispatcher/tmp/32194 Job finished correctly case: job
case_id: 3885713
definition: lava
result: pass