Help
Description
[lavafed 2019.04.0032.g55afae484] b2260 - health-check
Device-type
b2260
Submitter
Rémi Duraffort
Created
1 week, 4 days ago
Priority
Medium
Visibility
Publicly visible
Required Tags
staging.validation.linaro.org
#466
Complete
Device
staging-b2260-01@staging.validation.linaro.org
Started
1 week, 4 days ago
Duration
1 minute
Results
  
lava-dispatcher, installed at version: 2019.04.0032.g55afae484+stretch start: 0 validate Start time: 2019-05-15 09:07:37.084163+00:00 (UTC) Validating that http://images.validation.linaro.org/storage.kernelci.org/images/rootfs/buildroot/armel/rootfs.cpio.gz exists Validating that https://images.validation.linaro.org/builds.96boards.org/snapshots/b2260/linaro/debian/21/uImage exists Validating that https://images.validation.linaro.org/builds.96boards.org/snapshots/b2260/linaro/debian/21/stih410-b2260.dtb exists validate duration: 0.11 case: validate
case_id: 10066
definition: lava
result: pass
start: 1 tftp-deploy (timeout 00:04:00) [common] start: 1.1 download-retry (timeout 00:04:00) [common] start: 1.1.1 http-download (timeout 00:04:00) [common] Not decompressing ramdisk as can be used compressed. downloading http://images.validation.linaro.org/storage.kernelci.org/images/rootfs/buildroot/armel/rootfs.cpio.gz saving as /var/lib/lava/dispatcher/tmp/lavafed-466/tftp-deploy-h5c_5l8j/ramdisk/rootfs.cpio.gz total size: 3998795 (3MB) No compression specified progress 0% (0MB) progress 5% (0MB) progress 10% (0MB) progress 15% (0MB) progress 20% (0MB) progress 25% (0MB) progress 30% (1MB) progress 35% (1MB) progress 40% (1MB) progress 45% (1MB) progress 50% (1MB) progress 55% (2MB) progress 60% (2MB) progress 65% (2MB) progress 70% (2MB) progress 75% (2MB) progress 80% (3MB) progress 85% (3MB) progress 90% (3MB) progress 95% (3MB) progress 100% (3MB) 3MB downloaded in 0.21s (18.49MB/s) end: 1.1.1 http-download (duration 00:00:00) [common] case: http-download
case_id: 10070
definition: lava
duration: 0.21
extra: ...
level: 1.1.1
namespace: common
result: pass
end: 1.1 download-retry (duration 00:00:00) [common] start: 1.2 download-retry (timeout 00:04:00) [common] start: 1.2.1 http-download (timeout 00:04:00) [common] downloading https://images.validation.linaro.org/builds.96boards.org/snapshots/b2260/linaro/debian/21/uImage saving as /var/lib/lava/dispatcher/tmp/lavafed-466/tftp-deploy-h5c_5l8j/kernel/uImage total size: 7088336 (6MB) No compression specified progress 0% (0MB) progress 5% (0MB) progress 10% (0MB) progress 15% (1MB) progress 20% (1MB) progress 25% (1MB) progress 30% (2MB) progress 35% (2MB) progress 40% (2MB) progress 45% (3MB) progress 50% (3MB) progress 55% (3MB) progress 60% (4MB) progress 65% (4MB) progress 70% (4MB) progress 75% (5MB) progress 80% (5MB) progress 85% (5MB) progress 90% (6MB) progress 95% (6MB) progress 100% (6MB) 6MB downloaded in 0.61s (11.01MB/s) end: 1.2.1 http-download (duration 00:00:01) [common] case: http-download
case_id: 10070
definition: lava
duration: 0.62
extra: ...
level: 1.2.1
namespace: common
result: pass
end: 1.2 download-retry (duration 00:00:01) [common] start: 1.3 download-retry (timeout 00:03:59) [common] start: 1.3.1 http-download (timeout 00:03:59) [common] downloading https://images.validation.linaro.org/builds.96boards.org/snapshots/b2260/linaro/debian/21/stih410-b2260.dtb saving as /var/lib/lava/dispatcher/tmp/lavafed-466/tftp-deploy-h5c_5l8j/dtb/stih410-b2260.dtb total size: 51898 (0MB) No compression specified progress 63% (0MB) progress 100% (0MB) 0MB downloaded in 0.09s (0.54MB/s) end: 1.3.1 http-download (duration 00:00:00) [common] case: http-download
case_id: 10070
definition: lava
duration: 0.09
extra: ...
level: 1.3.1
namespace: common
result: pass
end: 1.3 download-retry (duration 00:00:00) [common] start: 1.4 prepare-tftp-overlay (timeout 00:03:59) [common] start: 1.4.1 extract-nfsrootfs (timeout 00:03:59) [common] end: 1.4.1 extract-nfsrootfs (duration 00:00:00) [common] start: 1.4.2 lava-overlay (timeout 00:03:59) [common] [common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb makedir: /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin makedir: /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/tests makedir: /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/results Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-add-keys Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-add-sources Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-background-process-start Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-background-process-stop Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-common-functions Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-echo-ipv4 Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-install-packages Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-installed-packages Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-os-build Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-probe-channel Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-probe-ip Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-target-ip Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-target-mac Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-target-storage Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-test-case Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-test-event Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-test-feedback Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-test-raise Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-test-reference Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-test-runner Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-test-set Creating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-test-shell Updating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-add-keys (debian) Updating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-add-sources (debian) Updating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-install-packages (debian) Updating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-installed-packages (debian) Updating /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/bin/lava-os-build (debian) start: 1.4.2.1 ssh-authorize (timeout 00:03:59) [common] end: 1.4.2.1 ssh-authorize (duration 00:00:00) [common] start: 1.4.2.2 lava-vland-overlay (timeout 00:03:59) [common] skipped lava-vland-overlay end: 1.4.2.2 lava-vland-overlay (duration 00:00:00) [common] start: 1.4.2.3 lava-multinode-overlay (timeout 00:03:59) [common] skipped lava-multinode-overlay end: 1.4.2.3 lava-multinode-overlay (duration 00:00:00) [common] start: 1.4.2.4 test-definition (timeout 00:03:59) [common] Loading test definitions start: 1.4.2.4.1 git-repo-action (timeout 00:03:59) [common] Using /lava-466 at stage 0 Fetching tests from http://git.linaro.org/lava-team/lava-functional-tests.git Running '/usr/bin/git clone http://git.linaro.org/lava-team/lava-functional-tests.git /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/0/tests/0_smoke-tests --depth=1' Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/0/tests/0_smoke-tests/lava-test-shell/smoke-tests-basic.yaml uuid=466_1.4.2.4.1 testdef=None end: 1.4.2.4.1 git-repo-action (duration 00:00:00) [common] case: git-repo-action
case_id: 10080
definition: lava
duration: 0.28
extra: ...
level: 1.4.2.4.1
namespace: common
result: pass
start: 1.4.2.4.2 test-overlay (timeout 00:03:59) [common] end: 1.4.2.4.2 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 10081
definition: lava
duration: 0.01
extra: ...
level: 1.4.2.4.2
namespace: common
result: pass
start: 1.4.2.4.3 test-install-overlay (timeout 00:03:59) [common] end: 1.4.2.4.3 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 10082
definition: lava
duration: 0.01
extra: ...
level: 1.4.2.4.3
namespace: common
result: pass
start: 1.4.2.4.4 test-runscript-overlay (timeout 00:03:59) [common] runner path: /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/0/tests/0_smoke-tests test_uuid 466_1.4.2.4.1 end: 1.4.2.4.4 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 10084
definition: lava
duration: 0.01
extra: ...
level: 1.4.2.4.4
namespace: common
result: pass
Creating lava-test-runner.conf files Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/lavafed-466/lava-overlay-rhdeebyb/lava-466/0 for stage 0 - 0_smoke-tests end: 1.4.2.4 test-definition (duration 00:00:00) [common] start: 1.4.2.5 compress-overlay (timeout 00:03:59) [common] end: 1.4.2.5 compress-overlay (duration 00:00:00) [common] start: 1.4.2.6 persistent-nfs-overlay (timeout 00:03:59) [common] end: 1.4.2.6 persistent-nfs-overlay (duration 00:00:00) [common] end: 1.4.2 lava-overlay (duration 00:00:00) [common] start: 1.4.3 extract-overlay-ramdisk (timeout 00:03:59) [common] nice cpio -iud -F /var/lib/lava/dispatcher/tmp/lavafed-466/extract-overlay-ramdisk-4xmt1cod/ramdisk.cpio output: 24233 blocks output: end: 1.4.3 extract-overlay-ramdisk (duration 00:00:00) [common] start: 1.4.4 extract-modules (timeout 00:03:58) [common] end: 1.4.4 extract-modules (duration 00:00:00) [common] start: 1.4.5 apply-overlay-tftp (timeout 00:03:58) [common] [common] Applying overlay /var/lib/lava/dispatcher/tmp/lavafed-466/compress-overlay-pg322oqy/overlay-1.4.2.5.tar.gz to ramdisk [common] Applying overlay /var/lib/lava/dispatcher/tmp/lavafed-466/compress-overlay-pg322oqy/overlay-1.4.2.5.tar.gz to directory /var/lib/lava/dispatcher/tmp/lavafed-466/extract-overlay-ramdisk-4xmt1cod/ramdisk end: 1.4.5 apply-overlay-tftp (duration 00:00:00) [common] start: 1.4.6 prepare-kernel (timeout 00:03:58) [common] start: 1.4.6.1 uboot-prepare-kernel (timeout 00:03:58) [common] end: 1.4.6.1 uboot-prepare-kernel (duration 00:00:00) [common] end: 1.4.6 prepare-kernel (duration 00:00:00) [common] start: 1.4.7 configure-preseed-file (timeout 00:03:58) [common] end: 1.4.7 configure-preseed-file (duration 00:00:00) [common] start: 1.4.8 compress-ramdisk (timeout 00:03:58) [common] Building ramdisk /var/lib/lava/dispatcher/tmp/lavafed-466/extract-overlay-ramdisk-4xmt1cod/ramdisk.cpio containing /var/lib/lava/dispatcher/tmp/lavafed-466/extract-overlay-ramdisk-4xmt1cod/ramdisk find . | cpio --create --format='newc' > /var/lib/lava/dispatcher/tmp/lavafed-466/extract-overlay-ramdisk-4xmt1cod/ramdisk.cpio 24434 blocks Adding RAMdisk u-boot header. nice mkimage -A arm -T ramdisk -C none -d /var/lib/lava/dispatcher/tmp/lavafed-466/extract-overlay-ramdisk-4xmt1cod/ramdisk.cpio.gz /var/lib/lava/dispatcher/tmp/lavafed-466/extract-overlay-ramdisk-4xmt1cod/ramdisk.cpio.gz.uboot output: Image Name: output: Created: Wed May 15 09:07:40 2019 output: Image Type: ARM Linux RAMDisk Image (uncompressed) output: Data Size: 4082006 Bytes = 3986.33 kB = 3.89 MB output: Load Address: 00000000 output: Entry Point: 00000000 output: rename /var/lib/lava/dispatcher/tmp/lavafed-466/extract-overlay-ramdisk-4xmt1cod/ramdisk.cpio.gz.uboot to /var/lib/lava/dispatcher/tmp/lavafed-466/tftp-deploy-h5c_5l8j/ramdisk/ramdisk.cpio.gz.uboot end: 1.4.8 compress-ramdisk (duration 00:00:01) [common] end: 1.4 prepare-tftp-overlay (duration 00:00:02) [common] start: 1.5 lxc-create-udev-rule-action (timeout 00:03:57) [common] No LXC device requested end: 1.5 lxc-create-udev-rule-action (duration 00:00:00) [common] start: 1.6 deploy-device-env (timeout 00:03:57) [common] end: 1.6 deploy-device-env (duration 00:00:00) [common] Checking files for TFTP limit of 4294967296 bytes. end: 1 tftp-deploy (duration 00:00:03) [common] start: 2 uboot-action (timeout 00:03:00) [common] start: 2.1 uboot-from-media (timeout 00:00:30) [common] end: 2.1 uboot-from-media (duration 00:00:00) [common] start: 2.2 bootloader-overlay (timeout 00:00:30) [common] {'bootm': {'kernel': '0x60000000', 'dtb': '0x47000000', 'ramdisk': '0x45000000'}, 'pass': None, 'uimage': {'kernel': '0x60000000', 'dtb': '0x47000000', 'ramdisk': '0x45000000'}} Parsed boot commands: setenv autoload no; setenv initrd_high 0xffffffff; setenv fdt_high 0xffffffff; setenv ethaddr 00:80:e1:12:81:30; dhcp; setenv serverip 10.3.1.1; tftp 0x60000000 lavafed-466/tftp-deploy-h5c_5l8j/kernel/uImage; tftp 0x45000000 lavafed-466/tftp-deploy-h5c_5l8j/ramdisk/ramdisk.cpio.gz.uboot; setenv initrd_size ${filesize}; tftp 0x47000000 lavafed-466/tftp-deploy-h5c_5l8j/dtb/stih410-b2260.dtb; setenv bootargs 'console=ttyAS1,115200n8 root=/dev/ram0 consoleblank=0 mem=992M@0x40000000 vmalloc=256m clk_ignore_unused earlyprintk ip=::::stiH410::dhcp kmac=dev:eth0,addr:${ethaddr}'; bootm 0x60000000 0x45000000 0x47000000 end: 2.2 bootloader-overlay (duration 00:00:00) [common] case: bootloader-overlay
case_id: 10097
definition: lava
duration: 0.00
extra: ...
level: 2.2
namespace: common
result: pass
start: 2.3 connect-device (timeout 00:00:30) [common] [common] connect-device Connecting to device using 'telnet staging01 7107' end: 2.3 connect-device (duration 00:00:01) [common] start: 2.4 uboot-retry (timeout 00:02:59) [common] start: 2.4.1 reset-device (timeout 00:00:30) [common] start: 2.4.1.1 pdu-reboot (timeout 00:00:30) [common] Calling: 'nice' '/usr/local/lab-scripts/snmp_pdu_control' '--port' '13' '--hostname' 'pdu15' '--command' 'reboot' >> pdu15 port 13 now powered off >> pdu15 port 13 now powered on >> pdu15 port 13 now power cycled Returned 0 in 24 seconds end: 2.4.1.1 pdu-reboot (duration 00:00:25) [common] case: pdu-reboot
case_id: 10103
definition: lava
duration: 24.51
extra: ...
level: 2.4.1.1
namespace: common
result: pass
end: 2.4.1 reset-device (duration 00:00:25) [common] start: 2.4.2 bootloader-interrupt (timeout 00:00:30) [common] bootloader-interrupt: Wait for prompt Hit any key to stop autoboot (timeout 00:00:30) Trying 10.3.1.1... Connected to staging01.lavalab. Escape character is '^]'. TI 96Board b2260 7107 [115200 N81] �d ��Lz|�� [u-bootrom] display version U-Boot 2015.01-st-2015 (Nov 22 2016 - 16:42:18) - stm24-2016-01-20 arm-stopensdk-linux-gnueabi-gcc (GCC) 5.3.0 GNU ld (GNU Binutils) 2.26.0.20160226 [u-bootrom] starting... [u-bootrom] silently sourcing [mmc 0:1]/b2260/u-bootrom.script [bootscript] boot from b2260/u-bootrom.script-uboot U-Boot 2016.09-g45114ee (Nov 30 2017 - 17:07:09 +0000), Build: jenkins-96boards-b2260-u-boot-18 Board: B2260-revx-STxH410 [ARM] I2C: ready DRAM: 1022 MiB MMC: boot: non-eMMC. stm-sdhci0: 0 Using default environment In: serial Out: serial Err: serial Net: stmac-1 Error: stmac-1 address not set. Hit any key to stop autoboot: 2  1 end: 2.4.2 bootloader-interrupt (duration 00:00:00) [common] start: 2.4.3 bootloader-commands (timeout 00:02:34) [common] bootloader-commands: Wait for prompt ['=>'] (timeout 00:02:34)  0 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.'] (timeout 00:02:34) setenv autoload no 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.'] (timeout 00:02:34) setenv initrd_high 0xffffffff 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.'] (timeout 00:02:34) setenv fdt_high 0xffffffff setenv ethaddr 00:80:e1:12:81:30 => setenv ethaddr 00:80:e1:12:81:30 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.'] (timeout 00:02:34) setenv ethaddr 00:80:e1:12:81:30 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.'] (timeout 00:02:34) dhcp Using MAC Address 00:80:e1:12:81:30 STM-GMAC: REALTEK RTL8211E(G) found STM-GMAC: 100Mbs full duplex link detected STM-GMAC: Allocating coherent descriptors Successfully allocated coherent descriptors BOOTP broadcast 1 BOOTP broadcast 2 BOOTP broadcast 3 BOOTP broadcast 4 DHCP client bound to address 10.15.15.81 (2346 ms) setenv serverip 10.3.1.1 => setenv serverip 10.3.1.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.'] (timeout 00:02:29) setenv serverip 10.3.1.1 tftp 0x60000000 lavafed-466/tftp-deploy-h5c_5l8j/kernel/uImage => tftp 0x60000000 lavafed-466/tftp-deploy-h5c_5l8j/kernel/uImage 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.'] (timeout 00:02:29) tftp 0x60000000 lavafed-466/tftp-deploy-h5c_5l8j/kernel/uImage Using MAC Address 00:80:e1:12:81:30 STM-GMAC: REALTEK RTL8211E(G) found STM-GMAC: 100Mbs full duplex link detected STM-GMAC: Using already allocated descriptors. Using stmac-1 device TFTP from server 10.3.1.1; our IP address is 10.15.15.81 Filename 'lavafed-466/tftp-deploy-h5c_5l8j/kernel/uImage'. Load address: 0x60000000 Loading: *################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ############################ 865.2 KiB/s done Bytes transferred = 7088336 (6c28d0 hex) CACHE: Misaligned operation at range [60000000, 606c28d0] tftp 0x45000000 lavafed-466/tftp-deploy-h5c_5l8j/ramdisk/ramdisk.cpio.gz.uboot =>tftp 0x45000000 lavafed-466/tftp-deploy-h5c_5l8j/ramdisk/ramdisk.cpio.gz.uboot bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.'] (timeout 00:02:21) tftp 0x45000000 lavafed-466/tftp-deploy-h5c_5l8j/ramdisk/ramdisk.cpio.gz.uboot Using MAC Address 00:80:e1:12:81:30 STM-GMAC: REALTEK RTL8211E(G) found STM-GMAC: 100Mbs full duplex link detected STM-GMAC: Using already allocated descriptors. Using stmac-1 device TFTP from server 10.3.1.1; our IP address is 10.15.15.81 Filename 'lavafed-466/tftp-deploy-h5c_5l8j/ramdisk/ramdisk.cpio.gz.uboot'. Load address: 0x45000000 Loading: *################################################################# ################################################################# ################################################################# ################################################################# ################### 589.8 KiB/s done Bytes transferred = 4082070 (3e4996 hex) CACHE: Misaligned operation at range [45000000, 453e4996] 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.'] (timeout 00:02:13) setenv initrd_size ${filesize} tftp 0x47000000 lavafed-466/tftp-deploy-h5c_5l8j/dtb/stih410-b2260.dtb => tftp 0x47000000 lavafed-466/tftp-deploy-h5c_5l8j/dtb/stih410-b2260.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.'] (timeout 00:02:13) tftp 0x47000000 lavafed-466/tftp-deploy-h5c_5l8j/dtb/stih410-b2260.dtb Using MAC Address 00:80:e1:12:81:30 STM-GMAC: REALTEK RTL8211E(G) found STM-GMAC: 100Mbs full duplex link detected STM-GMAC: Using already allocated descriptors. Using stmac-1 device TFTP from server 10.3.1.1; our IP address is 10.15.15.81 Filename 'lavafed-466/tftp-deploy-h5c_5l8j/dtb/stih410-b2260.dtb'. Load address: 0x47000000 Loading: *#### 9.8 KiB/s done Bytes transferred = 51898 (caba hex) CACHE: Misaligned operation at range [47000000, 4700caba] setenv bootargs 'console=ttyAS1,115200n8 root=/dev/ram0 consoleblank=0 mem=992M@0x40000000 vmalloc=256m clk_ignore_unused earlyprintk ip=::::stiH410::dhcp kmac=dev:eth0,addr:${ethaddr}' => setenv bootargs 'console=ttyAS1,115200n8 root=/dev/ram0 consoleblank=0 mem=992M@0x40000000 vmalloc=256m clk_ignore_unused earlyprintk ip=::::stiH410::dhcp kmac=dev:eth0,addr:${ethaddr}' 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.'] (timeout 00:02:07) setenv bootargs 'console=ttyAS1,115200n8 root=/dev/ram0 consoleblank=0 mem=992M@0x40000000 vmalloc=256m clk_ignore_unused earlyprintk ip=::::stiH410::dhcp kmac=dev:eth0,addr:${ethaddr}' bootm 0x60000000 0x45000000 0x47000000 => bootm 0x60000000 0x45000000 0x47000000 bootloader-commands: Wait for prompt Starting kernel (timeout 00:02:07) bootm 0x60000000 0x45000000 0x47000000 ## Booting kernel from Legacy Image at 60000000 ... Image Name: Linux Image Type: ARM Linux Kernel Image (uncompressed) Data Size: 7088272 Bytes = 6.8 MiB Load Address: 40080000 Entry Point: 40080000 Verifying Checksum ... OK ## Loading init Ramdisk from Legacy Image at 45000000 ... Image Name: Image Type: ARM Linux RAMDisk Image (uncompressed) Data Size: 4082006 Bytes = 3.9 MiB Load Address: 00000000 Entry Point: 00000000 Verifying Checksum ... OK ## Flattened Device Tree blob at 47000000 Booting using the fdt blob at 0x47000000 Loading Kernel Image ... OK Using Device Tree in place at 47000000, end 4700fab9 Starting kernel ... end: 2.4.3 bootloader-commands (duration 00:00:28) [common] start: 2.4.4 auto-login-action (timeout 00:02:00) [common] 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.'] (timeout 00:02:00) [ 0.000000] Booting Linux on physical CPU 0x0 The string 'linaro-test' 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. 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. Using line separator: #'\n'# No login prompt set. Parsing kernel messages ['-+\\[ cut here \\]-+\\s+(.*\\s+-+\\[ end trace (\\w*) \\]-+)', '(Unhandled fault.*)\\r\\n', 'Kernel panic - (.*) end Kernel panic', 'Stack:\\s+(.*\\s+-+\\[ end trace (\\w*) \\]-+)', 'linaro-test', 'root@debian:~#', '/ #', 'Login timed out', 'Login incorrect'] [auto-login-action] Waiting for messages, (timeout 00:01:59) Waiting using forced prompt support. 59.38423538208008s timeout [ 0.000000] Linux version 4.9.0-linaro-multi-v7 (buildslave@x86-64-10) (gcc version 5.3.1 20160113 (Linaro GCC 5.3-2016.02) ) #2 SMP Tue Jan 17 17:25:49 UTC 2017 [ 0.000000] CPU: ARMv7 Processor [413fc090] revision 0 (ARMv7), cr=10c5387d [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache [ 0.000000] OF: fdt:Machine model: STiH410 B2260 [ 0.000000] efi: Getting EFI parameters from FDT: [ 0.000000] efi: UEFI not found. [ 0.000000] Reserved memory: created DMA memory pool at 0x43000000, size 16 MiB [ 0.000000] OF: reserved mem: initialized node rproc@43000000, compatible id shared-dma-pool [ 0.000000] cma: Reserved 64 MiB at 0x7a000000 [ 0.000000] Memory policy: Data cache writealloc [ 0.000000] percpu: Embedded 14 pages/cpu @eeff3000 s26112 r8192 d23040 u57344 [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 248336 [ 0.000000] Kernel command line: console=ttyAS1,115200n8 root=/dev/ram0 consoleblank=0 mem=992M@0x40000000 vmalloc=256m clk_ignore_unused earlyprintk ip=::::stiH410::dhcp kmac=dev:eth0,addr:${ethaddr} [ 0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes) [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes) [ 0.000000] Memory: 903076K/999424K available (9216K kernel code, 1126K rwdata, 3868K rodata, 2048K init, 343K bss, 30812K reserved, 65536K cma-reserved, 172032K highmem) [ 0.000000] Virtual kernel memory layout: [ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB) [ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB) [ 0.000000] vmalloc : 0xf0000000 - 0xff800000 ( 248 MB) [ 0.000000] lowmem : 0xc0000000 - 0xef800000 ( 760 MB) [ 0.000000] pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB) [ 0.000000] modules : 0xbf000000 - 0xbfe00000 ( 14 MB) [ 0.000000] .text : 0xc0208000 - 0xc0c00000 (10208 kB) [ 0.000000] .init : 0xc1100000 - 0xc1300000 (2048 kB) [ 0.000000] .data : 0xc1300000 - 0xc1419a60 (1127 kB) [ 0.000000] .bss : 0xc141b000 - 0xc1470e78 ( 344 kB) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1 [ 0.000000] Hierarchical RCU implementation. [ 0.000000] Build-time adjustment of leaf fanout to 32. [ 0.000000] RCU restricting CPUs from NR_CPUS=16 to nr_cpu_ids=2. [ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=32, nr_cpu_ids=2 [ 0.000000] NR_IRQS:16 nr_irqs:16 16 [ 0.000000] L2C: platform modifies aux control register: 0x02080000 -> 0x30480000 [ 0.000000] L2C: DT/platform modifies aux control register: 0x02080000 -> 0x30480000 [ 0.000000] L2C: DT/platform tries to modify or specify cache size [ 0.000000] L2C-310 erratum 769419 enabled [ 0.000000] L2C-310 enabling early BRESP for Cortex-A9 [ 0.000000] L2C-310 dynamic clock gating disabled, standby mode disabled [ 0.000000] L2C-310 cache controller enabled, 8 ways, 1024 kB [ 0.000000] L2C-310: CACHE_ID 0x410000c8, AUX_CTRL 0x02080000 [ 0.000014] sched_clock: 32 bits at 30MHz, resolution 33ns, wraps every 71582788591ns [ 0.000034] clocksource: clksrc-st-lpc: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 63708681553 ns [ 0.000046] clksrc-st-lpc: clocksource initialised - running @ 30000000Hz [ 0.000759] GIC: PPI11 is secure or misconfigured [ 0.000784] sched_clock: 64 bits at 750MHz, resolution 1ns, wraps every 4398046511103ns [ 0.000798] clocksource: arm_global_timer: mask: 0xffffffffffffffff max_cycles: 0xacf9151134, max_idle_ns: 440795214493 ns [ 0.000823] GIC: PPI11 is secure or misconfigured [ 0.000835] Switching to timer-based delay loop, resolution 1ns [ 0.001026] Console: colour dummy device 80x30 [ 0.001057] Calibrating delay loop (skipped), value calculated using timer frequency.. 1500.00 BogoMIPS (lpj=7500000) [ 0.001072] pid_max: default: 32768 minimum: 301 [ 0.001172] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.001185] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.001911] CPU: Testing write buffer coherency: ok [ 0.002407] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 [ 0.003091] Setting up static identity map for 0x40300000 - 0x40300098 [ 0.010037] EFI services will not be available. [ 0.011311] GIC: PPI11 is secure or misconfigured [ 0.011326] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 [ 0.011465] Brought up 2 CPUs [ 0.011490] SMP: Total of 2 processors activated (3000.00 BogoMIPS). [ 0.011497] CPU: All CPU(s) started in SVC mode. [ 0.012318] devtmpfs: initialized [ 0.020022] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4 [ 0.020684] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.027281] pinctrl core: initialized pinctrl subsystem [ 0.029763] NET: Registered protocol family 16 [ 0.031888] DMA: preallocated 256 KiB pool for atomic coherent allocations [ 0.060876] cpuidle: using governor menu [ 0.061291] No ATAGs? [ 0.061328] hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers. [ 0.061338] hw-breakpoint: maximum watchpoint size is 4 bytes. [ 0.064221] Serial: AMBA PL011 UART driver [ 0.067281] st-pinctrl 961f080.pin-controller-sbc: nbanks = 6 [ 0.067298] st-pinctrl 961f080.pin-controller-sbc: nfunctions = 12 [ 0.067305] st-pinctrl 961f080.pin-controller-sbc: ngroups = 27 [ 0.067903] st-pinctrl 961f080.pin-controller-sbc: PIO0 bank added. [ 0.068570] st-pinctrl 961f080.pin-controller-sbc: PIO1 bank added. [ 0.069186] st-pinctrl 961f080.pin-controller-sbc: PIO2 bank added. [ 0.069832] st-pinctrl 961f080.pin-controller-sbc: PIO3 bank added. [ 0.070456] st-pinctrl 961f080.pin-controller-sbc: PIO4 bank added. [ 0.071189] st-pinctrl 961f080.pin-controller-sbc: PIO5 bank added. [ 0.071554] st-pinctrl 961f080.pin-controller-sbc: Function[0 name:cec0, groups:1] [ 0.071597] st-pinctrl 961f080.pin-controller-sbc: Function[1 name:rc, groups:4] [ 0.071618] st-pinctrl 961f080.pin-controller-sbc: Function[2 name:sbc_serial0, groups:1] [ 0.071634] st-pinctrl 961f080.pin-controller-sbc: Function[3 name:sbc_serial1, groups:1] [ 0.071650] st-pinctrl 961f080.pin-controller-sbc: Function[4 name:i2c10, groups:1] [ 0.071665] st-pinctrl 961f080.pin-controller-sbc: Function[5 name:i2c11, groups:1] [ 0.071696] st-pinctrl 961f080.pin-controller-sbc: Function[6 name:keyscan, groups:1] [ 0.071821] st-pinctrl 961f080.pin-controller-sbc: Function[7 name:gmac1, groups:7] [ 0.071852] st-pinctrl 961f080.pin-controller-sbc: Function[8 name:pwm1, groups:4] [ 0.071890] st-pinctrl 961f080.pin-controller-sbc: Function[9 name:spi10, groups:2] [ 0.071916] st-pinctrl 961f080.pin-controller-sbc: Function[10 name:spi11, groups:2] [ 0.071938] st-pinctrl 961f080.pin-controller-sbc: Function[11 name:spi12, groups:2] [ 0.072700] st-pinctrl 920f080.pin-controller-front0: nbanks = 10 [ 0.072715] st-pinctrl 920f080.pin-controller-front0: nfunctions = 22 [ 0.072722] st-pinctrl 920f080.pin-controller-front0: ngroups = 46 [ 0.073295] st-pinctrl 920f080.pin-controller-front0: PIO10 bank added. [ 0.074001] st-pinctrl 920f080.pin-controller-front0: PIO11 bank added. [ 0.074641] st-pinctrl 920f080.pin-controller-front0: PIO12 bank added. [ 0.075261] st-pinctrl 920f080.pin-controller-front0: PIO13 bank added. [ 0.075895] st-pinctrl 920f080.pin-controller-front0: PIO14 bank added. [ 0.076515] st-pinctrl 920f080.pin-controller-front0: PIO15 bank added. [ 0.077149] st-pinctrl 920f080.pin-controller-front0: PIO16 bank added. [ 0.077770] st-pinctrl 920f080.pin-controller-front0: PIO17 bank added. [ 0.078402] st-pinctrl 920f080.pin-controller-front0: PIO18 bank added. [ 0.079056] st-pinctrl 920f080.pin-controller-front0: PIO19 bank added. [ 0.079398] st-pinctrl 920f080.pin-controller-front0: Function[0 name:serial0, groups:1] [ 0.079437] st-pinctrl 920f080.pin-controller-front0: Function[1 name:serial1, groups:1] [ 0.079464] st-pinctrl 920f080.pin-controller-front0: Function[2 name:serial2, groups:1] [ 0.079523] st-pinctrl 920f080.pin-controller-front0: Function[3 name:mmc1, groups:1] [ 0.079546] st-pinctrl 920f080.pin-controller-front0: Function[4 name:i2c0, groups:1] [ 0.079568] st-pinctrl 920f080.pin-controller-front0: Function[5 name:i2c1, groups:1] [ 0.079602] st-pinctrl 920f080.pin-controller-front0: Function[6 name:i2c2, groups:2] [ 0.079645] st-pinctrl 920f080.pin-controller-front0: Function[7 name:i2c3, groups:3] [ 0.079707] st-pinctrl 920f080.pin-controller-front0: Function[8 name:spi0, groups:4] [ 0.079768] st-pinctrl 920f080.pin-controller-front0: Function[9 name:spi1, groups:4] [ 0.079848] st-pinctrl 920f080.pin-controller-front0: Function[10 name:spi2, groups:6] [ 0.079949] st-pinctrl 920f080.pin-controller-front0: Function[11 name:spi3, groups:6] [ 0.080026] st-pinctrl 920f080.pin-controller-front0: Function[12 name:tsin0, groups:2] [ 0.080102] st-pinctrl 920f080.pin-controller-front0: Function[13 name:tsin1, groups:2] [ 0.080185] st-pinctrl 920f080.pin-controller-front0: Function[14 name:tsin2, groups:2] [ 0.080217] st-pinctrl 920f080.pin-controller-front0: Function[15 name:tsin3, groups:1] [ 0.080250] st-pinctrl 920f080.pin-controller-front0: Function[16 name:tsin4, groups:1] [ 0.080315] st-pinctrl 920f080.pin-controller-front0: Function[17 name:tsin5, groups:2] [ 0.080395] st-pinctrl 920f080.pin-controller-front0: Function[18 name:tsout0, groups:2] [ 0.080434] st-pinctrl 920f080.pin-controller-front0: Function[19 name:tsout1, groups:1] [ 0.080487] st-pinctrl 920f080.pin-controller-front0: Function[20 name:mtsin0, groups:1] [ 0.080518] st-pinctrl 920f080.pin-controller-front0: Function[21 name:systrace, groups:1] [ 0.081271] st-pinctrl 921f080.pin-controller-front1: nbanks = 1 [ 0.081287] st-pinctrl 921f080.pin-controller-front1: nfunctions = 1 [ 0.081296] st-pinctrl 921f080.pin-controller-front1: ngroups = 1 [ 0.081859] st-pinctrl 921f080.pin-controller-front1: PIO20 bank added. [ 0.082268] st-pinctrl 921f080.pin-controller-front1: Function[0 name:tsin4, groups:1] [ 0.082931] st-pinctrl 922f080.pin-controller-rear: nbanks = 6 [ 0.082945] st-pinctrl 922f080.pin-controller-rear: nfunctions = 11 [ 0.082953] st-pinctrl 922f080.pin-controller-rear: ngroups = 16 [ 0.083531] st-pinctrl 922f080.pin-controller-rear: PIO30 bank added. [ 0.084204] st-pinctrl 922f080.pin-controller-rear: PIO31 bank added. [ 0.084873] st-pinctrl 922f080.pin-controller-rear: PIO32 bank added. [ 0.085513] st-pinctrl 922f080.pin-controller-rear: PIO33 bank added. [ 0.086122] st-pinctrl 922f080.pin-controller-rear: PIO34 bank added. [ 0.086753] st-pinctrl 922f080.pin-controller-rear: PIO35 bank added. [ 0.087133] st-pinctrl 922f080.pin-controller-rear: Function[0 name:i2c4, groups:1] [ 0.087203] st-pinctrl 922f080.pin-controller-rear: Function[1 name:i2c5, groups:1] [ 0.087276] st-pinctrl 922f080.pin-controller-rear: Function[2 name:usb3, groups:1] [ 0.087323] st-pinctrl 922f080.pin-controller-rear: Function[3 name:pwm0, groups:1] [ 0.087479] st-pinctrl 922f080.pin-controller-rear: Function[4 name:spi4, groups:4] [ 0.087643] st-pinctrl 922f080.pin-controller-rear: Function[5 name:i2s_out, groups:2] [ 0.087808] st-pinctrl 922f080.pin-controller-rear: Function[6 name:i2s_in, groups:2] [ 0.087839] st-pinctrl 922f080.pin-controller-rear: Function[7 name:spdif_out, groups:1] [ 0.087887] st-pinctrl 922f080.pin-controller-rear: Function[8 name:serial3, groups:1] [ 0.087939] st-pinctrl 922f080.pin-controller-rear: Function[9 name:usb0, groups:1] [ 0.087987] st-pinctrl 922f080.pin-controller-rear: Function[10 name:usb1, groups:1] [ 0.088699] st-pinctrl 923f080.pin-controller-flash: nbanks = 3 [ 0.088715] st-pinctrl 923f080.pin-controller-flash: nfunctions = 3 [ 0.088722] st-pinctrl 923f080.pin-controller-flash: ngroups = 4 [ 0.089260] st-pinctrl 923f080.pin-controller-flash: PIO40 bank added. [ 0.089907] st-pinctrl 923f080.pin-controller-flash: PIO41 bank added. [ 0.090541] st-pinctrl 923f080.pin-controller-flash: PIO42 bank added. [ 0.091424] st-pinctrl 923f080.pin-controller-flash: Function[0 name:mmc0, groups:2] [ 0.091588] st-pinctrl 923f080.pin-controller-flash: Function[1 name:fsm, groups:1] [ 0.091958] st-pinctrl 923f080.pin-controller-flash: Function[2 name:nand, groups:1] [ 0.095477] reset-stih407 soc:powerdown-controller: registered [ 0.104697] reset-stih407 soc:softreset-controller: registered [ 0.105936] reset-stih407 soc:picophyreset-controller: registered [ 0.170252] vgaarb: loaded [ 0.171249] SCSI subsystem initialized [ 0.171902] usbcore: registered new interface driver usbfs [ 0.171978] usbcore: registered new interface driver hub [ 0.172073] usbcore: registered new device driver usb [ 0.173612] pps_core: LinuxPPS API ver. 1 registered [ 0.173624] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it> [ 0.173653] PTP clock support registered [ 0.173923] EDAC MC: Ver: 3.0.0 [ 0.177114] clocksource: Switched to clocksource clksrc-st-lpc [ 0.193054] NET: Registered protocol family 2 [ 0.193584] TCP established hash table entries: 8192 (order: 3, 32768 bytes) [ 0.193659] TCP bind hash table entries: 8192 (order: 4, 65536 bytes) [ 0.193776] TCP: Hash tables configured (established 8192 bind 8192) [ 0.193930] UDP hash table entries: 512 (order: 2, 16384 bytes) [ 0.193991] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes) [ 0.194202] NET: Registered protocol family 1 [ 0.194873] RPC: Registered named UNIX socket transport module. [ 0.194888] RPC: Registered udp transport module. [ 0.194894] RPC: Registered tcp transport module. [ 0.194899] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.195412] Trying to unpack rootfs image as initramfs... [ 0.519508] Freeing initrd memory: 3988K (c5000000 - c53e5000) [ 0.520275] hw perfevents: enabled with armv7_cortex_a9 PMU driver, 7 counters available [ 0.521562] futex hash table entries: 512 (order: 3, 32768 bytes) [ 0.522418] workingset: timestamp_bits=30 max_order=18 bucket_order=0 [ 0.528648] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ 0.529491] NFS: Registering the id_resolver key type [ 0.529524] Key type id_resolver registered [ 0.529533] Key type id_legacy registered [ 0.529579] ntfs: driver 2.1.32 [Flags: R/O]. [ 0.531598] bounce: pool size: 64 pages [ 0.531796] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248) [ 0.531810] io scheduler noop registered [ 0.531816] io scheduler deadline registered [ 0.531969] io scheduler cfq registered (default) [ 0.537293] stih407-usb-genphy soc:phy1: STiH407 USB Generic picoPHY driver probed! [ 0.537645] stih407-usb-genphy soc:phy2: STiH407 USB Generic picoPHY driver probed! [ 0.537929] stih407-usb-genphy soc:phy3: STiH407 USB Generic picoPHY driver probed! [ 0.538784] libphy: mdio_driver_register: phy-bcm-ns2-pci [ 0.549283] st-pinctrl 922f080.pin-controller-rear: maps: function pwm0 group pwm0-0-default num 3 [ 0.549772] st-pinctrl 961f080.pin-controller-sbc: maps: function pwm1 group pwm1-0-default num 3 [ 0.549804] st-pinctrl 961f080.pin-controller-sbc: maps: function pwm1 group pwm1-1-default num 3 [ 0.549823] st-pinctrl 961f080.pin-controller-sbc: maps: function pwm1 group pwm1-2-default num 2 [ 0.549837] st-pinctrl 961f080.pin-controller-sbc: maps: function pwm1 group pwm1-3-default num 2 [ 0.550067] sti-pwm 9510000.pwm: Failed to obtain IRQ [ 0.563383] pwm-regulator pwm-regulator: Failed to get PWM: -517 [ 0.654486] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled [ 0.657873] SuperH (H)SCI(F) driver initialized [ 0.659298] msm_serial: driver initialized [ 0.659589] STMicroelectronics ASC driver initialized [ 0.659809] st-pinctrl 920f080.pin-controller-front0: maps: function serial0 group serial0-0 num 3 [ 0.660090] 9830000.serial: ttyAS0 at MMIO 0x9830000 (irq = 232, base_baud = 12500000) is a st-asc [ 0.660480] st-pinctrl 920f080.pin-controller-front0: maps: function serial1 group serial1-0 num 3 [ 0.660734] 9831000.serial: ttyAS1 at MMIO 0x9831000 (irq = 233, base_baud = 12500000) is a st-asc [ 2.141336] console [ttyAS1] enabled [ 2.149370] st-hwrandom 8a89000.rng: Successfully registered HW RNG [ 2.155721] st-hwrandom 8a8a000.rng: Successfully registered HW RNG [ 2.163025] [drm] Initialized [ 2.188166] brd: module loaded [ 2.198772] loop: module loaded [ 2.205398] miphy28lp-phy soc:miphy28lp@9b22000: sata-up mode, addr 0xf017d000 [ 2.213747] st_ahci 9b28000.sata: forcing port_map 0x0 -> 0x1 [ 2.219606] st_ahci 9b28000.sata: AHCI 0001.0300 32 slots 1 ports 6 Gbps 0x1 impl platform mode [ 2.228358] st_ahci 9b28000.sata: flags: ncq sntf pm led clo only pmp pio slum part ccc apst [ 2.238906] scsi host0: st_ahci [ 2.242311] ata1: SATA max UDMA/133 mmio [mem 0x09b28000-0x09b28fff] port 0x100 irq 244 [ 2.259643] libphy: Fixed MDIO Bus: probed [ 2.264648] CAN device driver interface [ 2.271606] e1000e: Intel(R) PRO/1000 Network Driver - 3.2.6-k [ 2.277482] e1000e: Copyright(c) 1999 - 2015 Intel Corporation. [ 2.283474] igb: Intel(R) Gigabit Ethernet Network Driver - version 5.4.0-k [ 2.290481] igb: Copyright (c) 2007-2014 Intel Corporation. [ 2.299459] st-pinctrl 961f080.pin-controller-sbc: maps: function gmac1 group rgmii1-0 num 15 [ 2.308070] st-pinctrl 961f080.pin-controller-sbc: maps: function gmac1 group rgmii1-mdio-1 num 3 [ 2.317461] sti-dwmac 9630000.dwmac: snps,phy-addr property is deprecated [ 2.324334] sti-dwmac 9630000.dwmac: Use internal clock source [ 2.330447] stmmac - user ID: 0xca, Synopsys ID: 0x37 [ 2.335497] Ring mode enabled [ 2.338580] DMA HW capability register supported[ 2.343107] Enhanced/Alternate descriptors [ 2.347314] Enabled extended descriptors [ 2.351317] RX Checksum Offload Engine supported [ 2.356012] COE Type 2 [ 2.358471] TX Checksum insertion supported [ 2.362734] Wake-Up On Lan supported [ 2.366433] Enable RX Mitigation via HW Watchdog Timer [ 2.578964] ata1: SATA link down (SStatus 0 SControl 300) [ 3.463534] libphy: stmmac: probed [ 3.466939] eth0: PHY ID 001cc915 at 0 IRQ POLL (stmmac-0:00) active [ 3.473347] eth0: PHY ID 001cc915 at 4 IRQ POLL (stmmac-0:04) [ 3.481234] pegasus: v0.9.3 (2013/04/25), Pegasus/Pegasus II USB Ethernet driver [ 3.488767] usbcore: registered new interface driver pegasus [ 3.494482] usbcore: registered new interface driver asix [ 3.499986] usbcore: registered new interface driver ax88179_178a [ 3.506126] usbcore: registered new interface driver cdc_ether [ 3.512064] usbcore: registered new interface driver smsc75xx [ 3.517935] usbcore: registered new interface driver smsc95xx [ 3.523733] usbcore: registered new interface driver net1080 [ 3.529492] usbcore: registered new interface driver cdc_subset [ 3.535459] usbcore: registered new interface driver zaurus [ 3.541143] usbcore: registered new interface driver cdc_ncm [ 3.549114] st-pinctrl 922f080.pin-controller-rear: maps: function usb3 group usb3-2 num 4 [ 3.559377] miphy28lp-phy soc:miphy28lp@9b22000: usb3-up mode, addr 0xf01a3000 [ 3.569237] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 3.575768] ehci-pci: EHCI PCI platform driver [ 3.580336] ehci-platform: EHCI generic platform driver [ 3.585894] ehci-orion: EHCI orion driver [ 3.590249] SPEAr-ehci: EHCI SPEAr driver [ 3.594527] ehci-st: EHCI STMicroelectronics driver [ 3.599763] st-pinctrl 922f080.pin-controller-rear: maps: function usb0 group usb2-0 num 3 [ 3.608371] st-ehci 9a03e00.usb: 48MHz clk not found [ 3.613526] st-ehci 9a03e00.usb: EHCI Host Controller [ 3.618663] st-ehci 9a03e00.usb: new USB bus registered, assigned bus number 1 [ 3.626168] st-ehci 9a03e00.usb: irq 254, io mem 0x09a03e00 [ 3.657187] st-ehci 9a03e00.usb: USB 2.0 started, EHCI 1.00 [ 3.663705] hub 1-0:1.0: USB hub found [ 3.667597] hub 1-0:1.0: 1 port detected [ 3.672037] st-pinctrl 922f080.pin-controller-rear: maps: function usb1 group usb2-1 num 3 [ 3.680646] st-ehci 9a83e00.usb: 48MHz clk not found [ 3.685796] st-ehci 9a83e00.usb: EHCI Host Controller [ 3.690936] st-ehci 9a83e00.usb: new USB bus registered, assigned bus number 2 [ 3.698474] st-ehci 9a83e00.usb: irq 256, io mem 0x09a83e00 [ 3.727197] st-ehci 9a83e00.usb: USB 2.0 started, EHCI 1.00 [ 3.733698] hub 2-0:1.0: USB hub found [ 3.737592] hub 2-0:1.0: 1 port detected [ 3.741996] ehci-exynos: EHCI EXYNOS driver [ 3.746512] ehci-atmel: EHCI Atmel driver [ 3.750851] tegra-ehci: Tegra EHCI driver [ 3.755140] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 3.761376] ohci-pci: OHCI PCI platform driver [ 3.765923] ohci-platform: OHCI generic platform driver [ 3.771498] ohci-omap3: OHCI OMAP3 driver [ 3.775778] SPEAr-ohci: OHCI SPEAr driver [ 3.780127] ohci-st: OHCI STMicroelectronics driver [ 3.785463] st-ohci 9a03c00.usb: 48MHz clk not found [ 3.790652] st-ohci 9a03c00.usb: ST OHCI controller [ 3.795570] st-ohci 9a03c00.usb: new USB bus registered, assigned bus number 3 [ 3.803972] st-ohci 9a03c00.usb: irq 253, io mem 0x09a03c00 [ 3.882144] hub 3-0:1.0: USB hub found [ 3.885965] hub 3-0:1.0: 1 port detected [ 3.890570] st-ohci 9a83c00.usb: 48MHz clk not found [ 3.895701] st-ohci 9a83c00.usb: ST OHCI controller [ 3.900676] st-ohci 9a83c00.usb: new USB bus registered, assigned bus number 4 [ 3.908125] st-ohci 9a83c00.usb: irq 255, io mem 0x09a83c00 [ 3.982087] hub 4-0:1.0: USB hub found [ 3.985911] hub 4-0:1.0: 1 port detected [ 3.990434] ohci-atmel: OHCI Atmel driver [ 3.995284] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller [ 4.000883] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 5 [ 4.009340] xhci-hcd xhci-hcd.0.auto: hcc params 0x0228f06c hci version 0x100 quirks 0x00010010 [ 4.018162] xhci-hcd xhci-hcd.0.auto: irq 262, io mem 0x09900000 [ 4.025087] hub 5-0:1.0: USB hub found [ 4.029263] hub 5-0:1.0: 1 port detected [ 4.033627] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller [ 4.039199] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 6 [ 4.047006] usb usb6: We don't know the algorithms for LPM for this host, disabling LPM. [ 4.056059] hub 6-0:1.0: USB hub found [ 4.059942] hub 6-0:1.0: 1 port detected [ 4.064840] usbcore: registered new interface driver usb-storage [ 4.073394] mousedev: PS/2 mouse device common for all mice [ 4.084861] i2c /dev entries driver [ 4.090984] st-pinctrl 920f080.pin-controller-front0: maps: function i2c0 group i2c0-default num 3 [ 4.100330] usb 2-1: new high-speed USB device number 2 using st-ehci [ 4.107726] st-i2c 9840000.i2c: ST I2C(0x09840000) initialized [ 4.113629] st-pinctrl 920f080.pin-controller-front0: maps: function i2c1 group i2c1-default num 3 [ 4.123545] st-i2c 9841000.i2c: ST I2C(0x09841000) initialized [ 4.129522] st-pinctrl 920f080.pin-controller-front0: maps: function i2c2 group i2c2-alt2-1 num 3 [ 4.139459] st-i2c 9842000.i2c: ST I2C(0x09842000) initialized [ 4.145376] st-pinctrl 920f080.pin-controller-front0: maps: function i2c3 group i2c3-alt3-0 num 3 [ 4.155206] st-i2c 9843000.i2c: ST I2C(0x09843000) initialized [ 4.161155] st-pinctrl 961f080.pin-controller-sbc: maps: function i2c11 group i2c11-default num 3 [ 4.171316] st-i2c 9541000.i2c: ST I2C(0x09541000) initialized [ 4.192447] st-lpc-wdt 8787000.lpc: LPC Watchdog driver registered, reset type is cold [ 4.205689] sdhci: Secure Digital Host Controller Interface driver [ 4.211927] sdhci: Copyright(c) Pierre Ossman [ 4.218948] Synopsys Designware Multimedia Card Interface Driver [ 4.226851] sdhci-pltfm: SDHCI platform and OF driver helper [ 4.235433] st-pinctrl 923f080.pin-controller-flash: maps: function mmc0 group sd0-0 num 12 [ 4.288535] hub 2-1:1.0: USB hub found [ 4.292490] hub 2-1:1.0: 3 ports detected [ 4.307167] mmc0: SDHCI controller on 9060000.sdhci [9060000.sdhci] using ADMA [ 4.314422] sdhci-st 9060000.sdhci: SDHCI ST Initialised: Host Version: 0x2 Vendor Version 0x10 [ 4.323282] st-pinctrl 920f080.pin-controller-front0: maps: function mmc1 group sd1-0 num 11 [ 4.332255] sdhci-st 9080000.sdhci: invalid resource [ 4.337284] sdhci-st 9080000.sdhci: FlashSS Top Dly registers not available [ 4.407232] mmc1: SDHCI controller on 9080000.sdhci [9080000.sdhci] using ADMA [ 4.414537] sdhci-st 9080000.sdhci: SDHCI ST Initialised: Host Version: 0x2 Vendor Version 0x10 [ 4.425884] ledtrig-cpu: registered to indicate activity on CPUs [ 4.432618] usbcore: registered new interface driver usbhid [ 4.438254] usbhid: USB HID core driver [ 4.447574] NET: Registered protocol family 10 [ 4.457534] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver [ 4.464122] NET: Registered protocol family 17 [ 4.468640] can: controller area network core (rev 20120528 abi 9) [ 4.474916] NET: Registered protocol family 29 [ 4.479407] can: raw protocol (rev 20120528) [ 4.483674] can: broadcast manager protocol (rev 20161123 t) [ 4.489377] can: netlink gateway (rev 20130117) max_hops=1 [ 4.495365] Key type dns_resolver registered [ 4.499880] ThumbEE CPU extension supported. [ 4.504158] Registering SWP/SWPB emulation handler [ 4.514923] pwm-regulator pwm-regulator: Failed to get PWM: -517 [ 4.522319] hctosys: unable to open rtc device (rtc0) [ 4.540882] sti-dwmac 9630000.dwmac eth0: IEEE 1588-2008 Advanced Timestamp supported [ 4.549053] sti-dwmac 9630000.dwmac eth0: registered PTP clock [ 4.555070] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready [ 4.558710] mmc0: new high speed SDHC card at address aaaa [ 4.561352] mmcblk0: mmc0:aaaa SL16G 14.8 GiB [ 4.572085] mmcblk0: p1 p2 [ 4.576300] pwm-regulator pwm-regulator: Failed to get PWM: -517 [ 4.717799] usb 2-1.1: new high-speed USB device number 3 using st-ehci [ 4.871691] pwm-regulator pwm-regulator: Failed to get PWM: -517 [ 9.767426] sti-dwmac 9630000.dwmac eth0: Link is Up - 1Gbps/Full - flow control off [ 9.787190] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 9.817225] Sending DHCP requests .[ 9.873075] Link is Up - 1000/Full [ 9.877155] , OK [ 9.937149] IP-Config: Got DHCP answer from 10.0.0.2, my address is 10.15.15.81 [ 9.944462] IP-Config: Complete: [ 9.947735] device=eth0, hwaddr=00:80:e1:12:81:30, ipaddr=10.15.15.81, mask=255.240.0.0, gw=10.0.0.1 [ 9.957336] host=stiH410, domain=lavalab, nis-domain=(none) [ 9.963339] bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath= nameserver0=10.0.0.2 [ 9.971983] clk: Not disabling unused clocks [ 9.980843] Freeing unused kernel memory: 2048K (c1100000 - c1300000) Starting logging: OK Populating /dev using udev: [ 10.132301] udevd[106]: starting version 3.1.5 [ 10.138015] random: udevd: uninitialized urandom read (16 bytes read) [ 10.144773] random: udevd: uninitialized urandom read (16 bytes read) [ 10.151465] random: udevd: uninitialized urandom read (16 bytes read) [ 10.273098] random: udevd: uninitialized urandom read (16 bytes read) done Initializing random number generator... [ 12.235085] random: dd: uninitialized urandom read (512 bytes read) done. Starting network... ip: RTNETLINK answers: File exists Starting dropbear sshd: [ 12.389816] random: dropbear: uninitialized urandom read (32 bytes read) OK /bin/sh: can't access tty; job control turned off Matched prompt #6: / # case: kernel-messages
case_id: 10125
definition: lava
duration: 12.32
extra: ...
level: 2.4.4
namespace: common
result: pass
end: 2.4.4 auto-login-action (duration 00:00:14) [common] case: auto-login-action
case_id: 10126
definition: lava
duration: 13.56
extra: ...
level: 2.4.4
namespace: common
result: pass
start: 2.4.5 expect-shell-connection (timeout 00:00:30) [common] Forcing a shell prompt, looking for ['linaro-test', 'root@debian:~#', '/ #'] / # expect-shell-connection: Wait for prompt ['linaro-test', 'root@debian:~#', '/ #'] (timeout 00:00:30) Waiting using forced prompt support. 14.974105954170227s timeout end: 2.4.5 expect-shell-connection (duration 00:00:00) [common] start: 2.4.6 export-device-env (timeout 00:00:30) [common] end: 2.4.6 export-device-env (duration 00:00:00) [common] end: 2.4 uboot-retry (duration 00:01:06) [common] end: 2 uboot-action (duration 00:01:08) [common] start: 3 lava-test-retry (timeout 00:05:00) [common] start: 3.1 lava-test-shell (timeout 00:05:00) [common] Using namespace: common # / # # lava-test-shell: Wait for prompt ['linaro-test', 'root@debian:~#', '/ #'] (timeout 00:05:00) # Using /lava-466 export SHELL=/bin/bash / # export SHELL=/bin/bash export SHELL=/bin/bash /lava-466/bin/lava-test-runner /lava-466/0 / # /lava-466/bin/lava-test-runner /lava-466/0 Test shell timeout: 10s (minimum of the action and connection timeout) /lava-466/bin/lava-test-runner /lava-466/0 + export TESTRUN_ID=0_smoke-tests + cd /lava-466/0/tests/0_smoke-tests + cat uuid + UUID=466_1.4.2.4.1 + set +x <LAVA_SIGNAL_STARTRUN 0_smoke-tests 466_1.4.2.4.1> + lava-test-case linux-posix-pwd --shell pwd <LAVA_SIGNAL_STARTTC linux-posix-pwd> /lava-466/0/tests/0_smoke-tests <LAVA_SIGNAL_ENDTC linux-posix-pwd> <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=linux-posix-pwd RESULT=pass> Received signal: <STARTRUN> 0_smoke-tests 466_1.4.2.4.1 Starting test lava.0_smoke-tests (466_1.4.2.4.1) Skipping test definition patterns. Received signal: <STARTTC> linux-posix-pwd Received signal: <ENDTC> linux-posix-pwd Received signal: <TESTCASE> TEST_CASE_ID=linux-posix-pwd RESULT=pass case: linux-posix-pwd
case_id: 10127
definition: 0_smoke-tests
result: pass
+ lava-test-case linux-posix-uname --shell uname -a <LAVA_SIGNAL_STARTTC linux-posix-uname> Linux buildroot 4.9.0-linaro-multi-v7 #2 SMP Tue Jan 17 17:25:49[ 14.272452] random: fast init done UTC 2017 armv7l GNU/Linux <LAVA_SIGNAL_ENDTC linux-posix-uname> <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=linux-posix-uname RESULT=pass> + lava-test-case linux-posix-vmstat --shell vmstat <LAVA_SIGNAL_STARTTC linux-posix-vmstat> /lava-466/0/../bin/lava-test-case: eval: line 1: vmstat: not found <LAVA_SIGNAL_ENDTC linux-posix-vmstat> <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=linux-posix-vmstat RESULT=fail> + lava-test-case linux-posix-ifconfig --shell ifconfig -a <LAVA_SIGNAL_STARTTC linux-posix-ifconfig> eth0 Link encap:Ethernet HWaddr 00:80:E1:12:81:30 inet addr:10.15.15.81 Bcast:10.15.255.255 Mask:255.240.0.0 inet6 addr: fe80::280:e1ff:fe12:8130%3068447520/64 Scope:Link UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:3 errors:0 dropped:0 overruns:0 frame:0 TX packets:8 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:744 (744.0 B) TX bytes:1688 (1.6 KiB) Interrupt:246 Base address:0x8000 lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 inet6 addr: ::1%3068447520/128 Scope:Host UP LOOPBACK RUNNING MTU:65536 Metric:1 RX packets:0 errors:0 dropped:0 overruns:0 frame:0 TX packets:0 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1 RX bytes:0 (0.0 B) TX bytes:0 (0.0 B) sit0 Link encap:IPv6-in-IPv4 NOARP MTU:1480 Metric:1 RX packets:0 errors:0 dropped:0 overruns:0 frame:0 TX packets:0 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1 RX bytes:0 (0.0 B) TX bytes:0 (0.0 B) <LAVA_SIGNAL_ENDTC linux-posix-ifconfig> <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=linux-posix-ifconfig RESULT=pass> + lava-test-case linux-posix-lscpu --shell lscpu <LAVA_SIGNAL_STARTTC linux-posix-lscpu> /lava-466/0/../bin/lava-test-case: eval: line 1: lscpu: not found <LAVA_SIGNAL_ENDTC linux-posix-lscpu> <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=linux-posix-lscpu RESULT=fail> + lava-test-case linux-posix-lsb_release --shell lsb_release -a <LAVA_SIGNAL_STARTTC linux-posix-lsb_release> /lava-466/0/../bin/lava-test-case: eval: line 1: lsb_release: not found <LAVA_SIGNAL_ENDTC linux-posix-lsb_release> <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=linux-posix-lsb_release RESULT=fail> + set +x <LAVA_SIGNAL_ENDRUN 0_smoke-tests 466_1.4.2.4.1> <LAVA_TEST_RUNNER EXIT> Received signal: <STARTTC> linux-posix-uname Received signal: <ENDTC> linux-posix-uname Received signal: <TESTCASE> TEST_CASE_ID=linux-posix-uname RESULT=pass case: linux-posix-uname
case_id: 10128
definition: 0_smoke-tests
result: pass
Received signal: <STARTTC> linux-posix-vmstat Received signal: <ENDTC> linux-posix-vmstat Received signal: <TESTCASE> TEST_CASE_ID=linux-posix-vmstat RESULT=fail case: linux-posix-vmstat
case_id: 10129
definition: 0_smoke-tests
result: fail
Received signal: <STARTTC> linux-posix-ifconfig Received signal: <ENDTC> linux-posix-ifconfig Received signal: <TESTCASE> TEST_CASE_ID=linux-posix-ifconfig RESULT=pass case: linux-posix-ifconfig
case_id: 10130
definition: 0_smoke-tests
result: pass
Received signal: <STARTTC> linux-posix-lscpu Received signal: <ENDTC> linux-posix-lscpu Received signal: <TESTCASE> TEST_CASE_ID=linux-posix-lscpu RESULT=fail case: linux-posix-lscpu
case_id: 10131
definition: 0_smoke-tests
result: fail
Received signal: <STARTTC> linux-posix-lsb_release Received signal: <ENDTC> linux-posix-lsb_release Received signal: <TESTCASE> TEST_CASE_ID=linux-posix-lsb_release RESULT=fail case: linux-posix-lsb_release
case_id: 10132
definition: 0_smoke-tests
result: fail
Received signal: <ENDRUN> 0_smoke-tests 466_1.4.2.4.1 Ending use of test pattern. Ending test lava.0_smoke-tests (466_1.4.2.4.1), duration 1.81 case: 0_smoke-tests
case_id: 10133
commit_id: 0f8952f18e992371f8686c59b36f44e9c6a94a1a
definition: lava
duration: 1.81
namespace: common
path: lava-test-shell/smoke-tests-basic.yaml
repository: http://git.linaro.org/lava-team/lava-functional-tests.git
result: pass
revision: unspecified
uuid: 466_1.4.2.4.1
ok: lava_test_shell seems to have completed linux-posix-ifconfig: pass linux-posix-lsb_release: fail linux-posix-lscpu: fail linux-posix-pwd: pass linux-posix-uname: pass linux-posix-vmstat: fail end: 3.1 lava-test-shell (duration 00:00:05) [common] end: 3 lava-test-retry (duration 00:00:05) [common] start: 4 finalize (timeout 00:00:30) [common] start: 4.1 power-off (timeout 00:00:15) [common] Calling: 'nice' '/usr/local/lab-scripts/snmp_pdu_control' '--port' '13' '--hostname' 'pdu15' '--command' 'off' >> pdu15 port 13 now powered off Returned 0 in 4 seconds Calling: 'nice' 'sleep' '10' power-off timed out after 15 seconds end: 4.1 power-off (duration 00:00:15) [common] case: power-off
case_id: 10136
definition: lava
duration: 15.02
extra: ...
level: 4.1
namespace: common
result: fail
Failed to run 'finalize': power-off timed out after 15 seconds Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/power.py", line 328, in run connection = super().run(connection, max_end_time) File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 767, in run return self.internal_pipeline.run_actions(connection, max_end_time) File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 243, in run_actions new_connection = action.run(connection, action_max_end_time) File "/usr/lib/python3/dist-packages/lava_dispatcher/power.py", line 239, in run self.run_cmd(cmd, error_msg="Unable to power-off: '%s' failed" % cmd) File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 614, in run_cmd for fd, event in poller.poll(): File "/usr/lib/python3/dist-packages/lava_common/timeout.py", line 75, in _timed_out raise self.exception("%s timed out after %s seconds" % (self.name, duration)) lava_common.exceptions.InfrastructureError: power-off timed out after 15 seconds end: 4 finalize (duration 00:00:15) [common] Cleaning after the job Cleaning up download directory: /var/lib/lava/dispatcher/tmp/lavafed-466/tftp-deploy-h5c_5l8j/ramdisk Cleaning up download directory: /var/lib/lava/dispatcher/tmp/lavafed-466/tftp-deploy-h5c_5l8j/kernel Cleaning up download directory: /var/lib/lava/dispatcher/tmp/lavafed-466/tftp-deploy-h5c_5l8j/dtb Override tmp directory removed at /var/lib/lava/dispatcher/tmp/lavafed-466 Root tmp directory removed at /var/lib/lava/dispatcher/tmp/lavafed-466 Job finished correctly case: job
case_id: 10137
definition: lava
result: pass

