lava-dispatcher, installed at version: 2023.10 start: 0 validate Start time: 2024-11-27 22:26:57.130580+00:00 (UTC) Validating that http://download.automotivelinux.org/AGL/upload/ci/30554/2/h3ulcb-nogfx/initramfs-netboot-image-h3ulcb.ext4.gz exists Validating that http://download.automotivelinux.org/AGL/upload/ci/30554/2/h3ulcb-nogfx/Image exists Validating that http://download.automotivelinux.org/AGL/upload/ci/30554/2/h3ulcb-nogfx/r8a77951-ulcb.dtb exists Validating that http://download.automotivelinux.org/AGL/upload/ci/30554/2/h3ulcb-nogfx/agl-ivi-demo-qt-h3ulcb.ext4.xz exists validate duration: 0.89 case: validate
case_id: 4098565
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 61952 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/30554/2/h3ulcb-nogfx/initramfs-netboot-image-h3ulcb.ext4.gz saving as /var/lib/lava/dispatcher/tmp/37916/nbd-deploy-wn8pv286/initrd/initramfs-netboot-image-h3ulcb.ext4.gz total size: 2151539 (2 MB) No compression specified progress 1 % (0 MB) progress 6 % (0 MB) progress 12 % (0 MB) progress 18 % (0 MB) progress 24 % (0 MB) progress 30 % (0 MB) progress 35 % (0 MB) progress 41 % (0 MB) progress 47 % (0 MB) progress 53 % (1 MB) progress 59 % (1 MB) progress 65 % (1 MB) progress 70 % (1 MB) progress 76 % (1 MB) progress 82 % (1 MB) progress 88 % (1 MB) progress 94 % (1 MB) progress 100 % (2 MB) 2 MB downloaded in 0.90 s (2.28 MB/s) end: 1.1.1 http-download (duration 00:00:01) [common] case: http-download
case_id: 4098655
definition: lava
duration: 0.90
extra: ...
level: 1.1.1
namespace: common
result: pass
end: 1.1 download-retry (duration 00:00:01) [common] start: 1.2 download-retry (timeout 01:29:59) [common] start: 1.2.1 http-download (timeout 01:29:59) [common] downloading http://download.automotivelinux.org/AGL/upload/ci/30554/2/h3ulcb-nogfx/Image saving as /var/lib/lava/dispatcher/tmp/37916/nbd-deploy-wn8pv286/kernel/Image total size: 39135744 (37 MB) No compression specified progress 0 % (0 MB) progress 5 % (1 MB) progress 10 % (3 MB) progress 15 % (5 MB) progress 20 % (7 MB) progress 25 % (9 MB) progress 30 % (11 MB) progress 35 % (13 MB) progress 40 % (14 MB) progress 45 % (16 MB) progress 50 % (18 MB) progress 55 % (20 MB) progress 60 % (22 MB) progress 65 % (24 MB) progress 70 % (26 MB) progress 75 % (28 MB) progress 80 % (29 MB) progress 85 % (31 MB) progress 90 % (33 MB) progress 95 % (35 MB) progress 100 % (37 MB) 37 MB downloaded in 2.21 s (16.92 MB/s) end: 1.2.1 http-download (duration 00:00:02) [common] case: http-download
case_id: 4098655
definition: lava
duration: 2.21
extra: ...
level: 1.2.1
namespace: common
result: pass
end: 1.2 download-retry (duration 00:00:02) [common] start: 1.3 download-retry (timeout 01:29:57) [common] start: 1.3.1 http-download (timeout 01:29:57) [common] downloading http://download.automotivelinux.org/AGL/upload/ci/30554/2/h3ulcb-nogfx/r8a77951-ulcb.dtb saving as /var/lib/lava/dispatcher/tmp/37916/nbd-deploy-wn8pv286/dtb/r8a77951-ulcb.dtb total size: 82960 (0 MB) No compression specified progress 39 % (0 MB) progress 78 % (0 MB) progress 100 % (0 MB) 0 MB downloaded in 0.40 s (0.20 MB/s) end: 1.3.1 http-download (duration 00:00:00) [common] case: http-download
case_id: 4098655
definition: lava
duration: 0.40
extra: ...
level: 1.3.1
namespace: common
result: pass
end: 1.3 download-retry (duration 00:00:00) [common] start: 1.4 download-retry (timeout 01:29:56) [common] start: 1.4.1 http-download (timeout 01:29:56) [common] downloading http://download.automotivelinux.org/AGL/upload/ci/30554/2/h3ulcb-nogfx/agl-ivi-demo-qt-h3ulcb.ext4.xz saving as /var/lib/lava/dispatcher/tmp/37916/nbd-deploy-wn8pv286/nbdroot/agl-ivi-demo-qt-h3ulcb.ext4 total size: 620551352 (591 MB) Using unxz to decompress xz progress 0 % (0 MB) progress 5 % (29 MB) progress 10 % (59 MB) progress 15 % (88 MB) progress 20 % (118 MB) progress 25 % (147 MB) progress 30 % (177 MB) progress 35 % (207 MB) progress 40 % (236 MB) progress 45 % (266 MB) progress 50 % (295 MB) progress 55 % (325 MB) progress 60 % (355 MB) progress 65 % (384 MB) progress 70 % (414 MB) progress 75 % (443 MB) progress 80 % (473 MB) progress 85 % (503 MB) progress 90 % (532 MB) progress 95 % (562 MB) progress 100 % (591 MB) 591 MB downloaded in 74.26 s (7.97 MB/s) end: 1.4.1 http-download (duration 00:01:14) [common] case: http-download
case_id: 4098655
definition: lava
duration: 74.26
extra: ...
level: 1.4.1
namespace: common
result: pass
end: 1.4 download-retry (duration 00:01:14) [common] start: 1.5 lava-overlay (timeout 01:28:42) [common] [common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk makedir: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin makedir: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/tests makedir: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/results Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-add-keys Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-add-sources Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-background-process-start Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-background-process-stop Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-common-functions Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-echo-ipv4 Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-install-packages Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-installed-packages Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-os-build Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-probe-channel Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-probe-ip Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-target-ip Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-target-mac Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-target-storage Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-test-case Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-test-event Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-test-feedback Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-test-raise Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-test-reference Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-test-runner Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-test-set Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-test-shell Updating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-install-packages (oe) Updating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/bin/lava-installed-packages (oe) Creating /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/environment LAVA metadata - LAVA_JOB_ID=37916 - LAVA_DISPATCHER_IP=192.168.66.1 start: 1.5.1 ssh-authorize (timeout 01:28:42) [common] end: 1.5.1 ssh-authorize (duration 00:00:00) [common] start: 1.5.2 lava-vland-overlay (timeout 01:28:42) [common] skipped lava-vland-overlay end: 1.5.2 lava-vland-overlay (duration 00:00:00) [common] start: 1.5.3 lava-multinode-overlay (timeout 01:28:42) [common] skipped lava-multinode-overlay end: 1.5.3 lava-multinode-overlay (duration 00:00:00) [common] start: 1.5.4 test-definition (timeout 01:28:42) [common] Loading test definitions start: 1.5.4.1 git-repo-action (timeout 01:28:42) [common] Using /lava-37916 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/37916/lava-overlay-yellvvhk/lava-37916/0/tests/0_network-veth' Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/0/tests/0_network-veth/test-suites/short-smoke/network-veth.yaml uuid=37916_1.5.4.1 testdef=None end: 1.5.4.1 git-repo-action (duration 00:00:00) [common] case: git-repo-action
case_id: 4098676
definition: lava
duration: 0.31
extra: ...
level: 1.5.4.1
namespace: common
result: pass
start: 1.5.4.2 test-overlay (timeout 01:28:42) [common] end: 1.5.4.2 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4098677
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.2
namespace: common
result: pass
start: 1.5.4.3 test-install-overlay (timeout 01:28:42) [common] end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4098678
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.3
namespace: common
result: pass
start: 1.5.4.4 test-runscript-overlay (timeout 01:28:42) [common] runner path: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/0/tests/0_network-veth test_uuid 37916_1.5.4.1 end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4098679
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.4
namespace: common
result: pass
start: 1.5.4.5 git-repo-action (timeout 01:28:42) [common] Using /lava-37916 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/37916/lava-overlay-yellvvhk/lava-37916/1/tests/1_ci-busybox' Removing '.git' directory in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/1/tests/1_ci-busybox Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/1/tests/1_ci-busybox/test-suites/short-smoke/busybox.yaml uuid=37916_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: 4098676
definition: lava
duration: 0.61
extra: ...
level: 1.5.4.5
namespace: common
result: pass
start: 1.5.4.6 test-overlay (timeout 01:28:41) [common] end: 1.5.4.6 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4098677
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.6
namespace: common
result: pass
start: 1.5.4.7 test-install-overlay (timeout 01:28:41) [common] end: 1.5.4.7 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4098678
definition: lava
duration: 0.04
extra: ...
level: 1.5.4.7
namespace: common
result: pass
start: 1.5.4.8 test-runscript-overlay (timeout 01:28:41) [common] runner path: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/1/tests/1_ci-busybox test_uuid 37916_1.5.4.5 end: 1.5.4.8 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4098679
definition: lava
duration: 0.07
extra: ...
level: 1.5.4.8
namespace: common
result: pass
start: 1.5.4.9 git-repo-action (timeout 01:28:41) [common] Using /lava-37916 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/37916/lava-overlay-yellvvhk/lava-37916/1/tests/2_ci-smoke-tests-basic' Removing '.git' directory in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/1/tests/2_ci-smoke-tests-basic Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/1/tests/2_ci-smoke-tests-basic/test-suites/short-smoke/smoke-tests-basic.yaml uuid=37916_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: 4098676
definition: lava
duration: 0.76
extra: ...
level: 1.5.4.9
namespace: common
result: pass
start: 1.5.4.10 test-overlay (timeout 01:28:40) [common] end: 1.5.4.10 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4098677
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.10
namespace: common
result: pass
start: 1.5.4.11 test-install-overlay (timeout 01:28:40) [common] end: 1.5.4.11 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4098678
definition: lava
duration: 0.08
extra: ...
level: 1.5.4.11
namespace: common
result: pass
start: 1.5.4.12 test-runscript-overlay (timeout 01:28:40) [common] runner path: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/1/tests/2_ci-smoke-tests-basic test_uuid 37916_1.5.4.9 end: 1.5.4.12 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4098679
definition: lava
duration: 0.08
extra: ...
level: 1.5.4.12
namespace: common
result: pass
start: 1.5.4.13 git-repo-action (timeout 01:28:40) [common] Using /lava-37916 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/37916/lava-overlay-yellvvhk/lava-37916/1/tests/3_ci-service-check' Removing '.git' directory in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/1/tests/3_ci-service-check Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/1/tests/3_ci-service-check/test-suites/short-smoke/service-check.yaml uuid=37916_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: 4098676
definition: lava
duration: 0.80
extra: ...
level: 1.5.4.13
namespace: common
result: pass
start: 1.5.4.14 test-overlay (timeout 01:28:39) [common] end: 1.5.4.14 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4098677
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.14
namespace: common
result: pass
start: 1.5.4.15 test-install-overlay (timeout 01:28:39) [common] end: 1.5.4.15 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4098678
definition: lava
duration: 0.08
extra: ...
level: 1.5.4.15
namespace: common
result: pass
start: 1.5.4.16 test-runscript-overlay (timeout 01:28:39) [common] runner path: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/1/tests/3_ci-service-check test_uuid 37916_1.5.4.13 BUILD_TAGS='' DEVICE_TAGS='kingfisher can bluetooth wifi audio' end: 1.5.4.16 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4098679
definition: lava
duration: 0.08
extra: ...
level: 1.5.4.16
namespace: common
result: pass
start: 1.5.4.17 git-repo-action (timeout 01:28:39) [common] Using /lava-37916 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/37916/lava-overlay-yellvvhk/lava-37916/2/tests/4_screenshooter' Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/2/tests/4_screenshooter/test-suites/short-smoke/screenshooter.yaml uuid=37916_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: 4098676
definition: lava
duration: 0.82
extra: ...
level: 1.5.4.17
namespace: common
result: pass
start: 1.5.4.18 test-overlay (timeout 01:28:38) [common] end: 1.5.4.18 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4098677
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:28:38) [common] end: 1.5.4.19 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4098678
definition: lava
duration: 0.07
extra: ...
level: 1.5.4.19
namespace: common
result: pass
start: 1.5.4.20 test-runscript-overlay (timeout 01:28:38) [common] runner path: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/2/tests/4_screenshooter test_uuid 37916_1.5.4.17 end: 1.5.4.20 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4098679
definition: lava
duration: 0.06
extra: ...
level: 1.5.4.20
namespace: common
result: pass
start: 1.5.4.21 git-repo-action (timeout 01:28:38) [common] Using /lava-37916 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/37916/lava-overlay-yellvvhk/lava-37916/3/tests/5_ci-dumpjournal' Removing '.git' directory in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/3/tests/5_ci-dumpjournal Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/3/tests/5_ci-dumpjournal/test-suites/short-smoke/dumpjournal.yaml uuid=37916_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:00) [common] case: git-repo-action
case_id: 4098676
definition: lava
duration: 0.32
extra: ...
level: 1.5.4.21
namespace: common
result: pass
start: 1.5.4.22 test-overlay (timeout 01:28:38) [common] end: 1.5.4.22 test-overlay (duration 00:00:00) [common] case: test-overlay
case_id: 4098677
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.22
namespace: common
result: pass
start: 1.5.4.23 test-install-overlay (timeout 01:28:38) [common] end: 1.5.4.23 test-install-overlay (duration 00:00:00) [common] case: test-install-overlay
case_id: 4098678
definition: lava
duration: 0.00
extra: ...
level: 1.5.4.23
namespace: common
result: pass
start: 1.5.4.24 test-runscript-overlay (timeout 01:28:38) [common] runner path: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/3/tests/5_ci-dumpjournal test_uuid 37916_1.5.4.21 end: 1.5.4.24 test-runscript-overlay (duration 00:00:00) [common] case: test-runscript-overlay
case_id: 4098679
definition: lava
duration: 0.00
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/37916/lava-overlay-yellvvhk/lava-37916/0 for stage 0 - 0_network-veth Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/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/37916/lava-overlay-yellvvhk/lava-37916/2 for stage 2 - 4_screenshooter Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/37916/lava-overlay-yellvvhk/lava-37916/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:28:38) [common] end: 1.5.5 compress-overlay (duration 00:00:00) [common] start: 1.5.6 persistent-nfs-overlay (timeout 01:28:38) [common] end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common] end: 1.5 lava-overlay (duration 00:00:04) [common] start: 1.6 prepare-kernel (timeout 01:28:38) [common] start: 1.6.1 uboot-prepare-kernel (timeout 01:28:38) [common] end: 1.6.1 uboot-prepare-kernel (duration 00:00:00) [common] end: 1.6 prepare-kernel (duration 00:00:00) [common] start: 1.7 xnbd-server-deploy (timeout 01:28:38) [common] xnbd-server-deploy: starting nbd-server NBD-IP: 192.168.66.1, NBD-PORT: 61952, NBD-ROOT: 37916/nbd-deploy-wn8pv286/nbdroot/agl-ivi-demo-qt-h3ulcb.ext4 nbd-server 61952 /var/lib/lava/dispatcher/tmp/37916/nbd-deploy-wn8pv286/nbdroot/agl-ivi-demo-qt-h3ulcb.ext4 output: output: ** (process:2433): WARNING **: 22:28:20.201: Specifying an export on the command line no longer uses the oldstyle protocol. output: xnbd-server-deploy: starting nbd-server done end: 1.7 xnbd-server-deploy (duration 00:00:00) [common] end: 1 nbd-deploy (duration 00:01:22) [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 0x68080000 0x4a000000:${initrd_size} 0x68000000 - {DTB_ADDR}: 0x68000000 - {DTB}: 37916/nbd-deploy-wn8pv286/dtb/r8a77951-ulcb.dtb - {INITRD}: 37916/nbd-deploy-wn8pv286/initrd/initramfs-netboot-image-h3ulcb.ext4.gz - {KERNEL_ADDR}: 0x68080000 - {KERNEL}: 37916/nbd-deploy-wn8pv286/kernel/Image - {LAVA_MAC}: None - {NBDSERVERIP}: 192.168.66.1 - {NBDSERVERPORT}: 61952 - {PRESEED_CONFIG}: None - {PRESEED_LOCAL}: None - {RAMDISK_ADDR}: 0x4a000000 - {RAMDISK}: 37916/nbd-deploy-wn8pv286/initrd/initramfs-netboot-image-h3ulcb.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 0xffffffffffffffff - setenv fdt_high 0xffffffffffffffff - dhcp - setenv serverip 192.168.66.1 - tftp 0x68080000 37916/nbd-deploy-wn8pv286/kernel/Image - tftp 0x4a000000 37916/nbd-deploy-wn8pv286/initrd/initramfs-netboot-image-h3ulcb.ext4.gz - setenv initrd_size ${filesize} - tftp 0x68000000 37916/nbd-deploy-wn8pv286/dtb/r8a77951-ulcb.dtb - setenv bootargs 'console=ttySC0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61952 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw' - booti 0x68080000 0x4a000000:${initrd_size} 0x68000000 end: 2.2 bootloader-overlay (duration 00:00:00) [common] case: bootloader-overlay
case_id: 4098680
definition: lava
duration: 0.00
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 63001' Setting prompt string to ['lava-test: # '] end: 2.3 connect-device (duration 00:00:00) [common] start: 2.4 uboot-commands (timeout 00:20:00) [common] start: 2.4.1 reset-device (timeout 00:20:00) [common] start: 2.4.1.1 pdu-reboot (timeout 00:20:00) [common] Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '2' >> Success >> Success Returned 0 in 1 seconds end: 2.4.1.1 pdu-reboot (duration 00:00:01) [common] case: pdu-reboot
case_id: 4098681
definition: lava
duration: 1.38
extra: ...
level: 2.4.1.1
namespace: common
result: pass
end: 2.4.1 reset-device (duration 00:00:01) [common] start: 2.4.2 bootloader-interrupt (timeout 00:19:59) [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 '^]'. NOTICE: BL2: R-Car Gen3 Initial Program Loa�NOTICE: BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.4.0.0 NOTICE: BL2: PRR is R-Car H3 Ver.3.0 NOTICE: BL2: Board is Starter Kit Premier Rev.2.0 NOTICE:�NOTICE: BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.4.0.0 NOTICE: BL2: PRR is R-Car H3 Ver.3.0 NOTICE: BL2: Board is Starter Kit Premier Rev.2.0 NOTICE: BL2: Boot device is HyperFlash(80MHz) NOTICE: BL2: LCM st�NOTICE: BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.4.0.0 NOTICE: BL2: PRR is R-Car H3 Ver.3.0 NOTICE: BL2: Board is Starter KNOTICE: BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.4.0.0 NOTICE: BL2: PRR is R-Car H3 Ver.3.0 NOTICE: BL2: BoNOTICE: BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.4.0.0 NOTICE: BL2: PRR is R-Car H3 Ver.3.0 NOTICE: BL2: Board is Starter Kit Premier Rev.2.0 NOTICE: BL2: Boot device is Hyper�NOTICE: BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.4.0.0 NOTICE: BL2: PRR is R-Car H3 Ver.3.0 NOTICE: BL2: Board is Starter Kit Premier Rev.2.0 NOTICE: BL2: Boot device is HyperFlash(80MHz) NOTICE: BL2: LCM state is CM NOTICE: AVS setting suc�NOTICE: BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.4.0.0 NOTICE: BL2: PRR is R-Car H3 Ver.3.0 NOTICE: BL2: Board is Starter Kit Premier Rev.2.0 NOTICE: BL2: Boot device is HyperFlash(80MHz) NOTICE: BL2: LCM state is CM NOTICE: AVS setting succeeded. DVFS_SetVID=0x53 NOTICE: BL2: DDR3200(rev.0.42) NOTICE: BL2: [COLD_BOOT] NOTICE: BL2: DRAM Split is 4ch(DDR f) NOTICE: BL2: QoS is default setting(rev.0.11) NOTICE: BL2: DRAM refresh interval 1.95 usec NOTICE: BL2: Periodic Write DQ Training NOTICE: BL2: CH0: 400000000 - 47fffffff, 2 GiB NOTICE: BL2: CH1: 500000000 - 57fffffff, 2 GiB NOTICE: BL2: CH2: 600000000 - 67fffffff, 2 GiB NOTICE: BL2: CH3: 700000000 - 77fffffff, 2 GiB NOTICE: BL2: FDT at 0xe6326f78 NOTICE: BL2: v2.9(release):9cdb21f75-dirty NOTICE: BL2: Built : 14:13:42, Oct 24 2024 NOTICE: BL2: Normal boot NOTICE: BL2: dst=0xe6326800 src=0x8180000 len=512(0x200) NOTICE: BL2: dst=0x43f00000 src=0x8180400 len=6144(0x1800) NOTICE: rcar_file_len: len: 0x0003e000 NOTICE: BL2: dst=0x44000000 src=0x81c0000 len=253952(0x3e000) NOTICE: rcar_file_len: len: 0x00200000 NOTICE: BL2: dst=0x44100000 src=0x8200000 len=2097152(0x200000) NOTICE: rcar_file_len: len: 0x00100000 NOTICE: BL2: dst=0x50000000 src=0x8640000 len=1048576(0x100000) NOTICE: BL2: Booting BL31 U-Boot 2020.10 (Oct 24 2024 - 14:13:42 +0000) CPU: Renesas Electronics R8A7795 rev 3.0 Model: Renesas H3ULCB board based on r8a77950 DRAM: 7.9 GiB RAM Configuration: Bank #0: 0x048000000 - 0x0bfffffff, 1.9 GiB Bank #1: 0x500000000 - 0x57fffffff, 2 GiB Bank #2: 0x600000000 - 0x67fffffff, 2 GiB Bank #3: 0x700000000 - 0x77fffffff, 2 GiB MMC: sd@ee100000: 0, sd@ee140000: 1 Loading Environment from MMC... OK In: serial@e6e88000 Out: serial@e6e88000 Err: serial@e6e88000 Net: eth0: ethernet@e6800000 Hit any key to stop autoboot: 3 end: 2.4.2 bootloader-interrupt (duration 00:00:02) [common] start: 2.4.3 bootloader-commands (timeout 00:19:57) [common] Setting prompt string to ['=>'] bootloader-commands: Wait for prompt ['=>'] (timeout 00:19:57)  0 Setting prompt string to ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] setenv autoload no => setenv autoload no bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:57) setenv autoload no setenv initrd_high 0xffffffffffffffff => setenv initrd_high 0xffffffffffffffff bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:57) setenv initrd_high 0xffffffffffffffff setenv fdt_high 0xffffffffffffffff => setenv fdt_high 0xffffffffffffffff bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:57) setenv fdt_high 0xffffffffffffffff dhcp => dhcp bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:56) dhcp ethernet@e6800000 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.15 (1011 ms) setenv serverip 192.168.66.1 => setenv serverip 192.168.66.1 bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:52) setenv serverip 192.168.66.1 tftp 0x68080000 37916/nbd-deploy-wn8pv286/kernel/Image => tftp 0x68080000 37916/nbd-deploy-wn8pv286/kernel/Image bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:52) tftp 0x68080000 37916/nbd-deploy-wn8pv286/kernel/Image Using ethernet@e6800000 device TFTP from server 192.168.66.1; our IP address is 192.168.66.15 Filename '37916/nbd-deploy-wn8pv286/kernel/Image'. Load address: 0x68080000 Loading: *################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# ################################################################# # 3.5 MiB/s done Bytes transferred = 39135744 (2552a00 hex) tftp 0x4a000000 37916/nbd-deploy-wn8pv286/initrd/initramfs-netboot-image-h3ulcb.ext4.gz => tftp 0x4a000000 37916/nbd-deploy-wn8pv286/initrd/initramfs-netboot-image-h3ulcb.ext4.gz bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:41) tftp 0x4a000000 37916/nbd-deploy-wn8pv286/initrd/initramfs-netboot-image-h3ulcb.ext4.gz Using ethernet@e6800000 device TFTP from server 192.168.66.1; our IP address is 192.168.66.15 Filename '37916/nbd-deploy-wn8pv286/initrd/initramfs-netboot-image-h3ulcb.ext4.gz'. Load address: 0x4a000000 Loading: *################################################################# ################################################################# ################# 3.2 MiB/s done Bytes transferred = 2151539 (20d473 hex) setenv initrd_size ${filesize} => setenv initrd_size ${filesize} bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:41) setenv initrd_size ${filesize} tftp 0x68000000 37916/nbd-deploy-wn8pv286/dtb/r8a77951-ulcb.dtb => tftp 0x68000000 37916/nbd-deploy-wn8pv286/dtb/r8a77951-ulcb.dtb bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:40) tftp 0x68000000 37916/nbd-deploy-wn8pv286/dtb/r8a77951-ulcb.dtb Using ethernet@e6800000 device TFTP from server 192.168.66.1; our IP address is 192.168.66.15 Filename '37916/nbd-deploy-wn8pv286/dtb/r8a77951-ulcb.dtb'. Load address: 0x68000000 Loading: *###### 3.3 MiB/s done Bytes transferred = 82960 (14410 hex) setenv bootargs 'console=ttySC0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61952 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw' =>setenv bootargs 'console=ttySC0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61952 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw' bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:40) setenv bootargs 'console=ttySC0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61952 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw' booti 0x68080000 0x4a000000:${initrd_size} 0x68000000 => booti 0x68080000 0x4a000000:${initrd_size} 0x68000000 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:40) booti 0x68080000 0x4a000000:${initrd_size} 0x68000000 Moving Image from 0x68080000 to 0x68200000, end=6a7f0000 ## Flattened Device Tree blob at 68000000 Booting using the fdt blob at 0x68000000 Using Device Tree in place at 0000000068000000, end 000000006801740f Starting kernel ... end: 2.4.3 bootloader-commands (duration 00:00:17) [common] start: 2.4.4 auto-login-action (timeout 00:19:40) [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 [0x411fd073] [ 0.000000] Linux version 5.10.194-yocto-standard (oe-user@oe-host) (aarch64-agl-linux-gcc (GCC) 13.3.0, GNU ld (GNU Binutils) 2.42.0.20240716) #1 SMP PREEMPT Mon Nov 25 10:43:33 UTC 2024 [ 0.000000] Machine model: Renesas H3ULCB board based on r8a77951 [ 0.000000] efi: UEFI not found. start: 2.4.4.1 login-action (timeout 00:19:39) [common] The string '/ #' does not look like a typical prompt and could match status messages instead. Please check the job log files and use a prompt string which matches the actual prompt string more closely. Setting prompt string to [] Setting prompt string to ['-\\[ cut here \\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing'] Using line separator: #'\n'# Waiting for the login prompt Parsing kernel messages ['-\\[ cut here \\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing', 'root@h3ulcb:~', 'h3ulcb:~#', '/ #', 'login:', 'Login incorrect'] [login-action] Waiting for messages, (timeout 00:19:39) [ 0.000000] Reserved memory: created CMA memory pool at 0x0000000057000000, size 400 MiB [ 0.000000] OF: reserved mem: initialized node linux,cma@57000000, compatible id shared-dma-pool [ 0.000000] Reserved memory: created CMA memory pool at 0x0000000070000000, size 256 MiB [ 0.000000] OF: reserved mem: initialized node linux,multimedia@70000000, compatible id shared-dma-pool [ 0.000000] NUMA: No NUMA configuration found [ 0.000000] NUMA: Faking a node at [mem 0x0000000048000000-0x000000077fffffff] [ 0.000000] NUMA: NODE_DATA [mem 0x77efe9b00-0x77efebfff] [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000048000000-0x00000000ffffffff] [ 0.000000] DMA32 empty [ 0.000000] Normal [mem 0x0000000100000000-0x000000077fffffff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000048000000-0x0000000053ffffff] [ 0.000000] node 0: [mem 0x0000000054000000-0x0000000056ffffff] [ 0.000000] node 0: [mem 0x0000000057000000-0x00000000bfffffff] [ 0.000000] node 0: [mem 0x0000000500000000-0x000000057fffffff] [ 0.000000] node 0: [mem 0x0000000600000000-0x000000067fffffff] [ 0.000000] node 0: [mem 0x0000000700000000-0x000000077fffffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000048000000-0x000000077fffffff] [ 0.000000] psci: probing for conduit method from DT. [ 0.000000] psci: PSCIv1.1 detected in firmware. [ 0.000000] psci: Using standard PSCI v0.2 function IDs [ 0.000000] psci: Trusted OS resident on physical CPU 0x0 [ 0.000000] psci: SMC Calling Convention v1.2 [ 0.000000] percpu: Embedded 33 pages/cpu s94808 r8192 d32168 u135168 [ 0.000000] Detected PIPT I-cache on CPU0 [ 0.000000] CPU features: detected: EL2 vector hardening [ 0.000000] CPU features: detected: Spectre-v2 [ 0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923 [ 0.000000] CPU features: detected: Spectre-BHB [ 0.000000] CPU features: detected: ARM erratum 1742098 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 2032128 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: console=ttySC0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61952 root=/dev/ram0 ramdisk_size=16384 rootdelay=7 systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw [ 0.000000] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear) [ 0.000000] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) [ 0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off [ 0.000000] software IO TLB: mapped [mem 0x00000000bc000000-0x00000000c0000000] (64MB) [ 0.000000] Memory: 7307716K/8257536K available (17664K kernel code, 3786K rwdata, 9332K rodata, 7296K init, 563K bss, 278076K reserved, 671744K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=8, Nodes=1 [ 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=8. [ 0.000000] Trampoline variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=8 [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 [ 0.000000] GIC: Adjusting CPU interface base to 0x00000000f102f000 [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] arch_timer: cp15 timer(s) running at 8.33MHz (phys). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x1ec02923e, max_idle_ns: 440795202125 ns [ 0.000003] sched_clock: 56 bits at 8MHz, resolution 120ns, wraps every 2199023255496ns [ 0.000165] Console: colour dummy device 80x25 [ 0.000244] Calibrating delay loop (skipped), value calculated using timer frequency.. 16.66 BogoMIPS (lpj=33333) [ 0.000256] pid_max: default: 32768 minimum: 301 [ 0.000308] LSM: Security Framework initializing [ 0.000336] SELinux: Initializing. [ 0.000375] LSM support for eBPF active [ 0.000445] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 0.000492] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 0.002061] rcu: Hierarchical SRCU implementation. [ 0.003603] Detected Renesas R-Car Gen3 r8a7795 ES3.0 [ 0.005459] EFI services will not be available. [ 0.005806] smp: Bringing up secondary CPUs ... [ 0.006310] Detected PIPT I-cache on CPU1 [ 0.006361] CPU1: Booted secondary processor 0x0000000001 [0x411fd073] [ 0.006875] Detected PIPT I-cache on CPU2 [ 0.006900] CPU2: Booted secondary processor 0x0000000002 [0x411fd073] [ 0.007358] Detected PIPT I-cache on CPU3 [ 0.007380] CPU3: Booted secondary processor 0x0000000003 [0x411fd073] [ 0.007838] CPU features: detected: ARM erratum 845719 [ 0.007851] Detected VIPT I-cache on CPU4 [ 0.007897] CPU4: Booted secondary processor 0x0000000100 [0x410fd034] [ 0.008419] Detected VIPT I-cache on CPU5 [ 0.008447] CPU5: Booted secondary processor 0x0000000101 [0x410fd034] [ 0.008924] Detected VIPT I-cache on CPU6 [ 0.008951] CPU6: Booted secondary processor 0x0000000102 [0x410fd034] [ 0.009409] Detected VIPT I-cache on CPU7 [ 0.009436] CPU7: Booted secondary processor 0x0000000103 [0x410fd034] [ 0.009518] smp: Brought up 1 node, 8 CPUs [ 0.009544] SMP: Total of 8 processors activated. [ 0.009550] CPU features: detected: 32-bit EL0 Support [ 0.009556] CPU features: detected: CRC32 instructions [ 0.009560] CPU features: detected: 32-bit EL1 Support [ 0.023385] CPU: All CPU(s) started at EL2 [ 0.023435] alternatives: patching kernel code [ 0.024555] devtmpfs: initialized [ 0.031034] KASLR disabled due to lack of seed [ 0.031178] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns [ 0.031194] futex hash table entries: 2048 (order: 5, 131072 bytes, linear) [ 0.035252] BUG: Bad page state in process swapper/0 pfn:6a7e0 [ 0.035269] page:(____ptrval____) refcount:0 mapcount:-128 mapping:0000000000000000 index:0x0 pfn:0x6a7e0 Matched prompt #7: (kernel BUG at|BUG:) Setting prompt string to ['\\r', 'root@h3ulcb:~', 'h3ulcb:~#', '/ #', 'login:', 'Login incorrect'] 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', 'root@h3ulcb:~', 'h3ulcb:~#', '/ #', 'login:', 'Login incorrect'] login-action: kernel 'bug' [login-action] Waiting for messages, (timeout 00:19:38) [ 0.035277] flags: 0x3fffc0000000000() CMA [ 0.035286] raw: 03fffc0000000000 ffff00073efe9ca0 ffff00073efe9ca0 0000000000000000 [ 0.035292] raw: 0000000000000000 0000000000000002 00000000ffffff7f 0000000000000000 [ 0.035296] page dumped because: nonzero mapcount [ 0.035301] Modules linked in: [ 0.035313] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.10.194-yocto-standard #1 [ 0.035318] Hardware name: Renesas H3ULCB board based on r8a77951 (DT) [ 0.035323] Call trace: [ 0.035337] dump_backtrace+0x0/0x1c4 [ 0.035343] show_stack+0x18/0x2c [ 0.035352] dump_stack+0xe4/0x120 [ 0.035361] bad_page+0xe0/0x110 [ 0.035367] check_free_page_bad+0x7c/0x90 [ 0.035372] __free_pages_ok+0x37c/0x3e4 [ 0.035378] __free_pages+0xd8/0xf0 [ 0.035388] init_cma_reserved_pageblock+0x54/0x70 [ 0.035394] cma_init_reserved_areas+0x11c/0x190 [ 0.035400] do_one_initcall+0x58/0x2e0 [ 0.035408] kernel_init_freeable+0x240/0x2ac [ 0.035416] kernel_init+0x14/0x118 [ 0.035421] ret_from_fork+0x10/0x3c [ 0.035426] Disabling lock debugging due to kernel taint [ 0.035432] BUG: Bad page state in process swapper/0 pfn:6a7e4 [ 0.035438] page:(____ptrval____) refcount:0 mapcount:-128 mapping:0000000000000000 index:0x0 pfn:0x6a7e4 [ 0.035442] flags: 0x3fffc0000000000() CMA [ 0.035448] raw: 03fffc0000000000 ffff00073efe9bd0 ffff00073efe9bd0 0000000000000000 Matched prompt #7: (kernel BUG at|BUG:) Setting prompt string to ['\\r', 'root@h3ulcb:~', 'h3ulcb:~#', '/ #', 'login:', 'Login incorrect'] 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', 'root@h3ulcb:~', 'h3ulcb:~#', '/ #', 'login:', 'Login incorrect'] login-action: kernel 'bug' [login-action] Waiting for messages, (timeout 00:19:38) [ 0.035453] raw: 0000000000000000 0000000000000000 00000000ffffff7f 0000000000000000 [ 0.035456] page dumped because: nonzero mapcount [ 0.035460] Modules linked in: [ 0.035467] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G B 5.10.194-yocto-standard #1 [ 0.035471] Hardware name: Renesas H3ULCB board based on r8a77951 (DT) [ 0.035475] Call trace: [ 0.035479] dump_backtrace+0x0/0x1c4 [ 0.035483] show_stack+0x18/0x2c [ 0.035488] dump_stack+0xe4/0x120 [ 0.035492] bad_page+0xe0/0x110 [ 0.035497] check_free_page_bad+0x7c/0x90 [ 0.035502] __free_pages_ok+0x37c/0x3e4 [ 0.035507] __free_pages+0xd8/0xf0 [ 0.035512] init_cma_reserved_pageblock+0x54/0x70 [ 0.035517] cma_init_reserved_areas+0x11c/0x190 [ 0.035521] do_one_initcall+0x58/0x2e0 [ 0.035526] kernel_init_freeable+0x240/0x2ac [ 0.035531] kernel_init+0x14/0x118 [ 0.035536] ret_from_fork+0x10/0x3c [ 0.040147] pinctrl core: initialized pinctrl subsystem [ 0.041564] DMI not present or invalid. [ 0.042032] NET: Registered protocol family 16 [ 0.042978] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations [ 0.043148] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.043432] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.043472] audit: initializing netlink subsys (disabled) [ 0.043648] audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1 [ 0.044763] thermal_sys: Registered thermal governor 'power_allocator' [ 0.045285] cpuidle: using governor menu [ 0.045455] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers. [ 0.045575] ASID allocator initialised with 65536 entries [ 0.046765] Serial: AMBA PL011 UART driver [ 0.077324] sh-pfc e6060000.pinctrl: r8a77951_pfc support registered [ 0.088870] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.088877] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages [ 0.088882] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.088888] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages [ 0.089879] cryptd: max_cpu_qlen set to 1000 [ 0.091927] ACPI: Interpreter disabled. [ 0.095303] rcar-avs: use avs value: 0 [ 0.095313] rcar-avs: cpu@0 is running with: opp_table0 [ 0.095320] rcar-avs: cpu@1 is running with: opp_table0 [ 0.095327] rcar-avs: cpu@2 is running with: opp_table0 [ 0.095334] rcar-avs: cpu@3 is running with: opp_table0 [ 0.095406] rcar-avs: gsx@fd000000 is running with: gsx_opp_table0 [ 0.096379] iommu: Default domain type: Translated [ 0.096872] ipmmu-vmsa e67b0000.iommu: IPMMU context 0 is reserved [ 0.097672] vgaarb: loaded [ 0.097902] SCSI subsystem initialized [ 0.098151] usbcore: registered new interface driver usbfs [ 0.098175] usbcore: registered new interface driver hub [ 0.098198] usbcore: registered new device driver usb [ 0.100333] i2c-sh_mobile e60b0000.i2c: I2C adapter 7, bus speed 400000 Hz [ 0.100722] mc: Linux media interface: v0.10 [ 0.100740] videodev: Linux video capture interface: v2.00 [ 0.100785] pps_core: LinuxPPS API ver. 1 registered [ 0.100790] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <[email protected]> [ 0.100799] PTP clock support registered [ 0.100928] EDAC MC: Ver: 3.0.0 [ 0.102479] FPGA manager framework [ 0.102532] Advanced Linux Sound Architecture Driver Initialized. [ 0.103129] clocksource: Switched to clocksource arch_sys_counter [ 0.548372] VFS: Disk quotas dquot_6.6.0 [ 0.548421] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.548568] pnp: PnP ACPI: disabled [ 0.553382] NET: Registered protocol family 2 [ 0.553782] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, linear) [ 0.555994] tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes, linear) [ 0.556090] TCP established hash table entries: 65536 (order: 7, 524288 bytes, linear) [ 0.556369] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear) [ 0.556952] TCP: Hash tables configured (established 65536 bind 65536) [ 0.557087] UDP hash table entries: 4096 (order: 5, 131072 bytes, linear) [ 0.557197] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes, linear) [ 0.557409] NET: Registered protocol family 1 [ 0.557827] RPC: Registered named UNIX socket transport module. [ 0.557834] RPC: Registered udp transport module. [ 0.557838] RPC: Registered tcp transport module. [ 0.557842] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.557854] PCI: CLS 0 bytes, default 64 [ 0.557985] Trying to unpack rootfs image as initramfs... [ 0.558157] rootfs image is not initramfs (no cpio magic); looks like an initrd [ 0.561328] Freeing initrd memory: 2100K [ 0.562235] hw perfevents: enabled with armv8_cortex_a53 PMU driver, 7 counters available [ 0.562518] hw perfevents: enabled with armv8_cortex_a57 PMU driver, 7 counters available [ 0.562988] kvm [1]: IPA Size Limit: 40 bits [ 0.563886] kvm [1]: vgic interrupt IRQ9 [ 0.564055] kvm [1]: Hyp mode initialized successfully [ 0.567318] Initialise system trusted keyrings [ 0.567464] workingset: timestamp_bits=42 max_order=21 bucket_order=0 [ 0.570829] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ 0.571283] NFS: Registering the id_resolver key type [ 0.571317] Key type id_resolver registered [ 0.571321] Key type id_legacy registered [ 0.571375] nfs4filelayout_init: NFSv4 File Layout Driver Registering... [ 0.571382] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... [ 0.571522] 9p: Installing v9fs 9p2000 file system support [ 0.598378] NET: Registered protocol family 38 [ 0.598388] Key type asymmetric registered [ 0.598394] Asymmetric key parser 'x509' registered [ 0.598425] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 243) [ 0.598431] io scheduler mq-deadline registered [ 0.598437] io scheduler kyber registered [ 0.608078] gpio_rcar e6050000.gpio: driving 16 GPIOs [ 0.608380] gpio_rcar e6051000.gpio: driving 29 GPIOs [ 0.608660] gpio_rcar e6052000.gpio: driving 15 GPIOs [ 0.608982] gpio_rcar e6053000.gpio: driving 16 GPIOs [ 0.609338] gpio_rcar e6054000.gpio: driving 18 GPIOs [ 0.609603] gpio_rcar e6055000.gpio: driving 26 GPIOs [ 0.609879] gpio_rcar e6055400.gpio: driving 32 GPIOs [ 0.610134] gpio_rcar e6055800.gpio: driving 4 GPIOs [ 0.613431] EINJ: ACPI disabled. [ 0.643550] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 0.645535] SuperH (H)SCI(F) driver initialized [ 0.645925] e6e88000.serial: ttySC0 at MMIO 0xe6e88000 (irq = 125, base_baud = 0) is a scif [ 1.976889] printk: console [ttySC0] enabled [ 1.982098] msm_serial: driver initialized [ 1.991223] rcar-dw-hdmi fead0000.hdmi: Detected HDMI TX controller v2.01a with HDCP (DWC HDMI 2.0 TX PHY) [ 2.001134] rcar-dw-hdmi fead0000.hdmi: registered DesignWare HDMI I2C bus driver [ 2.015287] brd: module loaded [ 2.022748] loop: module loaded [ 2.048973] megasas: 07.714.04.00-rc1 [ 2.057545] tun: Universal TUN/TAP device driver, 1.6 [ 2.063295] thunder_xcv, ver 1.0 [ 2.066535] thunder_bgx, ver 1.0 [ 2.069787] nicpf, ver 1.0 [ 2.073513] hclge is initializing [ 2.076848] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version [ 2.084071] hns3: Copyright (c) 2017 Huawei Corporation. [ 2.089406] e1000: Intel(R) PRO/1000 Network Driver [ 2.094284] e1000: Copyright (c) 1999-2006 Intel Corporation. [ 2.100049] e1000e: Intel(R) PRO/1000 Network Driver [ 2.105012] e1000e: Copyright(c) 1999 - 2015 Intel Corporation. [ 2.110960] igb: Intel(R) Gigabit Ethernet Network Driver [ 2.116360] igb: Copyright (c) 2007-2014 Intel Corporation. [ 2.121944] igbvf: Intel(R) Gigabit Virtual Function Network Driver [ 2.128208] igbvf: Copyright (c) 2009 - 2012 Intel Corporation. [ 2.134421] sky2: driver version 1.30 [ 2.142004] ravb e6800000.ethernet eth0: Base address at 0xe6800000, aa:bb:cc:dd:ee:77, IRQ 122. [ 2.151970] VFIO - User Level meta-driver version: 0.3 [ 2.158646] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 2.165189] ehci-pci: EHCI PCI platform driver [ 2.169654] ehci-platform: EHCI generic platform driver [ 2.175150] ehci-platform ee0a0100.usb: EHCI Host Controller [ 2.180826] ehci-platform ee0a0100.usb: new USB bus registered, assigned bus number 1 [ 2.188733] ehci-platform ee0a0100.usb: irq 160, io mem 0xee0a0100 [ 2.207140] ehci-platform ee0a0100.usb: USB 2.0 started, EHCI 1.10 [ 2.213692] hub 1-0:1.0: USB hub found [ 2.217466] hub 1-0:1.0: 1 port detected [ 2.221832] ehci-orion: EHCI orion driver [ 2.225997] ehci-exynos: EHCI Exynos driver [ 2.230265] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 2.236476] ohci-pci: OHCI PCI platform driver [ 2.240952] ohci-platform: OHCI generic platform driver [ 2.246372] ohci-platform ee0a0000.usb: Generic Platform OHCI controller [ 2.253083] ohci-platform ee0a0000.usb: new USB bus registered, assigned bus number 2 [ 2.260984] ohci-platform ee0a0000.usb: irq 160, io mem 0xee0a0000 [ 2.357518] hub 2-0:1.0: USB hub found [ 2.361286] hub 2-0:1.0: 1 port detected [ 2.365597] ohci-exynos: OHCI Exynos driver [ 2.370322] usbcore: registered new interface driver usb-storage [ 2.376377] usbcore: registered new interface driver usbserial_generic [ 2.382915] usbserial: USB Serial support registered for generic [ 2.388941] usbcore: registered new interface driver cp210x [ 2.394520] usbserial: USB Serial support registered for cp210x [ 2.403292] i2c /dev entries driver [ 2.417170] cs2000-cp 2-004f: revision - C1 [ 2.421412] i2c-rcar e6510000.i2c: probed [ 2.431269] vc5 4-006a: Invalid clock output configuration (0d) [ 2.437539] vc5 4-006a: Invalid clock output configuration (0d) [ 2.443634] vc5 4-006a: Invalid clock output configuration (0d) [ 2.449604] i2c-rcar e66d8000.i2c: probed [ 2.454236] usbcore: registered new interface driver i2c-tiny-usb [ 2.466535] rcar_gen3_thermal e6198000.thermal: is using pseudo fixed FUSE values [ 2.475151] usb 1-1: new high-speed USB device number 2 using ehci-platform [ 2.478647] rcar_gen3_thermal e6198000.thermal: TSC0: Loaded 1 trip points [ 2.493382] rcar_gen3_thermal e6198000.thermal: TSC1: Loaded 1 trip points [ 2.504386] rcar_gen3_thermal e6198000.thermal: TSC2: Loaded 3 trip points [ 2.515507] sdhci: Secure Digital Host Controller Interface driver [ 2.521697] sdhci: Copyright(c) Pierre Ossman [ 2.526662] Synopsys Designware Multimedia Card Interface Driver [ 2.526848] renesas_sdhi_internal_dmac ee100000.mmc: Got CD GPIO [ 2.526936] renesas_sdhi_internal_dmac ee140000.mmc: Adding to iommu group 0 [ 2.526960] renesas_sdhi_internal_dmac ee140000.mmc: Using IPMMU context 1 [ 2.533692] sdhci-pltfm: SDHCI platform and OF driver helper [ 2.560409] ledtrig-cpu: registered to indicate activity on CPUs [ 2.567064] SMCCC: SOC_ID: ARCH_SOC_ID not implemented, skipping .... [ 2.574048] usbcore: registered new interface driver usbhid [ 2.579624] usbhid: USB HID core driver [ 2.579806] renesas_sdhi_internal_dmac ee140000.mmc: mmc0 base at 0x00000000ee140000, max clock rate 200 MHz [ 2.586242] optee: probing for conduit method. [ 2.597751] optee: revision 3.22 (314ecf9d) [ 2.598169] optee driver R-Car Rev.1.0.11 [ 2.606674] optee: dynamic shared memory is enabled [ 2.611815] optee: initialized driver [ 2.616591] usbcore: registered new interface driver snd-usb-audio [ 2.633978] rcar_sound ec500000.sound: probed [ 2.638993] NET: Registered protocol family 17 [ 2.643560] 9pnet: Installing 9P2000 support [ 2.647891] Key type dns_resolver registered [ 2.652589] registered taskstats version 1 [ 2.656704] Loading compiled-in X.509 certificates [ 2.672871] thermal emergency: set temperature to 110 celsius [ 2.673454] mmc0: new HS400 MMC card at address 0001 [ 2.678815] thermal emergency: shutdown target cpus 1-7 [ 2.684444] mmcblk0: mmc0:0001 DJUD4R 119 GiB [ 2.688813] thermal emergency: freq scaled target cpus 0 [ 2.689165] renesas_irqc e61c0000.interrupt-controller: driving 6 irqs [ 2.693662] mmcblk0boot0: mmc0:0001 DJUD4R partition 1 31.9 MiB [ 2.702742] [drm] Initialized rcar-du 1.0.0 20130110 for feb00000.display on minor 0 [ 2.705531] mmcblk0boot1: mmc0:0001 DJUD4R partition 2 31.9 MiB [ 2.711040] [drm] Device feb00000.display probed [ 2.729445] mmcblk0rpmb: mmc0:0001 DJUD4R partition 3 4.00 MiB, chardev (508:0) [ 3.141383] Console: switching to colour frame buffer device 240x67 [ 3.287159] rcar-du feb00000.display: [drm] fb0: rcar-dudrmfb frame buffer device [ 3.308377] cpu cpu0: EM: created perf domain [ 3.313157] cpu cpu4: EM: created perf domain [ 3.320239] renesas_sdhi_internal_dmac ee100000.mmc: Got CD GPIO [ 3.329595] input: keyboard as /devices/platform/keyboard/input/input0 [ 3.375237] renesas_sdhi_internal_dmac ee100000.mmc: mmc1 base at 0x00000000ee100000, max clock rate 200 MHz [ 3.458073] Micrel KSZ9031 Gigabit PHY e6800000.ethernet-ffffffff:00: attached PHY driver [Micrel KSZ9031 Gigabit PHY] (mii_bus:phy_addr=e6800000.ethernet-ffffffff:00, irq=209) [ 5.744684] ravb e6800000.ethernet eth0: Link is Up - 100Mbps/Full - flow control off [ 5.775141] Sending DHCP requests .., OK [ 8.003214] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.15 [ 8.011053] IP-Config: Complete: [ 8.014288] device=eth0, hwaddr=aa:bb:cc:dd:ee:77, ipaddr=192.168.66.15, mask=255.255.255.0, gw=192.168.66.1 [ 8.024553] host=192.168.66.15, domain=example.org, nis-domain=(none) [ 8.031429] bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath= [ 8.031433] nameserver0=10.1.1.1 [ 8.041846] ALSA device list: [ 8.044829] #0: ak4613 [ 8.047817] Waiting 7 sec before mounting root device... [ 15.071339] RAMDISK: gzip image found at block 0 [ 15.183773] EXT4-fs (ram0): mounted filesystem with ordered data mode. Opts: (null) [ 15.191482] VFS: Mounted root (ext4 filesystem) on device 1:0. [ 15.197425] devtmpfs: mounted [ 15.202640] BUG: Bad page state in process swapper/0 pfn:6a000 [ 15.208560] page:(____ptrval____) refcount:0 mapcount:-128 mapping:0000000000000000 index:0x4 pfn:0x6a000 [ 15.218121] flags: 0x3fffc0000000000() CMA Matched prompt #7: (kernel BUG at|BUG:) Setting prompt string to ['\\r', 'root@h3ulcb:~', 'h3ulcb:~#', '/ #', 'login:', 'Login incorrect'] 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', 'root@h3ulcb:~', 'h3ulcb:~#', '/ #', 'login:', 'Login incorrect'] login-action: kernel 'bug' [login-action] Waiting for messages, (timeout 00:19:24) [ 15.222215] raw: 03fffc0000000000 dead000000000100 dead000000000122 0000000000000000 [ 15.229951] raw: 0000000000000004 000000000000000a 00000000ffffff7f 0000000000000000 [ 15.237686] page dumped because: nonzero mapcount [ 15.242383] Modules linked in: [ 15.245437] CPU: 1 PID: 1 Comm: swapper/0 Tainted: G B 5.10.194-yocto-standard #1 [ 15.254214] Hardware name: Renesas H3ULCB board based on r8a77951 (DT) [ 15.260736] Call trace: [ 15.263184] dump_backtrace+0x0/0x1c4 [ 15.266841] show_stack+0x18/0x2c [ 15.270154] dump_stack+0xe4/0x120 [ 15.273553] bad_page+0xe0/0x110 [ 15.276776] check_free_page_bad+0x7c/0x90 [ 15.280866] free_pcppages_bulk+0x1a8/0x350 [ 15.285043] free_unref_page_commit+0xdc/0x100 [ 15.289481] free_unref_page+0xb4/0xd0 [ 15.293224] __free_pages+0xc0/0xf0 [ 15.296707] free_reserved_area+0x94/0x160 [ 15.300800] free_initmem+0x5c/0x78 [ 15.304285] kernel_init+0x20/0x118 [ 15.307768] ret_from_fork+0x10/0x3c [ 15.312396] Freeing unused kernel memory: 7296K [ 15.317003] 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:61952 /sbin/init[1]: Starting NBD client /sbin/init[1]: NBD client successfully started [ 15.528083] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) /sbin/init[1]: Moving /dev to new rootfs /sbin/init[1]: Moving /proc to new rootfs /sbin/init[1]: Moving /sys to new rootfs /sbin/init[1]: Moving /tmp to new rootfs /sbin/init[1]: Moving /run to new rootfs /sbin/init[1]: Switching to new rootfs /sbin/init[1]: find_active_interface: first active interface is eth0 /sbin/init[1]: Adjusting Connman command line. Will be: 'connmand -r -n -I eth0,enp2s0,enp3s0,end0,enp0s2,enp0s1 ' /sbin/init[1]: Unmounting /tmp and /run /sbin/init[1]: Exec'ing systemd ________________________________________________________________________________ ___ ________ ____ __ _ / | / ____/ / / __ )____ ____ / /_(_)___ ____ _ / /| |/ / __/ / / __ / __ \/ __ \/ __/ / __ \/ __ `/ / ___ / /_/ / /___ / /_/ / /_/ / /_/ / /_/ / / / / /_/ / _ _ _ /_/ |_\____/_____/ /_____/\____/\____/\__/_/_/ /_/\__, / (_) (_) (_) _____________________________________________________/____/_____________________ [ 17.855159] random: crng init done [ 18.017955] SELinux: policy capability network_peer_controls=1 [ 18.023912] SELinux: policy capability open_perms=1 [ 18.028879] SELinux: policy capability extended_socket_class=1 [ 18.034796] SELinux: policy capability always_check_network=0 [ 18.040626] SELinux: policy capability cgroup_seclabel=1 [ 18.046023] SELinux: policy capability nnp_nosuid_transition=1 [ 18.051940] SELinux: policy capability genfs_seclabel_symlinks=0 [ 18.058030] SELinux: policy capability ioctl_skip_cloexec=0 [ 18.127348] audit: type=1403 audit(18.123:2): auid=4294967295 ses=4294967295 lsm=selinux res=1 [ 18.169170] systemd[1]: Successfully loaded SELinux policy in 524.148ms. [ 19.021365] systemd[1]: System time before build time, advancing clock. [ 19.273664] NET: Registered protocol family 10 [ 19.279549] Segment Routing with IPv6 [ 19.511592] systemd[1]: Relabeled /dev, /dev/shm, /run, /sys/fs/cgroup in 67.827ms. [ 19.588825] systemd[1]: systemd 255.4^ running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA -SMACK +SECCOMP -GCRYPT -GNUTLS -OPENSSL +ACL +BLKID -CURL -ELFUTILS -FIDO2 -IDN2 -IDN +IPTC +KMOD -LIBCRYPTSETUP +LIBFDISK -PCRE2 -PWQUALITY -P11KIT -QRENCODE -TPM2 -BZIP2 -LZ4 -XZ -ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified) [ 19.620795] systemd[1]: Detected architecture arm64. Welcome to Automotive Grade Linux 18.91.0 (salmon)! [ 19.662535] systemd[1]: Hostname set to <h3ulcb>. [ 19.700682] systemd[1]: Initializing machine ID from random generator. [ 20.428990] systemd[1]: Queued start job for default target Graphical Interface. [ 20.449671] systemd[1]: Created slice Slice /system/getty. [ OK ] Created slice Slice /system/getty. [ 20.472772] systemd[1]: Created slice Slice /system/modprobe. [ OK ] Created slice Slice /system/modprobe. [ 20.492670] systemd[1]: Created slice Slice /system/serial-getty. [ OK ] Created slice Slice /system/serial-getty. [ 20.512485] systemd[1]: Created slice Slice /system/wireplumber. [ OK ] Created slice Slice /system/wireplumber. [ 20.532141] systemd[1]: Created slice User and Session Slice. [ OK ] Created slice User and Session Slice. [ 20.551786] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 20.575763] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ 20.599315] systemd[1]: Reached target Host and Network Name Lookups. [ OK ] Reached target Host and Network Name Lookups. [ 20.619190] systemd[1]: Reached target Path Units. [ OK ] Reached target Path Units. [ 20.635217] systemd[1]: Reached target Remote File Systems. [ OK ] Reached target Remote File Systems. [ 20.655220] systemd[1]: Reached target Slice Units. [ OK ] Reached target Slice Units. [ 20.671214] systemd[1]: Reached target Swaps. [ OK ] Reached target Swaps. [ 20.694000] systemd[1]: Listening on Process Core Dump Socket. [ OK ] Listening on Process Core Dump Socket. [ 20.715992] systemd[1]: Listening on initctl Compatibility Named Pipe. [ OK ] Listening on initctl Compatibility Named Pipe. [ 20.737304] systemd[1]: Listening on Journal Audit Socket. [ OK ] Listening on Journal Audit Socket. [ 20.757398] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 20.776342] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 20.796289] systemd[1]: Listening on Network Service Netlink Socket. [ OK ] Listening on Network Service Netlink Socket. [ 20.818600] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 20.836248] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 20.856702] systemd[1]: Listening on User Database Manager Socket. [ OK ] Listening on User Database Manager Socket. [ 20.882582] systemd[1]: Mounting Huge Pages File System... Mounting Huge Pages File System... [ 20.907301] systemd[1]: Mounting POSIX Message Queue File System... Mounting POSIX Message Queue File System... [ 20.931477] systemd[1]: Mounting Kernel Debug File System... Mounting Kernel Debug File System... [ 20.955181] systemd[1]: Mounting Kernel Trace File System... Mounting Kernel Trace File System... [ 20.994020] systemd[1]: Mounting Temporary Directory /tmp... Mounting Temporary Directory /tmp... [ 21.015425] systemd[1]: Starting Create List of Static Device Nodes... Starting Create List of Static Device Nodes... [ 21.039639] systemd[1]: Starting Load Kernel Module configfs... Starting Load Kernel Module configfs... [ 21.063327] systemd[1]: Starting Load Kernel Module drm... Starting Load Kernel Module drm... [ 21.087645] systemd[1]: Starting Load Kernel Module fuse... Starting Load Kernel Module fuse... [ 21.111348] systemd[1]: Starting Start psplash boot splash screen... Starting Start psplash boot splash screen... [ 21.133365] (psplash)[358]: psplash-start.service: Referenced but unset environment variable evaluates to an empty string: PSPLASH_ARGS [ 21.135440] systemd[1]: Starting SELinux autorelabel service loading... Starting SELinux autorelabel service loading... [ 21.171488] systemd[1]: Starting SELinux init for /dev service loading... Starting SELinux init for /dev service loading.[ 21.182460] fuse: init (API version 7.32) .. [ 21.199486] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/). [ 21.218964] systemd[1]: Starting Journal Service... Starting Journal Service... [ 21.515760] systemd[1]: Starting Load Kernel Modules... Starting Load Kernel Modules... [ 21.541223] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... [ 21.572137] systemd[1]: Starting Coldplug All udev Devices... Starting Coldplug All udev Devices... [ 21.600059] systemd[1]: Started Start psplash boot splash screen. [ OK ] Started Start psplash boot splash screen. [ 21.612878] EXT4-fs (nbd0): re-mounted. Opts: (null) [ 21.631250] systemd[1]: Mounted Huge Pages File System. [ 21.632134] systemd-journald[362]: Collecting audit messages is enabled. [ OK ] Mounted Huge Pages File System. [ 21.656332] systemd[1]: Mounted POSIX Message Queue File System. [ OK ] Mounted POSIX Message Queue File System. [ 21.680151] systemd[1]: Mounted Kernel Debug File System. [ OK ] Mounted Kernel Debug File System. [ 21.700641] systemd[1]: Mounted Kernel Trace File System. [ OK ] Mounted Kernel Trace File System. [ 21.720627] systemd[1]: Started Journal Service. [ OK ] Started Journal Service. [ 21.740145] audit: type=1130 audit(1721815280.715:3): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-journald comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Mounted Temporary Directory /tmp. [ OK ] Finished Create List of Static Device Nodes. [ 21.791590] audit: type=1130 audit(1721815280.767:4): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=kmod-static-nodes comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished Load Kernel Module configfs. [ 21.827438] audit: type=1130 audit(1721815280.803:5): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@configfs comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 21.849237] audit: type=1131 audit(1721815280.803:6): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@configfs comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished Load Kernel Module drm. [ 21.883796] audit: type=1130 audit(1721815280.859:7): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@drm comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 21.905151] audit: type=1131 audit(1721815280.859:8): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@drm comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished Load Kernel Module fuse. [ 21.939828] audit: type=1130 audit(1721815280.915:9): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@fuse comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 21.961245] audit: type=1131 audit(1721815280.915:10): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=modprobe@fuse comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished SELinux autorelabel service loading. [ 21.995543] audit: type=1130 audit(1721815280.971:11): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=selinux-autorelabel comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished SELinux init for /dev service loading. [ OK ] Finished Load Kernel Modules. [ OK ] Finished Remount Root and Kernel File Systems. Mounting FUSE Control File System... Mounting Kernel Configuration File System... [ OK ] Started Start psplash-systemd progress communication helper. Starting Flush Journal to Persistent Storage... Starting Apply Kernel Variables... Starting Create Static Device Nodes in /dev gracefully... [ 22.289458] systemd-journald[362]: Received client request to flush runtime journal. [ OK ] Mounted FUSE Control File System. [ OK ] Mounted Kernel Configuration File System. [ OK ] Finished Flush Journal to Persistent Storage. [ OK ] Finished Apply Kernel Variables. [ OK ] Finished Create Static Device Nodes in /dev gracefully. [ OK ] Finished Coldplug All udev Devices. Starting Create System Users... Starting User Database Manager... [ OK ] Started User Database Manager. [ OK ] Finished Create System Users. Starting Create Static Device Nodes in /dev... [ OK ] Finished Create Static Device Nodes in /dev. [ OK ] Reached target Preparation for Local File Systems. Mounting /var/volatile... Starting Rule-based Manager for Device Events and Files... [ OK ] Mounted /var/volatile. Starting Load/Save OS Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting SELinux resolv.conf relabeling... Starting SELinux init service loading... Starting Create Volatile Files and Directories... [ OK ] Finished Load/Save OS Random Seed. [ 23.323718] kauditd_printk_skb: 18 callbacks suppressed [ 23.323731] audit: type=1130 audit(1721815282.299:30): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-random-seed comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished SELinux resolv.conf relabeling. [ 23.367619] audit: type=1130 audit(1721815282.343:31): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=resolv-conf-relabel comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 23.389713] audit: type=1131 audit(1721815282.343:32): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=resolv-conf-relabel comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ OK ] Finished SELinux init service loading. [ 23.431500] audit: type=1130 audit(1721815282.407:33): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=selinux-init comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' [ 23.453996] audit: type=1131 audit(1721815282.407:34): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=selinux-init comm=\"systemd\" exe=\"/usr/lib/systemd/systemd\" hostname=? addr=? terminal=? res=success' Startin[ 23.475789] audit: type=1400 audit(1721815282.439:35): avc: denied { create } for pid=434 comm=\"systemd-tmpfile\" name=\".#mpd9081ce97cfcfc1cd\" scontext=system_u:system_r:systemd_tmpfiles_t:s0 tcontext=system_u:object_r:mpd_var_lib_t:s0 tclass=lnk_file permissive=1 g Generated file[ 23.500916] audit: type=1400 audit(1721815282.439:36): avc: denied { unlink } for pid=434 comm=\"systemd-tmpfile\" name=\".#mpd9081ce97cfcfc1cd\" dev=\"nbd0\" ino=107641 scontext=system_u:system_r:systemd_tmpfiles_t:s0 tcontext=system_u:object_r:mpd_var_lib_t:s0 tclass=lnk_file permissive=1 SELinux relabeling... [ 23.529139] audit: type=1400 audit(1721815282.503:37): avc: denied { getattr } for pid=434 comm=\"systemd-tmpfile\" path=\"/var/lib/mpd\" dev=\"nbd0\" ino=105979 scontext=system_u:system_r:systemd_tmpfiles_t:s0 tcontext=system_u:object_r:mpd_var_lib_t:s0 tclass=lnk_file permissive=1 [ 23.554391] audit: type=1400 audit(1721815282.503:38): avc: denied { relabelfrom } for pid=434 comm=\"systemd-tmpfile\" name=\"mpd\" dev=\"nbd0\" ino=105979 scontext=system_u:system_r:systemd_tmpfiles_t:s0 tcontext=system_u:object_r:mpd_var_lib_t:s0 tclass=lnk_file permissive=1 [ 23.578762] audit: type=1400 audit(1721815282.503:38): avc: denied { relabelto } for pid=434 comm=\"systemd-tmpfile\" name=\"mpd\" dev=\"nbd0\" ino=105979 scontext=system_u:system_r:systemd_tmpfiles_t:s0 tcontext=system_u:object_r:mpd_var_lib_t:s0 tclass=lnk_file permissive=1 [ OK ] Finished Create Volatile Files and Directories. Starting Load Audit Rules... Starting Rebuild Journal Catalog... [ OK ] Started Rule-based Manager for Device Events and Files. [ 24.448561] ccree e6601000.crypto: ARM CryptoCell 630P Driver: HW version 0xAF400001/0xDCC63000, Driver version 5.0 [ 24.531510] ccree e6601000.crypto: ARM ccree device initialized [ OK ] Finished Load Audit Rules. [ OK ] Finished Rebuild Journal Catalog. [ OK ] Finished Generated file SELinux relabeling. Starting Security Audit Logging Service... [ 24.769879] usb 1-1: dvb_usb_v2: found a 'Realtek RTL2832U reference design' in warm state Starting Virtual Console Setup... [ 24.836570] usb 1-1: dvb_usb_v2: will pass the complete MPEG2 transport stream to the software demuxer [ 24.846000] dvbdev: DVB: registering new adapter (Realtek RTL2832U reference design) [ 24.886552] rcar_sound ec500000.sound: Can't update kctrl when idle [ 24.899466] i2c i2c-9: Added multiplexed i2c bus 10 [ 24.904444] rtl2832 9-0010: Realtek RTL2832 successfully attached [ 24.910773] usb 1-1: DVB: registering adapter 0 frontend 0 (Realtek RTL2832 (DVB-T))... Starting SELinux resolv.conf relabeling... Starting SELinux autorelabel service loading... Starting SELinux init service loading... Starting SELinux init for /dev service loading... Starting Network Name Resolution... [ OK ] Started Security Audit Logging Service. Starting Record System Boot/Shutdown in UTMP... [ OK ] Finished SELinux aut[ 24.980250] r820t 10-001a: creating new instance orelabel service loading. [ OK ] Finished SELinux init service loading. [ 24.993688] r820t 10-001a: Rafael Micro r820t successfully identified [ OK ] Finished SELinux resolv.conf relabeling. [ 25.035910] rtl2832_sdr rtl2832_sdr.5.auto: Registered as swradio0 [ 25.042282] rtl2832_sdr rtl2832_sdr.5.auto: Realtek RTL2832 SDR attached [ 25.049039] rtl2832_sdr rtl2832_sdr.5.auto: SDR API is still slightly experimental and functionality changes may follow [ 25.066855] Registered IR keymap rc-empty [ OK ] Finishe[ 25.071123] rc rc0: Realtek RTL2832U reference design as /devices/platform/soc/ee0a0100.usb/usb1/1-1/rc/rc0 d Record System [ 25.082365] input: Realtek RTL2832U reference design as /devices/platform/soc/ee0a0100.usb/usb1/1-1/rc/rc0/input1 Boot/Shutdown in[ 25.094366] usb 1-1: dvb_usb_v2: schedule remote query interval to 200 msecs UTMP. [ 25.111297] usb 1-1: dvb_usb_v2: 'Realtek RTL2832U reference design' successfully initialized and connected [ 25.121263] usbcore: registered new interface driver dvb_usb_rtl28xxu [ OK ] Finished SELinux init for /dev service loading. [ OK ] Started Network Name Resolution. [ OK ] Finished Virtual Console Setup. [* ] A start job is running for Rebuild …namic Linker Cache (2s / no limit) M[K[** ] A start job is running for Rebuild …namic Linker Cache (3s / no limit) M[K[*** ] A start job is running for Rebuild …namic Linker Cache (3s / no limit) M[K[ *** ] A start job is running for Rebuild …namic Linker Cache (4s / no limit) M[K[ *** ] A start job is running for Rebuild …namic Linker Cache (4s / no limit) M[K[ ***] A start job is running for Rebuild …namic Linker Cache (5s / no limit) M[K[ **] A start job is running for Rebuild …namic Linker Cache (5s / no limit) M[K[ OK ] Finished Rebuild Dynamic Linker Cache. [K Starting Update is Completed... [ OK ] Finished Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timer Units. [ OK ] Listening on agl-compositor, a Wayl…ositor, as a systemd user service. [ OK ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Listening on GPS (Global Positioning System) Daemon Sockets. [ OK ] Listening on mpd.socket. Starting PipeWire Multimedia System Manager Socket... Starting PipeWire Multimedia System Socket... Starting sshd.socket... [ OK ] Listening on PipeWire Multimedia System Manager Socket. [ OK ] Listening on PipeWire Multimedia System Socket. [ OK ] Listening on sshd.socket. [ OK ] Reached target Socket Units. [ OK ] Reached target Basic System. Starting Save/Restore Sound Card State... Starting CAN interface helper... Starting D-Bus System Message Bus... Starting IPv6 P[ 31.105857] rcar_sound ec500000.sound: Can't update kctrl when idle acket Filtering Framework... Starting IPv4 Packet Filtering Framework... Starting Telephony service... [ OK ] Started PipeWire Multimedia Service. Starting Authorization Manager... Starting User Login Management... Starting Disk Manager... [ OK ] Started Multimedia Service Session Manager (audio). [ OK ] Started Multimedia Service Session Manager (bluetooth). [ 31.322021] vcan: Virtual CAN interface driver [ OK ] Started Multimedia Service Session Manager (policy). [ OK ] Started Multimedia Service Session Manager (video-capture). Starting OpenSSH Key Generation... [ OK ] Finished Save/Restore Sound Card State. [ OK ] Finished CAN interface helper. [ OK ] Finished IPv6 Packet Filtering Framework. [ OK ] Finished IPv4 Packet Filtering Framework. [ OK ] Reached target Preparation for Network. [ OK ] Reached target Sound Card. Starting Network Configuration... [ OK ] Started User Login Management. [ OK ] Started D-Bus System Message Bus. Starting Connection service... [ OK ] Started Telephony service. [ OK ] Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. [ 32.669038] cfg80211: Loading compiled-in X.509 certificates for regulatory database [ 32.690318] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' [ 32.921666] Bluetooth: Core ver 2.22 [ 32.925457] NET: Registered protocol family 31 [ 32.930012] Bluetooth: HCI device and connection manager initialized [ 32.936507] Bluetooth: HCI socket layer initialized [ 32.941489] Bluetooth: L2CAP socket layer initialized [ 32.946688] Bluetooth: SCO socket layer initialized [ 32.961088] cfg80211: loaded regulatory.db is malformed or signature is missing/invalid [ OK ] Started Connection service. Starting Avahi mDNS/DNS-SD Stack... [ OK ] Started Avahi mDNS/DNS-SD Stack. [ OK ] Started Network Configuration. [ OK ] Reached target Network. [ OK ] Started agl-service-radio.service. [ OK ] Started Eclipse KUKSA.val databroker. [ OK ] Started agl-service-audiomixer.service. [ OK ] Started agl-service-hvac.service. Starting agl-vss-helper.service... [ OK ] Started Eclipse KUKSA.val DBC feeder. Starting Permit User Sessions... [ OK ] Finished Permit User Sessions. Starting AGL compositor... [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttySC0. [ OK ] Reached target Login Prompts. Starting Hostname Service... Starting WPA supplicant... [ OK ] Started Hostname Service. [ OK ] Started WPA supplicant. [ OK ] Created slice User Slice of UID 1001. Starting User Runtime Directory /run/user/1001... [ OK ] Finished User Runtime Directory /run/user/1001. Starting User Manager for UID 1001... [ OK ] Finished OpenSSH Key Generation. [ 36.431522] can: controller area network core [ 36.436033] NET: Registered protocol family 29 [ 36.486765] can: raw protocol [ 36.664557] r820t 10-001a: destroying instance [ 36.676463] dvb_usb_v2: 'Realtek RTL2832U reference design:1-1' successfully deinitialized and disconnected [ OK ] Started Authorization Manager. Starting applaunchd.service... [ OK ] Started Disk Manager. [ OK ] Started Automount Disk Manager. [ 37.160683] usb 1-1: dvb_usb_v2: found a 'Realtek RTL2832U reference design' in warm state [ 37.226591] usb 1-1: dvb_usb_v2: will pass the complete MPEG2 transport stream to the software demuxer [ 37.235994] dvbdev: DVB: registering new adapter (Realtek RTL2832U reference design) [ 37.259775] i2c i2c-9: Added multiplexed i2c bus 10 [ 37.264833] rtl2832 9-0010: Realtek RTL2832 successfully attached [ 37.271210] usb 1-1: DVB: registering adapter 0 frontend 0 (Realtek RTL2832 (DVB-T))... [ 37.279715] r820t 10-001a: creating new instance [ 37.292442] r820t 10-001a: Rafael Micro r820t successfully identified [ 37.315516] rtl2832_sdr rtl2832_sdr.5.auto: Registered as swradio0 [ 37.322189] rtl2832_sdr rtl2832_sdr.5.auto: Realtek RTL2832 SDR attached [ 37.329295] rtl2832_sdr rtl2832_sdr.5.auto: SDR API is still slightly experimental and functionality changes may follow [ 37.348060] Registered IR keymap rc-empty [ 37.352244] rc rc0: Realtek RTL2832U reference design as /devices/platform/soc/ee0a0100.usb/usb1/1-1/rc/rc0 [ OK ] Started[ 37.362444] input: Realtek RTL2832U reference design as /devices/platform/soc/ee0a0100.usb/usb1/1-1/rc/rc0/input2 User Manager fo[ 37.374410] usb 1-1: dvb_usb_v2: schedule remote query interval to 200 msecs r UID 1001. [ 37.390630] usb 1-1: dvb_usb_v2: 'Realtek RTL2832U reference design' successfully initialized and connected [ OK ] Started Session c1 of User agl-driver. [ 37.580121] r820t 10-001a: destroying instance [ 37.589400] dvb_usb_v2: 'Realtek RTL2832U reference design:1-1' successfully deinitialized and disconnected [ OK ] Started applaunchd.service. Automotive Grade Linux 18.91.0 h3ulcb ttySC0 Matched prompt #13: login: case: kernel-messages
case_id: 4098767
definition: lava
duration: 39.07
extra: ...
level: 2.4.4.1
namespace: common
result: pass
Kernel warnings or errors detected. Sending username root root h3ulcb login: root Setting prompt string to ['root@h3ulcb:~', 'h3ulcb:~#', '/ #'] login-action: Wait for prompt ['root@h3ulcb:~', 'h3ulcb:~#', '/ #', 'Login incorrect', 'Login timed out'] (timeout 00:19:00) root [ 39.903207] SDHI0 VccQ: disabling Setting prompt string to ['root@h3ulcb:~', 'h3ulcb:~#', '/ #'] end: 2.4.4.1 login-action (duration 00:00:43) [common] case: login-action
case_id: 4098770
definition: lava
duration: 43.20
extra: ...
level: 2.4.4.1
namespace: common
result: pass
end: 2.4.4 auto-login-action (duration 00:00:44) [common] start: 2.4.5 expect-shell-connection (timeout 00:18:56) [common] Setting prompt string to ['root@h3ulcb:~', 'h3ulcb:~#', '/ #'] Forcing a shell prompt, looking for ['root@h3ulcb:~', 'h3ulcb:~#', '/ #'] 7[r[999;999H[6nroot@h3ulcb:~# expect-shell-connection: Wait for prompt ['root@h3ulcb:~', 'h3ulcb:~#', '/ #'] (timeout 00:20:00) Waiting using forced prompt support (timeout 00:10:00) end: 2.4.5 expect-shell-connection (duration 00:00:00) [common] start: 2.4.6 overlay-unpack (timeout 00:18:56) [common] rm overlay-1.5.5.tar.gz root@h3ulcb:~# rm overlay-1.5.5.tar.gz rm overlay-1.5.5.tar.gz rm: cannot remove 'overlay-1.5.5.tar.gz': No such file or directory wget http://192.168.66.1/tmp/37916/compress-overlay-2f3fi2_7/overlay-1.5.5.tar.gz root@h3ulcb:~# wget http://192.168.66.1/tmp/37916/compress-overlay-2f3fi2_7/overlay-1.5.5.tar.gz wget http://192.168.66.1/tmp/37916/compress-overlay-2f3fi2_7/overllay-1.5.5.tar.gz Connecting to 192.168.66.1 (192.168.66.1:80) saving to 'overlay-1.5.5.tar.gz' overlay-1.5.5.tar.gz 100% |********************************| 224k 0:00:00 ETA 'overlay-1.5.5.tar.gz' saved tar -C / -xvpf overlay-1.5.5.tar.gz root@h3ulcb:~# tar -C / -xvpf overlay-1.5.5.tar.gz [ 44.354691] BUG: Bad page state in process kworker/2:6 pfn:6935a [ 44.360797] page:00000000512c8d3b refcount:42 mapcount:42 mapping:0000000000000000 index:0x4 pfn:0x6935a [ 44.370275] flags: 0x3fffc0000000802(referenced|arch_1) CMA [ 44.370323] ttySC ttySC0: 1 input overrun(s) [ 44.375846] raw: 03fffc0000000802 dead000000000100 dead000000000122 0000000000000000 [ 44.375849] raw: 0000000000000004 0000000000000000 0000002a00000029 0000000000000000 [ 44.375852] page dumped because: nonzero _refcount [ 44.375855] Modules linked in: can_raw can iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c iptable_mangle iptable_filter bluetooth cfg80211 ecdh_generic ecc rfkill vcan rtl2832_sdr r820t rtl2832 dvb_usb_rtl28xxu dvb_usb_v2 rc_core dw_hdmi_cec gpio_bd9571mwv crct10dif_ce ccree authenc libdes optee_rng rng_core uio_pdrv_genirq fuse ip_tables x_tables ipv6 [ 44.433801] CPU: 2 PID: 97 Comm: kworker/2:6 Tainted: G B 5.10.194-yocto-standard #1 [ 44.442841] Hardware name: Renesas H3ULCB board based on r8a77951 (DT) [ 44.449382] Workqueue: mm_percpu_wq drain_local_pages_wq [ 44.454692] Call trace: [ 44.457137] dump_backtrace+0x0/0x1c4 [ 44.460795] show_stack+0x18/0x2c [ 44.464108] dump_stack+0xe4/0x120 [ 44.467505] bad_page+0xe0/0x110 [ 44.470728] check_free_page_bad+0x7c/0x90 [ 44.474819] free_pcppages_bulk+0x1a8/0x350 [ 44.478997] drain_local_pages+0x68/0x80 [ 44.482914] drain_local_pages_wq+0x28/0x5c [ 44.487093] process_one_work+0x1d0/0x4c4 [ 44.491097] worker_thread+0x70/0x470 [ 44.494757] kthread+0x150/0x154 [ 44.497981] ret_from_fork+0x10/0x3c tar -C / -xvpf o�� tar: Error opening archive: Failed to open 'o��' end: 2.4.6 overlay-unpack (duration 00:00:01) [common] start: 2.4.7 export-device-env (timeout 00:18:55) [common] end: 2.4.7 export-device-env (duration 00:00:00) [common] end: 2.4 uboot-commands (duration 00:01:05) [common] end: 2 uboot-action (duration 00:01:05) [common] start: 3 lava-test-retry (timeout 00:04:00) [common] start: 3.1 lava-test-shell (timeout 00:04:00) [common] Using namespace: common # root@h3ulcb:~# # lava-test-shell: Wait for prompt ['root@h3ulcb:~', 'h3ulcb:~#', '/ #'] (timeout 00:04:00) # Using /lava-37916 export SHELL=/bin/sh root@h3ulcb:~# export SHELL=/bin/sh export SHELL=/bin/sh . /lava-37916/environment root@h3ulcb:~# . /lava-37916/environment . /lava-37916/environment -sh: /lava-37916/environment: No such file or directory /lava-37916/bin/lava-test-runner /lava-37916/0 root@h3ulcb:~# /lava-37916/bin/lava-test-runner /lava-37916/0 Test shell timeout: 240s (minimum of the action and connection timeout) /lava-37916/bin/lava-test-runner /lava-37916/0 -sh: /lava-37916/bin/lava-test-runner: No such file or directory lava-test-shell timed out after 240 seconds end: 3.1 lava-test-shell (duration 00:04:00) [common] case: lava-test-shell
case_id: 4098891
definition: lava
duration: 240.00
extra: ...
level: 3.1
namespace: common
result: fail
lava-test-retry failed: 1 of 1 attempts. 'lava-test-shell timed out after 240 seconds' lava-test-shell timed out after 240 seconds end: 3 lava-test-retry (duration 00:04:00) [common] case: lava-test-retry
case_id: 4098892
definition: lava
duration: 240.00
extra: ...
level: 3
namespace: common
result: fail
Cleaning after the job Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37916/nbd-deploy-wn8pv286/initrd Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37916/nbd-deploy-wn8pv286/kernel Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37916/nbd-deploy-wn8pv286/dtb Cleaning up download directory: /var/lib/lava/dispatcher/tmp/37916/nbd-deploy-wn8pv286/nbdroot start: 7.1 power-off (timeout 00:00:10) [common] Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '2' >> Success Returned 0 in 0 seconds end: 7.1 power-off (duration 00:00:00) [common] case: power-off
case_id: 4098893
definition: lava
duration: 0.25
extra: ...
level: 7.1
namespace: common
result: pass
start: 7.2 read-feedback (timeout 00:30:00) [common] Listened to connection for namespace 'common' for up to 1s Finalising connection for namespace 'common' Disconnecting from shell: Finalise root@h3ulcb:~# end: 7.2 read-feedback (duration 00:00:01) [common] lava-xnbd cleanup clean NBD port 61952 Override tmp directory removed at /var/lib/lava/dispatcher/tmp/37916 Root tmp directory removed at /var/lib/lava/dispatcher/tmp/37916 TestError: A test failed to run, look at the error message. case: job
case_id: 4098894
definition: lava
error_msg: lava-test-shell timed out after 240 seconds
error_type: Test
result: fail