- {"dt": "2025-08-21T12:48:44.062357", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2025.06.dev0075"}
- {"dt": "2025-08-21T12:48:44.062461", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2025-08-21T12:48:44.062550", "lvl": "info", "msg": "Start time: 2025-08-21 12:48:44.062543+00:00 (UTC)"}
- {"dt": "2025-08-21T12:48:44.063252", "lvl": "debug", "msg": "Validating that file:///tmp/tuxrun-nt9e39f9/startup.nsh exists"}
- {"dt": "2025-08-21T12:48:44.063356", "lvl": "debug", "msg": "Validating that https://storage.tuxboot.com/buildroot/fvp-aemva/FVP_AARCH64_EFI.fd exists"}
- {"dt": "2025-08-21T12:48:44.484191", "lvl": "debug", "msg": "Validating that https://storage.tuxboot.com/buildroot/fvp-aemva/bl1.bin exists"}
- {"dt": "2025-08-21T12:48:44.841355", "lvl": "debug", "msg": "Validating that https://storage.tuxboot.com/buildroot/fvp-aemva/fvp-base-revc.dtb exists"}
- {"dt": "2025-08-21T12:48:44.996769", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxmake/builds/502/Image.gz exists"}
- {"dt": "2025-08-21T12:48:44.996926", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian_20250617_trixie_arm64_rootfs.ext4.xz exists"}
- {"dt": "2025-08-21T12:48:44.997044", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxmake/builds/502/modules.tar.xz exists"}
- {"dt": "2025-08-21T12:48:44.997153", "lvl": "debug", "msg": "Validating that https://people.linaro.org/~anders.roxell/yesloop.sh exists"}
- {"dt": "2025-08-21T12:48:45.358717", "lvl": "debug", "msg": "Validating that https://storage.tuxboot.com/buildroot/fvp-aemva/fip.bin exists"}
- {"dt": "2025-08-21T12:48:45.724859", "lvl": "info", "msg": "validate duration: 1.66"}
- {"dt": "2025-08-21T12:48:45.725013", "lvl": "results", "msg": {"definition": "lava", "case": "validate", "result": "pass"}}
- {"dt": "2025-08-21T12:48:45.725151", "lvl": "info", "msg": "start: 1 fvp-deploy (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.725242", "lvl": "debug", "msg": "start: 1.1 lava-overlay (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.725401", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4"}
- {"dt": "2025-08-21T12:48:45.725514", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin"}
- {"dt": "2025-08-21T12:48:45.725606", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/tests"}
- {"dt": "2025-08-21T12:48:45.725686", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/results"}
- {"dt": "2025-08-21T12:48:45.725769", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-add-keys"}
- {"dt": "2025-08-21T12:48:45.726042", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-add-sources"}
- {"dt": "2025-08-21T12:48:45.726291", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-background-process-start"}
- {"dt": "2025-08-21T12:48:45.726445", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-background-process-stop"}
- {"dt": "2025-08-21T12:48:45.726593", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-common-functions"}
- {"dt": "2025-08-21T12:48:45.726698", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-echo-ipv4"}
- {"dt": "2025-08-21T12:48:45.726808", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-install-packages"}
- {"dt": "2025-08-21T12:48:45.726919", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-installed-packages"}
- {"dt": "2025-08-21T12:48:45.727036", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-os-build"}
- {"dt": "2025-08-21T12:48:45.727150", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-probe-channel"}
- {"dt": "2025-08-21T12:48:45.727260", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-probe-ip"}
- {"dt": "2025-08-21T12:48:45.727369", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-target-ip"}
- {"dt": "2025-08-21T12:48:45.727477", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-target-mac"}
- {"dt": "2025-08-21T12:48:45.727586", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-target-storage"}
- {"dt": "2025-08-21T12:48:45.727699", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-test-case"}
- {"dt": "2025-08-21T12:48:45.727814", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-test-event"}
- {"dt": "2025-08-21T12:48:45.727919", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-test-feedback"}
- {"dt": "2025-08-21T12:48:45.728028", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-test-raise"}
- {"dt": "2025-08-21T12:48:45.728134", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-test-reference"}
- {"dt": "2025-08-21T12:48:45.728240", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-test-runner"}
- {"dt": "2025-08-21T12:48:45.728346", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-test-set"}
- {"dt": "2025-08-21T12:48:45.728453", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/bin/lava-test-shell"}
- {"dt": "2025-08-21T12:48:45.728543", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/environment"}
- {"dt": "2025-08-21T12:48:45.728622", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2025-08-21T12:48:45.728682", "lvl": "debug", "msg": "- LAVA_JOB_ID=1"}
- {"dt": "2025-08-21T12:48:45.728736", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=10.89.19.2"}
- {"dt": "2025-08-21T12:48:45.728789", "lvl": "debug", "msg": "- LAVA_DISPATCHER_PREFIX=tuxrun-nt9e39f9-"}
- {"dt": "2025-08-21T12:48:45.728890", "lvl": "debug", "msg": "start: 1.1.1 lava-vland-overlay (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.728949", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2025-08-21T12:48:45.729015", "lvl": "debug", "msg": "end: 1.1.1 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.729086", "lvl": "debug", "msg": "start: 1.1.2 lava-multinode-overlay (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.729138", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2025-08-21T12:48:45.729199", "lvl": "debug", "msg": "end: 1.1.2 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.729265", "lvl": "debug", "msg": "start: 1.1.3 test-definition (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.729333", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2025-08-21T12:48:45.729408", "lvl": "debug", "msg": "start: 1.1.3.1 inline-repo-action (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.729471", "lvl": "debug", "msg": "Using /lava-1 at stage 0"}
- {"dt": "2025-08-21T12:48:45.729705", "lvl": "debug", "msg": "uuid=1_1.1.3.1 testdef=None"}
- {"dt": "2025-08-21T12:48:45.729792", "lvl": "debug", "msg": "end: 1.1.3.1 inline-repo-action (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.729883", "lvl": "debug", "msg": "start: 1.1.3.2 test-overlay (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.730241", "lvl": "debug", "msg": "end: 1.1.3.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.730308", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "test-overlay", "level": "1.1.3.2", "duration": "0.00", "result": "pass", "extra": {"uuid": "1_1.1.3.1", "name": "commands", "path": "command", "from": "inline"}}}
- {"dt": "2025-08-21T12:48:45.730440", "lvl": "debug", "msg": "start: 1.1.3.3 test-install-overlay (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.730833", "lvl": "debug", "msg": "end: 1.1.3.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.730902", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "test-install-overlay", "level": "1.1.3.3", "duration": "0.00", "result": "pass", "extra": {"uuid": "1_1.1.3.1", "name": "commands", "path": "command", "from": "inline", "skipped test-install-overlay": "1_1.1.3.1"}}}
- {"dt": "2025-08-21T12:48:45.731024", "lvl": "debug", "msg": "start: 1.1.3.4 test-runscript-overlay (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.731426", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/0/tests/0_commands test_uuid 1_1.1.3.1"}
- {"dt": "2025-08-21T12:48:45.731521", "lvl": "debug", "msg": "A delay of 50 milliseconds will be used for sending result signals"}
- {"dt": "2025-08-21T12:48:45.731703", "lvl": "debug", "msg": "end: 1.1.3.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.731769", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "test-runscript-overlay", "level": "1.1.3.4", "duration": "0.00", "result": "pass", "extra": {"uuid": "1_1.1.3.1", "name": "commands", "path": "command", "from": "inline", "filename": "/var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/0/tests/0_commands/run.sh"}}}
- {"dt": "2025-08-21T12:48:45.731870", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2025-08-21T12:48:45.731918", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/lava-overlay-n57dqce4/lava-1/0 for stage 0"}
- {"dt": "2025-08-21T12:48:45.731988", "lvl": "debug", "msg": "- 0_commands"}
- {"dt": "2025-08-21T12:48:45.732071", "lvl": "debug", "msg": "end: 1.1.3 test-definition (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.732143", "lvl": "debug", "msg": "start: 1.1.4 compress-overlay (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.736898", "lvl": "debug", "msg": "end: 1.1.4 compress-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.736986", "lvl": "debug", "msg": "end: 1.1 lava-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.737060", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.737133", "lvl": "debug", "msg": "start: 1.2.1 file-download (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:45.737228", "lvl": "info", "msg": "downloading file:///tmp/tuxrun-nt9e39f9/startup.nsh"}
- {"dt": "2025-08-21T12:48:45.737287", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/startup.nsh"}
- {"dt": "2025-08-21T12:48:45.737341", "lvl": "debug", "msg": "total size: 120 (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:45.737393", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2025-08-21T12:48:45.737488", "lvl": "info", "msg": "0\u202FMB downloaded in 0.00\u202Fs (0.79\u202FMB/s)"}
- {"dt": "2025-08-21T12:48:45.737584", "lvl": "debug", "msg": "end: 1.2.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.737648", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.2.1", "duration": "0.00", "result": "pass", "extra": {"label": "startup", "size": ! "120", "sha256sum": "a5ece2b65c7e7a975cc419e5a26d82ccf6d3359a19e6227ce24736ab3d5d0cf0"}}}
- {"dt": "2025-08-21T12:48:45.737770", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:45.737846", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T12:48:45.737913", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:45.738002", "lvl": "info", "msg": "downloading https://storage.tuxboot.com/buildroot/fvp-aemva/FVP_AARCH64_EFI.fd"}
- {"dt": "2025-08-21T12:48:45.738058", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/FVP_AARCH64_EFI.fd"}
- {"dt": "2025-08-21T12:48:45.738110", "lvl": "debug", "msg": "total size: 2621440 (2\u202FMB)"}
- {"dt": "2025-08-21T12:48:45.738161", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2025-08-21T12:48:46.597639", "lvl": "debug", "msg": "progress   1\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:46.787626", "lvl": "debug", "msg": "progress   6\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:46.888378", "lvl": "debug", "msg": "progress  15\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:47.021574", "lvl": "debug", "msg": "progress  32\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:47.123467", "lvl": "debug", "msg": "progress  50\u202F% (1\u202FMB)"}
- {"dt": "2025-08-21T12:48:47.224208", "lvl": "debug", "msg": "progress  73\u202F% (1\u202FMB)"}
- {"dt": "2025-08-21T12:48:47.304928", "lvl": "info", "msg": "2\u202FMB downloaded in 1.57\u202Fs (1.60\u202FMB/s)"}
- {"dt": "2025-08-21T12:48:47.305108", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2025-08-21T12:48:47.305198", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.3.1", "duration": "1.57", "result": "pass", "extra": {"label": "uefi", "size": ! "2621440", "sha256sum": "696d4cf998e91d68b8d45fe35f82a2f57cefea941f031f68a16cf99b314337f6"}}}
- {"dt": "2025-08-21T12:48:47.305357", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:02) [common]"}
- {"dt": "2025-08-21T12:48:47.305450", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:04:58) [common]"}
- {"dt": "2025-08-21T12:48:47.305541", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:47.305637", "lvl": "info", "msg": "downloading https://storage.tuxboot.com/buildroot/fvp-aemva/bl1.bin"}
- {"dt": "2025-08-21T12:48:47.305692", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/bl1.bin"}
- {"dt": "2025-08-21T12:48:47.305738", "lvl": "debug", "msg": "total size: 31181 (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:47.305792", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2025-08-21T12:48:47.789658", "lvl": "debug", "msg": "progress 100\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:47.789781", "lvl": "info", "msg": "0\u202FMB downloaded in 0.48\u202Fs (0.06\u202FMB/s)"}
- {"dt": "2025-08-21T12:48:47.790054", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:47.790172", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.4.1", "duration": "0.48", "result": "pass", "extra": {"label": "bl1", "size": ! "31181", "sha256sum": "063732a1ba119b62d25a83afd5e0ba3ba2ef384749189bfec84bef5d87fe034c"}}}
- {"dt": "2025-08-21T12:48:47.790342", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:47.790437", "lvl": "debug", "msg": "start: 1.5 download-retry (timeout 00:04:58) [common]"}
- {"dt": "2025-08-21T12:48:47.790509", "lvl": "debug", "msg": "start: 1.5.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:47.790608", "lvl": "info", "msg": "downloading https://storage.tuxboot.com/buildroot/fvp-aemva/fvp-base-revc.dtb"}
- {"dt": "2025-08-21T12:48:47.790661", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/fvp-base-revc.dtb"}
- {"dt": "2025-08-21T12:48:47.790706", "lvl": "debug", "msg": "total size: 10350 (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:47.790750", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2025-08-21T12:48:48.261936", "lvl": "debug", "msg": "progress 100\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:48.262071", "lvl": "info", "msg": "0\u202FMB downloaded in 0.47\u202Fs (0.02\u202FMB/s)"}
- {"dt": "2025-08-21T12:48:48.262182", "lvl": "debug", "msg": "end: 1.5.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:48.262252", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.5.1", "duration": "0.47", "result": "pass", "extra": {"label": "dtb", "size": ! "10350", "sha256sum": "e7b02cf2cae34c6f2fa8cf4efc7678067f8b5cb06bd5c26616cd4d7630464f7b"}}}
- {"dt": "2025-08-21T12:48:48.262371", "lvl": "debug", "msg": "end: 1.5 download-retry (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:48.262437", "lvl": "debug", "msg": "start: 1.6 download-retry (timeout 00:04:57) [common]"}
- {"dt": "2025-08-21T12:48:48.262502", "lvl": "debug", "msg": "start: 1.6.1 file-download (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:48.262589", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxmake/builds/502/Image.gz"}
- {"dt": "2025-08-21T12:48:48.262645", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/Image"}
- {"dt": "2025-08-21T12:48:48.262693", "lvl": "debug", "msg": "total size: 14355336 (13\u202FMB)"}
- {"dt": "2025-08-21T12:48:48.262742", "lvl": "info", "msg": "Using gunzip to decompress gz"}
- {"dt": "2025-08-21T12:48:48.364839", "lvl": "debug", "msg": "progress  64\u202F% (8\u202FMB)"}
- {"dt": "2025-08-21T12:48:48.451386", "lvl": "info", "msg": "13\u202FMB downloaded in 0.19\u202Fs (72.56\u202FMB/s)"}
- {"dt": "2025-08-21T12:48:48.451589", "lvl": "debug", "msg": "end: 1.6.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:48.451661", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.6.1", "duration": "0.19", "result": "pass", "extra": {"label": "kernel", "size": ! "14355336", "sha256sum": "ca818a8b92551a389e1f7aed1118386d13e15779a6773aca76be0912ac635a09"}}}
- {"dt": "2025-08-21T12:48:48.451812", "lvl": "debug", "msg": "end: 1.6 download-retry (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:48.451907", "lvl": "debug", "msg": "start: 1.7 download-retry (timeout 00:04:57) [common]"}
- {"dt": "2025-08-21T12:48:48.451998", "lvl": "debug", "msg": "start: 1.7.1 file-download (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:48.452125", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian_20250617_trixie_arm64_rootfs.ext4.xz"}
- {"dt": "2025-08-21T12:48:48.452202", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/https___storage.tuxboot.com_debian_20250617_trixie_arm64_rootfs.ext4"}
- {"dt": "2025-08-21T12:48:48.452268", "lvl": "debug", "msg": "total size: 150840416 (143\u202FMB)"}
- {"dt": "2025-08-21T12:48:48.452335", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-08-21T12:48:48.553211", "lvl": "debug", "msg": "progress   1\u202F% (2\u202FMB)"}
- {"dt": "2025-08-21T12:48:48.709731", "lvl": "debug", "msg": "progress   6\u202F% (8\u202FMB)"}
- {"dt": "2025-08-21T12:48:48.913847", "lvl": "debug", "msg": "progress  11\u202F% (15\u202FMB)"}
- {"dt": "2025-08-21T12:48:49.107348", "lvl": "debug", "msg": "progress  16\u202F% (23\u202FMB)"}
- {"dt": "2025-08-21T12:48:49.302906", "lvl": "debug", "msg": "progress  21\u202F% (30\u202FMB)"}
- {"dt": "2025-08-21T12:48:49.511390", "lvl": "debug", "msg": "progress  26\u202F% (37\u202FMB)"}
- {"dt": "2025-08-21T12:48:49.686789", "lvl": "debug", "msg": "progress  31\u202F% (44\u202FMB)"}
- {"dt": "2025-08-21T12:48:49.878728", "lvl": "debug", "msg": "progress  36\u202F% (51\u202FMB)"}
- {"dt": "2025-08-21T12:48:50.087140", "lvl": "debug", "msg": "progress  41\u202F% (59\u202FMB)"}
- {"dt": "2025-08-21T12:48:50.290139", "lvl": "debug", "msg": "progress  46\u202F% (66\u202FMB)"}
- {"dt": "2025-08-21T12:48:50.495275", "lvl": "debug", "msg": "progress  51\u202F% (73\u202FMB)"}
- {"dt": "2025-08-21T12:48:50.712060", "lvl": "debug", "msg": "progress  56\u202F% (80\u202FMB)"}
- {"dt": "2025-08-21T12:48:50.916021", "lvl": "debug", "msg": "progress  61\u202F% (87\u202FMB)"}
- {"dt": "2025-08-21T12:48:51.096350", "lvl": "debug", "msg": "progress  66\u202F% (94\u202FMB)"}
- {"dt": "2025-08-21T12:48:51.293394", "lvl": "debug", "msg": "progress  71\u202F% (102\u202FMB)"}
- {"dt": "2025-08-21T12:48:51.492667", "lvl": "debug", "msg": "progress  76\u202F% (109\u202FMB)"}
- {"dt": "2025-08-21T12:48:51.685261", "lvl": "debug", "msg": "progress  81\u202F% (116\u202FMB)"}
- {"dt": "2025-08-21T12:48:51.880545", "lvl": "debug", "msg": "progress  86\u202F% (123\u202FMB)"}
- {"dt": "2025-08-21T12:48:52.053830", "lvl": "debug", "msg": "progress  91\u202F% (130\u202FMB)"}
- {"dt": "2025-08-21T12:48:52.179908", "lvl": "debug", "msg": "progress  96\u202F% (138\u202FMB)"}
- {"dt": "2025-08-21T12:48:55.169705", "lvl": "info", "msg": "143\u202FMB downloaded in 6.72\u202Fs (21.41\u202FMB/s)"}
- {"dt": "2025-08-21T12:48:55.169976", "lvl": "debug", "msg": "end: 1.7.1 file-download (duration 00:00:07) [common]"}
- {"dt": "2025-08-21T12:48:55.170047", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.7.1", "duration": "6.72", "result": "pass", "extra": {"label": "rootfs", "size": ! "150840416", "sha256sum": "1eaaae772692e22cefec5345d642e254407cec1431dd51a20007af2a1819b610"}}}
- {"dt": "2025-08-21T12:48:55.170163", "lvl": "debug", "msg": "start: 1.7.2 download-retry (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:55.170227", "lvl": "debug", "msg": "start: 1.7.2.1 file-download (timeout 00:00:33) [common]"}
- {"dt": "2025-08-21T12:48:55.170335", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxmake/builds/502/modules.tar.xz"}
- {"dt": "2025-08-21T12:48:55.170394", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/rootfs.modules/modules.tar"}
- {"dt": "2025-08-21T12:48:55.170437", "lvl": "debug", "msg": "total size: 12546244 (11\u202FMB)"}
- {"dt": "2025-08-21T12:48:55.170484", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-08-21T12:48:55.312940", "lvl": "info", "msg": "11\u202FMB downloaded in 0.14\u202Fs (83.97\u202FMB/s)"}
- {"dt": "2025-08-21T12:48:55.313209", "lvl": "debug", "msg": "end: 1.7.2.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:55.313332", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.7.2.1", "duration": "0.14", "result": "pass", "extra": {"label": "rootfs.modules", "size": ! "12546244", "sha256sum": "a6b81fa4d0e3e28caeb4b5bc0111c9d995969032d2c16d3e7a34425b0cc34999"}}}
- {"dt": "2025-08-21T12:48:55.313607", "lvl": "debug", "msg": "end: 1.7.2 download-retry (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:55.313753", "lvl": "debug", "msg": "start: 1.7.3 download-retry (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:55.313866", "lvl": "debug", "msg": "start: 1.7.3.1 http-download (timeout 00:00:33) [common]"}
- {"dt": "2025-08-21T12:48:55.313971", "lvl": "info", "msg": "downloading https://people.linaro.org/~anders.roxell/yesloop.sh"}
- {"dt": "2025-08-21T12:48:55.314026", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/rootfs.overlay-00/yesloop.sh"}
- {"dt": "2025-08-21T12:48:55.314075", "lvl": "debug", "msg": "total size: 73 (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:55.314131", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2025-08-21T12:48:55.603414", "lvl": "debug", "msg": "progress 100\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:55.603567", "lvl": "info", "msg": "0\u202FMB downloaded in 0.29\u202Fs (0.00\u202FMB/s)"}
- {"dt": "2025-08-21T12:48:55.603678", "lvl": "debug", "msg": "end: 1.7.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:55.603735", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.7.3.1", "duration": "0.29", "result": "pass", "extra": {"label": "rootfs.overlay-00", "size": ! "73", "sha256sum": "e9bce4d40961b32557e0d91a52e089b8ce9ea8ee2cab9a31f6bec9389f04ffad"}}}
- {"dt": "2025-08-21T12:48:55.603838", "lvl": "debug", "msg": "end: 1.7.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:55.603903", "lvl": "debug", "msg": "start: 1.7.4 append-overlays (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:55.603956", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/https___storage.tuxboot.com_debian_20250617_trixie_arm64_rootfs.ext4'"}
- {"dt": "2025-08-21T12:48:56.639531", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2025-08-21T12:48:56.640367", "lvl": "debug", "msg": "- rootfs.lava: '/var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/compress-overlay-lk9h2rig/overlay-1.1.4.tar.gz' to '/'"}
- {"dt": "2025-08-21T12:48:56.645217", "lvl": "debug", "msg": "- rootfs.modules: '/var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/rootfs.modules/modules.tar' to '/usr/'"}
- {"dt": "2025-08-21T12:48:56.820748", "lvl": "debug", "msg": "- rootfs.overlay-00: '/var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/rootfs.overlay-00/yesloop.sh' to '/yesloop.sh'"}
- {"dt": "2025-08-21T12:48:57.066844", "lvl": "debug", "msg": "end: 1.7.4 append-overlays (duration 00:00:01) [common]"}
- {"dt": "2025-08-21T12:48:57.067216", "lvl": "debug", "msg": "end: 1.7 download-retry (duration 00:00:09) [common]"}
- {"dt": "2025-08-21T12:48:57.067308", "lvl": "debug", "msg": "start: 1.8 download-retry (timeout 00:04:49) [common]"}
- {"dt": "2025-08-21T12:48:57.067383", "lvl": "debug", "msg": "start: 1.8.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-08-21T12:48:57.067532", "lvl": "info", "msg": "downloading https://storage.tuxboot.com/buildroot/fvp-aemva/fip.bin"}
- {"dt": "2025-08-21T12:48:57.067595", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/fip.bin"}
- {"dt": "2025-08-21T12:48:57.067652", "lvl": "debug", "msg": "total size: 2738964 (2\u202FMB)"}
- {"dt": "2025-08-21T12:48:57.067711", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2025-08-21T12:48:57.976560", "lvl": "debug", "msg": "progress   1\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:58.169105", "lvl": "debug", "msg": "progress   7\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:58.269568", "lvl": "debug", "msg": "progress  16\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:58.371514", "lvl": "debug", "msg": "progress  33\u202F% (0\u202FMB)"}
- {"dt": "2025-08-21T12:48:58.471676", "lvl": "debug", "msg": "progress  61\u202F% (1\u202FMB)"}
- {"dt": "2025-08-21T12:48:58.572646", "lvl": "debug", "msg": "progress  94\u202F% (2\u202FMB)"}
- {"dt": "2025-08-21T12:48:58.586231", "lvl": "info", "msg": "2\u202FMB downloaded in 1.52\u202Fs (1.72\u202FMB/s)"}
- {"dt": "2025-08-21T12:48:58.586378", "lvl": "debug", "msg": "end: 1.8.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2025-08-21T12:48:58.586447", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.8.1", "duration": "1.52", "result": "pass", "extra": {"label": "fip", "size": ! "2738964", "sha256sum": "520afbd0ffd585c23090d42fc24cc8c48c84ae568dc3852077b11d616509e2f5"}}}
- {"dt": "2025-08-21T12:48:58.586567", "lvl": "debug", "msg": "end: 1.8 download-retry (duration 00:00:02) [common]"}
- {"dt": "2025-08-21T12:48:58.586646", "lvl": "info", "msg": "end: 1 fvp-deploy (duration 00:00:13) [common]"}
- {"dt": "2025-08-21T12:48:58.586721", "lvl": "info", "msg": "start: 2 boot-fvp (timeout 00:30:00) [common]"}
- {"dt": "2025-08-21T12:48:58.586793", "lvl": "debug", "msg": "start: 2.1 boot-fvp-main (timeout 00:30:00) [common]"}
- {"dt": "2025-08-21T12:48:58.586863", "lvl": "debug", "msg": "start: 2.1.1 check-fvp-version (timeout 00:30:00) [common]"}
- {"dt": "2025-08-21T12:48:58.586923", "lvl": "debug", "msg": "Calling: ['docker', 'image', 'inspect', '--format', 'Image fvp:aemva-11.28.23 exists locally', 'fvp:aemva-11.28.23']"}
- {"dt": "2025-08-21T12:48:58.620125", "lvl": "debug", "msg": ">> Image fvp:aemva-11.28.23 exists locally"}
- {"dt": "2025-08-21T12:48:58.621671", "lvl": "debug", "msg": "Returned 0 in 0 seconds"}
- {"dt": "2025-08-21T12:48:58.621766", "lvl": "debug", "msg": "docker run --rm fvp:aemva-11.28.23 /opt/model/FVP_AEMvA/models/Linux64_GCC-9.3/FVP_Base_RevC-2xAEMvA --version"}
- {"dt": "2025-08-21T12:48:59.109618", "lvl": "debug", "msg": "output: "}
- {"dt": "2025-08-21T12:48:59.109779", "lvl": "debug", "msg": "output: Fast Models [11.28.23 (Feb 17 2025)]"}
- {"dt": "2025-08-21T12:48:59.109853", "lvl": "debug", "msg": "output: Copyright 2000-2025 ARM Limited."}
- {"dt": "2025-08-21T12:48:59.109903", "lvl": "debug", "msg": "output: All Rights Reserved."}
- {"dt": "2025-08-21T12:48:59.109952", "lvl": "debug", "msg": "output: "}
- {"dt": "2025-08-21T12:48:59.110000", "lvl": "debug", "msg": "output: "}
- {"dt": "2025-08-21T12:48:59.110045", "lvl": "debug", "msg": "output: Info: /OSCI/SystemC: Simulation stopped by user."}
- {"dt": "2025-08-21T12:48:59.110092", "lvl": "debug", "msg": "output: "}
- {"dt": "2025-08-21T12:48:59.110251", "lvl": "results", "msg": {"definition": "lava", "case": "fvp-version", "level": "2.1.1", "extra": {"fvp-version": "\nFast Models [11.28.23 (Feb 17 2025)]\nCopyright 2000-2025 ARM Limited.\nAll Rights Reserved.\n\n\nInfo: /OSCI/SystemC: Simulation stopped by user.\n"}, "result": "pass", "duration": "0.52"}}
- {"dt": "2025-08-21T12:48:59.110367", "lvl": "debug", "msg": "end: 2.1.1 check-fvp-version (duration 00:00:01) [common]"}
- {"dt": "2025-08-21T12:48:59.110439", "lvl": "debug", "msg": "start: 2.1.2 run-fvp (timeout 00:29:59) [common]"}
- {"dt": "2025-08-21T12:48:59.110502", "lvl": "debug", "msg": "Download action namespace keys are: dict_keys(['startup', 'uefi', 'bl1', 'dtb', 'kernel', 'rootfs', 'rootfs.modules', 'rootfs.overlay-00', 'fip', 'file'])"}
- {"dt": "2025-08-21T12:48:59.110594", "lvl": "warning", "msg": "Empty value for action='download-action' label='file' key='file'"}
- {"dt": "2025-08-21T12:48:59.110649", "lvl": "warning", "msg": "'license_variable' or 'ubl_license' not set, model may not function."}
- {"dt": "2025-08-21T12:48:59.110863", "lvl": "debug", "msg": "FVP model arguments:"}
- {"dt": "2025-08-21T12:48:59.110928", "lvl": "debug", "msg": "/opt/model/FVP_AEMvA/models/Linux64_GCC-9.3/FVP_Base_RevC-2xAEMvA\n--stat \\\n-C bp.dram_size=4 \\\n-C bp.flashloader0.fname='/tuxrun-nt9e39f9-lava-1/fip.bin' \\\n-C bp.flashloader1.fname='/tuxrun-nt9e39f9-lava-1/FVP_AARCH64_EFI.fd' \\\n-C bp.hostbridge.userNetPorts=8022=22 \\\n-C bp.hostbridge.userNetworking=1 \\\n-C bp.refcounter.non_arch_start_at_default=1 \\\n-C bp.refcounter.use_real_time=0 \\\n-C bp.secure_memory=1 \\\n-C bp.secureflashloader.fname='/tuxrun-nt9e39f9-lava-1/bl1.bin' \\\n-C bp.smsc_91c111.enabled=1 \\\n-C bp.terminal_0.mode=telnet \\\n-C bp.terminal_0.start_telnet=0 \\\n-C bp.terminal_1.mode=raw \\\n-C bp.terminal_1.start_telnet=0 \\\n-C bp.terminal_2.mode=raw \\\n-C bp.terminal_2.start_telnet=0 \\\n-C bp.terminal_3.mode=raw \\\n-C bp.terminal_3.start_telnet=0 \\\n-C bp.ve_sysregs.exit_on_shutdown=1 \\\n-C bp.virtio_rng.enabled=1 \\\n-C bp.virtioblockdevice.image_path='/tuxrun-nt9e39f9-lava-1/https___storage.tuxboot.com_debian_20250617_trixie_arm64_rootfs.ext4' \\\n-C bp.virtiop9device.root_path= \\\n-C bp.vis.disable_visualisation=1 \\\n-C cache_state_modelled=0 \\\n-C cluster0.NUM_CORES=4 \\\n-C cluster0.PA_SIZE=48 \\\n-C cluster0.check_memory_attributes=0 \\\n-C cluster0.clear_reg_top_eret=2 \\\n-C cluster0.cpu0.semihosting-cwd=/tuxrun-nt9e39f9-lava-1 \\\n-C cluster0.ecv_support_level=2 \\\n-C cluster0.enhanced_pac2_level=3 \\\n-C cluster0.gicv3.cpuintf-mmap-access-level=2 \\\n-C cluster0.gicv3.without-DS-support=1 \\\n-C cluster0.gicv4.mask-virtual-interrupt=1 \\\n-C cluster0.has_16k_granule=1 \\\n-C cluster0.has_amu=1 \\\n-C cluster0.has_arm_v8-1=1 \\\n-C cluster0.has_arm_v8-2=1 \\\n-C cluster0.has_arm_v8-3=1 \\\n-C cluster0.has_arm_v8-4=1 \\\n-C cluster0.has_arm_v8-5=1 \\\n-C cluster0.has_arm_v8-6=1 \\\n-C cluster0.has_arm_v8-7=1 \\\n-C cluster0.has_arm_v8-8=1 \\\n-C cluster0.has_arm_v8-9=1 \\\n-C cluster0.has_arm_v9-0=1 \\\n-C cluster0.has_arm_v9-1=1 \\\n-C cluster0.has_arm_v9-2=1 \\\n-C cluster0.has_arm_v9-3=1 \\\n-C cluster0.has_arm_v9-4=1 \\\n-C cluster0.has_arm_v9-5=1 \\\n-C cluster0.has_branch_target_exception=1 \\\n-C cluster0.has_brbe=1 \\\n-C cluster0.has_brbe_v1p1=1 \\\n-C cluster0.has_const_pac=1 \\\n-C cluster0.has_gcs=1 \\\n-C cluster0.has_hpmn0=1 \\\n-C cluster0.has_large_system_ext=1 \\\n-C cluster0.has_large_va=1 \\\n-C cluster0.has_permission_indirection_s1=1 \\\n-C cluster0.has_permission_indirection_s2=1 \\\n-C cluster0.has_permission_overlay_s1=1 \\\n-C cluster0.has_permission_overlay_s2=1 \\\n-C cluster0.has_rndr=1 \\\n-C cluster0.has_sve=1 \\\n-C cluster0.max_32bit_el=0 \\\n-C cluster0.pmb_idr_external_abort=1 \\\n-C cluster0.stage12_tlb_size=1024 \\\n-C cluster0.sve.has_sme2=1 \\\n-C cluster0.sve.has_sme=1 \\\n-C cluster0.sve.has_sve2=1 \\\n-C cluster1.NUM_CORES=4 \\\n-C cluster1.PA_SIZE=48 \\\n-C cluster1.check_memory_attributes=0 \\\n-C cluster1.clear_reg_top_eret=2 \\\n-C cluster1.ecv_support_level=2 \\\n-C cluster1.enhanced_pac2_level=3 \\\n-C cluster1.gicv3.cpuintf-mmap-access-level=2 \\\n-C cluster1.gicv3.without-DS-support=1 \\\n-C cluster1.gicv4.mask-virtual-interrupt=1 \\\n-C cluster1.has_16k_granule=1 \\\n-C cluster1.has_amu=1 \\\n-C cluster1.has_arm_v8-1=1 \\\n-C cluster1.has_arm_v8-2=1 \\\n-C cluster1.has_arm_v8-3=1 \\\n-C cluster1.has_arm_v8-4=1 \\\n-C cluster1.has_arm_v8-5=1 \\\n-C cluster1.has_arm_v8-6=1 \\\n-C cluster1.has_arm_v8-7=1 \\\n-C cluster1.has_arm_v8-8=1 \\\n-C cluster1.has_arm_v8-9=1 \\\n-C cluster1.has_arm_v9-0=1 \\\n-C cluster1.has_arm_v9-1=1 \\\n-C cluster1.has_arm_v9-2=1 \\\n-C cluster1.has_arm_v9-3=1 \\\n-C cluster1.has_arm_v9-4=1 \\\n-C cluster1.has_arm_v9-5=1 \\\n-C cluster1.has_branch_target_exception=1 \\\n-C cluster1.has_brbe=1 \\\n-C cluster1.has_brbe_v1p1=1 \\\n-C cluster1.has_const_pac=1 \\\n-C cluster1.has_gcs=1 \\\n-C cluster1.has_hpmn0=1 \\\n-C cluster1.has_large_system_ext=1 \\\n-C cluster1.has_large_va=1 \\\n-C cluster1.has_permission_indirection_s1=1 \\\n-C cluster1.has_permission_indirection_s2=1 \\\n-C cluster1.has_permission_overlay_s1=1 \\\n-C cluster1.has_permission_overlay_s2=1 \\\n-C cluster1.has_rndr=1 \\\n-C cluster1.has_sve=1 \\\n-C cluster1.max_32bit_el=0 \\\n-C cluster1.pmb_idr_external_abort=1 \\\n-C cluster1.stage12_tlb_size=1024 \\\n-C cluster1.sve.has_sme2=1 \\\n-C cluster1.sve.has_sme=1 \\\n-C cluster1.sve.has_sve2=1 \\\n-C gic_distributor.has_nmi=1 \\\n-C pci.pci_smmuv3.mmu.SMMU_AIDR=2 \\\n-C pci.pci_smmuv3.mmu.SMMU_IDR0=135263935 \\\n-C pci.pci_smmuv3.mmu.SMMU_IDR1=216481056 \\\n-C pci.pci_smmuv3.mmu.SMMU_IDR3=5908 \\\n-C pci.pci_smmuv3.mmu.SMMU_IDR5=4294902901 \\\n-C pci.pci_smmuv3.mmu.SMMU_S_IDR1=2684354562 \\\n-C pci.pci_smmuv3.mmu.SMMU_S_IDR2=0 \\\n-C pci.pci_smmuv3.mmu.SMMU_S_IDR3=0 \\\n-C pctl.startup=0.0.0.0"}
- {"dt": "2025-08-21T12:48:59.111090", "lvl": "debug", "msg": "Boot command: lava-outerr docker run --rm --interactive --tty --hostname lava --name tuxrun-nt9e39f9-lava-1 --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/startup.nsh:/tuxrun-nt9e39f9-lava-1/startup.nsh --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/FVP_AARCH64_EFI.fd:/tuxrun-nt9e39f9-lava-1/FVP_AARCH64_EFI.fd --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/bl1.bin:/tuxrun-nt9e39f9-lava-1/bl1.bin --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/fvp-base-revc.dtb:/tuxrun-nt9e39f9-lava-1/fvp-base-revc.dtb --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/Image:/tuxrun-nt9e39f9-lava-1/Image --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/https___storage.tuxboot.com_debian_20250617_trixie_arm64_rootfs.ext4:/tuxrun-nt9e39f9-lava-1/https___storage.tuxboot.com_debian_20250617_trixie_arm64_rootfs.ext4 --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/rootfs.modules/modules.tar:/tuxrun-nt9e39f9-lava-1/modules.tar --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/rootfs.overlay-00/yesloop.sh:/tuxrun-nt9e39f9-lava-1/yesloop.sh --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/fip.bin:/tuxrun-nt9e39f9-lava-1/fip.bin --volume /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/run-fvp-7hk16nbp/script.sh:/root/script.sh fvp:aemva-11.28.23 sh /root/script.sh"}
- {"dt": "2025-08-21T12:48:59.115275", "lvl": "debug", "msg": "Setting prompt string to ['(?P<NAME>terminal_1): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_3): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_2): Listening for serial connection on port (?P<PORT>\\\\d+)', 'terminal_0: Listening for serial connection on port (?P<PORT>\\\\d+)']"}
- {"dt": "2025-08-21T12:48:59.115490", "lvl": "debug", "msg": "run-fvp: Wait for prompt ['(?P<NAME>terminal_1): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_3): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_2): Listening for serial connection on port (?P<PORT>\\\\d+)', 'terminal_0: Listening for serial connection on port (?P<PORT>\\\\d+)'] (timeout 00:30:00)"}
- {"dt": "2025-08-21T12:48:59.338472", "lvl": "target", "msg": "Starting the FVP model"}
- {"dt": "2025-08-21T12:48:59.455583", "lvl": "target", "msg": ""}
- {"dt": "2025-08-21T12:48:59.455787", "lvl": "target", "msg": "Info: FVP_Base_RevC_2xAEMvA: terminal_0: Listening for serial connection on port 5000"}
- {"dt": "2025-08-21T12:48:59.455868", "lvl": "target", "msg": ""}
- {"dt": "2025-08-21T12:48:59.455936", "lvl": "target", "msg": ""}
- {"dt": "2025-08-21T12:48:59.455998", "lvl": "target", "msg": "Info: FVP_Base_RevC_2xAEMvA: terminal_1: Listening for serial connection on port 5001"}
- {"dt": "2025-08-21T12:48:59.456059", "lvl": "target", "msg": ""}
- {"dt": "2025-08-21T12:48:59.456121", "lvl": "target", "msg": ""}
- {"dt": "2025-08-21T12:48:59.456186", "lvl": "target", "msg": "Info: FVP_Base_RevC_2xAEMvA: terminal_2: Listening for serial connection on port 5002"}
- {"dt": "2025-08-21T12:48:59.456246", "lvl": "target", "msg": ""}
- {"dt": "2025-08-21T12:48:59.456509", "lvl": "debug", "msg": "Connection group(0) terminal_0: Listening for serial connection on port 5000"}
- {"dt": "2025-08-21T12:48:59.456701", "lvl": "info", "msg": "Found FVP port 5000"}
- {"dt": "2025-08-21T12:48:59.456761", "lvl": "debug", "msg": "Setting prompt string to ['(?P<NAME>terminal_1): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_3): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_2): Listening for serial connection on port (?P<PORT>\\\\d+)', 'terminal_0: Listening for serial connection on port (?P<PORT>\\\\d+)']"}
- {"dt": "2025-08-21T12:48:59.456818", "lvl": "debug", "msg": "run-fvp: Wait for prompt ['(?P<NAME>terminal_1): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_3): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_2): Listening for serial connection on port (?P<PORT>\\\\d+)', 'terminal_0: Listening for serial connection on port (?P<PORT>\\\\d+)'] (timeout 00:30:00)"}
- {"dt": "2025-08-21T12:48:59.456898", "lvl": "debug", "msg": "Connection group(0) terminal_1: Listening for serial connection on port 5001"}
- {"dt": "2025-08-21T12:48:59.456955", "lvl": "info", "msg": "Found secondary FVP port 5001"}
- {"dt": "2025-08-21T12:48:59.457009", "lvl": "debug", "msg": "Setting prompt string to ['(?P<NAME>terminal_1): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_3): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_2): Listening for serial connection on port (?P<PORT>\\\\d+)', 'terminal_0: Listening for serial connection on port (?P<PORT>\\\\d+)']"}
- {"dt": "2025-08-21T12:48:59.457058", "lvl": "debug", "msg": "run-fvp: Wait for prompt ['(?P<NAME>terminal_1): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_3): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_2): Listening for serial connection on port (?P<PORT>\\\\d+)', 'terminal_0: Listening for serial connection on port (?P<PORT>\\\\d+)'] (timeout 00:30:00)"}
- {"dt": "2025-08-21T12:48:59.457120", "lvl": "debug", "msg": "Connection group(0) terminal_2: Listening for serial connection on port 5002"}
- {"dt": "2025-08-21T12:48:59.457168", "lvl": "info", "msg": "Found secondary FVP port 5002"}
- {"dt": "2025-08-21T12:48:59.457214", "lvl": "debug", "msg": "Setting prompt string to ['(?P<NAME>terminal_1): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_3): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_2): Listening for serial connection on port (?P<PORT>\\\\d+)', 'terminal_0: Listening for serial connection on port (?P<PORT>\\\\d+)']"}
- {"dt": "2025-08-21T12:48:59.457260", "lvl": "debug", "msg": "run-fvp: Wait for prompt ['(?P<NAME>terminal_1): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_3): Listening for serial connection on port (?P<PORT>\\\\d+)', '(?P<NAME>terminal_2): Listening for serial connection on port (?P<PORT>\\\\d+)', 'terminal_0: Listening for serial connection on port (?P<PORT>\\\\d+)'] (timeout 00:30:00)"}
- {"dt": "2025-08-21T12:48:59.457330", "lvl": "target", "msg": ""}
- {"dt": "2025-08-21T12:48:59.457383", "lvl": "target", "msg": "Info: FVP_Base_RevC_2xAEMvA: terminal_3: Listening for serial connection on port 5003"}
- {"dt": "2025-08-21T12:48:59.457426", "lvl": "target", "msg": ""}
- {"dt": "2025-08-21T12:48:59.457635", "lvl": "debug", "msg": "Connection group(0) terminal_3: Listening for serial connection on port 5003"}
- {"dt": "2025-08-21T12:48:59.457685", "lvl": "info", "msg": "Found secondary FVP port 5003"}
- {"dt": "2025-08-21T12:48:59.457777", "lvl": "debug", "msg": "end: 2.1.2 run-fvp (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:59.457877", "lvl": "debug", "msg": "start: 2.1.3 fvp-serial-connect (timeout 00:29:59) [common]"}
- {"dt": "2025-08-21T12:48:59.457953", "lvl": "debug", "msg": "Feedback command: lava-outerr docker exec --interactive --tty tuxrun-nt9e39f9-lava-1 telnet localhost 5001"}
- {"dt": "2025-08-21T12:48:59.462295", "lvl": "debug", "msg": "Feedback command: lava-outerr docker exec --interactive --tty tuxrun-nt9e39f9-lava-1 telnet localhost 5002"}
- {"dt": "2025-08-21T12:48:59.466769", "lvl": "debug", "msg": "Feedback command: lava-outerr docker exec --interactive --tty tuxrun-nt9e39f9-lava-1 telnet localhost 5003"}
- {"dt": "2025-08-21T12:48:59.471427", "lvl": "debug", "msg": "Connect command: lava-outerr docker exec --interactive --tty tuxrun-nt9e39f9-lava-1 telnet localhost 5000"}
- {"dt": "2025-08-21T12:48:59.476506", "lvl": "debug", "msg": "end: 2.1.3 fvp-serial-connect (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:59.476858", "lvl": "debug", "msg": "start: 2.1.4 read-feedback (timeout 00:29:59) [common]"}
- {"dt": "2025-08-21T12:48:59.701150", "lvl": "feedback", "msg": "Trying ::1...", "ns": "terminal_1"}
- {"dt": "2025-08-21T12:48:59.701387", "lvl": "feedback", "msg": "Trying 127.0.0.1...", "ns": "terminal_1"}
- {"dt": "2025-08-21T12:48:59.701461", "lvl": "feedback", "msg": "Connected to localhost.", "ns": "terminal_1"}
- {"dt": "2025-08-21T12:48:59.701524", "lvl": "feedback", "msg": "Escape character is '^]'.", "ns": "terminal_1"}
- {"dt": "2025-08-21T12:48:59.701773", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T12:48:59.702029", "lvl": "feedback", "msg": "Trying ::1...", "ns": "terminal_2"}
- {"dt": "2025-08-21T12:48:59.702132", "lvl": "feedback", "msg": "Trying 127.0.0.1...", "ns": "terminal_2"}
- {"dt": "2025-08-21T12:48:59.702212", "lvl": "feedback", "msg": "Connected to localhost.", "ns": "terminal_2"}
- {"dt": "2025-08-21T12:48:59.702282", "lvl": "feedback", "msg": "Escape character is '^]'.", "ns": "terminal_2"}
- {"dt": "2025-08-21T12:48:59.702531", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_2' for up to 1s"}
- {"dt": "2025-08-21T12:48:59.702644", "lvl": "feedback", "msg": "Trying ::1...", "ns": "terminal_3"}
- {"dt": "2025-08-21T12:48:59.702723", "lvl": "feedback", "msg": "Trying 127.0.0.1...", "ns": "terminal_3"}
- {"dt": "2025-08-21T12:48:59.702792", "lvl": "feedback", "msg": "Connected to localhost.", "ns": "terminal_3"}
- {"dt": "2025-08-21T12:48:59.702859", "lvl": "feedback", "msg": "Escape character is '^]'.", "ns": "terminal_3"}
- {"dt": "2025-08-21T12:48:59.703095", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_3' for up to 1s"}
- {"dt": "2025-08-21T12:48:59.703185", "lvl": "debug", "msg": "end: 2.1.4 read-feedback (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T12:48:59.703260", "lvl": "debug", "msg": "end: 2.1 boot-fvp-main (duration 00:00:01) [common]"}
- {"dt": "2025-08-21T12:48:59.703326", "lvl": "debug", "msg": "start: 2.2 read-feedback (timeout 00:29:59) [common]"}
- {"dt": "2025-08-21T12:49:00.563133", "lvl": "feedback", "msg": "UEFI firmware (version  built at 13:03:53 on Mar 21 2025)", "ns": "terminal_1"}
- {"dt": "2025-08-21T12:49:00.563467", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T12:49:02.565894", "lvl": "debug", "msg": "end: 2.2 read-feedback (duration 00:00:03) [common]"}
- {"dt": "2025-08-21T12:49:02.566094", "lvl": "debug", "msg": "start: 2.3 auto-login-action (timeout 00:29:56) [common]"}
- {"dt": "2025-08-21T12:49:02.566201", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2025-08-21T12:49:02.566287", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:30:00)"}
- {"dt": "2025-08-21T12:49:02.566495", "lvl": "target", "msg": "Trying ::1..."}
- {"dt": "2025-08-21T12:49:02.566552", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2025-08-21T12:49:02.566597", "lvl": "target", "msg": "Connected to localhost."}
- {"dt": "2025-08-21T12:49:02.566641", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2025-08-21T12:49:02.566682", "lvl": "target", "msg": "NOTICE:  Booting Trusted Firmware"}
- {"dt": "2025-08-21T12:49:02.566725", "lvl": "target", "msg": "NOTICE:  BL1: v2.12.0(release):v2.12.0"}
- {"dt": "2025-08-21T12:49:02.566765", "lvl": "target", "msg": "NOTICE:  BL1: Built : 13:04:04, Mar 21 2025"}
- {"dt": "2025-08-21T12:49:02.566805", "lvl": "target", "msg": "INFO:    BL1: RAM 0x4034000 - 0x403b000"}
- {"dt": "2025-08-21T12:49:02.566845", "lvl": "target", "msg": "INFO:    Loading image id=32 at address 0x4001010"}
- {"dt": "2025-08-21T12:49:02.566885", "lvl": "target", "msg": "INFO:    Image id=32 loaded: 0x4001010 - 0x4001213"}
- {"dt": "2025-08-21T12:49:02.566924", "lvl": "target", "msg": "INFO:    FCONF: Config file with image ID:32 loaded at address = 0x4001010"}
- {"dt": "2025-08-21T12:49:02.566964", "lvl": "target", "msg": "INFO:    Loading image id=24 at address 0x4001300"}
- {"dt": "2025-08-21T12:49:02.567004", "lvl": "target", "msg": "INFO:    Image id=24 loaded: 0x4001300 - 0x40015e4"}
- {"dt": "2025-08-21T12:49:02.567044", "lvl": "target", "msg": "INFO:    FCONF: Config file with image ID:24 loaded at address = 0x4001300"}
- {"dt": "2025-08-21T12:49:02.567083", "lvl": "target", "msg": "INFO:    BL1: Loading BL2"}
- {"dt": "2025-08-21T12:49:02.567121", "lvl": "target", "msg": "INFO:    Loading image id=1 at address 0x4020000"}
- {"dt": "2025-08-21T12:49:02.567166", "lvl": "target", "msg": "INFO:    Image id=1 loaded: 0x4020000 - 0x4028821"}
- {"dt": "2025-08-21T12:49:02.567208", "lvl": "target", "msg": "NOTICE:  BL1: Booting BL2"}
- {"dt": "2025-08-21T12:49:02.567247", "lvl": "target", "msg": "INFO:    Entry point address = 0x4020000"}
- {"dt": "2025-08-21T12:49:02.567286", "lvl": "target", "msg": "INFO:    SPSR = 0x3c5"}
- {"dt": "2025-08-21T12:49:02.567324", "lvl": "target", "msg": "INFO:    FCONF: Reading FW_CONFIG firmware configuration file from: 0x4001010"}
- {"dt": "2025-08-21T12:49:02.567362", "lvl": "target", "msg": "INFO:    FCONF: Reading firmware configuration information for: dyn_cfg"}
- {"dt": "2025-08-21T12:49:02.567400", "lvl": "target", "msg": "INFO:    FCONF: Reading TB_FW firmware configuration file from: 0x4001300"}
- {"dt": "2025-08-21T12:49:02.567438", "lvl": "target", "msg": "NOTICE:  BL2: v2.12.0(release):v2.12.0"}
- {"dt": "2025-08-21T12:49:02.567476", "lvl": "target", "msg": "NOTICE:  BL2: Built : 13:04:04, Mar 21 2025"}
- {"dt": "2025-08-21T12:49:02.567515", "lvl": "target", "msg": "INFO:    BL2: Doing platform setup"}
- {"dt": "2025-08-21T12:49:02.567554", "lvl": "target", "msg": "INFO:    Configuring TrustZone Controller"}
- {"dt": "2025-08-21T12:49:02.567592", "lvl": "target", "msg": "INFO:    Total 8 regions set."}
- {"dt": "2025-08-21T12:49:02.567630", "lvl": "target", "msg": "INFO:    BL2: Loading image id 3"}
- {"dt": "2025-08-21T12:49:02.567668", "lvl": "target", "msg": "INFO:    Loading image id=3 at address 0x4003000"}
- {"dt": "2025-08-21T12:49:02.567706", "lvl": "target", "msg": "INFO:    Image id=3 loaded: 0x4003000 - 0x40141ad"}
- {"dt": "2025-08-21T12:49:02.567744", "lvl": "target", "msg": "INFO:    BL2: Loading image id 23"}
- {"dt": "2025-08-21T12:49:02.567782", "lvl": "target", "msg": "INFO:    Loading image id=23 at address 0x7f00000"}
- {"dt": "2025-08-21T12:49:02.567820", "lvl": "target", "msg": "INFO:    Image id=23 loaded: 0x7f00000 - 0x7f02a57"}
- {"dt": "2025-08-21T12:49:02.567857", "lvl": "target", "msg": "INFO:    BL2: Loading image id 25"}
- {"dt": "2025-08-21T12:49:02.567898", "lvl": "target", "msg": "INFO:    Loading image id=25 at address 0x4001300"}
- {"dt": "2025-08-21T12:49:02.567938", "lvl": "target", "msg": "INFO:    Image id=25 loaded: 0x4001300 - 0x4001348"}
- {"dt": "2025-08-21T12:49:02.567976", "lvl": "target", "msg": "INFO:    BL2: Loading image id 5"}
- {"dt": "2025-08-21T12:49:02.568014", "lvl": "target", "msg": "INFO:    Loading image id=5 at address 0x88000000"}
- {"dt": "2025-08-21T12:49:02.568053", "lvl": "target", "msg": "INFO:    Image id=5 loaded: 0x88000000 - 0x88280000"}
- {"dt": "2025-08-21T12:49:02.568092", "lvl": "target", "msg": "INFO:    BL2: Loading image id 27"}
- {"dt": "2025-08-21T12:49:02.568132", "lvl": "target", "msg": "INFO:    Loading image id=27 at address 0x80000000"}
- {"dt": "2025-08-21T12:49:02.568171", "lvl": "target", "msg": "INFO:    Image id=27 loaded: 0x80000000 - 0x80000048"}
- {"dt": "2025-08-21T12:49:02.568209", "lvl": "target", "msg": "NOTICE:  BL1: Booting BL31"}
- {"dt": "2025-08-21T12:49:02.568435", "lvl": "target", "msg": "INFO:    Entry point address = 0x4003000"}
- {"dt": "2025-08-21T12:49:02.568487", "lvl": "target", "msg": "INFO:    SPSR = 0x3cd"}
- {"dt": "2025-08-21T12:49:02.568529", "lvl": "target", "msg": "INFO:    BL31 FCONF: FW_CONFIG address = 4001010"}
- {"dt": "2025-08-21T12:49:02.568570", "lvl": "target", "msg": "INFO:    FCONF: Reading FW_CONFIG firmware configuration file from: 0x4001010"}
- {"dt": "2025-08-21T12:49:02.568610", "lvl": "target", "msg": "INFO:    FCONF: Reading firmware configuration information for: dyn_cfg"}
- {"dt": "2025-08-21T12:49:02.568651", "lvl": "target", "msg": "INFO:    FCONF: Reading HW_CONFIG firmware configuration file from: 0x7f00000"}
- {"dt": "2025-08-21T12:49:02.568690", "lvl": "target", "msg": "INFO:    FCONF: Reading firmware configuration information for: dram_layout"}
- {"dt": "2025-08-21T12:49:02.568731", "lvl": "target", "msg": "INFO:    FCONF: Reading firmware configuration information for: cpu_timer"}
- {"dt": "2025-08-21T12:49:02.568775", "lvl": "target", "msg": "INFO:    FCONF: Reading firmware configuration information for: uart_config"}
- {"dt": "2025-08-21T12:49:02.568816", "lvl": "target", "msg": "INFO:    FCONF: Reading firmware configuration information for: topology"}
- {"dt": "2025-08-21T12:49:02.568855", "lvl": "target", "msg": "INFO:    FCONF: Reading firmware configuration information for: gicv3_config"}
- {"dt": "2025-08-21T12:49:02.568894", "lvl": "target", "msg": "NOTICE:  BL31: v2.12.0(release):v2.12.0"}
- {"dt": "2025-08-21T12:49:02.568933", "lvl": "target", "msg": "NOTICE:  BL31: Built : 13:04:05, Mar 21 2025"}
- {"dt": "2025-08-21T12:49:02.568973", "lvl": "target", "msg": "INFO:    GICv3 with legacy support detected."}
- {"dt": "2025-08-21T12:49:02.569012", "lvl": "target", "msg": "INFO:    ARM GICv3 driver initialized in EL3"}
- {"dt": "2025-08-21T12:49:02.569050", "lvl": "target", "msg": "INFO:    Maximum SPI INTID supported: 255"}
- {"dt": "2025-08-21T12:49:02.569088", "lvl": "target", "msg": "INFO:    BL31: Initializing runtime services"}
- {"dt": "2025-08-21T12:49:02.569127", "lvl": "target", "msg": "INFO:    BL31: Preparing for EL3 exit to normal world"}
- {"dt": "2025-08-21T12:49:02.569165", "lvl": "target", "msg": "INFO:    Entry point address = 0x88000000"}
- {"dt": "2025-08-21T12:49:02.569204", "lvl": "target", "msg": "INFO:    SPSR = 0x3c9"}
- {"dt": "2025-08-21T12:49:03.939244", "lvl": "target", "msg": "[2J[04D[=3h[2J[09DPress ESCAPE for boot options ...........[2J[45DUEFI Interactive Shell v2.2"}
- {"dt": "2025-08-21T12:49:03.940829", "lvl": "target", "msg": "EDK II"}
- {"dt": "2025-08-21T12:49:03.942523", "lvl": "target", "msg": "UEFI v2.70 (EDK II, 0x00010000)"}
- {"dt": "2025-08-21T12:49:03.949818", "lvl": "target", "msg": "[1m[33m[40mMapping table[0m[37m[40m"}
- {"dt": "2025-08-21T12:49:03.958877", "lvl": "target", "msg": "[1m[33m[40m      FS2:[0m[37m[40m [1m[37m[40mAlias(s):[0m[37m[40mF4:"}
- {"dt": "2025-08-21T12:49:03.958957", "lvl": "target", "msg": "          VenHw(C5B9C74A-6D72-4719-99AB-C59F199091EB)"}
- {"dt": "2025-08-21T12:49:03.965902", "lvl": "target", "msg": "[1m[33m[40m      FS1:[0m[37m[40m [1m[37m[40mAlias(s):[0m[37m[40mF1:"}
- {"dt": "2025-08-21T12:49:03.966162", "lvl": "target", "msg": "          MemoryMapped(0xB,0x88000000,0x8827FFFF)"}
- {"dt": "2025-08-21T12:49:03.973706", "lvl": "target", "msg": "[1m[33m[40m      FS0:[0m[37m[40m [1m[37m[40mAlias(s):[0m[37m[40mF0:"}
- {"dt": "2025-08-21T12:49:03.973813", "lvl": "target", "msg": "          Fv(87940482-FC81-41C3-87E6-399CF85AC8A0)"}
- {"dt": "2025-08-21T12:49:03.982610", "lvl": "target", "msg": "[1m[33m[40m     BLK2:[0m[37m[40m [1m[37m[40mAlias(s):[0m[37m[40m"}
- {"dt": "2025-08-21T12:49:03.982688", "lvl": "target", "msg": "          VenHw(DE6AE758-D662-4E17-A97C-4C5964DA4C41,00)"}
- {"dt": "2025-08-21T12:49:03.990506", "lvl": "target", "msg": "[1m[33m[40m     BLK3:[0m[37m[40m [1m[37m[40mAlias(s):[0m[37m[40m"}
- {"dt": "2025-08-21T12:49:03.991077", "lvl": "target", "msg": "          VenHw(DE6AE758-D662-4E17-A97C-4C5964DA4C41,01)"}
- {"dt": "2025-08-21T12:49:03.998951", "lvl": "target", "msg": "[1m[33m[40m     BLK4:[0m[37m[40m [1m[37m[40mAlias(s):[0m[37m[40m"}
- {"dt": "2025-08-21T12:49:03.999124", "lvl": "target", "msg": "          VenHw(DE6AE758-D662-4E17-A97C-4C5964DA4C41,02)"}
- {"dt": "2025-08-21T12:49:04.007520", "lvl": "target", "msg": "[1m[33m[40m     BLK5:[0m[37m[40m [1m[37m[40mAlias(s):[0m[37m[40m"}
- {"dt": "2025-08-21T12:49:04.007632", "lvl": "target", "msg": "          VenHw(DE6AE758-D662-4E17-A97C-4C5964DA4C41,03)"}
- {"dt": "2025-08-21T12:49:04.014773", "lvl": "target", "msg": "[1m[33m[40m     BLK0:[0m[37m[40m [1m[37m[40mAlias(s):[0m[37m[40m"}
- {"dt": "2025-08-21T12:49:04.015315", "lvl": "target", "msg": "          VenHw(09831032-6FA3-4484-AF4F-0A000A8D3A82)"}
- {"dt": "2025-08-21T12:49:04.023105", "lvl": "target", "msg": "[1m[33m[40m     BLK1:[0m[37m[40m [1m[37m[40mAlias(s):[0m[37m[40m"}
- {"dt": "2025-08-21T12:49:04.023214", "lvl": "target", "msg": "          VenHw(405B2307-6839-4D52-AEB9-BECE64252800)"}
- {"dt": "2025-08-21T12:49:04.042115", "lvl": "target", "msg": ""}
- {"dt": "2025-08-21T12:49:04.136244", "lvl": "target", "msg": "[1m[33m[40mShell> [0m[37m[40mImage dtb=fvp-base-revc.dtb systemd.log_level=warning rw console=ttyAMA0 "}
- {"dt": "2025-08-21T12:49:04.136579", "lvl": "target", "msg": "earlycon=pl011,0x1c090000 root=/dev/vda ip=dhcp"}
- {"dt": "2025-08-21T12:49:06.221080", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd0f0]"}
- {"dt": "2025-08-21T12:49:06.221491", "lvl": "debug", "msg": "start: 2.3.1 login-action (timeout 00:29:52) [common]"}
- {"dt": "2025-08-21T12:49:06.221624", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2025-08-21T12:49:06.221740", "lvl": "debug", "msg": "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', 'U-Boot SPL 20[0-9][0-9]']"}
- {"dt": "2025-08-21T12:49:06.221857", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2025-08-21T12:49:06.221939", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2025-08-21T12:49:06.222016", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2025-08-21T12:49:06.222085", "lvl": "debug", "msg": ["-\\[ cut here \\]", "Unhandled fault", "BUG: KCSAN:", "BUG: KASAN:", "BUG: KFENCE:", "Oops(?: -|:)", "WARNING:", "(kernel BUG at|BUG:)", "invalid opcode:", "Kernel panic - not syncing", "U-Boot SPL 20[0-9][0-9]", "root@(.*):[/~]#", "login:", "Login incorrect"]}
- {"dt": "2025-08-21T12:49:06.222223", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:29:52)"}
- {"dt": "2025-08-21T12:49:06.222303", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:14:56)"}
- {"dt": "2025-08-21T12:49:06.222725", "lvl": "target", "msg": "[    0.000000] Linux version 6.17.0-rc1 (tuxmake@tuxmake) (aarch64-linux-gnu-gcc (Debian 13.4.0-1) 13.4.0, GNU ld (GNU Binutils for Debian) 2.45) #1 SMP PREEMPT @1755005689"}
- {"dt": "2025-08-21T12:49:06.222788", "lvl": "target", "msg": "[    0.000000] KASLR enabled"}
- {"dt": "2025-08-21T12:49:06.222838", "lvl": "target", "msg": "[    0.000000] Machine model: FVP Base RevC"}
- {"dt": "2025-08-21T12:49:06.222886", "lvl": "target", "msg": "[    0.000000] earlycon: pl11 at MMIO 0x000000001c090000 (options '')"}
- {"dt": "2025-08-21T12:49:06.222935", "lvl": "target", "msg": "[    0.000000] printk: legacy bootconsole [pl11] enabled"}
- {"dt": "2025-08-21T12:49:06.225013", "lvl": "target", "msg": "[    0.000000] efi: EFI v2.7 by EDK II"}
- {"dt": "2025-08-21T12:49:06.225564", "lvl": "target", "msg": "[    0.000000] efi: ACPI 2.0=0xf2f8b018 MEMATTR=0xf6ed0018 MEMRESERVE=0xf2b61f18 "}
- {"dt": "2025-08-21T12:49:06.357370", "lvl": "target", "msg": "[    0.000000] Reserved memory: created DMA memory pool at 0x0000000018000000, size 8 MiB"}
- {"dt": "2025-08-21T12:49:06.357555", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: initialized node vram@18000000, compatible id shared-dma-pool"}
- {"dt": "2025-08-21T12:49:06.357852", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: 0x0000000018000000..0x00000000187fffff (8192 KiB) nomap non-reusable vram@18000000"}
- {"dt": "2025-08-21T12:49:06.366214", "lvl": "target", "msg": "[    0.000000] NUMA: Faking a node at [mem 0x0000000080000000-0x00000008ffffffff]"}
- {"dt": "2025-08-21T12:49:06.367328", "lvl": "target", "msg": "[    0.000000] NODE_DATA(0) allocated [mem 0x8ff818b00-0x8ff81b17f]"}
- {"dt": "2025-08-21T12:49:06.371244", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2025-08-21T12:49:06.371547", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000080000000-0x00000000ffffffff]"}
- {"dt": "2025-08-21T12:49:06.371852", "lvl": "target", "msg": "[    0.000000]   DMA32    empty"}
- {"dt": "2025-08-21T12:49:06.371946", "lvl": "target", "msg": "[    0.000000]   Normal   [mem 0x0000000100000000-0x00000008ffffffff]"}
- {"dt": "2025-08-21T12:49:06.372021", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2025-08-21T12:49:06.372398", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2025-08-21T12:49:06.372664", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000080000000-0x00000000f299ffff]"}
- {"dt": "2025-08-21T12:49:06.372718", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f29a0000-0x00000000f2a0ffff]"}
- {"dt": "2025-08-21T12:49:06.372948", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f2a10000-0x00000000f2b1ffff]"}
- {"dt": "2025-08-21T12:49:06.373005", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f2b20000-0x00000000f2b5ffff]"}
- {"dt": "2025-08-21T12:49:06.373052", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f2b60000-0x00000000f2b9ffff]"}
- {"dt": "2025-08-21T12:49:06.373104", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f2ba0000-0x00000000f2f7ffff]"}
- {"dt": "2025-08-21T12:49:06.373689", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f2f80000-0x00000000f7f4ffff]"}
- {"dt": "2025-08-21T12:49:06.373743", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f7f50000-0x00000000f7f8ffff]"}
- {"dt": "2025-08-21T12:49:06.373800", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f7f90000-0x00000000f7f9ffff]"}
- {"dt": "2025-08-21T12:49:06.373851", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f7fa0000-0x00000000f7feffff]"}
- {"dt": "2025-08-21T12:49:06.374129", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x00000000f7ff0000-0x00000000fbffffff]"}
- {"dt": "2025-08-21T12:49:06.374200", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000880000000-0x00000008ffffffff]"}
- {"dt": "2025-08-21T12:49:06.374257", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000080000000-0x00000008ffffffff]"}
- {"dt": "2025-08-21T12:49:06.608841", "lvl": "target", "msg": "[    0.000000] On node 0, zone Normal: 16384 pages in unavailable ranges"}
- {"dt": "2025-08-21T12:49:06.609301", "lvl": "target", "msg": "[    0.000000] cma: Reserved 32 MiB at 0x00000000fa000000"}
- {"dt": "2025-08-21T12:49:06.610951", "lvl": "target", "msg": "[    0.000000] psci: probing for conduit method from DT."}
- {"dt": "2025-08-21T12:49:06.613207", "lvl": "target", "msg": "[    0.000000] psci: PSCIv1.1 detected in firmware."}
- {"dt": "2025-08-21T12:49:06.613313", "lvl": "target", "msg": "[    0.000000] psci: Using standard PSCI v0.2 function IDs"}
- {"dt": "2025-08-21T12:49:06.613763", "lvl": "target", "msg": "[    0.000000] psci: MIGRATE_INFO_TYPE not supported."}
- {"dt": "2025-08-21T12:49:06.614884", "lvl": "target", "msg": "[    0.000000] psci: SMC Calling Convention v1.5"}
- {"dt": "2025-08-21T12:49:06.622146", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 25 pages/cpu s62552 r8192 d31656 u102400"}
- {"dt": "2025-08-21T12:49:06.625525", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2025-08-21T12:49:06.645613", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Address authentication (IMP DEF algorithm)"}
- {"dt": "2025-08-21T12:49:06.646700", "lvl": "target", "msg": "[    0.000000] CPU features: detected: GICv3 CPU interface"}
- {"dt": "2025-08-21T12:49:06.646958", "lvl": "target", "msg": "[    0.000000] CPU features: detected: HCRX_EL2 register"}
- {"dt": "2025-08-21T12:49:06.647026", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Stage-1 Permission Indirection Extension (S1PIE)"}
- {"dt": "2025-08-21T12:49:06.647305", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Stage-1 Permission Overlay Extension (S1POE)"}
- {"dt": "2025-08-21T12:49:06.647389", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Virtualization Host Extensions"}
- {"dt": "2025-08-21T12:49:06.648375", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-BHB"}
- {"dt": "2025-08-21T12:49:06.648934", "lvl": "target", "msg": "[    0.000000] alternatives: applying boot alternatives"}
- {"dt": "2025-08-21T12:49:06.660696", "lvl": "target", "msg": "[    0.000000] Kernel command line: Image dtb=fvp-base-revc.dtb systemd.log_level=warning rw console=ttyAMA0 earlycon=pl011,0x1c090000 root=/dev/vda ip=dhcp"}
- {"dt": "2025-08-21T12:49:06.663474", "lvl": "target", "msg": "[    0.000000] Unknown kernel command line parameters \"Image dtb=fvp-base-revc.dtb\", will be passed to user space."}
- {"dt": "2025-08-21T12:49:06.665701", "lvl": "target", "msg": "[    0.000000] random: crng init done"}
- {"dt": "2025-08-21T12:49:06.665804", "lvl": "target", "msg": "[    0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes"}
- {"dt": "2025-08-21T12:49:06.676311", "lvl": "target", "msg": "[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2025-08-21T12:49:06.681907", "lvl": "target", "msg": "[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2025-08-21T12:49:06.682002", "lvl": "target", "msg": "[    0.000000] software IO TLB: area num 8."}
- {"dt": "2025-08-21T12:49:06.885514", "lvl": "target", "msg": "[    0.000000] software IO TLB: mapped [mem 0x00000000e9800000-0x00000000ed800000] (64MB)"}
- {"dt": "2025-08-21T12:49:06.887039", "lvl": "target", "msg": "[    0.000000] Fallback order for Node 0: 0 "}
- {"dt": "2025-08-21T12:49:06.887145", "lvl": "target", "msg": "[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1032192"}
- {"dt": "2025-08-21T12:49:06.887583", "lvl": "target", "msg": "[    0.000000] Policy zone: Normal"}
- {"dt": "2025-08-21T12:49:06.888172", "lvl": "target", "msg": "[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off"}
- {"dt": "2025-08-21T12:49:07.051711", "lvl": "target", "msg": "[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=8, Nodes=1"}
- {"dt": "2025-08-21T12:49:07.065024", "lvl": "target", "msg": "[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2025-08-21T12:49:07.065153", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2025-08-21T12:49:07.065532", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=8."}
- {"dt": "2025-08-21T12:49:07.065642", "lvl": "target", "msg": "[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2025-08-21T12:49:07.065726", "lvl": "target", "msg": "[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2025-08-21T12:49:07.066089", "lvl": "target", "msg": "[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2025-08-21T12:49:07.066149", "lvl": "target", "msg": "[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=8"}
- {"dt": "2025-08-21T12:49:07.068346", "lvl": "target", "msg": "[    0.000000] RCU Tasks: Setting shift to 3 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=8."}
- {"dt": "2025-08-21T12:49:07.068658", "lvl": "target", "msg": "[    0.000000] RCU Tasks Trace: Setting shift to 3 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=8."}
- {"dt": "2025-08-21T12:49:07.068961", "lvl": "target", "msg": "[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2025-08-21T12:49:07.081793", "lvl": "target", "msg": "[    0.000000] GICv3: GIC: Using split EOI/Deactivate mode"}
- {"dt": "2025-08-21T12:49:07.081881", "lvl": "target", "msg": "[    0.000000] GICv3: 224 SPIs implemented"}
- {"dt": "2025-08-21T12:49:07.081944", "lvl": "target", "msg": "[    0.000000] GICv3: 0 Extended SPIs implemented"}
- {"dt": "2025-08-21T12:49:07.084046", "lvl": "target", "msg": "[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2025-08-21T12:49:07.084629", "lvl": "target", "msg": "[    0.000000] GICv3: GICv3 features: 16 PPIs"}
- {"dt": "2025-08-21T12:49:07.084693", "lvl": "target", "msg": "[    0.000000] GICv3: GICD_CTLR.DS=0, SCR_EL3.FIQ=0"}
- {"dt": "2025-08-21T12:49:07.085851", "lvl": "target", "msg": "[    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x000000002f100000"}
- {"dt": "2025-08-21T12:49:07.094050", "lvl": "target", "msg": "[    0.000000] ITS [mem 0x2f020000-0x2f03ffff]"}
- {"dt": "2025-08-21T12:49:07.095879", "lvl": "target", "msg": "[    0.000000] ITS@0x000000002f020000: allocated 8192 Devices @880080000 (indirect, esz 8, psz 64K, shr 1)"}
- {"dt": "2025-08-21T12:49:07.096464", "lvl": "target", "msg": "[    0.000000] ITS@0x000000002f020000: allocated 8192 Virtual CPUs @880090000 (indirect, esz 8, psz 64K, shr 1)"}
- {"dt": "2025-08-21T12:49:07.096557", "lvl": "target", "msg": "[    0.000000] ITS@0x000000002f020000: allocated 8192 Interrupt Collections @8800a0000 (flat, esz 8, psz 64K, shr 1)"}
- {"dt": "2025-08-21T12:49:07.098646", "lvl": "target", "msg": "[    0.000000] GICv3: using LPI property table @0x00000008800b0000"}
- {"dt": "2025-08-21T12:49:07.103216", "lvl": "target", "msg": "[    0.000000] GICv3: CPU0: using allocated LPI pending table @0x00000008800d0000"}
- {"dt": "2025-08-21T12:49:07.106856", "lvl": "target", "msg": "[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention."}
- {"dt": "2025-08-21T12:49:07.121927", "lvl": "target", "msg": "[    0.000000] timer_sp804: timer clock not found: -517"}
- {"dt": "2025-08-21T12:49:07.122460", "lvl": "target", "msg": "[    0.000000] timer_sp804: arm,sp804 clock not found: -2"}
- {"dt": "2025-08-21T12:49:07.123048", "lvl": "target", "msg": "[    0.000000] Failed to initialize '/bus@8000000/motherboard-bus@8000000/iofpga-bus@300000000/timer@110000': -22"}
- {"dt": "2025-08-21T12:49:07.123592", "lvl": "target", "msg": "[    0.000000] timer_sp804: timer clock not found: -517"}
- {"dt": "2025-08-21T12:49:07.124158", "lvl": "target", "msg": "[    0.000000] timer_sp804: arm,sp804 clock not found: -2"}
- {"dt": "2025-08-21T12:49:07.124722", "lvl": "target", "msg": "[    0.000000] Failed to initialize '/bus@8000000/motherboard-bus@8000000/iofpga-bus@300000000/timer@120000': -22"}
- {"dt": "2025-08-21T12:49:07.131482", "lvl": "target", "msg": "[    0.000000] arch_timer: cp15 timer(s) running at 100.00MHz (phys)."}
- {"dt": "2025-08-21T12:49:07.132045", "lvl": "target", "msg": "[    0.000000] clocksource: arch_sys_counter: mask: 0x1ffffffffffffff max_cycles: 0x171024e7e0, max_idle_ns: 440795205315 ns"}
- {"dt": "2025-08-21T12:49:07.132650", "lvl": "target", "msg": "[    0.000003] sched_clock: 57 bits at 100MHz, resolution 10ns, wraps every 4398046511100ns"}
- {"dt": "2025-08-21T12:49:07.144858", "lvl": "target", "msg": "[    0.001778] Console: colour dummy device 80x25"}
- {"dt": "2025-08-21T12:49:07.148139", "lvl": "target", "msg": "[    0.002318] Calibrating delay loop (skipped), value calculated using timer frequency.. 200.00 BogoMIPS (lpj=400000)"}
- {"dt": "2025-08-21T12:49:07.148708", "lvl": "target", "msg": "[    0.002457] pid_max: default: 32768 minimum: 301"}
- {"dt": "2025-08-21T12:49:07.149804", "lvl": "target", "msg": "[    0.002795] Allocated 8 global dynstack pages"}
- {"dt": "2025-08-21T12:49:07.151475", "lvl": "target", "msg": "[    0.003176] LSM: initializing lsm=capability"}
- {"dt": "2025-08-21T12:49:07.158199", "lvl": "target", "msg": "[    0.003822] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2025-08-21T12:49:07.158756", "lvl": "target", "msg": "[    0.003946] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2025-08-21T12:49:07.196669", "lvl": "target", "msg": "[    0.008880] cacheinfo: Unable to detect cache hierarchy for CPU 0"}
- {"dt": "2025-08-21T12:49:07.218909", "lvl": "target", "msg": "[    0.013141] rcu: Hierarchical SRCU implementation."}
- {"dt": "2025-08-21T12:49:07.219274", "lvl": "target", "msg": "[    0.013208] rcu: \tMax phase no-delay instances is 1000."}
- {"dt": "2025-08-21T12:49:07.222795", "lvl": "target", "msg": "[    0.014185] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level"}
- {"dt": "2025-08-21T12:49:07.226698", "lvl": "target", "msg": "[    0.015114] fsl-mc MSI: msi-controller@2f020000 domain created"}
- {"dt": "2025-08-21T12:49:07.235597", "lvl": "target", "msg": "[    0.022412] Remapping and enabling EFI services."}
- {"dt": "2025-08-21T12:49:07.243957", "lvl": "target", "msg": "[    0.024963] smp: Bringing up secondary CPUs ..."}
- {"dt": "2025-08-21T12:49:07.736676", "lvl": "target", "msg": "[    0.027390] Detected PIPT I-cache on CPU1"}
- {"dt": "2025-08-21T12:49:07.737675", "lvl": "target", "msg": "[    0.027626] GICv3: CPU1: found redistributor 100 region 0:0x000000002f120000"}
- {"dt": "2025-08-21T12:49:07.738456", "lvl": "target", "msg": "[    0.027685] GICv3: CPU1: using allocated LPI pending table @0x00000008800e0000"}
- {"dt": "2025-08-21T12:49:07.739049", "lvl": "target", "msg": "[    0.027798] CPU1: Booted secondary processor 0x0000000100 [0x410fd0f0]"}
- {"dt": "2025-08-21T12:49:07.739123", "lvl": "target", "msg": "[    0.030564] Detected PIPT I-cache on CPU2"}
- {"dt": "2025-08-21T12:49:07.739187", "lvl": "target", "msg": "[    0.030813] GICv3: CPU2: found redistributor 200 region 0:0x000000002f140000"}
- {"dt": "2025-08-21T12:49:07.739247", "lvl": "target", "msg": "[    0.030872] GICv3: CPU2: using allocated LPI pending table @0x00000008800f0000"}
- {"dt": "2025-08-21T12:49:07.739305", "lvl": "target", "msg": "[    0.030984] CPU2: Booted secondary processor 0x0000000200 [0x410fd0f0]"}
- {"dt": "2025-08-21T12:49:07.739365", "lvl": "target", "msg": "[    0.033629] Detected PIPT I-cache on CPU3"}
- {"dt": "2025-08-21T12:49:07.739436", "lvl": "target", "msg": "[    0.033892] GICv3: CPU3: found redistributor 300 region 0:0x000000002f160000"}
- {"dt": "2025-08-21T12:49:07.739495", "lvl": "target", "msg": "[    0.033948] GICv3: CPU3: using allocated LPI pending table @0x0000000880100000"}
- {"dt": "2025-08-21T12:49:07.740237", "lvl": "target", "msg": "[    0.034064] CPU3: Booted secondary processor 0x0000000300 [0x410fd0f0]"}
- {"dt": "2025-08-21T12:49:07.740309", "lvl": "target", "msg": "[    0.036717] Detected PIPT I-cache on CPU4"}
- {"dt": "2025-08-21T12:49:07.740376", "lvl": "target", "msg": "[    0.036993] GICv3: CPU4: found redistributor 10000 region 0:0x000000002f180000"}
- {"dt": "2025-08-21T12:49:07.740436", "lvl": "target", "msg": "[    0.037054] GICv3: CPU4: using allocated LPI pending table @0x0000000880110000"}
- {"dt": "2025-08-21T12:49:07.740498", "lvl": "target", "msg": "[    0.037165] CPU4: Booted secondary processor 0x0000010000 [0x410fd0f0]"}
- {"dt": "2025-08-21T12:49:07.740559", "lvl": "target", "msg": "[    0.039806] Detected PIPT I-cache on CPU5"}
- {"dt": "2025-08-21T12:49:07.740620", "lvl": "target", "msg": "[    0.040095] GICv3: CPU5: found redistributor 10100 region 0:0x000000002f1a0000"}
- {"dt": "2025-08-21T12:49:07.740692", "lvl": "target", "msg": "[    0.040156] GICv3: CPU5: using allocated LPI pending table @0x0000000880120000"}
- {"dt": "2025-08-21T12:49:07.741168", "lvl": "target", "msg": "[    0.040268] CPU5: Booted secondary processor 0x0000010100 [0x410fd0f0]"}
- {"dt": "2025-08-21T12:49:07.741256", "lvl": "target", "msg": "[    0.042898] Detected PIPT I-cache on CPU6"}
- {"dt": "2025-08-21T12:49:07.741524", "lvl": "target", "msg": "[    0.043201] GICv3: CPU6: found redistributor 10200 region 0:0x000000002f1c0000"}
- {"dt": "2025-08-21T12:49:07.741580", "lvl": "target", "msg": "[    0.043262] GICv3: CPU6: using allocated LPI pending table @0x0000000880130000"}
- {"dt": "2025-08-21T12:49:07.741627", "lvl": "target", "msg": "[    0.043375] CPU6: Booted secondary processor 0x0000010200 [0x410fd0f0]"}
- {"dt": "2025-08-21T12:49:07.741672", "lvl": "target", "msg": "[    0.046128] Detected PIPT I-cache on CPU7"}
- {"dt": "2025-08-21T12:49:07.741718", "lvl": "target", "msg": "[    0.046443] GICv3: CPU7: found redistributor 10300 region 0:0x000000002f1e0000"}
- {"dt": "2025-08-21T12:49:07.741792", "lvl": "target", "msg": "[    0.046505] GICv3: CPU7: using allocated LPI pending table @0x0000000880140000"}
- {"dt": "2025-08-21T12:49:07.741875", "lvl": "target", "msg": "[    0.046618] CPU7: Booted secondary processor 0x0000010300 [0x410fd0f0]"}
- {"dt": "2025-08-21T12:49:07.741941", "lvl": "target", "msg": "[    0.047400] smp: Brought up 1 node, 8 CPUs"}
- {"dt": "2025-08-21T12:49:07.741994", "lvl": "target", "msg": "[    0.048704] SMP: Total of 8 processors activated."}
- {"dt": "2025-08-21T12:49:07.742321", "lvl": "target", "msg": "[    0.048811] CPU: All CPU(s) started at EL2"}
- {"dt": "2025-08-21T12:49:07.743079", "lvl": "target", "msg": "[    0.048877] CPU features: detected: Branch Target Identification"}
- {"dt": "2025-08-21T12:49:07.743130", "lvl": "target", "msg": "[    0.048958] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2025-08-21T12:49:07.743176", "lvl": "target", "msg": "[    0.049030] CPU features: detected: ARMv8.4 Translation Table Level"}
- {"dt": "2025-08-21T12:49:07.743443", "lvl": "target", "msg": "[    0.049113] CPU features: detected: Data cache clean to the PoU not required for I/D coherence"}
- {"dt": "2025-08-21T12:49:07.744020", "lvl": "target", "msg": "[    0.049211] CPU features: detected: Common not Private translations"}
- {"dt": "2025-08-21T12:49:07.744277", "lvl": "target", "msg": "[    0.049295] CPU features: detected: CRC32 instructions"}
- {"dt": "2025-08-21T12:49:07.744327", "lvl": "target", "msg": "[    0.049371] CPU features: detected: Data independent timing control (DIT)"}
- {"dt": "2025-08-21T12:49:07.744373", "lvl": "target", "msg": "[    0.049457] CPU features: detected: E0PD"}
- {"dt": "2025-08-21T12:49:07.744626", "lvl": "target", "msg": "[    0.049526] CPU features: detected: Enhanced Counter Virtualization"}
- {"dt": "2025-08-21T12:49:07.744677", "lvl": "target", "msg": "[    0.049610] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)"}
- {"dt": "2025-08-21T12:49:07.744730", "lvl": "target", "msg": "[    0.049699] CPU features: detected: Enhanced Privileged Access Never"}
- {"dt": "2025-08-21T12:49:07.745178", "lvl": "target", "msg": "[    0.049783] CPU features: detected: Enhanced Virtualization Traps"}
- {"dt": "2025-08-21T12:49:07.745452", "lvl": "target", "msg": "[    0.049865] CPU features: detected: Fine Grained Traps"}
- {"dt": "2025-08-21T12:49:07.745514", "lvl": "target", "msg": "[    0.049944] CPU features: detected: Fine Grained Traps 2"}
- {"dt": "2025-08-21T12:49:07.745773", "lvl": "target", "msg": "[    0.050024] CPU features: detected: Guarded Control Stack (GCS)"}
- {"dt": "2025-08-21T12:49:07.745868", "lvl": "target", "msg": "[    0.050114] CPU features: detected: Generic authentication (IMP DEF algorithm)"}
- {"dt": "2025-08-21T12:49:07.746262", "lvl": "target", "msg": "[    0.050204] CPU features: detected: RCpc load-acquire (LDAPR)"}
- {"dt": "2025-08-21T12:49:07.746532", "lvl": "target", "msg": "[    0.050286] CPU features: detected: LSE atomic instructions"}
- {"dt": "2025-08-21T12:49:07.746837", "lvl": "target", "msg": "[    0.050365] CPU features: detected: Memory Copy and Memory Set instructions"}
- {"dt": "2025-08-21T12:49:07.746895", "lvl": "target", "msg": "[    0.050454] CPU features: detected: Privileged Access Never"}
- {"dt": "2025-08-21T12:49:07.748529", "lvl": "target", "msg": "[    0.050527] CPU features: detected: PMUv3"}
- {"dt": "2025-08-21T12:49:07.749671", "lvl": "target", "msg": "[    0.050602] CPU features: detected: SCTLR2"}
- {"dt": "2025-08-21T12:49:07.750437", "lvl": "target", "msg": "[    0.050672] CPU features: detected: RAS Extension Support"}
- {"dt": "2025-08-21T12:49:07.750497", "lvl": "target", "msg": "[    0.050750] CPU features: detected: Random Number Generator"}
- {"dt": "2025-08-21T12:49:07.750547", "lvl": "target", "msg": "[    0.050829] CPU features: detected: Speculation barrier (SB)"}
- {"dt": "2025-08-21T12:49:07.750611", "lvl": "target", "msg": "[    0.050908] CPU features: detected: Stage-2 Force Write-Back"}
- {"dt": "2025-08-21T12:49:07.750915", "lvl": "target", "msg": "[    0.050990] CPU features: detected: Trap EL0 IMPLEMENTATION DEFINED functionality"}
- {"dt": "2025-08-21T12:49:07.750983", "lvl": "target", "msg": "[    0.051082] CPU features: detected: TLB range maintenance instructions"}
- {"dt": "2025-08-21T12:49:07.751392", "lvl": "target", "msg": "[    0.051164] CPU features: detected: WFx with timeout"}
- {"dt": "2025-08-21T12:49:07.751672", "lvl": "target", "msg": "[    0.051252] CPU features: detected: Scalable Matrix Extension"}
- {"dt": "2025-08-21T12:49:07.751944", "lvl": "target", "msg": "[    0.051326] CPU features: detected: SME2"}
- {"dt": "2025-08-21T12:49:07.752004", "lvl": "target", "msg": "[    0.051405] CPU features: detected: Scalable Vector Extension"}
- {"dt": "2025-08-21T12:49:07.856540", "lvl": "target", "msg": "[    0.051845] alternatives: applying system-wide alternatives"}
- {"dt": "2025-08-21T12:49:08.074871", "lvl": "target", "msg": "[    0.067497] CPU features: detected: Activity Monitors Unit (AMU) on CPU0-7"}
- {"dt": "2025-08-21T12:49:08.075328", "lvl": "target", "msg": "[    0.067596] CPU features: detected: Hardware dirty bit management on CPU0-7"}
- {"dt": "2025-08-21T12:49:08.076075", "lvl": "target", "msg": "[    0.067698] SVE: maximum available vector length 64 bytes per vector"}
- {"dt": "2025-08-21T12:49:08.076134", "lvl": "target", "msg": "[    0.067777] SVE: default vector length 64 bytes per vector"}
- {"dt": "2025-08-21T12:49:08.076628", "lvl": "target", "msg": "[    0.067863] SME: minimum available vector length 16 bytes per vector"}
- {"dt": "2025-08-21T12:49:08.076681", "lvl": "target", "msg": "[    0.067940] SME: maximum available vector length 64 bytes per vector"}
- {"dt": "2025-08-21T12:49:08.076723", "lvl": "target", "msg": "[    0.068018] SME: default vector length 32 bytes per vector"}
- {"dt": "2025-08-21T12:49:08.094927", "lvl": "target", "msg": "[    0.070867] Memory: 3896888K/4128768K available (17792K kernel code, 5390K rwdata, 12672K rodata, 3264K init, 684K bss, 192248K reserved, 32768K cma-reserved)"}
- {"dt": "2025-08-21T12:49:08.159344", "lvl": "target", "msg": "[    0.073542] devtmpfs: initialized"}
- {"dt": "2025-08-21T12:49:08.325742", "lvl": "target", "msg": "[    0.110400] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2025-08-21T12:49:08.326767", "lvl": "target", "msg": "[    0.110544] posixtimers hash table entries: 4096 (order: 4, 65536 bytes, linear)"}
- {"dt": "2025-08-21T12:49:08.328431", "lvl": "target", "msg": "[    0.111066] futex hash table entries: 2048 (131072 bytes on 1 NUMA nodes, total 128 KiB, linear)."}
- {"dt": "2025-08-21T12:49:08.337396", "lvl": "target", "msg": "[    0.112922] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL"}
- {"dt": "2025-08-21T12:49:08.337909", "lvl": "target", "msg": "[    0.112994] 0 pages in range for non-PLT usage"}
- {"dt": "2025-08-21T12:49:08.342944", "lvl": "target", "msg": "[    0.113024] 514272 pages in range for PLT usage"}
- {"dt": "2025-08-21T12:49:08.343034", "lvl": "target", "msg": "[    0.113704] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2025-08-21T12:49:08.376477", "lvl": "target", "msg": "[    0.125506] DMI not present or invalid."}
- {"dt": "2025-08-21T12:49:08.470608", "lvl": "target", "msg": "[    0.151491] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2025-08-21T12:49:08.505201", "lvl": "target", "msg": "[    0.157524] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations"}
- {"dt": "2025-08-21T12:49:08.508989", "lvl": "target", "msg": "[    0.158399] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations"}
- {"dt": "2025-08-21T12:49:08.515100", "lvl": "target", "msg": "[    0.160023] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations"}
- {"dt": "2025-08-21T12:49:08.515656", "lvl": "target", "msg": "[    0.160225] audit: initializing netlink subsys (disabled)"}
- {"dt": "2025-08-21T12:49:08.528545", "lvl": "target", "msg": "[    0.160695] audit: type=2000 audit(0.140:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2025-08-21T12:49:08.548054", "lvl": "target", "msg": "[    0.167773] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2025-08-21T12:49:08.551962", "lvl": "target", "msg": "[    0.167806] thermal_sys: Registered thermal governor 'power_allocator'"}
- {"dt": "2025-08-21T12:49:08.552089", "lvl": "target", "msg": "[    0.168154] cpuidle: using governor menu"}
- {"dt": "2025-08-21T12:49:08.557019", "lvl": "target", "msg": "[    0.169854] hw-breakpoint: found 16 breakpoint and 16 watchpoint registers."}
- {"dt": "2025-08-21T12:49:08.570871", "lvl": "target", "msg": "[    0.170611] ASID allocator initialised with 65536 entries"}
- {"dt": "2025-08-21T12:49:08.609347", "lvl": "target", "msg": "[    0.187592] Serial: AMBA PL011 UART driver"}
- {"dt": "2025-08-21T13:04:02.503224", "lvl": "warning", "msg": "ShellCommand command timed out.: Sending # in case of corruption. Connection timeout 00:29:52, retry in 00:14:56"}
- {"dt": "2025-08-21T13:04:02.503395", "lvl": "debug", "msg": "pattern: ['-\\\\[ cut here \\\\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing', 'U-Boot SPL 20[0-9][0-9]', 'root@(.*):[/~]#', 'login:', 'Login incorrect']"}
- {"dt": "2025-08-21T13:04:02.503505", "lvl": "debug", "msg": "Sending line: '#'"}
- {"dt": "2025-08-21T13:04:02.603761", "lvl": "input", "msg": "#"}
- {"dt": "2025-08-21T13:07:01.937959", "lvl": "warning", "msg": "ShellCommand command timed out.: Sending # in case of corruption. Connection timeout 00:29:52, retry in 00:02:59"}
- {"dt": "2025-08-21T13:07:01.938132", "lvl": "debug", "msg": "pattern: ['-\\\\[ cut here \\\\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing', 'U-Boot SPL 20[0-9][0-9]', 'root@(.*):[/~]#', 'login:', 'Login incorrect']"}
- {"dt": "2025-08-21T13:07:01.938221", "lvl": "debug", "msg": "Sending line: '#'"}
- {"dt": "2025-08-21T13:07:02.038471", "lvl": "input", "msg": "#"}
- {"dt": "2025-08-21T13:10:01.375358", "lvl": "warning", "msg": "ShellCommand command timed out.: Sending # in case of corruption. Connection timeout 00:29:52, retry in 00:02:59"}
- {"dt": "2025-08-21T13:10:01.375543", "lvl": "debug", "msg": "pattern: ['-\\\\[ cut here \\\\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing', 'U-Boot SPL 20[0-9][0-9]', 'root@(.*):[/~]#', 'login:', 'Login incorrect']"}
- {"dt": "2025-08-21T13:10:01.375646", "lvl": "debug", "msg": "Sending line: '#'"}
- {"dt": "2025-08-21T13:10:01.475890", "lvl": "input", "msg": "#"}
- {"dt": "2025-08-21T13:13:00.810400", "lvl": "warning", "msg": "ShellCommand command timed out.: Sending # in case of corruption. Connection timeout 00:29:52, retry in 00:02:59"}
- {"dt": "2025-08-21T13:13:00.810584", "lvl": "debug", "msg": "pattern: ['-\\\\[ cut here \\\\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing', 'U-Boot SPL 20[0-9][0-9]', 'root@(.*):[/~]#', 'login:', 'Login incorrect']"}
- {"dt": "2025-08-21T13:13:00.810682", "lvl": "debug", "msg": "Sending line: '#'"}
- {"dt": "2025-08-21T13:13:00.910905", "lvl": "input", "msg": "#"}
- {"dt": "2025-08-21T13:16:00.242813", "lvl": "warning", "msg": "ShellCommand command timed out.: Sending # in case of corruption. Connection timeout 00:29:52, retry in 00:02:59"}
- {"dt": "2025-08-21T13:16:00.242997", "lvl": "debug", "msg": "pattern: ['-\\\\[ cut here \\\\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing', 'U-Boot SPL 20[0-9][0-9]', 'root@(.*):[/~]#', 'login:', 'Login incorrect']"}
- {"dt": "2025-08-21T13:16:00.243109", "lvl": "debug", "msg": "Sending line: '#'"}
- {"dt": "2025-08-21T13:16:00.343348", "lvl": "input", "msg": "#"}
- {"dt": "2025-08-21T13:18:58.221604", "lvl": "exception", "msg": "login-action timed out after 1792 seconds"}
- {"dt": "2025-08-21T13:18:58.221847", "lvl": "debug", "msg": "end: 2.3.1 login-action (duration 00:29:52) [common]"}
- {"dt": "2025-08-21T13:18:58.221995", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "login-action", "level": "2.3.1", "duration": "1792.00", "result": "fail", "extra": {"fail": "login-action timed out after 1792 seconds"}}}
- {"dt": "2025-08-21T13:18:58.222146", "lvl": "error", "msg": "auto-login-action failed: 1 of 1 attempts. 'login-action timed out after 1792 seconds'"}
- {"dt": "2025-08-21T13:18:58.222247", "lvl": "exception", "msg": "login-action timed out after 1792 seconds"}
- {"dt": "2025-08-21T13:18:58.222329", "lvl": "debug", "msg": "end: 2.3 auto-login-action (duration 00:29:56) [common]"}
- {"dt": "2025-08-21T13:18:58.222393", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "auto-login-action", "level": "2.3", "duration": "1795.66", "result": "fail", "extra": {"fail": "login-action timed out after 1792 seconds"}}}
- {"dt": "2025-08-21T13:18:58.222476", "lvl": "error", "msg": "boot-fvp failed: 1 of 1 attempts. 'login-action timed out after 1792 seconds'"}
- {"dt": "2025-08-21T13:18:58.222536", "lvl": "debug", "msg": "Stopping container tuxrun-nt9e39f9-lava-1 from action check-fvp-version"}
- {"dt": "2025-08-21T13:18:58.222589", "lvl": "debug", "msg": "Calling: ['docker', 'stop', 'tuxrun-nt9e39f9-lava-1']"}
- {"dt": "2025-08-21T13:19:08.570829", "lvl": "debug", "msg": ">> tuxrun-nt9e39f9-lava-1"}
- {"dt": "2025-08-21T13:19:08.572227", "lvl": "debug", "msg": "Returned 0 in 10 seconds"}
- {"dt": "2025-08-21T13:19:08.572317", "lvl": "debug", "msg": "Stopped container tuxrun-nt9e39f9-lava-1"}
- {"dt": "2025-08-21T13:19:08.572381", "lvl": "debug", "msg": "Listening to feedback from FVP binary for 60s."}
- {"dt": "2025-08-21T13:19:08.572495", "lvl": "feedback", "msg": ""}
- {"dt": "2025-08-21T13:19:08.572555", "lvl": "feedback", "msg": "Info: FVP_Base_RevC_2xAEMvA: FVP_Base_RevC_2xAEMvA.bp.flashloader1: FlashLoader: Loaded 2560 kB from file '/tuxrun-nt9e39f9-lava-1/FVP_AARCH64_EFI.fd'"}
- {"dt": "2025-08-21T13:19:08.572607", "lvl": "feedback", "msg": ""}
- {"dt": "2025-08-21T13:19:08.572656", "lvl": "feedback", "msg": "Info: FVP_Base_RevC_2xAEMvA: FVP_Base_RevC_2xAEMvA.bp.flashloader0: FlashLoader: Loaded 2675 kB from file '/tuxrun-nt9e39f9-lava-1/fip.bin'"}
- {"dt": "2025-08-21T13:19:08.572704", "lvl": "feedback", "msg": ""}
- {"dt": "2025-08-21T13:19:08.572750", "lvl": "feedback", "msg": "Info: FVP_Base_RevC_2xAEMvA: FVP_Base_RevC_2xAEMvA.bp.secureflashloader: FlashLoader: Loaded 31 kB from file '/tuxrun-nt9e39f9-lava-1/bl1.bin'"}
- {"dt": "2025-08-21T13:19:08.575515", "lvl": "debug", "msg": "Stopping container tuxrun-nt9e39f9-lava-1 from action run-fvp"}
- {"dt": "2025-08-21T13:19:08.575603", "lvl": "debug", "msg": "Calling: ['docker', 'stop', 'tuxrun-nt9e39f9-lava-1']"}
- {"dt": "2025-08-21T13:19:08.601019", "lvl": "debug", "msg": ">> Error: no container with name or ID \"tuxrun-nt9e39f9-lava-1\" found: no such container"}
- {"dt": "2025-08-21T13:19:08.602628", "lvl": "debug", "msg": "Returned 125 in 0 seconds"}
- {"dt": "2025-08-21T13:19:08.602709", "lvl": "debug", "msg": "Listening to feedback from FVP binary."}
- {"dt": "2025-08-21T13:19:08.602852", "lvl": "exception", "msg": "login-action timed out after 1792 seconds"}
- {"dt": "2025-08-21T13:19:08.602923", "lvl": "info", "msg": "end: 2 boot-fvp (duration 00:30:10) [common]"}
- {"dt": "2025-08-21T13:19:08.602990", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "boot-fvp", "level": "2", "duration": "1810.02", "result": "fail", "extra": {"fail": "login-action timed out after 1792 seconds"}}}
- {"dt": "2025-08-21T13:19:08.603117", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2025-08-21T13:19:08.603211", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/startup.nsh"}
- {"dt": "2025-08-21T13:19:08.603293", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/FVP_AARCH64_EFI.fd"}
- {"dt": "2025-08-21T13:19:08.603644", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/bl1.bin"}
- {"dt": "2025-08-21T13:19:08.603723", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/fvp-base-revc.dtb"}
- {"dt": "2025-08-21T13:19:08.603790", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/Image"}
- {"dt": "2025-08-21T13:19:08.608515", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/https___storage.tuxboot.com_debian_20250617_trixie_arm64_rootfs.ext4"}
- {"dt": "2025-08-21T13:19:08.701063", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/rootfs.modules/modules.tar"}
- {"dt": "2025-08-21T13:19:08.709639", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/rootfs.overlay-00/yesloop.sh"}
- {"dt": "2025-08-21T13:19:08.709759", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1/fvp-deploy-e65s5itt/fip.bin"}
- {"dt": "2025-08-21T13:19:08.710389", "lvl": "debug", "msg": "Stopping container tuxrun-nt9e39f9-lava-1 from action check-fvp-version"}
- {"dt": "2025-08-21T13:19:08.710452", "lvl": "debug", "msg": "Calling: ['docker', 'stop', 'tuxrun-nt9e39f9-lava-1']"}
- {"dt": "2025-08-21T13:19:08.736411", "lvl": "debug", "msg": ">> Error: no container with name or ID \"tuxrun-nt9e39f9-lava-1\" found: no such container"}
- {"dt": "2025-08-21T13:19:08.738042", "lvl": "debug", "msg": "Returned 125 in 0 seconds"}
- {"dt": "2025-08-21T13:19:08.738140", "lvl": "debug", "msg": "Listening to feedback from FVP binary for 60s."}
- {"dt": "2025-08-21T13:19:08.738250", "lvl": "debug", "msg": "Stopping container tuxrun-nt9e39f9-lava-1 from action run-fvp"}
- {"dt": "2025-08-21T13:19:08.738309", "lvl": "debug", "msg": "Calling: ['docker', 'stop', 'tuxrun-nt9e39f9-lava-1']"}
- {"dt": "2025-08-21T13:19:08.764513", "lvl": "debug", "msg": ">> Error: no container with name or ID \"tuxrun-nt9e39f9-lava-1\" found: no such container"}
- {"dt": "2025-08-21T13:19:08.765974", "lvl": "debug", "msg": "Returned 125 in 0 seconds"}
- {"dt": "2025-08-21T13:19:08.766052", "lvl": "debug", "msg": "Listening to feedback from FVP binary."}
- {"dt": "2025-08-21T13:19:08.766219", "lvl": "debug", "msg": "start: 4.1 power-off (timeout 00:01:00) [common]"}
- {"dt": "2025-08-21T13:19:08.766297", "lvl": "debug", "msg": "end: 4.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T13:19:08.766365", "lvl": "debug", "msg": "start: 4.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2025-08-21T13:19:08.766462", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.766599", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2025-08-21T13:19:08.766677", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2025-08-21T13:19:08.866946", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/ArmPlatformPkg/PeilessSec/PeilessSec/DEBUG/PeilessSec.dll 0x88000400", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867091", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Core/Dxe/DxeMain/DEBUG/DxeCore.dll 0xFB5D0000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867155", "lvl": "feedback", "msg": "Loading DxeCore at 0x00FB5CF000 EntryPoint=0x00FB5D8B6C", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867211", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Core/Dxe/DxeMain/DEBUG/DxeCore.dll 0xFB5D0000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867262", "lvl": "feedback", "msg": "HOBLIST address in DXE = 0xF7DBD018", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867317", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFFB000 - 0xFBFFBFFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867366", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0x88000000 - 0x8BFFFFFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867415", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFFA000 - 0xFBFFAFFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867460", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFF9000 - 0xFBFF9FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867504", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFF8000 - 0xFBFF8FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867547", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFF7000 - 0xFBFF7FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867591", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFF6000 - 0xFBFF6FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867635", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFF5000 - 0xFBFF5FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867678", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFF4000 - 0xFBFF4FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867721", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFF3000 - 0xFBFF3FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867764", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFF2000 - 0xFBFF2FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867807", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFFC000 - 0xFBFFFFFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867850", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBFE2000 - 0xFBFF1FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867893", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFBAFC000 - 0xFBFE1FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867936", "lvl": "feedback", "msg": "Memory Allocation 0x00000004 0xFB616000 - 0xFBAFBFFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.867979", "lvl": "feedback", "msg": "Memory Allocation 0x00000003 0xFB5CF000 - 0xFB615FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868022", "lvl": "feedback", "msg": "Memory Allocation 0x00000003 0xFB5CF000 - 0xFB615FFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868065", "lvl": "feedback", "msg": "FV Hob            0x88000000 - 0x8827FFFF", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868110", "lvl": "feedback", "msg": "FV Hob            0xFB616000 - 0xFBAFA37F", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868153", "lvl": "feedback", "msg": "FV2 Hob           0xFB616000 - 0xFBAFA37F", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868196", "lvl": "feedback", "msg": "                  87940482-FC81-41C3-87E6-399CF85AC8A0 - 9E21FD93-9C72-4C15-8C4B-E77F1DB2D792", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868240", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/PCD/Dxe/Pcd/DEBUG/PcdDxe.dll 0xF7F48000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868302", "lvl": "feedback", "msg": "Loading driver at 0x000F7F47000 EntryPoint=0x000F7F4BE64 PcdDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868522", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.868607", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Core/RuntimeDxe/RuntimeDxe/DEBUG/RuntimeDxe.dll 0xF2F40000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868661", "lvl": "feedback", "msg": "Loading driver at 0x000F2F30000 EntryPoint=0x000F2F41B6C RuntimeDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868709", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/SecurityStubDxe/SecurityStubDxe/DEBUG/SecurityStubDxe.dll 0xF7F3E000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868761", "lvl": "feedback", "msg": "Loading driver at 0x000F7F3D000 EntryPoint=0x000F7F41C90 SecurityStubDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868809", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/ResetSystemRuntimeDxe/ResetSystemRuntimeDxe/DEBUG/ResetSystemRuntimeDxe.dll 0xF2EA0000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868858", "lvl": "feedback", "msg": "Loading driver at 0x000F2E90000 EntryPoint=0x000F2EA1E38 ResetSystemRuntimeDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868905", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/EmbeddedPkg/MetronomeDxe/MetronomeDxe/DEBUG/MetronomeDxe.dll 0xF7F39000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868950", "lvl": "feedback", "msg": "Loading driver at 0x000F7F38000 EntryPoint=0x000F7F3A0F0 MetronomeDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.868994", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/HiiDatabaseDxe/HiiDatabaseDxe/DEBUG/HiiDatabase.dll 0xF7F1A000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869038", "lvl": "feedback", "msg": "Loading driver at 0x000F7F19000 EntryPoint=0x000F7F1D7CC HiiDatabase.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869082", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/Acpi/AcpiTableDxe/AcpiTableDxe/DEBUG/AcpiTableDxe.dll 0xF7F13000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869127", "lvl": "feedback", "msg": "Loading driver at 0x000F7F12000 EntryPoint=0x000F7F157A4 AcpiTableDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869171", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/Platform/ARM/VExpressPkg/ConfigurationManager/ConfigurationManagerDxe/ConfigurationManagerDxe/DEBUG/ConfigurationManagerDxe.dll 0xF7F0D000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869216", "lvl": "feedback", "msg": "Loading driver at 0x000F7F0C000 EntryPoint=0x000F7F0E788 ConfigurationManagerDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869259", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/DynamicTablesPkg/Drivers/DynamicTableFactoryDxe/DynamicTableFactoryDxe/DEBUG/DynamicTableFactoryDxe.dll 0xF7ED9000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869303", "lvl": "feedback", "msg": "Loading driver at 0x000F7ED8000 EntryPoint=0x000F7ED99CC DynamicTableFactoryDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869511", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.869589", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/SerialDxe/SerialDxe/DEBUG/SerialDxe.dll 0xF7ED3000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869640", "lvl": "feedback", "msg": "Loading driver at 0x000F7ED2000 EntryPoint=0x000F7ED4760 SerialDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869686", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/ArmPkg/Drivers/ArmGic/ArmGicDxe/DEBUG/ArmGicDxe.dll 0xF7ECC000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869731", "lvl": "feedback", "msg": "Loading driver at 0x000F7ECB000 EntryPoint=0x000F7ECE244 ArmGicDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869774", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/EmbeddedPkg/Universal/MmcDxe/MmcDxe/DEBUG/MmcDxe.dll 0xF7EC1000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869835", "lvl": "feedback", "msg": "Loading driver at 0x000F7EC0000 EntryPoint=0x000F7EC5D44 MmcDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869891", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/SmbiosDxe/SmbiosDxe/DEBUG/SmbiosDxe.dll 0xF7EB9000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869936", "lvl": "feedback", "msg": "Loading driver at 0x000F7EB8000 EntryPoint=0x000F7EBC174 SmbiosDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.869980", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/DevicePathDxe/DevicePathDxe/DEBUG/DevicePathDxe.dll 0xF7EAA000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870024", "lvl": "feedback", "msg": "Loading driver at 0x000F7EA9000 EntryPoint=0x000F7EB2070 DevicePathDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870068", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/ArmPkg/Drivers/ArmPciCpuIo2Dxe/ArmPciCpuIo2Dxe/DEBUG/ArmPciCpuIo2Dxe.dll 0xF7EA5000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870111", "lvl": "feedback", "msg": "Loading driver at 0x000F7EA4000 EntryPoint=0x000F7EA6570 ArmPciCpuIo2Dxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870155", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/ArmPkg/Drivers/CpuDxe/CpuDxe/DEBUG/ArmCpuDxe.dll 0xF7E99000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870197", "lvl": "feedback", "msg": "Loading driver at 0x000F7E98000 EntryPoint=0x000F7E9C47C ArmCpuDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870239", "lvl": "feedback", "msg": "ReplaceTableEntry: splitting block entry with MMU disabled", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870282", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/FaultTolerantWriteDxe/FaultTolerantWriteDxe/DEBUG/FaultTolerantWriteDxe.dll 0xF7E91000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870327", "lvl": "feedback", "msg": "Loading driver at 0x000F7E90000 EntryPoint=0x000F7E950DC FaultTolerantWriteDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870534", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.870612", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/DynamicTablesPkg/Drivers/DynamicTableManagerDxe/DynamicTableManagerDxe/DEBUG/DynamicTableManagerDxe.dll 0xF7E8C000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870664", "lvl": "feedback", "msg": "Loading driver at 0x000F7E8B000 EntryPoint=0x000F7E8D524 DynamicTableManagerDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870711", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/ArmPkg/Drivers/TimerDxe/TimerDxe/DEBUG/ArmTimerDxe.dll 0xF7E87000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870755", "lvl": "feedback", "msg": "Loading driver at 0x000F7E86000 EntryPoint=0x000F7E882A8 ArmTimerDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870798", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/ArmPkg/Drivers/GenericWatchdogDxe/GenericWatchdogDxe/DEBUG/GenericWatchdogDxe.dll 0xF7E82000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870843", "lvl": "feedback", "msg": "Loading driver at 0x000F7E81000 EntryPoint=0x000F7E83360 GenericWatchdogDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870887", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/BootManagerPolicyDxe/BootManagerPolicyDxe/DEBUG/BootManagerPolicyDxe.dll 0xF7E7B000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870931", "lvl": "feedback", "msg": "Loading driver at 0x000F7E7A000 EntryPoint=0x000F7E7D738 BootManagerPolicyDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.870980", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/SetupBrowserDxe/SetupBrowserDxe/DEBUG/SetupBrowser.dll 0xF7E60000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871027", "lvl": "feedback", "msg": "Loading driver at 0x000F7E5F000 EntryPoint=0x000F7E60D10 SetupBrowser.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871072", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/BdsDxe/BdsDxe/DEBUG/BdsDxe.dll 0xF7E46000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871115", "lvl": "feedback", "msg": "Loading driver at 0x000F7E45000 EntryPoint=0x000F7E470A4 BdsDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871159", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/Platform/ARM/Drivers/NorFlashDxe/NorFlashDxe/DEBUG/NorFlashDxe.dll 0xF2E00000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871203", "lvl": "feedback", "msg": "Loading driver at 0x000F2DF0000 EntryPoint=0x000F2E033A4 NorFlashDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871246", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/Platform/ARM/VExpressPkg/Drivers/PL180MciDxe/PL180MciDxe/DEBUG/PL180MciDxe.dll 0xF7E3F000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871291", "lvl": "feedback", "msg": "Loading driver at 0x000F7E3E000 EntryPoint=0x000F7E40D98 PL180MciDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871498", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.871575", "lvl": "feedback", "msg": "Probing ID registers at 0x1C050FE0 for a PL180", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871626", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/DisplayEngineDxe/DisplayEngineDxe/DEBUG/DisplayEngine.dll 0xF7E28000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871675", "lvl": "feedback", "msg": "Loading driver at 0x000F7E27000 EntryPoint=0x000F7E28A9C DisplayEngine.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871720", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Bus/Pci/PciHostBridgeDxe/PciHostBridgeDxe/DEBUG/PciHostBridgeDxe.dll 0xF7E19000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871765", "lvl": "feedback", "msg": "Loading driver at 0x000F7E18000 EntryPoint=0x000F7E1FF5C PciHostBridgeDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871810", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/Variable/RuntimeDxe/VariableRuntimeDxe/DEBUG/VariableRuntimeDxe.dll 0xF2CC0000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871855", "lvl": "feedback", "msg": "Loading driver at 0x000F2CB0000 EntryPoint=0x000F2CC75E8 VariableRuntimeDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871901", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/CapsuleRuntimeDxe/CapsuleRuntimeDxe/DEBUG/CapsuleRuntimeDxe.dll 0xF7F60000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871947", "lvl": "feedback", "msg": "Loading driver at 0x000F7F50000 EntryPoint=0x000F7F61510 CapsuleRuntimeDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.871992", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/MonotonicCounterRuntimeDxe/MonotonicCounterRuntimeDxe/DEBUG/MonotonicCounterRuntimeDxe.dll 0xF2BF0000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872042", "lvl": "feedback", "msg": "Loading driver at 0x000F2BE0000 EntryPoint=0x000F2BF1328 MonotonicCounterRuntimeDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872088", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/EmbeddedPkg/RealTimeClockRuntimeDxe/RealTimeClockRuntimeDxe/DEBUG/RealTimeClock.dll 0xF2BB0000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872133", "lvl": "feedback", "msg": "Loading driver at 0x000F2BA0000 EntryPoint=0x000F2BB1B70 RealTimeClock.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872177", "lvl": "feedback", "msg": "InitializeRealTimeClock: using default timezone/daylight settings", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872221", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/Console/ConPlatformDxe/ConPlatformDxe/DEBUG/ConPlatformDxe.dll 0xF7E12000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872265", "lvl": "feedback", "msg": "Loading driver at 0x000F7E11000 EntryPoint=0x000F7E149C0 ConPlatformDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872472", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.872548", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/Console/ConSplitterDxe/ConSplitterDxe/DEBUG/ConSplitterDxe.dll 0xF7E07000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872599", "lvl": "feedback", "msg": "Loading driver at 0x000F7E06000 EntryPoint=0x000F7E0CE7C ConSplitterDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872644", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/Console/GraphicsConsoleDxe/GraphicsConsoleDxe/DEBUG/GraphicsConsoleDxe.dll 0xF7DFE000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872690", "lvl": "feedback", "msg": "Loading driver at 0x000F7DFD000 EntryPoint=0x000F7E011A4 GraphicsConsoleDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872735", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/Console/TerminalDxe/TerminalDxe/DEBUG/TerminalDxe.dll 0xF7DF3000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872780", "lvl": "feedback", "msg": "Loading driver at 0x000F7DF2000 EntryPoint=0x000F7DF94C4 TerminalDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872824", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/ArmPkg/Filesystem/SemihostFs/SemihostFs/DEBUG/SemihostFs.dll 0xF7DEC000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872872", "lvl": "feedback", "msg": "Loading driver at 0x000F7DEB000 EntryPoint=0x000F7DEEBE8 SemihostFs.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872916", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/Disk/DiskIoDxe/DiskIoDxe/DEBUG/DiskIoDxe.dll 0xF7DE4000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.872960", "lvl": "feedback", "msg": "Loading driver at 0x000F7DE3000 EntryPoint=0x000F7DE71A4 DiskIoDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873004", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/Disk/PartitionDxe/PartitionDxe/DEBUG/PartitionDxe.dll 0xF7DDA000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873049", "lvl": "feedback", "msg": "Loading driver at 0x000F7DD9000 EntryPoint=0x000F7DDEBE4 PartitionDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873093", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/FatPkg/EnhancedFatDxe/Fat/DEBUG/Fat.dll 0xF7DCD000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873142", "lvl": "feedback", "msg": "Loading driver at 0x000F7DCC000 EntryPoint=0x000F7DD50D4 Fat.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873188", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/Disk/UnicodeCollation/EnglishDxe/EnglishDxe/DEBUG/EnglishDxe.dll 0xF7DC8000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873233", "lvl": "feedback", "msg": "Loading driver at 0x000F7DC7000 EntryPoint=0x000F7DC9388 EnglishDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873440", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.873517", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/Platform/ARM/VExpressPkg/Drivers/ArmVExpressDxe/ArmFvpDxe/DEBUG/ArmFvpDxe.dll 0xF2B96000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873568", "lvl": "feedback", "msg": "Loading driver at 0x000F2B95000 EntryPoint=0x000F2B9BE64 ArmFvpDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873614", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/OvmfPkg/VirtioBlkDxe/VirtioBlk/DEBUG/VirtioBlkDxe.dll 0xF7DC1000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873659", "lvl": "feedback", "msg": "Loading driver at 0x000F7DC0000 EntryPoint=0x000F7DC333C VirtioBlkDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873703", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Bus/Pci/PciBusDxe/PciBusDxe/DEBUG/PciBusDxe.dll 0xF2B81000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873747", "lvl": "feedback", "msg": "Loading driver at 0x000F2B80000 EntryPoint=0x000F2B8941C PciBusDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873803", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Bus/Ata/AtaAtapiPassThru/AtaAtapiPassThru/DEBUG/AtaAtapiPassThruDxe.dll 0xF2B73000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873856", "lvl": "feedback", "msg": "Loading driver at 0x000F2B72000 EntryPoint=0x000F2B7BA2C AtaAtapiPassThruDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873901", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Bus/Ata/AtaBusDxe/AtaBusDxe/DEBUG/AtaBusDxe.dll 0xF2F81000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873945", "lvl": "feedback", "msg": "Loading driver at 0x000F2F80000 EntryPoint=0x000F2F85A20 AtaBusDxe.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.873989", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Bus/Pci/SataControllerDxe/SataControllerDxe/DEBUG/SataController.dll 0xF2B6C000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874033", "lvl": "feedback", "msg": "Loading driver at 0x000F2B6B000 EntryPoint=0x000F2B6E0FC SataController.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874077", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/MdeModulePkg/Universal/FvSimpleFileSystemDxe/FvSimpleFileSystemDxe/DEBUG/FvSimpleFileSystem.dll 0xF2B63000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874121", "lvl": "feedback", "msg": "Loading driver at 0x000F2B62000 EntryPoint=0x000F2B67244 FvSimpleFileSystem.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874164", "lvl": "feedback", "msg": "Process PlatformRecovery0000 (Default PlatformRecovery) ...", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874207", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 0. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874251", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 1. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874463", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.874539", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 2. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874589", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 3. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874635", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 0. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874681", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 1. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874726", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 2. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874771", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 3. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874816", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 0. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874861", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 1. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874906", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 2. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874951", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 3. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.874997", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 0. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875042", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 1. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875086", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 2. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875131", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 3. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875176", "lvl": "feedback", "msg": "[Bds] Unable to boot!", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875220", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 0. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875265", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 1. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875309", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 262144 for FAT filesystem on MediaId 2. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875517", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.875587", "lvl": "feedback", "msg": "FatAllocateVolume invalid BlockIo BlockSize 65536 for FAT filesystem on MediaId 3. Must be 512B, 1KB, 2KB, or 4KB", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875641", "lvl": "feedback", "msg": "[Bds]Booting UEFI Shell (default)", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875688", "lvl": "feedback", "msg": "add-symbol-file /home/anders/.shrinkwrap/build/build/ns-edk2/edk2/DEBUG_GCC5/AARCH64/ShellPkg/Application/Shell/Shell/DEBUG/Shell.dll 0xF2A17000", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875734", "lvl": "feedback", "msg": "Loading driver at 0x000F2A16000 EntryPoint=0x000F2A1E240 Shell.efi", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875779", "lvl": "feedback", "msg": "[HiiDatabase]: Memory allocation is required after ReadyToBoot, which may change memory map and cause S4 resume issue.", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875825", "lvl": "feedback", "msg": "[HiiDatabase]: Memory allocation is required after ReadyToBoot, which may change memory map and cause S4 resume issue.", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875870", "lvl": "feedback", "msg": "[HiiDatabase]: Memory allocation is required after ReadyToBoot, which may change memory map and cause S4 resume issue.", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875915", "lvl": "feedback", "msg": "[HiiDatabase]: Memory allocation is required after ReadyToBoot, which may change memory map and cause S4 resume issue.", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.875958", "lvl": "feedback", "msg": "[HiiDatabase]: Memory allocation is required after ReadyToBoot, which may change memory map and cause S4 resume issue.", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.876002", "lvl": "feedback", "msg": "Loading driver at 0x000F0270000 EntryPoint=0x000F20F3320", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.876046", "lvl": "feedback", "msg": "Loading driver at 0x000F0270000 EntryPoint=0x000F20F3320 ", "ns": "terminal_1"}
- {"dt": "2025-08-21T13:19:08.876289", "lvl": "debug", "msg": "Listened to connection for namespace 'terminal_1' for up to 1s"}
- {"dt": "2025-08-21T13:19:08.876364", "lvl": "info", "msg": "Finalising connection for namespace 'terminal_1'"}
- {"dt": "2025-08-21T13:19:08.876418", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2025-08-21T13:19:08.976691", "lvl": "info", "msg": "Finalising connection for namespace 'terminal_2'"}
- {"dt": "2025-08-21T13:19:08.976858", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2025-08-21T13:19:09.077132", "lvl": "info", "msg": "Finalising connection for namespace 'terminal_3'"}
- {"dt": "2025-08-21T13:19:09.077261", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2025-08-21T13:19:09.177496", "lvl": "debug", "msg": "end: 4.2 read-feedback (duration 00:00:00) [common]"}
- {"dt": "2025-08-21T13:19:09.177668", "lvl": "info", "msg": "Removing root tmp directory at /var/lib/lava/dispatcher/tmp/tuxrun-nt9e39f9-1"}
- {"dt": "2025-08-21T13:19:09.178365", "lvl": "error", "msg": "JobError: Your job cannot terminate cleanly."}
- {"dt": "2025-08-21T13:19:09.178437", "lvl": "results", "msg": {"definition": "lava", "case": "job", "result": "fail", "error_msg": "login-action timed out after 1792 seconds", "error_type": "Job"}}