Top of page

Please read the triage guidelines for help on debugging failures in the test job, test definitions or in individual test cases.

Job Description YAML

Pipeline jobs use the job definition to generate a descriptive YAML file when the pipeline is validated. The file represents the data sent to the dispatcher at the start of the job, including details of the device as well as the job parameters and the details of the parameters sent to each of the deploy, boot and test actions in the job pipeline.

Click on the Device or Job Actions headings below to see some of the information from the description file for this job or download the complete file as YAML using the link above.

device type
hostname
timeouts
  • actions: {'minutes': 20}{'seconds': 45}{'seconds': 15}{'minutes': 10}{'minutes': 2}{'minutes': 3}{'minutes': 2}{'minutes': 3}{'minutes': 3}{'seconds': 30}{'minutes': 3}{'minutes': 3}{'minutes': 2}{'minutes': 3}{'minutes': 10}{'minutes': 5}{'minutes': 2}{'seconds': 30}{'minutes': 5} flash-uboot-umsumount-retrypower-offdd-imageboot-image-retrybootloader-retryapply-overlay-imageuboot-retrylava-test-shellu-boot-interruptbootloader-actionuboot-actionboot-qemu-imagebootloader-commandsnfs-deploydownload-retryauto-login-actionbootloader-interrupthttp-download
  • connections: {'minutes': 10}{'seconds': 30}{'seconds': 10}{'seconds': 30}{'seconds': 30}{'minutes': 2}{'seconds': 30} dd-imageuboot-retrylava-test-shellu-boot-interruptbootloader-commandsauto-login-actionbootloader-interrupt
