extra keys not allowed @ data['actions[0]']['deploy']['nbd']['initrd']['allow_modify']
Job error: wait for prompt timed out
lava-dispatcher, installed at version: 2023.01
start: 0 validate
Start time: 2023-11-14 17:30:24.952472+00:00 (UTC)
Validating that http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz exists
Validating that http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/Image exists
Validating that http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb exists
Validating that http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/agl-demo-platform-raspberrypi4-64.ext4.xz exists
validate duration: 0.88
case: validate
case_id: 3941016
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 61999
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/29406/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz
saving as /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz
total size: 2066870 (1MB)
No compression specified
progress 1% (0MB)
progress 6% (0MB)
progress 11% (0MB)
progress 17% (0MB)
progress 22% (0MB)
progress 28% (0MB)
progress 33% (0MB)
progress 38% (0MB)
progress 44% (0MB)
progress 49% (0MB)
progress 55% (1MB)
progress 60% (1MB)
progress 65% (1MB)
progress 71% (1MB)
progress 76% (1MB)
progress 82% (1MB)
progress 87% (1MB)
progress 93% (1MB)
progress 98% (1MB)
1MB downloaded in 1.15s (1.71MB/s)
end: 1.1.1 http-download (duration 00:00:01) [common]
case: http-download
case_id: 3941159
definition: lava
duration: 1.16
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/29406/1/raspberrypi4/Image
saving as /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/kernel/Image
total size: 24244736 (23MB)
No compression specified
progress 0% (0MB)
progress 5% (1MB)
progress 10% (2MB)
progress 15% (3MB)
progress 20% (4MB)
progress 25% (5MB)
progress 30% (6MB)
progress 35% (8MB)
progress 40% (9MB)
progress 45% (10MB)
progress 50% (11MB)
progress 55% (12MB)
progress 60% (13MB)
progress 65% (15MB)
progress 70% (16MB)
progress 75% (17MB)
progress 80% (18MB)
progress 85% (19MB)
progress 90% (20MB)
progress 95% (21MB)
progress 100% (23MB)
23MB downloaded in 5.03s (4.60MB/s)
end: 1.2.1 http-download (duration 00:00:05) [common]
case: http-download
case_id: 3941159
definition: lava
duration: 5.03
extra: ...
level: 1.2.1
namespace: common
result: pass
end: 1.2 download-retry (duration 00:00:05) [common]
start: 1.3 download-retry (timeout 01:29:54) [common]
start: 1.3.1 http-download (timeout 01:29:54) [common]
downloading http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb
saving as /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb
total size: 52323 (0MB)
No compression specified
progress 62% (0MB)
progress 100% (0MB)
0MB downloaded in 0.43s (0.12MB/s)
end: 1.3.1 http-download (duration 00:00:00) [common]
case: http-download
case_id: 3941159
definition: lava
duration: 0.43
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:53) [common]
start: 1.4.1 http-download (timeout 01:29:53) [common]
downloading http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/agl-demo-platform-raspberrypi4-64.ext4.xz
saving as /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/nbdroot/agl-demo-platform-raspberrypi4-64.ext4
total size: 795850408 (758MB)
Using unxz to decompress xz
progress 0% (0MB)
progress 5% (37MB)
progress 10% (75MB)
progress 15% (113MB)
progress 20% (151MB)
progress 25% (189MB)
progress 30% (227MB)
progress 35% (265MB)
progress 40% (303MB)
progress 45% (341MB)
progress 50% (379MB)
progress 55% (417MB)
progress 60% (455MB)
progress 65% (493MB)
progress 70% (531MB)
progress 75% (569MB)
progress 80% (607MB)
progress 85% (645MB)
progress 90% (683MB)
progress 95% (721MB)
progress 100% (758MB)
758MB downloaded in 186.61s (4.07MB/s)
end: 1.4.1 http-download (duration 00:03:07) [common]
case: http-download
case_id: 3941159
definition: lava
duration: 186.62
extra: ...
level: 1.4.1
namespace: common
result: pass
end: 1.4 download-retry (duration 00:03:07) [common]
start: 1.5 lava-overlay (timeout 01:26:47) [common]
[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup
makedir: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin
makedir: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/tests
makedir: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/results
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-add-keys
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-add-sources
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-background-process-start
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-background-process-stop
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-common-functions
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-echo-ipv4
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-install-packages
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-installed-packages
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-os-build
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-probe-channel
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-probe-ip
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-target-ip
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-target-mac
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-target-storage
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-case
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-event
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-feedback
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-raise
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-reference
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-runner
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-set
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-shell
Updating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-install-packages (oe)
Updating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-installed-packages (oe)
Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/environment
LAVA metadata
- LAVA_JOB_ID=33479
- LAVA_DISPATCHER_IP=192.168.66.1
start: 1.5.1 ssh-authorize (timeout 01:26:47) [common]
end: 1.5.1 ssh-authorize (duration 00:00:00) [common]
start: 1.5.2 lava-vland-overlay (timeout 01:26:47) [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:26:47) [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:26:47) [common]
Loading test definitions
start: 1.5.4.1 git-repo-action (timeout 01:26:47) [common]
Using /lava-33479 at stage 0
Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions
Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/0/tests/0_network-veth'
Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/0/tests/0_network-veth/test-suites/short-smoke/network-veth.yaml
uuid=33479_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: 3941183
definition: lava
duration: 0.60
extra: ...
level: 1.5.4.1
namespace: common
result: pass
start: 1.5.4.2 test-overlay (timeout 01:26:46) [common]
end: 1.5.4.2 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 3941184
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:26:46) [common]
end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 3941185
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:26:46) [common]
runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/0/tests/0_network-veth test_uuid 33479_1.5.4.1
end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common]
case: test-runscript-overlay
case_id: 3941186
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.4
namespace: common
result: pass
start: 1.5.4.5 git-repo-action (timeout 01:26:46) [common]
Using /lava-33479 at stage 1
Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions
Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/1_ci-busybox'
Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/1_ci-busybox
Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/1_ci-busybox/test-suites/short-smoke/busybox.yaml
uuid=33479_1.5.4.5 testdef={'testdef_pattern': {'pattern': '^(?P<test_case_id>[a-zA-Z0-9_-]+):\\s(?P<result>\\w+)', 'fixupdict': {'PASS': 'pass', 'FAIL': 'fail'}}}
end: 1.5.4.5 git-repo-action (duration 00:00:01) [common]
case: git-repo-action
case_id: 3941183
definition: lava
duration: 0.60
extra: ...
level: 1.5.4.5
namespace: common
result: pass
start: 1.5.4.6 test-overlay (timeout 01:26:45) [common]
end: 1.5.4.6 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 3941184
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.6
namespace: common
result: pass
start: 1.5.4.7 test-install-overlay (timeout 01:26:45) [common]
end: 1.5.4.7 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 3941185
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.7
namespace: common
result: pass
start: 1.5.4.8 test-runscript-overlay (timeout 01:26:45) [common]
runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/1_ci-busybox test_uuid 33479_1.5.4.5
end: 1.5.4.8 test-runscript-overlay (duration 00:00:00) [common]
case: test-runscript-overlay
case_id: 3941186
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.8
namespace: common
result: pass
start: 1.5.4.9 git-repo-action (timeout 01:26:45) [common]
Using /lava-33479 at stage 1
Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions
Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/2_ci-smoke-tests-basic'
Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/2_ci-smoke-tests-basic
Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/2_ci-smoke-tests-basic/test-suites/short-smoke/smoke-tests-basic.yaml
uuid=33479_1.5.4.9 testdef=None
end: 1.5.4.9 git-repo-action (duration 00:00:01) [common]
case: git-repo-action
case_id: 3941183
definition: lava
duration: 0.61
extra: ...
level: 1.5.4.9
namespace: common
result: pass
start: 1.5.4.10 test-overlay (timeout 01:26:45) [common]
end: 1.5.4.10 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 3941184
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.10
namespace: common
result: pass
start: 1.5.4.11 test-install-overlay (timeout 01:26:45) [common]
end: 1.5.4.11 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 3941185
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.11
namespace: common
result: pass
start: 1.5.4.12 test-runscript-overlay (timeout 01:26:45) [common]
runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/2_ci-smoke-tests-basic test_uuid 33479_1.5.4.9
end: 1.5.4.12 test-runscript-overlay (duration 00:00:00) [common]
case: test-runscript-overlay
case_id: 3941186
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.12
namespace: common
result: pass
start: 1.5.4.13 git-repo-action (timeout 01:26:45) [common]
Using /lava-33479 at stage 1
Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions
Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/3_ci-service-check'
Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/3_ci-service-check
Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/3_ci-service-check/test-suites/short-smoke/service-check.yaml
uuid=33479_1.5.4.13 testdef=None
end: 1.5.4.13 git-repo-action (duration 00:00:01) [common]
case: git-repo-action
case_id: 3941183
definition: lava
duration: 0.62
extra: ...
level: 1.5.4.13
namespace: common
result: pass
start: 1.5.4.14 test-overlay (timeout 01:26:44) [common]
end: 1.5.4.14 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 3941184
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.14
namespace: common
result: pass
start: 1.5.4.15 test-install-overlay (timeout 01:26:44) [common]
end: 1.5.4.15 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 3941185
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.15
namespace: common
result: pass
start: 1.5.4.16 test-runscript-overlay (timeout 01:26:44) [common]
runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/3_ci-service-check test_uuid 33479_1.5.4.13
BUILD_TAGS=''
DEVICE_TAGS=''
end: 1.5.4.16 test-runscript-overlay (duration 00:00:00) [common]
case: test-runscript-overlay
case_id: 3941186
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.16
namespace: common
result: pass
start: 1.5.4.17 git-repo-action (timeout 01:26:44) [common]
Using /lava-33479 at stage 2
Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions
Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/2/tests/4_screenshooter'
Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/2/tests/4_screenshooter/test-suites/short-smoke/screenshooter.yaml
uuid=33479_1.5.4.17 testdef=None
end: 1.5.4.17 git-repo-action (duration 00:00:01) [common]
case: git-repo-action
case_id: 3941183
definition: lava
duration: 0.58
extra: ...
level: 1.5.4.17
namespace: common
result: pass
start: 1.5.4.18 test-overlay (timeout 01:26:44) [common]
end: 1.5.4.18 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 3941184
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.18
namespace: common
result: pass
start: 1.5.4.19 test-install-overlay (timeout 01:26:44) [common]
end: 1.5.4.19 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 3941185
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.19
namespace: common
result: pass
start: 1.5.4.20 test-runscript-overlay (timeout 01:26:44) [common]
runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/2/tests/4_screenshooter test_uuid 33479_1.5.4.17
end: 1.5.4.20 test-runscript-overlay (duration 00:00:00) [common]
case: test-runscript-overlay
case_id: 3941186
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.20
namespace: common
result: pass
start: 1.5.4.21 git-repo-action (timeout 01:26:44) [common]
Using /lava-33479 at stage 3
Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions
Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3/tests/5_ci-dumpjournal'
Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3/tests/5_ci-dumpjournal
Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3/tests/5_ci-dumpjournal/test-suites/short-smoke/dumpjournal.yaml
uuid=33479_1.5.4.21 testdef={'testdef_pattern': {'pattern': '^(?P<test_case_id>[a-zA-Z0-9_-]+):\\s(?P<result>\\w+)', 'fixupdict': {'PASS': 'pass', 'FAIL': 'fail'}}}
end: 1.5.4.21 git-repo-action (duration 00:00:01) [common]
case: git-repo-action
case_id: 3941183
definition: lava
duration: 0.63
extra: ...
level: 1.5.4.21
namespace: common
result: pass
start: 1.5.4.22 test-overlay (timeout 01:26:43) [common]
end: 1.5.4.22 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 3941184
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.22
namespace: common
result: pass
start: 1.5.4.23 test-install-overlay (timeout 01:26:43) [common]
end: 1.5.4.23 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 3941185
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.23
namespace: common
result: pass
start: 1.5.4.24 test-runscript-overlay (timeout 01:26:43) [common]
runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3/tests/5_ci-dumpjournal test_uuid 33479_1.5.4.21
end: 1.5.4.24 test-runscript-overlay (duration 00:00:00) [common]
case: test-runscript-overlay
case_id: 3941186
definition: lava
duration: 0.01
extra: ...
level: 1.5.4.24
namespace: common
result: pass
Creating lava-test-runner.conf files
Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/0 for stage 0
- 0_network-veth
Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1 for stage 1
- 1_ci-busybox
- 2_ci-smoke-tests-basic
- 3_ci-service-check
Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/2 for stage 2
- 4_screenshooter
Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3 for stage 3
- 5_ci-dumpjournal
end: 1.5.4 test-definition (duration 00:00:04) [common]
start: 1.5.5 compress-overlay (timeout 01:26:43) [common]
end: 1.5.5 compress-overlay (duration 00:00:01) [common]
start: 1.5.6 persistent-nfs-overlay (timeout 01:26:42) [common]
end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common]
end: 1.5 lava-overlay (duration 00:00:05) [common]
start: 1.6 prepare-kernel (timeout 01:26:42) [common]
start: 1.6.1 uboot-prepare-kernel (timeout 01:26:42) [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:26:42) [common]
xnbd-server-deploy: starting nbd-server
NBD-IP: 192.168.66.1, NBD-PORT: 61999, NBD-ROOT: 33479/nbd-deploy-85hoc_z8/nbdroot/agl-demo-platform-raspberrypi4-64.ext4
nbd-server 61999 /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/nbdroot/agl-demo-platform-raspberrypi4-64.ext4
output:
output: ** (process:1551): WARNING **: 17:33:43.736: 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:03:18) [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}: booti 0x00080000 0x02700000:${initrd_size} 0x02400000
- {DTB_ADDR}: 0x02400000
- {DTB}: 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb
- {INITRD}: 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz
- {KERNEL_ADDR}: 0x00080000
- {KERNEL}: 33479/nbd-deploy-85hoc_z8/kernel/Image
- {LAVA_MAC}: None
- {NBDSERVERIP}: 192.168.66.1
- {NBDSERVERPORT}: 61999
- {PRESEED_CONFIG}: None
- {PRESEED_LOCAL}: None
- {RAMDISK_ADDR}: 0x02700000
- {RAMDISK}: 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.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 0x00080000 33479/nbd-deploy-85hoc_z8/kernel/Image
- tftp 0x02700000 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz
- setenv initrd_size ${filesize}
- tftp 0x02400000 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb
- setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'
- fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000
end: 2.2 bootloader-overlay (duration 00:00:00) [common]
case: bootloader-overlay
case_id: 3941187
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 63003'
Setting prompt string to ['lava-test: # ']
end: 2.3 connect-device (duration 00:00:03) [common]
start: 2.4 uboot-commands (timeout 00:19:56) [common]
start: 2.4.1 reset-device (timeout 00:19:56) [common]
start: 2.4.1.1 pdu-reboot (timeout 00:19:56) [common]
Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '7'
>> Success
>> Success
Returned 0 in 5 seconds
end: 2.4.1.1 pdu-reboot (duration 00:00:05) [common]
case: pdu-reboot
case_id: 3941200
definition: lava
duration: 5.21
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:51) [common]
Setting prompt string to ['Hit any key to stop autoboot']
bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:20:00)
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)
DRAM: 3.9 GiB
RPI 4 Model B (0xc03111)
MMC: emmc2@7e340000: 0, mmcnr@7e300000: 1
Loading Environment from FAT... *** Warning - bad CRC, using default environment
In: serial
Out: serial
Err: serial
Net: eth0: genet@7d580000
starting USB...
No working controllers found
c
end: 2.4.2 bootloader-interrupt (duration 00:00:07) [common]
start: 2.4.3 bootloader-commands (timeout 00:19:44) [common]
Setting prompt string to ['U-Boot>']
bootloader-commands: Wait for prompt ['U-Boot>'] (timeout 00:19:44)
Hit any key to stop autoboot: 2 0
Setting prompt string to ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image']
setenv autoload no
U-Boot> setenv autoload no
bootloader-commands: Wait for prompt ['U-Boot>', '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
setenv initrd_high 0xffffffff
U-Boot> setenv initrd_high 0xffffffff
bootloader-commands: Wait for prompt ['U-Boot>', '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 initrd_high 0xffffffff
setenv fdt_high 0xffffffff
U-Boot> setenv fdt_high 0xffffffff
bootloader-commands: Wait for prompt ['U-Boot>', '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 fdt_high 0xffffffff
dhcp
U-Boot> dhcp
bootloader-commands: Wait for prompt ['U-Boot>', '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)
dhcp
genet@7d580000 Waiting for PHY auto negotiation to complete....... done
BOOTP broadcast 1
BOOTP broadcast 2
BOOTP broadcast 3
DHCP client bound to address 192.168.66.241 (2384 ms)
setenv serverip 192.168.66.1
U-Boot> setenv serverip 192.168.66.1
bootloader-commands: Wait for prompt ['U-Boot>', '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
tftp 0x00080000 33479/nbd-deploy-85hoc_z8/kernel/Image
U-Boot> tftp 0x00080000 33479/nbd-deploy-85hoc_z8/kernel/Image
bootloader-commands: Wait for prompt ['U-Boot>', '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)
tftp 0x00080000 33479/nbd-deploy-85hoc_z8/kernel/Image
Using genet@7d580000 device
TFTP from server 192.168.66.1; our IP address is 192.168.66.241
Filename '33479/nbd-deploy-85hoc_z8/kernel/Image'.
Load address: 0x80000
Loading: *#################T ################################# 23.1 MiB
1.8 MiB/s
done
Bytes transferred = 24244736 (171f200 hex)
tftp 0x02700000 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz
U-Boot> tftp 0x02700000 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz
bootloader-commands: Wait for prompt ['U-Boot>', '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)
tftp 0x02700000 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz
Using genet@7d580000 device
TFTP from server 192.168.66.1; our IP address is 192.168.66.241
Filename '33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz'.
Load address: 0x2700000
Loading: *################################################## 2 MiB
2.8 MiB/s
done
Bytes transferred = 2066870 (1f89b6 hex)
setenv initrd_size ${filesize}
U-Boot> setenv initrd_size ${filesize}
bootloader-commands: Wait for prompt ['U-Boot>', '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:24)
setenv initrd_size ${filesize}
tftp 0x02400000 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb
U-Boot> tftp 0x02400000 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb
bootloader-commands: Wait for prompt ['U-Boot>', '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:24)
tftp 0x02400000 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb
Using genet@7d580000 device
TFTP from server 192.168.66.1; our IP address is 192.168.66.241
Filename '33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb'.
Load address: 0x2400000
Loading: *################################################## 51.1 KiB
1.9 MiB/s
done
Bytes transferred = 52323 (cc63 hex)
setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'
U-Boot> setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'
bootloader-commands: Wait for prompt ['U-Boot>', '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:24)
setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'
fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000
U-Boot> fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000
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:24)
fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000
## Flattened Device Tree blob at 02400000
Booting using the fdt blob at 0x2400000
Loading Ramdisk to 3ad50000, end 3af489b6 ... OK
Loading Device Tree to 000000003ad40000, end 000000003ad4ffff ... OK
Starting kernel ...
end: 2.4.3 bootloader-commands (duration 00:00:21) [common]
start: 2.4.4 auto-login-action (timeout 00:19:23) [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 0x0000000000 [0x410fd083]
start: 2.4.4.1 login-action (timeout 00:19:22) [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@raspberrypi4-64:~', 'raspberrypi4-64:~#', '/ #', 'login:', 'Login incorrect']
[login-action] Waiting for messages, (timeout 00:19:22)
[ 0.000000] Linux version 5.15.34-v8 (oe-user@oe-host) (aarch64-agl-linux-gcc (GCC) 11.4.0, GNU ld (GNU Binutils) 2.38.20220708) #1 SMP PREEMPT Wed Aug 2 18:13:20 UTC 2023
[ 0.000000] Machine model: Raspberry Pi 4 Model B
[ 0.000000] efi: UEFI not found.
[ 0.000000] Reserved memory: created CMA memory pool at 0x000000001c400000, size 316 MiB
[ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[ 0.000000] Zone ranges:
[ 0.000000] DMA [mem 0x0000000000000000-0x000000003fffffff]
[ 0.000000] DMA32 [mem 0x0000000040000000-0x00000000fbffffff]
[ 0.000000] Normal empty
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000000000000-0x000000003b3fffff]
[ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]
[ 0.000000] percpu: Embedded 29 pages/cpu s77848 r8192 d32744 u118784
[ 0.000000] Detected PIPT I-cache on CPU0
[ 0.000000] CPU features: detected: Spectre-v2
[ 0.000000] CPU features: detected: Spectre-v3a
[ 0.000000] CPU features: detected: Spectre-v4
[ 0.000000] CPU features: detected: Spectre-BHB
[ 0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 996912
[ 0.000000] Kernel command line: console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw
[ 0.000000] Unknown kernel command line parameters \"verbose earlyprintk ${extraargs} fstab=no\", will be passed to user space.
[ 0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] software IO TLB: mapped [mem 0x0000000036d40000-0x000000003ad40000] (64MB)
[ 0.000000] Memory: 3553928K/4050944K available (12928K kernel code, 2044K rwdata, 4504K rodata, 4096K init, 1007K bss, 173432K reserved, 323584K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 40745 entries in 160 pages
[ 0.000000] ftrace: allocated 160 pages with 2 groups
[ 0.000000] trace event string verifier disabled
[ 0.000000] rcu: Preemptible hierarchical RCU implementation.
[ 0.000000] rcu: RCU event tracing is enabled.
[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4.
[ 0.000000] Trampoline variant of Tasks RCU enabled.
[ 0.000000] Rude variant of Tasks RCU enabled.
[ 0.000000] Tracing variant of Tasks RCU enabled.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
[ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[ 0.000000] Root IRQ handler: gic_handle_irq
[ 0.000000] GIC: Using split EOI/Deactivate mode
[ 0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 10)
[ 0.000000] random: get_random_bytes called from start_kernel+0x514/0x708 with crng_init=0
[ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[ 0.000000] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[ 0.000252] Console: colour dummy device 80x25
[ 0.000332] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)
[ 0.000362] pid_max: default: 32768 minimum: 301
[ 0.000496] LSM: Security Framework initializing
[ 0.000746] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[ 0.000807] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[ 0.002003] cgroup: Disabling memory control group subsystem
[ 0.004555] rcu: Hierarchical SRCU implementation.
[ 0.005580] EFI services will not be available.
[ 0.006097] smp: Bringing up secondary CPUs ...
[ 0.007153] Detected PIPT I-cache on CPU1
[ 0.007224] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]
[ 0.008470] Detected PIPT I-cache on CPU2
[ 0.008519] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]
[ 0.009639] Detected PIPT I-cache on CPU3
[ 0.009687] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]
[ 0.009871] smp: Brought up 1 node, 4 CPUs
[ 0.009916] SMP: Total of 4 processors activated.
[ 0.009932] CPU features: detected: 32-bit EL0 Support
[ 0.009945] CPU features: detected: 32-bit EL1 Support
[ 0.009961] CPU features: detected: CRC32 instructions
[ 0.042709] CPU: All CPU(s) started at EL2
[ 0.042793] alternatives: patching kernel code
[ 0.044367] devtmpfs: initialized
[ 0.054717] Enabled cp15_barrier support
[ 0.054763] Enabled setend support
[ 0.054786] KASLR disabled due to lack of seed
[ 0.055116] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.055151] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[ 0.065522] pinctrl core: initialized pinctrl subsystem
[ 0.066310] DMI not present or invalid.
[ 0.066910] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[ 0.070397] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations
[ 0.070696] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[ 0.071583] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[ 0.071681] audit: initializing netlink subsys (disabled)
[ 0.071965] audit: type=2000 audit(0.068:1): state=initialized audit_enabled=0 res=1
[ 0.072499] thermal_sys: Registered thermal governor 'step_wise'
[ 0.072726] cpuidle: using governor menu
[ 0.072954] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[ 0.073140] ASID allocator initialised with 65536 entries
[ 0.073291] Serial: AMBA PL011 UART driver
[ 0.084990] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[ 0.112332] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-01-22T17:23:15, variant start
[ 0.116350] raspberrypi-firmware soc:firmware: Firmware hash is acb03c7d18aa08f25f6419d696d0cc39761d3e62
[ 0.166918] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[ 0.171200] vgaarb: loaded
[ 0.171619] SCSI subsystem initialized
[ 0.171828] usbcore: registered new interface driver usbfs
[ 0.171885] usbcore: registered new interface driver hub
[ 0.171953] usbcore: registered new device driver usb
[ 0.172303] usb_phy_generic phy: supply vcc not found, using dummy regulator
[ 0.172871] pps_core: LinuxPPS API ver. 1 registered
[ 0.172890] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <[email protected]>
[ 0.172925] PTP clock support registered
[ 0.173183] Advanced Linux Sound Architecture Driver Initialized.
[ 0.174389] clocksource: Switched to clocksource arch_sys_counter
[ 0.262962] VFS: Disk quotas dquot_6.6.0
[ 0.263084] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 0.263250] FS-Cache: Loaded
[ 0.263477] CacheFiles: Loaded
[ 0.274231] NET: Registered PF_INET protocol family
[ 0.274729] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)
[ 0.278034] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)
[ 0.278095] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)
[ 0.278310] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)
[ 0.278865] TCP: Hash tables configured (established 32768 bind 32768)
[ 0.279102] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)
[ 0.279170] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)
[ 0.279474] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 0.280473] RPC: Registered named UNIX socket transport module.
[ 0.280497] RPC: Registered udp transport module.
[ 0.280511] RPC: Registered tcp transport module.
[ 0.280524] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.280547] PCI: CLS 0 bytes, default 64
[ 0.281085] Trying to unpack rootfs image as initramfs...
[ 0.281496] rootfs image is not initramfs (no cpio magic); looks like an initrd
[ 0.288620] Freeing initrd memory: 2016K
[ 0.290514] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available
[ 0.290855] kvm [1]: IPA Size Limit: 44 bits
[ 0.292099] kvm [1]: vgic interrupt IRQ9
[ 0.292375] kvm [1]: Hyp mode initialized successfully
[ 1.053355] Initialise system trusted keyrings
[ 1.053722] workingset: timestamp_bits=46 max_order=20 bucket_order=0
[ 1.060357] zbud: loaded
[ 1.062144] FS-Cache: Netfs 'nfs' registered for caching
[ 1.062813] NFS: Registering the id_resolver key type
[ 1.062866] Key type id_resolver registered
[ 1.062881] Key type id_legacy registered
[ 1.062986] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 1.063005] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 1.064280] NET: Registered PF_ALG protocol family
[ 1.064304] Key type asymmetric registered
[ 1.064318] Asymmetric key parser 'x509' registered
[ 1.064403] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 246)
[ 1.064654] io scheduler mq-deadline registered
[ 1.064674] io scheduler kyber registered
[ 1.072554] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[ 1.072604] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[ 1.072693] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000
[ 1.072776] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000
[ 1.120489] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
[ 1.120878] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[ 1.120901] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 1.120922] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
[ 1.121009] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[ 1.121257] pci 0000:00:00.0: PME# supported from D0 D3hot
[ 1.124981] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.125259] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[ 1.125330] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[ 1.125575] pci 0000:01:00.0: PME# supported from D0 D3cold
[ 1.129156] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.129204] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[ 1.129230] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[ 1.129273] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 1.129298] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff]
[ 1.135439] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[ 1.138260] iproc-rng200 fe104000.rng: hwrng registered
[ 1.138788] vc-mem: phys_addr:0x00000000 mem_base=0x00000000 mem_size:0x00000000(0 MiB)
[ 1.140226] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[ 1.152965] brd: module loaded
[ 1.162566] loop: module loaded
[ 1.193298] Loading iSCSI transport class v2.0-870.
[ 1.197949] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[ 1.258548] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[ 1.259629] usbcore: registered new interface driver r8152
[ 1.259697] usbcore: registered new interface driver lan78xx
[ 1.259714] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 1.259730] ehci-pci: EHCI PCI platform driver
[ 1.259790] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 1.259827] ohci-pci: OHCI PCI platform driver
[ 1.261382] pci 0000:00:00.0: enabling device (0000 -> 0002)
[ 1.261424] xhci_hcd 0000:01:00.0: enabling device (0000 -> 0002)
[ 1.261527] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 1.261562] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[ 1.262279] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00003c0000000890
[ 1.263247] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15
[ 1.263273] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1.263292] usb usb1: Product: xHCI Host Controller
[ 1.263307] usb usb1: Manufacturer: Linux 5.15.34-v8 xhci-hcd
[ 1.263323] usb usb1: SerialNumber: 0000:01:00.0
[ 1.264050] hub 1-0:1.0: USB hub found
[ 1.264129] hub 1-0:1.0: 1 port detected
[ 1.264784] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 1.264811] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[ 1.264850] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[ 1.265225] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15
[ 1.265248] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1.265266] usb usb2: Product: xHCI Host Controller
[ 1.265282] usb usb2: Manufacturer: Linux 5.15.34-v8 xhci-hcd
[ 1.265298] usb usb2: SerialNumber: 0000:01:00.0
[ 1.265979] hub 2-0:1.0: USB hub found
[ 1.266047] hub 2-0:1.0: 4 ports detected
[ 1.267672] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 1.268544] usbcore: registered new interface driver uas
[ 1.268649] usbcore: registered new interface driver usb-storage
[ 1.268769] usbcore: registered new interface driver usbserial_generic
[ 1.268806] usbserial: USB Serial support registered for generic
[ 1.268869] usbcore: registered new interface driver cp210x
[ 1.268912] usbserial: USB Serial support registered for cp210x
[ 1.269150] mousedev: PS/2 mouse device common for all mice
[ 1.269756] usbcore: registered new interface driver i2c-tiny-usb
[ 1.274805] sdhci: Secure Digital Host Controller Interface driver
[ 1.274829] sdhci: Copyright(c) Pierre Ossman
[ 1.275461] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.278904] ledtrig-cpu: registered to indicate activity on CPUs
[ 1.279483] hid: raw HID events driver (C) Jiri Kosina
[ 1.279819] usbcore: registered new interface driver usbhid
[ 1.279837] usbhid: USB HID core driver
[ 1.280152] ashmem: initialized
[ 1.288362] usbcore: registered new interface driver snd-usb-audio
[ 1.289350] Initializing XFRM netlink socket
[ 1.289397] NET: Registered PF_PACKET protocol family
[ 1.289522] Key type dns_resolver registered
[ 1.290759] registered taskstats version 1
[ 1.290798] Loading compiled-in X.509 certificates
[ 1.291746] Key type ._fscrypt registered
[ 1.291767] Key type .fscrypt registered
[ 1.291780] Key type fscrypt-provisioning registered
[ 1.303142] uart-pl011 fe201000.serial: there is not valid maps for state default
[ 1.303423] uart-pl011 fe201000.serial: cts_event_workaround enabled
[ 1.303596] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 19, base_baud = 0) is a PL011 rev2
[ 1.311565] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default
[ 1.312265] printk: console [ttyS0] disabled
[ 1.312383] fe215040.serial: ttyS0 at MMIO 0xfe215040 (irq = 20, base_baud = 62500000) is a 16550
[ 1.518430] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[ 1.531103] printk: console [ttyS0] enabled
[ 1.684429] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.20
[ 1.690187] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[ 1.696692] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[ 1.702914] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[ 1.707313] usb 1-1: Product: USB2.0 Hub
[ 1.713109] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[ 1.717955] hub 1-1:1.0: USB hub found
[ 1.720644] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[ 1.727701] hub 1-1:1.0: 4 ports detected
[ 1.760784] of_cfs_init
[ 1.796763] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA
[ 1.797395] of_cfs_init: OK
[ 2.098432] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd
[ 2.108928] random: fast init done
[ 2.823824] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
[ 2.832654] bcmgenet fd580000.ethernet eth0: Link is Down
[ 2.864578] mmc1: new high speed SDIO card at address 0001
[ 2.923253] mmc0: new ultra high speed DDR50 SDHC card at address 59b4
[ 2.924115] usb 1-1.3: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0
[ 2.930857] mmcblk0: mmc0:59b4 USDU1 7.51 GiB
[ 2.938398] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 2.945840] mmcblk0: p1 p2
[ 2.950326] usb 1-1.3: Product: USB2.0 Hub
[ 2.950340] usb 1-1.3: Manufacturer: VIA Labs, Inc.
[ 2.953697] mmcblk0: mmc0:59b4 USDU1 7.51 GiB
[ 2.960010] hub 1-1.3:1.0: USB hub found
[ 2.972890] hub 1-1.3:1.0: 4 ports detected
[ 3.282420] usb 1-1.3.1: new high-speed USB device number 4 using xhci_hcd
[ 3.404114] usb 1-1.3.1: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0
[ 3.412802] usb 1-1.3.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 3.420415] usb 1-1.3.1: Product: USB2.0 Hub
[ 3.425913] usb 1-1.3.1: Manufacturer: VIA Labs, Inc.
[ 3.433276] hub 1-1.3.1:1.0: USB hub found
[ 3.437706] hub 1-1.3.1:1.0: 4 ports detected
[ 3.746419] usb 1-1.3.1.1: new high-speed USB device number 5 using xhci_hcd
[ 3.878108] usb 1-1.3.1.1: New USB device found, idVendor=0bda, idProduct=2838, bcdDevice= 1.00
[ 3.886968] usb 1-1.3.1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 3.894771] usb 1-1.3.1.1: Product: RTL2838UHIDIR
[ 3.899561] usb 1-1.3.1.1: Manufacturer: Realtek
[ 3.904261] usb 1-1.3.1.1: SerialNumber: 00000001
[ 6.910650] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[ 6.942413] Sending DHCP requests ., OK
[ 6.962366] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.241
[ 6.970462] IP-Config: Complete:
[ 6.973738] device=eth0, hwaddr=dc:a6:32:54:fa:25, ipaddr=192.168.66.241, mask=255.255.255.0, gw=192.168.66.1
[ 6.984263] host=192.168.66.241, domain=, nis-domain=(none)
[ 6.990382] bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath=
[ 6.990396] nameserver0=10.1.1.1
[ 7.002523] ALSA device list:
[ 7.005547] No soundcards found.
[ 7.009478] Waiting 7 sec before mounting root device...
[ 14.046611] RAMDISK: gzip image found at block 0
[ 14.359410] EXT4-fs (ram0): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[ 14.368976] VFS: Mounted root (ext4 filesystem) on device 1:0.
[ 14.375129] devtmpfs: mounted
[ 14.387585] Freeing unused kernel memory: 4096K
[ 14.392411] 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:61999
/sbin/init[1]: Starting NBD client
nbd-client: can't connect to remote host (192.168.66.1): Connection refused
/sbin/init[1]: NBD client failed
/sbin/init[1]: Retrying (5 trie(s) left)...
/sbin/init[1]: Starting NBD client
nbd-client: can't connect to remote host (192.168.66.1): Connection refused
/sbin/init[1]: NBD client failed
/sbin/init[1]: Retrying (4 trie(s) left)...
/sbin/init[1]: Starting NBD client
nbd-client: can't connect to remote host (192.168.66.1): Connection refused
/sbin/init[1]: NBD client failed
/sbin/init[1]: Retrying (3 trie(s) left)...
/sbin/init[1]: Starting NBD client
nbd-client: can't connect to remote host (192.168.66.1): Connection refused
/sbin/init[1]: NBD client failed
/sbin/init[1]: Retrying (2 trie(s) left)...
/sbin/init[1]: Starting NBD client
nbd-client: can't connect to remote host (192.168.66.1): Connection refused
/sbin/init[1]: NBD client failed
/sbin/init[1]: Retrying (1 trie(s) left)...
/sbin/init[1]: Starting NBD client
nbd-client: can't connect to remote host (192.168.66.1): Connection refused
/sbin/init[1]: NBD client failed
/[ 29.632606] kvm: exiting hardware virtualization
sbin/init[1]: ERROR Unable to mount NBD device /dev/nbd0 using server 192.168.66.1:61999
/sbin/init[1]: Rebooting...
[ 29.672504] bcmgenet fd580000.ethernet eth0: Link is Down
[ 29.696858] reboot: Restarting system
U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)
DRAM: 3.9 GiB
RPI 4 Model B (0xc03111)
MMC: emmc2@7e340000: 0, mmcnr@7e300000: 1
Loading Environment from FAT... *** Warning - bad CRC, using default environment
In: serial
Out: serial
Err: serial
Net: eth0: genet@7d580000
starting USB...
No working controllers found
Hit any key to stop autoboot: 2 1 0
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1...
Card did not respond to voltage select!
starting USB...
No working controllers found
USB is stopped. Please issue 'usb start' first.
starting USB...
No working controllers found
genet@7d580000 Waiting for PHY auto negotiation to complete... done
BOOTP broadcast 1
DHCP client bound to address 192.168.66.241 (3 ms)
*** ERROR: `serverip' not set
Cannot autoload with TFTPGET
missing environment variable: pxeuuid
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/01-dc-a6-32-54-fa-25
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/C0A842F1
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/C0A842F
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/C0A842
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/C0A84
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/C0A8
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/C0A
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/C0
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/C
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/default-arm-bcm283x-rpi
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/default-arm-bcm283x
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/default-arm
*** ERROR: `serverip' not set
missing environment variable: bootfile
Retrieving file: pxelinux.cfg/default
*** ERROR: `serverip' not set
Config file not found
starting USB...
No working controllers found
BOOTP broadcast 1
DHCP client bound to address 192.168.66.241 (3 ms)
*** ERROR: `serverip' not set
Cannot autoload with TFTPGET
BOOTP broadcast 1
DHCP client bound to address 192.168.66.241 (2 ms)
*** ERROR: `serverip' not set
Cannot autoload with TFTPGET
wait for prompt timed out
end: 2.4.4.1 login-action (duration 00:19:22) [common]
case: login-action
case_id: 3941271
definition: lava
duration: 1161.61
extra: ...
level: 2.4.4.1
namespace: common
result: fail
auto-login-action failed: 1 of 1 attempts. 'wait for prompt timed out'
wait for prompt timed out
end: 2.4.4 auto-login-action (duration 00:19:23) [common]
case: auto-login-action
case_id: 3941272
definition: lava
duration: 1163.46
extra: ...
level: 2.4.4
namespace: common
result: fail
wait for prompt timed out
end: 2.4 uboot-commands (duration 00:19:57) [common]
case: uboot-commands
case_id: 3941273
definition: lava
duration: 1196.55
extra: ...
level: 2.4
namespace: common
result: fail
uboot-action failed: 1 of 1 attempts. 'wait for prompt timed out'
wait for prompt timed out
end: 2 uboot-action (duration 00:20:00) [common]
case: uboot-action
case_id: 3941274
definition: lava
duration: 1200.08
extra: ...
level: 2
namespace: common
result: fail
Cleaning after the job
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/initrd
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/kernel
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/dtb
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/nbdroot
start: 7.1 power-off (timeout 00:00:10) [common]
Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '7'
>> Success
Returned 0 in 3 seconds
end: 7.1 power-off (duration 00:00:04) [common]
case: power-off
case_id: 3941275
definition: lava
duration: 3.54
extra: ...
level: 7.1
namespace: common
result: pass
start: 7.2 read-feedback (timeout 00:29:56) [common]
Listened to connection for namespace 'common' for up to 1s
Finalising connection for namespace 'common'
Disconnecting from shell: Finalise
U-Boot>
end: 7.2 read-feedback (duration 00:00:01) [common]
lava-xnbd cleanup
clean NBD port 61999
Override tmp directory removed at /var/lib/lava/dispatcher/tmp/33479
Root tmp directory removed at /var/lib/lava/dispatcher/tmp/33479
JobError: Your job cannot terminate cleanly.
case: job
case_id: 3941276
definition: lava
error_msg: wait for prompt timed out
error_type: Job
result: fail
Please read the triage guidelines for help on debugging failures in the test job, test definitions or in individual test cases.
This section helps test writers to check for actions with a duration which is much shorter than the requested timeout. Reducing these timeouts will allow failures to be identified more quickly.
The graph only shows actions that are longer than 1 second. The full list is anyway available in the table.