device action methods
deploy:
  • lxc:
  • nbd:
  • image:
  • ssh:
  • usb:
  • tftp:
  • overlay:
boot:
  • dfu:
    • enter-commands: ['dfu']
    • command: dfu-util
  • minimal:
  • u-boot:
    • bootloader_prompt: =>
    • mkimage_arch: arm
    • interrupt_char:
    • interrupt_prompt: Hit any key to stop autoboot
    • needs_interrupt: True
  • ssh:
target
...
timeouts
  • job: {'seconds': 600}

  1. Timeout
    • 4 minutes
    namespace
    common
    os
    debian
    to
    tftp
    deployment_data
    {'lava_test_shell_file': '~/.bashrc', 'tar_flags': '--warning no-timestamp', 'TESTER_PS1': 'linaro-test [rc=$(echo \\$?)]# ', 'TESTER_PS1_PATTERN': 'linaro-test \\[rc=(\\d+)\\]# ', 'line_separator': '\n', 'distro': 'debian', 'TESTER_PS1_INCLUDES_RC': True, 'lava_test_dir': '/lava-%s', 'lava_test_sh_cmd': '/bin/bash', 'boot_cmds': 'boot_cmds', 'lava_test_results_dir': '/lava-%s', 'lava_test_results_part_attr': 'root_part'}
    kernel
    {'url': 'https://images.validation.linaro.org/builds.96boards.org/snapshots/b2260/linaro/debian/21/uImage', 'type': 'uimage'}
    dtb
    {'url': 'https://images.validation.linaro.org/builds.96boards.org/snapshots/b2260/linaro/debian/21/stih410-b2260.dtb'}
    ramdisk
    {'url': 'http://images.validation.linaro.org/storage.kernelci.org/images/rootfs/buildroot/armel/rootfs.cpio.gz', 'compression': 'gz'}

  1. namespace
    common
    prompts
    ['linaro-test', 'root@debian:~#', '/ #']
    method
    u-boot
    commands
    ramdisk

  1. namespace
    common
    stage
    0
    Definitions
    • from git
    • repository http://git.linaro.org/lava-team/lava-functional-tests.git
    • name smoke-tests
    • path lava-test-shell/smoke-tests-basic.yaml
    Timeout
    • 5 minutes

Job Timings

This section helps test writers to check for actions with a duration which is much shorter than the requested timeout. Reducing these timeouts will allow failures to be identified more quickly.

The graph only shows actions that are longer than 1 second. The full list is anyway available in the table.

Loading the data...