- {"dt": "2024-11-20T11:03:17.688203", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2024.05.dev0067"}
- {"dt": "2024-11-20T11:03:17.688292", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-11-20T11:03:17.688369", "lvl": "info", "msg": "Start time: 2024-11-20 11:03:17.688358+00:00 (UTC)"}
- {"dt": "2024-11-20T11:03:17.688959", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2024.07.tar.zst exists"}
- {"dt": "2024-11-20T11:03:17.689256", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2p6O1zkQwG2EdbthGjl1rXbHuQl/Image.gz exists"}
- {"dt": "2024-11-20T11:03:18.106503", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2024-11-20T11:03:18.787560", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian-kvm_trixie_arm64_rootfs.ext4.xz exists"}
- {"dt": "2024-11-20T11:03:18.787760", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2p6O1zkQwG2EdbthGjl1rXbHuQl/modules.tar.xz exists"}
- {"dt": "2024-11-20T11:03:18.896306", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2024-11-20T11:03:19.546056", "lvl": "debug", "msg": "Validating that https://storage.dev.tuxboot.com/overlays/debian/trixie/arm64/20240216/kvm-unit-tests/master/kvm-unit-tests.tar.xz exists"}
- {"dt": "2024-11-20T11:03:21.952514", "lvl": "info", "msg": "qemu-system-arm, installed at version: 1:9.1.1+ds-5, host architecture: amd64"}
- {"dt": "2024-11-20T11:03:21.952755", "lvl": "warning", "msg": "Missing image arg for url_repo"}
- {"dt": "2024-11-20T11:03:21.952845", "lvl": "warning", "msg": "Missing image arg for rootfs.modules"}
- {"dt": "2024-11-20T11:03:21.952910", "lvl": "warning", "msg": "Missing image arg for rootfs.overlay-00"}
- {"dt": "2024-11-20T11:03:21.953063", "lvl": "info", "msg": "validate duration: 4.26"}
- {"dt": "2024-11-20T11:03:21.953131", "lvl": "results", "msg": {"definition": "lava", "case": "validate", "result": "pass"}}
- {"dt": "2024-11-20T11:03:21.953272", "lvl": "info", "msg": "start: 1 deployimages (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:21.953354", "lvl": "debug", "msg": "start: 1.1 lava-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:21.953524", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6"}
- {"dt": "2024-11-20T11:03:21.953665", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin"}
- {"dt": "2024-11-20T11:03:21.953763", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/tests"}
- {"dt": "2024-11-20T11:03:21.953856", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/results"}
- {"dt": "2024-11-20T11:03:21.953931", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-add-keys"}
- {"dt": "2024-11-20T11:03:21.954065", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-add-sources"}
- {"dt": "2024-11-20T11:03:21.954225", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-background-process-start"}
- {"dt": "2024-11-20T11:03:21.954356", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-background-process-stop"}
- {"dt": "2024-11-20T11:03:21.954483", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-common-functions"}
- {"dt": "2024-11-20T11:03:21.954604", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-echo-ipv4"}
- {"dt": "2024-11-20T11:03:21.954728", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-install-packages"}
- {"dt": "2024-11-20T11:03:21.954843", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-installed-packages"}
- {"dt": "2024-11-20T11:03:21.954957", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-os-build"}
- {"dt": "2024-11-20T11:03:21.955070", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-probe-channel"}
- {"dt": "2024-11-20T11:03:21.955182", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-probe-ip"}
- {"dt": "2024-11-20T11:03:21.955296", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-target-ip"}
- {"dt": "2024-11-20T11:03:21.955409", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-target-mac"}
- {"dt": "2024-11-20T11:03:21.955524", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-target-storage"}
- {"dt": "2024-11-20T11:03:21.955640", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-test-case"}
- {"dt": "2024-11-20T11:03:21.955756", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-test-event"}
- {"dt": "2024-11-20T11:03:21.955870", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-test-feedback"}
- {"dt": "2024-11-20T11:03:21.955983", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-test-raise"}
- {"dt": "2024-11-20T11:03:21.956096", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-test-reference"}
- {"dt": "2024-11-20T11:03:21.956216", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-test-runner"}
- {"dt": "2024-11-20T11:03:21.956336", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-test-set"}
- {"dt": "2024-11-20T11:03:21.956464", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-test-shell"}
- {"dt": "2024-11-20T11:03:21.956591", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-install-packages (oe)"}
- {"dt": "2024-11-20T11:03:21.956733", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/bin/lava-installed-packages (oe)"}
- {"dt": "2024-11-20T11:03:21.956839", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/environment"}
- {"dt": "2024-11-20T11:03:21.956924", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2024-11-20T11:03:21.956973", "lvl": "debug", "msg": "- LAVA_JOB_ID=1"}
- {"dt": "2024-11-20T11:03:21.957017", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.32.138"}
- {"dt": "2024-11-20T11:03:21.957092", "lvl": "debug", "msg": "start: 1.1.1 lava-vland-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:21.957137", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2024-11-20T11:03:21.957189", "lvl": "debug", "msg": "end: 1.1.1 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:21.957266", "lvl": "debug", "msg": "start: 1.1.2 lava-multinode-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:21.957307", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2024-11-20T11:03:21.957356", "lvl": "debug", "msg": "end: 1.1.2 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:21.957409", "lvl": "debug", "msg": "start: 1.1.3 test-definition (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:21.957458", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2024-11-20T11:03:21.957515", "lvl": "debug", "msg": "start: 1.1.3.1 url-repo-action (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:21.957569", "lvl": "debug", "msg": "start: 1.1.3.1.1 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:21.957624", "lvl": "debug", "msg": "start: 1.1.3.1.1.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:21.957751", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2024.07.tar.zst"}
- {"dt": "2024-11-20T11:03:21.957802", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/url-repo-action-j78ii7ri/url_repo/https___storage.tuxboot.com_test-definitions_2024.07.tar"}
- {"dt": "2024-11-20T11:03:21.957842", "lvl": "debug", "msg": "total size: 13692979 (13\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.957883", "lvl": "info", "msg": "Using unzstd to decompress zstd"}
- {"dt": "2024-11-20T11:03:21.958206", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.960928", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.962846", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.964638", "lvl": "debug", "msg": "progress  15\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.966786", "lvl": "debug", "msg": "progress  20\u202F% (2\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.968776", "lvl": "debug", "msg": "progress  25\u202F% (3\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.970615", "lvl": "debug", "msg": "progress  30\u202F% (3\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.972418", "lvl": "debug", "msg": "progress  35\u202F% (4\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.974312", "lvl": "debug", "msg": "progress  40\u202F% (5\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.976157", "lvl": "debug", "msg": "progress  45\u202F% (5\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.977882", "lvl": "debug", "msg": "progress  50\u202F% (6\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.979663", "lvl": "debug", "msg": "progress  55\u202F% (7\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.981518", "lvl": "debug", "msg": "progress  60\u202F% (7\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.983347", "lvl": "debug", "msg": "progress  65\u202F% (8\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.985964", "lvl": "debug", "msg": "progress  70\u202F% (9\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.988493", "lvl": "debug", "msg": "progress  75\u202F% (9\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.991142", "lvl": "debug", "msg": "progress  80\u202F% (10\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.994480", "lvl": "debug", "msg": "progress  85\u202F% (11\u202FMB)"}
- {"dt": "2024-11-20T11:03:21.996743", "lvl": "debug", "msg": "progress  90\u202F% (11\u202FMB)"}
- {"dt": "2024-11-20T11:03:22.000775", "lvl": "debug", "msg": "progress  95\u202F% (12\u202FMB)"}
- {"dt": "2024-11-20T11:03:22.004521", "lvl": "debug", "msg": "progress 100\u202F% (13\u202FMB)"}
- {"dt": "2024-11-20T11:03:22.011947", "lvl": "info", "msg": "13\u202FMB downloaded in 0.05\u202Fs (241.39\u202FMB/s)"}
- {"dt": "2024-11-20T11:03:22.012111", "lvl": "debug", "msg": "end: 1.1.3.1.1.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:22.012185", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.1.3.1.1.1", "duration": "0.05", "result": "pass", "extra": {"label": "url_repo", "size": ! "13692979", "md5sum": "30eb6f40044a706e0edae9b32f16a662", "sha256sum": "c850bed1a93201581f64754245d951f99a4942fe707b841bfe6ea3c9cd7624b0", "sha512sum": "3435daea585c61fec8b4c72eeb412c9d550e229d1220195bd592f268fe6baad5d210433f9802e5f9931fb5b8b17a10a4c5c569f16a3c286247222b96634c6310"}}}
- {"dt": "2024-11-20T11:03:22.012344", "lvl": "debug", "msg": "end: 1.1.3.1.1 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:22.012411", "lvl": "debug", "msg": "Using /lava-1 at stage 0"}
- {"dt": "2024-11-20T11:03:22.012493", "lvl": "debug", "msg": "Runner path : /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/0/tests/0_kvm-unit-tests"}
- {"dt": "2024-11-20T11:03:22.012553", "lvl": "info", "msg": "Untar tests from file /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/url-repo-action-j78ii7ri/url_repo/https___storage.tuxboot.com_test-definitions_2024.07.tar to directory /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/0/tests/0_kvm-unit-tests"}
- {"dt": "2024-11-20T11:03:22.206391", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/0/tests/0_kvm-unit-tests/automated/linux/kvm-unit-tests/kvm-unit-tests.yaml"}
- {"dt": "2024-11-20T11:03:22.206689", "lvl": "debug", "msg": "uuid=1_1.1.3.1 testdef=None"}
- {"dt": "2024-11-20T11:03:22.206772", "lvl": "debug", "msg": "end: 1.1.3.1 url-repo-action (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:22.206838", "lvl": "debug", "msg": "start: 1.1.3.2 test-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:22.207337", "lvl": "debug", "msg": "end: 1.1.3.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:22.207391", "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": "kvm-unit-tests", "path": "automated/linux/kvm-unit-tests/kvm-unit-tests.yaml", "from": "url", "repository": "file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2024.07.tar.zst"}}}
- {"dt": "2024-11-20T11:03:22.207493", "lvl": "debug", "msg": "start: 1.1.3.3 test-install-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:22.208165", "lvl": "debug", "msg": "end: 1.1.3.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:22.208221", "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": "kvm-unit-tests", "path": "automated/linux/kvm-unit-tests/kvm-unit-tests.yaml", "from": "url", "repository": "file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2024.07.tar.zst", "skipped test-install-overlay": "1_1.1.3.1"}}}
- {"dt": "2024-11-20T11:03:22.208330", "lvl": "debug", "msg": "start: 1.1.3.4 test-runscript-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:22.216582", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/0/tests/0_kvm-unit-tests test_uuid 1_1.1.3.1"}
- {"dt": "2024-11-20T11:03:22.216668", "lvl": "debug", "msg": "SKIP_INSTALL='True'"}
- {"dt": "2024-11-20T11:03:22.216730", "lvl": "debug", "msg": "SMP='True'"}
- {"dt": "2024-11-20T11:03:22.216886", "lvl": "debug", "msg": "end: 1.1.3.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:22.216941", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "test-runscript-overlay", "level": "1.1.3.4", "duration": "0.01", "result": "pass", "extra": {"uuid": "1_1.1.3.1", "name": "kvm-unit-tests", "path": "automated/linux/kvm-unit-tests/kvm-unit-tests.yaml", "from": "url", "repository": "file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2024.07.tar.zst", "filename": "/var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/0/tests/0_kvm-unit-tests/run.sh"}}}
- {"dt": "2024-11-20T11:03:22.217036", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2024-11-20T11:03:22.217077", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/lava-overlay-zzlig6b6/lava-1/0 for stage 0"}
- {"dt": "2024-11-20T11:03:22.217152", "lvl": "debug", "msg": "- 0_kvm-unit-tests"}
- {"dt": "2024-11-20T11:03:22.217243", "lvl": "debug", "msg": "end: 1.1.3 test-definition (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:22.217307", "lvl": "debug", "msg": "start: 1.1.4 compress-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:27.904825", "lvl": "debug", "msg": "end: 1.1.4 compress-overlay (duration 00:00:06) [common]"}
- {"dt": "2024-11-20T11:03:27.904976", "lvl": "debug", "msg": "start: 1.1.5 persistent-nfs-overlay (timeout 00:04:54) [common]"}
- {"dt": "2024-11-20T11:03:27.905035", "lvl": "debug", "msg": "end: 1.1.5 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:27.905093", "lvl": "debug", "msg": "end: 1.1 lava-overlay (duration 00:00:06) [common]"}
- {"dt": "2024-11-20T11:03:27.905146", "lvl": "debug", "msg": "start: 1.2 apply-overlay-guest (timeout 00:04:54) [common]"}
- {"dt": "2024-11-20T11:03:27.905190", "lvl": "debug", "msg": "Overlay already applied"}
- {"dt": "2024-11-20T11:03:27.905249", "lvl": "debug", "msg": "end: 1.2 apply-overlay-guest (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:27.905301", "lvl": "debug", "msg": "start: 1.3 deploy-device-env (timeout 00:04:54) [common]"}
- {"dt": "2024-11-20T11:03:27.905351", "lvl": "debug", "msg": "end: 1.3 deploy-device-env (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:27.905401", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:04:54) [common]"}
- {"dt": "2024-11-20T11:03:27.905453", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:04:54) [common]"}
- {"dt": "2024-11-20T11:03:27.905606", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2p6O1zkQwG2EdbthGjl1rXbHuQl/Image.gz"}
- {"dt": "2024-11-20T11:03:27.905656", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/kernel/Image"}
- {"dt": "2024-11-20T11:03:27.905698", "lvl": "debug", "msg": "total size: 16846474 (16\u202FMB)"}
- {"dt": "2024-11-20T11:03:27.905737", "lvl": "info", "msg": "Using gunzip to decompress gz"}
- {"dt": "2024-11-20T11:03:28.578666", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:28.962788", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.062026", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.136759", "lvl": "debug", "msg": "progress  15\u202F% (2\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.209157", "lvl": "debug", "msg": "progress  20\u202F% (3\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.282469", "lvl": "debug", "msg": "progress  25\u202F% (4\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.355603", "lvl": "debug", "msg": "progress  30\u202F% (4\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.531243", "lvl": "debug", "msg": "progress  35\u202F% (5\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.542729", "lvl": "debug", "msg": "progress  40\u202F% (6\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.573421", "lvl": "debug", "msg": "progress  45\u202F% (7\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.648620", "lvl": "debug", "msg": "progress  50\u202F% (8\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.720795", "lvl": "debug", "msg": "progress  55\u202F% (8\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.794630", "lvl": "debug", "msg": "progress  60\u202F% (9\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.869534", "lvl": "debug", "msg": "progress  65\u202F% (10\u202FMB)"}
- {"dt": "2024-11-20T11:03:29.940370", "lvl": "debug", "msg": "progress  70\u202F% (11\u202FMB)"}
- {"dt": "2024-11-20T11:03:30.014774", "lvl": "debug", "msg": "progress  75\u202F% (12\u202FMB)"}
- {"dt": "2024-11-20T11:03:30.087966", "lvl": "debug", "msg": "progress  80\u202F% (12\u202FMB)"}
- {"dt": "2024-11-20T11:03:30.159023", "lvl": "debug", "msg": "progress  85\u202F% (13\u202FMB)"}
- {"dt": "2024-11-20T11:03:30.232495", "lvl": "debug", "msg": "progress  90\u202F% (14\u202FMB)"}
- {"dt": "2024-11-20T11:03:30.305816", "lvl": "debug", "msg": "progress  95\u202F% (15\u202FMB)"}
- {"dt": "2024-11-20T11:03:30.375516", "lvl": "debug", "msg": "progress 100\u202F% (16\u202FMB)"}
- {"dt": "2024-11-20T11:03:30.380257", "lvl": "info", "msg": "16\u202FMB downloaded in 2.47\u202Fs (6.49\u202FMB/s)"}
- {"dt": "2024-11-20T11:03:30.380421", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2024-11-20T11:03:30.380498", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.4.1", "duration": "2.47", "result": "pass", "extra": {"label": "kernel", "size": ! "16846474", "md5sum": "b305f7f5beca418d42f1748c4faccd66", "sha256sum": "f037a1bfb3eee0ff0d6e5da539616c381172a719d9cdd2ab0398515fc7e3d675", "sha512sum": "b1058da27b6979f398f440042d3a0aec39e4c18d69926479acb8dc85590096f30205d69df95aae2d2d3f59c7c80613bc2b6a463afd1ec8685e6b6634cdbef25b"}}}
- {"dt": "2024-11-20T11:03:30.380655", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:02) [common]"}
- {"dt": "2024-11-20T11:03:30.380736", "lvl": "debug", "msg": "start: 1.5 download-retry (timeout 00:04:52) [common]"}
- {"dt": "2024-11-20T11:03:30.380818", "lvl": "debug", "msg": "start: 1.5.1 file-download (timeout 00:04:52) [common]"}
- {"dt": "2024-11-20T11:03:30.381033", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian-kvm_trixie_arm64_rootfs.ext4.xz"}
- {"dt": "2024-11-20T11:03:30.381107", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs/https___storage.tuxboot.com_debian-kvm_trixie_arm64_rootfs.ext4"}
- {"dt": "2024-11-20T11:03:30.381167", "lvl": "debug", "msg": "total size: 206865760 (197\u202FMB)"}
- {"dt": "2024-11-20T11:03:30.381235", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-11-20T11:03:30.381632", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:30.745395", "lvl": "debug", "msg": "progress   5\u202F% (9\u202FMB)"}
- {"dt": "2024-11-20T11:03:31.061671", "lvl": "debug", "msg": "progress  10\u202F% (19\u202FMB)"}
- {"dt": "2024-11-20T11:03:31.374792", "lvl": "debug", "msg": "progress  15\u202F% (29\u202FMB)"}
- {"dt": "2024-11-20T11:03:31.682331", "lvl": "debug", "msg": "progress  20\u202F% (39\u202FMB)"}
- {"dt": "2024-11-20T11:03:32.005082", "lvl": "debug", "msg": "progress  25\u202F% (49\u202FMB)"}
- {"dt": "2024-11-20T11:03:32.316177", "lvl": "debug", "msg": "progress  30\u202F% (59\u202FMB)"}
- {"dt": "2024-11-20T11:03:32.631627", "lvl": "debug", "msg": "progress  35\u202F% (69\u202FMB)"}
- {"dt": "2024-11-20T11:03:32.943929", "lvl": "debug", "msg": "progress  40\u202F% (78\u202FMB)"}
- {"dt": "2024-11-20T11:03:33.256202", "lvl": "debug", "msg": "progress  45\u202F% (88\u202FMB)"}
- {"dt": "2024-11-20T11:03:33.583029", "lvl": "debug", "msg": "progress  50\u202F% (98\u202FMB)"}
- {"dt": "2024-11-20T11:03:33.878831", "lvl": "debug", "msg": "progress  55\u202F% (108\u202FMB)"}
- {"dt": "2024-11-20T11:03:34.235416", "lvl": "debug", "msg": "progress  60\u202F% (118\u202FMB)"}
- {"dt": "2024-11-20T11:03:34.534801", "lvl": "debug", "msg": "progress  65\u202F% (128\u202FMB)"}
- {"dt": "2024-11-20T11:03:34.852321", "lvl": "debug", "msg": "progress  70\u202F% (138\u202FMB)"}
- {"dt": "2024-11-20T11:03:35.157752", "lvl": "debug", "msg": "progress  75\u202F% (147\u202FMB)"}
- {"dt": "2024-11-20T11:03:35.438207", "lvl": "debug", "msg": "progress  80\u202F% (157\u202FMB)"}
- {"dt": "2024-11-20T11:03:35.733862", "lvl": "debug", "msg": "progress  85\u202F% (167\u202FMB)"}
- {"dt": "2024-11-20T11:03:36.028043", "lvl": "debug", "msg": "progress  90\u202F% (177\u202FMB)"}
- {"dt": "2024-11-20T11:03:36.335276", "lvl": "debug", "msg": "progress  95\u202F% (187\u202FMB)"}
- {"dt": "2024-11-20T11:03:38.308212", "lvl": "debug", "msg": "progress 100\u202F% (197\u202FMB)"}
- {"dt": "2024-11-20T11:03:39.107783", "lvl": "info", "msg": "197\u202FMB downloaded in 8.73\u202Fs (22.61\u202FMB/s)"}
- {"dt": "2024-11-20T11:03:39.108062", "lvl": "debug", "msg": "end: 1.5.1 file-download (duration 00:00:09) [common]"}
- {"dt": "2024-11-20T11:03:39.108152", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.5.1", "duration": "8.73", "result": "pass", "extra": {"label": "rootfs", "size": ! "206865760", "md5sum": "af4836065f4543355243f883d3c6442f", "sha256sum": "e592fde880d4f0fe887687f6629c223469caa40ddb5a91a7781783b6cc8e3a08", "sha512sum": "2015046db0a79526b3f319fe0f69780251dedc425c08d82780f787ff4251ac560d3eda238a858f066f423007f666e1644f9e0e816f04049f9aefa20c1ad9fe47"}}}
- {"dt": "2024-11-20T11:03:39.108337", "lvl": "debug", "msg": "start: 1.5.2 download-retry (timeout 00:04:43) [common]"}
- {"dt": "2024-11-20T11:03:39.108446", "lvl": "debug", "msg": "start: 1.5.2.1 http-download (timeout 00:04:43) [common]"}
- {"dt": "2024-11-20T11:03:39.108687", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2p6O1zkQwG2EdbthGjl1rXbHuQl/modules.tar.xz"}
- {"dt": "2024-11-20T11:03:39.108756", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs.modules/modules.tar"}
- {"dt": "2024-11-20T11:03:39.108814", "lvl": "debug", "msg": "total size: 12435356 (11\u202FMB)"}
- {"dt": "2024-11-20T11:03:39.108877", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-11-20T11:03:39.807132", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.102373", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.213149", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.288576", "lvl": "debug", "msg": "progress  15\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.342255", "lvl": "debug", "msg": "progress  20\u202F% (2\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.400056", "lvl": "debug", "msg": "progress  25\u202F% (2\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.453747", "lvl": "debug", "msg": "progress  30\u202F% (3\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.507988", "lvl": "debug", "msg": "progress  35\u202F% (4\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.563114", "lvl": "debug", "msg": "progress  40\u202F% (4\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.616871", "lvl": "debug", "msg": "progress  45\u202F% (5\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.675762", "lvl": "debug", "msg": "progress  50\u202F% (5\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.738609", "lvl": "debug", "msg": "progress  55\u202F% (6\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.794799", "lvl": "debug", "msg": "progress  60\u202F% (7\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.943225", "lvl": "debug", "msg": "progress  65\u202F% (7\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.996125", "lvl": "debug", "msg": "progress  70\u202F% (8\u202FMB)"}
- {"dt": "2024-11-20T11:03:40.998247", "lvl": "debug", "msg": "progress  75\u202F% (8\u202FMB)"}
- {"dt": "2024-11-20T11:03:41.019267", "lvl": "debug", "msg": "progress  80\u202F% (9\u202FMB)"}
- {"dt": "2024-11-20T11:03:41.084019", "lvl": "debug", "msg": "progress  85\u202F% (10\u202FMB)"}
- {"dt": "2024-11-20T11:03:41.137883", "lvl": "debug", "msg": "progress  90\u202F% (10\u202FMB)"}
- {"dt": "2024-11-20T11:03:41.193071", "lvl": "debug", "msg": "progress  95\u202F% (11\u202FMB)"}
- {"dt": "2024-11-20T11:03:41.250896", "lvl": "debug", "msg": "progress 100\u202F% (11\u202FMB)"}
- {"dt": "2024-11-20T11:03:41.291313", "lvl": "info", "msg": "11\u202FMB downloaded in 2.18\u202Fs (5.43\u202FMB/s)"}
- {"dt": "2024-11-20T11:03:41.291569", "lvl": "debug", "msg": "end: 1.5.2.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2024-11-20T11:03:41.291647", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.5.2.1", "duration": "2.18", "result": "pass", "extra": {"label": "rootfs.modules", "size": ! "12435356", "md5sum": "b68a44158b1ffe070945af1f51a9889f", "sha256sum": "eed94202902c1267ca954794b23c5adbdb57d73ff10e4f30b3a44aae640b9e0a", "sha512sum": "baf74230e0f5a25f32ce061191814a4fa12c94b9ae87eea503019b5138d468a47e26b7130b68c3ffdafb9d74a1d602de0da5a880b68470f8923fcf6ebb370761"}}}
- {"dt": "2024-11-20T11:03:41.291803", "lvl": "debug", "msg": "end: 1.5.2 download-retry (duration 00:00:02) [common]"}
- {"dt": "2024-11-20T11:03:41.291886", "lvl": "debug", "msg": "start: 1.5.3 download-retry (timeout 00:04:41) [common]"}
- {"dt": "2024-11-20T11:03:41.291964", "lvl": "debug", "msg": "start: 1.5.3.1 http-download (timeout 00:04:41) [common]"}
- {"dt": "2024-11-20T11:03:41.292139", "lvl": "info", "msg": "downloading https://storage.dev.tuxboot.com/overlays/debian/trixie/arm64/20240216/kvm-unit-tests/master/kvm-unit-tests.tar.xz"}
- {"dt": "2024-11-20T11:03:41.292190", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs.overlay-00/kvm-unit-tests.tar"}
- {"dt": "2024-11-20T11:03:41.292230", "lvl": "debug", "msg": "total size: 1379552 (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:41.292270", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-11-20T11:03:42.325411", "lvl": "debug", "msg": "progress   2\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.418475", "lvl": "debug", "msg": "progress   7\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.510708", "lvl": "debug", "msg": "progress  14\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.516509", "lvl": "debug", "msg": "progress  19\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.524089", "lvl": "debug", "msg": "progress  26\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.618589", "lvl": "debug", "msg": "progress  33\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.627214", "lvl": "debug", "msg": "progress  38\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.638811", "lvl": "debug", "msg": "progress  45\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.648856", "lvl": "debug", "msg": "progress  52\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.702174", "lvl": "debug", "msg": "progress  57\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.715478", "lvl": "debug", "msg": "progress  64\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.730091", "lvl": "debug", "msg": "progress  71\u202F% (0\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.739091", "lvl": "debug", "msg": "progress  76\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.752596", "lvl": "debug", "msg": "progress  83\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.762618", "lvl": "debug", "msg": "progress  90\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.769641", "lvl": "debug", "msg": "progress  95\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.776731", "lvl": "debug", "msg": "progress 100\u202F% (1\u202FMB)"}
- {"dt": "2024-11-20T11:03:42.778503", "lvl": "info", "msg": "1\u202FMB downloaded in 1.49\u202Fs (0.89\u202FMB/s)"}
- {"dt": "2024-11-20T11:03:42.778632", "lvl": "debug", "msg": "end: 1.5.3.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2024-11-20T11:03:42.778686", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.5.3.1", "duration": "1.49", "result": "pass", "extra": {"label": "rootfs.overlay-00", "size": ! "1379552", "md5sum": "6335250536bca4c4b17082fee52b08a4", "sha256sum": "04214c75d651b8a553bdd783ac5032597d2bca6a1ffb729857857d35729a130e", "sha512sum": "35d11451b55260fdcc72dfecf75c84ae2dec2bc1c5b1b7e0ea67193ae7a5c7e75f93faa0cb0e16e71ad49e374b46e4f18e40d686bc70975e0b77f496f12f1dc8"}}}
- {"dt": "2024-11-20T11:03:42.778800", "lvl": "debug", "msg": "end: 1.5.3 download-retry (duration 00:00:01) [common]"}
- {"dt": "2024-11-20T11:03:42.778860", "lvl": "debug", "msg": "start: 1.5.4 append-overlays (timeout 00:04:39) [common]"}
- {"dt": "2024-11-20T11:03:42.778910", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs/https___storage.tuxboot.com_debian-kvm_trixie_arm64_rootfs.ext4'"}
- {"dt": "2024-11-20T11:03:44.460140", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2024-11-20T11:03:44.461056", "lvl": "debug", "msg": "- rootfs.lava: '/var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/compress-overlay-69fcj5k5/overlay-1.1.4.tar.gz' to '/'"}
- {"dt": "2024-11-20T11:03:44.822969", "lvl": "debug", "msg": "- rootfs.modules: '/var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs.modules/modules.tar' to '/usr/'"}
- {"dt": "2024-11-20T11:03:45.045961", "lvl": "debug", "msg": "- rootfs.overlay-00: '/var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs.overlay-00/kvm-unit-tests.tar' to '/'"}
- {"dt": "2024-11-20T11:03:45.332671", "lvl": "debug", "msg": "end: 1.5.4 append-overlays (duration 00:00:03) [common]"}
- {"dt": "2024-11-20T11:03:45.333056", "lvl": "debug", "msg": "end: 1.5 download-retry (duration 00:00:15) [common]"}
- {"dt": "2024-11-20T11:03:45.333181", "lvl": "info", "msg": "end: 1 deployimages (duration 00:00:23) [common]"}
- {"dt": "2024-11-20T11:03:45.333330", "lvl": "info", "msg": "start: 2 boot-image-retry (timeout 00:30:00) [common]"}
- {"dt": "2024-11-20T11:03:45.333461", "lvl": "debug", "msg": "start: 2.1 boot-qemu-image (timeout 00:30:00) [common]"}
- {"dt": "2024-11-20T11:03:45.333583", "lvl": "debug", "msg": "start: 2.1.1 execute-qemu (timeout 00:30:00) [common]"}
- {"dt": "2024-11-20T11:03:45.333905", "lvl": "info", "msg": "Boot command: /usr/bin/qemu-system-aarch64 -cpu max,pauth-impdef=on -machine virt,virtualization=on,gic-version=3,mte=on -nographic -nic none -m 4G -monitor none -no-reboot -smp 2 -kernel /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/kernel/Image -append \"console=ttyAMA0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog systemd.log_level=warning rw kvm-arm.mode=protected earlycon\" -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs/https___storage.tuxboot.com_debian-kvm_trixie_arm64_rootfs.ext4,format=raw,id=hd0,if=virtio"}
- {"dt": "2024-11-20T11:03:45.337736", "lvl": "debug", "msg": "started a shell command"}
- {"dt": "2024-11-20T11:03:45.338164", "lvl": "debug", "msg": "end: 2.1.1 execute-qemu (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:45.338274", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "execute-qemu", "level": "2.1.1", "duration": "0.00", "result": "pass", "extra": {"qemu_version": "1:9.1.1+ds-5", "host_arch": "amd64", "job_arch": "arm64"}}}
- {"dt": "2024-11-20T11:03:45.338467", "lvl": "debug", "msg": "end: 2.1 boot-qemu-image (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:45.338579", "lvl": "debug", "msg": "start: 2.2 auto-login-action (timeout 00:30:00) [common]"}
- {"dt": "2024-11-20T11:03:45.338680", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2024-11-20T11:03:45.338744", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:30:00)"}
- {"dt": "2024-11-20T11:03:45.457832", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x000f0510]"}
- {"dt": "2024-11-20T11:03:45.458274", "lvl": "target", "msg": "[    0.000000] Linux version 6.12.0 (tuxmake@tuxmake) (aarch64-linux-gnu-gcc (Debian 13.3.0-5) 13.3.0, GNU ld (GNU Binutils for Debian) 2.43.1) #1 SMP PREEMPT @1732083206"}
- {"dt": "2024-11-20T11:03:45.458364", "lvl": "target", "msg": "[    0.000000] KASLR enabled"}
- {"dt": "2024-11-20T11:03:45.458491", "lvl": "target", "msg": "[    0.000000] random: crng init done"}
- {"dt": "2024-11-20T11:03:45.458627", "lvl": "target", "msg": "[    0.000000] Machine model: linux,dummy-virt"}
- {"dt": "2024-11-20T11:03:45.458741", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2024-11-20T11:03:45.459001", "lvl": "target", "msg": "[    0.000000] Capping linear region to 51 bits for KVM in nVHE mode on LVA capable hardware."}
- {"dt": "2024-11-20T11:03:45.459178", "lvl": "target", "msg": "[    0.000000] earlycon: pl11 at MMIO 0x0000000009000000 (options '')"}
- {"dt": "2024-11-20T11:03:45.459335", "lvl": "target", "msg": "[    0.000000] printk: legacy bootconsole [pl11] enabled"}
- {"dt": "2024-11-20T11:03:45.459631", "lvl": "debug", "msg": "start: 2.2.1 login-action (timeout 00:30:00) [common]"}
- {"dt": "2024-11-20T11:03:45.459712", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2024-11-20T11:03:45.459785", "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']"}
- {"dt": "2024-11-20T11:03:45.459862", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2024-11-20T11:03:45.459915", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2024-11-20T11:03:45.459971", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2024-11-20T11:03:45.460019", "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", "root@(.*):[/~]#", "login:", "Login incorrect"]}
- {"dt": "2024-11-20T11:03:45.460124", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:30:00)"}
- {"dt": "2024-11-20T11:03:45.460184", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:15:00)"}
- {"dt": "2024-11-20T11:03:45.463723", "lvl": "target", "msg": "[    0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2024-11-20T11:03:45.464456", "lvl": "target", "msg": "[    0.000000] NODE_DATA(0) allocated [mem 0x13df61f40-0x13df6497f]"}
- {"dt": "2024-11-20T11:03:45.465373", "lvl": "target", "msg": "[    0.000000] kvm [0]: Reserved 512 MiB at 0x100000000"}
- {"dt": "2024-11-20T11:03:45.467487", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2024-11-20T11:03:45.467945", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000040000000-0x00000000ffffffff]"}
- {"dt": "2024-11-20T11:03:45.468079", "lvl": "target", "msg": "[    0.000000]   DMA32    empty"}
- {"dt": "2024-11-20T11:03:45.468297", "lvl": "target", "msg": "[    0.000000]   Normal   [mem 0x0000000100000000-0x000000013fffffff]"}
- {"dt": "2024-11-20T11:03:45.468452", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2024-11-20T11:03:45.468600", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2024-11-20T11:03:45.468828", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2024-11-20T11:03:45.469249", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2024-11-20T11:03:45.472342", "lvl": "target", "msg": "[    0.000000] cma: Reserved 512 MiB at 0x00000000e0000000 on node -1"}
- {"dt": "2024-11-20T11:03:45.473347", "lvl": "target", "msg": "[    0.000000] psci: probing for conduit method from DT."}
- {"dt": "2024-11-20T11:03:45.473580", "lvl": "target", "msg": "[    0.000000] psci: PSCIv1.1 detected in firmware."}
- {"dt": "2024-11-20T11:03:45.473741", "lvl": "target", "msg": "[    0.000000] psci: Using standard PSCI v0.2 function IDs"}
- {"dt": "2024-11-20T11:03:45.474019", "lvl": "target", "msg": "[    0.000000] psci: Trusted OS migration not required"}
- {"dt": "2024-11-20T11:03:45.474170", "lvl": "target", "msg": "[    0.000000] psci: SMC Calling Convention v1.0"}
- {"dt": "2024-11-20T11:03:45.478136", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 10 pages/cpu s592792 r8192 d54376 u655360"}
- {"dt": "2024-11-20T11:03:45.478751", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: s592792 r8192 d54376 u655360 alloc=10*65536"}
- {"dt": "2024-11-20T11:03:45.479018", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: [0] 0 [0] 1 "}
- {"dt": "2024-11-20T11:03:45.480197", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2024-11-20T11:03:45.481662", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Address authentication (IMP DEF algorithm)"}
- {"dt": "2024-11-20T11:03:45.481993", "lvl": "target", "msg": "[    0.000000] CPU features: detected: GIC system register CPU interface"}
- {"dt": "2024-11-20T11:03:45.482173", "lvl": "target", "msg": "[    0.000000] CPU features: detected: HCRX_EL2 register"}
- {"dt": "2024-11-20T11:03:45.482370", "lvl": "target", "msg": "[    0.000000] CPU features: detected: 52-bit Virtual Addressing (LVA)"}
- {"dt": "2024-11-20T11:03:45.482606", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Memory Tagging Extension"}
- {"dt": "2024-11-20T11:03:45.482758", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Asymmetric MTE Tag Check Fault"}
- {"dt": "2024-11-20T11:03:45.483026", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v4"}
- {"dt": "2024-11-20T11:03:45.486542", "lvl": "target", "msg": "[    0.000000] alternatives: applying boot alternatives"}
- {"dt": "2024-11-20T11:03:45.488234", "lvl": "target", "msg": "[    0.000000] Kernel command line: console=ttyAMA0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog systemd.log_level=warning rw kvm-arm.mode=protected earlycon"}
- {"dt": "2024-11-20T11:03:45.490412", "lvl": "target", "msg": "<5>[    0.000000] Unknown kernel command line parameters \"verbose\", will be passed to user space."}
- {"dt": "2024-11-20T11:03:45.495650", "lvl": "target", "msg": "<6>[    0.000000] Dentry cache hash table entries: 524288 (order: 6, 4194304 bytes, linear)"}
- {"dt": "2024-11-20T11:03:45.497590", "lvl": "target", "msg": "<6>[    0.000000] Inode-cache hash table entries: 262144 (order: 5, 2097152 bytes, linear)"}
- {"dt": "2024-11-20T11:03:45.498789", "lvl": "target", "msg": "<6>[    0.000000] Fallback order for Node 0: 0 "}
- {"dt": "2024-11-20T11:03:45.498982", "lvl": "target", "msg": "<6>[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 65536"}
- {"dt": "2024-11-20T11:03:45.499113", "lvl": "target", "msg": "<6>[    0.000000] Policy zone: Normal"}
- {"dt": "2024-11-20T11:03:45.499914", "lvl": "target", "msg": "<6>[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off"}
- {"dt": "2024-11-20T11:03:45.500204", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: area num 2."}
- {"dt": "2024-11-20T11:03:45.574075", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: mapped [mem 0x00000000dc000000-0x00000000e0000000] (64MB)"}
- {"dt": "2024-11-20T11:03:45.582930", "lvl": "target", "msg": "<6>[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1"}
- {"dt": "2024-11-20T11:03:45.584793", "lvl": "target", "msg": "<6>[    0.000000] ftrace: allocating 72528 entries in 18 pages"}
- {"dt": "2024-11-20T11:03:46.541309", "lvl": "target", "msg": "<6>[    0.000000] ftrace: allocated 18 pages with 2 groups"}
- {"dt": "2024-11-20T11:03:46.545079", "lvl": "target", "msg": "<6>[    0.000000] trace event string verifier disabled"}
- {"dt": "2024-11-20T11:03:46.551374", "lvl": "target", "msg": "<6>[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2024-11-20T11:03:46.551466", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2024-11-20T11:03:46.551680", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=2."}
- {"dt": "2024-11-20T11:03:46.551970", "lvl": "target", "msg": "<6>[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2024-11-20T11:03:46.552112", "lvl": "target", "msg": "<6>[    0.000000] \tRude variant of Tasks RCU enabled."}
- {"dt": "2024-11-20T11:03:46.552259", "lvl": "target", "msg": "<6>[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2024-11-20T11:03:46.552550", "lvl": "target", "msg": "<6>[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2024-11-20T11:03:46.552780", "lvl": "target", "msg": "<6>[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2"}
- {"dt": "2024-11-20T11:03:46.554090", "lvl": "target", "msg": "<6>[    0.000000] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2."}
- {"dt": "2024-11-20T11:03:46.554389", "lvl": "target", "msg": "<6>[    0.000000] RCU Tasks Rude: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2."}
- {"dt": "2024-11-20T11:03:46.554699", "lvl": "target", "msg": "<6>[    0.000000] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2."}
- {"dt": "2024-11-20T11:03:46.566502", "lvl": "target", "msg": "<6>[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2024-11-20T11:03:46.571356", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GIC: Using split EOI/Deactivate mode"}
- {"dt": "2024-11-20T11:03:46.571477", "lvl": "target", "msg": "<6>[    0.000000] GICv3: 256 SPIs implemented"}
- {"dt": "2024-11-20T11:03:46.571641", "lvl": "target", "msg": "<6>[    0.000000] GICv3: 0 Extended SPIs implemented"}
- {"dt": "2024-11-20T11:03:46.573151", "lvl": "target", "msg": "<6>[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2024-11-20T11:03:46.573399", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GICv3 features: 16 PPIs"}
- {"dt": "2024-11-20T11:03:46.573643", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GICD_CTRL.DS=1, SCR_EL3.FIQ=0"}
- {"dt": "2024-11-20T11:03:46.574168", "lvl": "target", "msg": "<6>[    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000"}
- {"dt": "2024-11-20T11:03:46.578833", "lvl": "target", "msg": "<6>[    0.000000] ITS [mem 0x08080000-0x0809ffff]"}
- {"dt": "2024-11-20T11:03:46.579561", "lvl": "target", "msg": "<6>[    0.000000] ITS@0x0000000008080000: allocated 8192 Devices @603e0000 (indirect, esz 8, psz 64K, shr 1)"}
- {"dt": "2024-11-20T11:03:46.579976", "lvl": "target", "msg": "<6>[    0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @603f0000 (flat, esz 8, psz 64K, shr 1)"}
- {"dt": "2024-11-20T11:03:46.580800", "lvl": "target", "msg": "<6>[    0.000000] GICv3: using LPI property table @0x0000000060410000"}
- {"dt": "2024-11-20T11:03:46.581527", "lvl": "target", "msg": "<6>[    0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000060420000"}
- {"dt": "2024-11-20T11:03:46.583442", "lvl": "target", "msg": "<6>[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention."}
- {"dt": "2024-11-20T11:03:46.589509", "lvl": "target", "msg": "<6>[    0.000000] arch_timer: cp15 timer(s) running at 1000.00MHz (phys)."}
- {"dt": "2024-11-20T11:03:46.590048", "lvl": "target", "msg": "<6>[    0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns"}
- {"dt": "2024-11-20T11:03:46.590634", "lvl": "target", "msg": "<6>[    0.000056] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns"}
- {"dt": "2024-11-20T11:03:46.594683", "lvl": "target", "msg": "<6>[    0.003938] kfence: initialized - using 33554432 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)"}
- {"dt": "2024-11-20T11:03:46.608762", "lvl": "target", "msg": "<6>[    0.016419] Console: colour dummy device 80x25"}
- {"dt": "2024-11-20T11:03:46.612670", "lvl": "target", "msg": "<6>[    0.021565] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)"}
- {"dt": "2024-11-20T11:03:46.612959", "lvl": "target", "msg": "<6>[    0.022496] pid_max: default: 32768 minimum: 301"}
- {"dt": "2024-11-20T11:03:46.615119", "lvl": "target", "msg": "<6>[    0.024513] LSM: initializing lsm=capability"}
- {"dt": "2024-11-20T11:03:46.618707", "lvl": "target", "msg": "<6>[    0.028117] Mount-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)"}
- {"dt": "2024-11-20T11:03:46.619532", "lvl": "target", "msg": "<6>[    0.028809] Mountpoint-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)"}
- {"dt": "2024-11-20T11:03:46.650567", "lvl": "target", "msg": "<4>[    0.060007] cacheinfo: Unable to detect cache hierarchy for CPU 0"}
- {"dt": "2024-11-20T11:03:46.679825", "lvl": "target", "msg": "<6>[    0.089274] rcu: Hierarchical SRCU implementation."}
- {"dt": "2024-11-20T11:03:46.680002", "lvl": "target", "msg": "<6>[    0.089523] rcu: \tMax phase no-delay instances is 1000."}
- {"dt": "2024-11-20T11:03:46.682814", "lvl": "target", "msg": "<6>[    0.092030] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level"}
- {"dt": "2024-11-20T11:03:46.690195", "lvl": "target", "msg": "<6>[    0.099672] fsl-mc MSI: its@8080000 domain created"}
- {"dt": "2024-11-20T11:03:46.692729", "lvl": "target", "msg": "<6>[    0.102216] EFI services will not be available."}
- {"dt": "2024-11-20T11:03:46.695687", "lvl": "target", "msg": "<6>[    0.105147] smp: Bringing up secondary CPUs ..."}
- {"dt": "2024-11-20T11:03:46.717245", "lvl": "target", "msg": "<6>[    0.118406] Detected PIPT I-cache on CPU1"}
- {"dt": "2024-11-20T11:03:46.717363", "lvl": "target", "msg": "<6>[    0.119882] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000"}
- {"dt": "2024-11-20T11:03:46.717841", "lvl": "target", "msg": "<6>[    0.120723] GICv3: CPU1: using allocated LPI pending table @0x0000000060430000"}
- {"dt": "2024-11-20T11:03:46.717921", "lvl": "target", "msg": "<6>[    0.122440] CPU1: Booted secondary processor 0x0000000001 [0x000f0510]"}
- {"dt": "2024-11-20T11:03:46.717993", "lvl": "target", "msg": "<6>[    0.126632] smp: Brought up 1 node, 2 CPUs"}
- {"dt": "2024-11-20T11:03:46.718287", "lvl": "target", "msg": "<6>[    0.127809] SMP: Total of 2 processors activated."}
- {"dt": "2024-11-20T11:03:46.718532", "lvl": "target", "msg": "<6>[    0.128083] CPU: All CPU(s) started at EL2"}
- {"dt": "2024-11-20T11:03:46.719049", "lvl": "target", "msg": "<6>[    0.128555] CPU features: detected: Branch Target Identification"}
- {"dt": "2024-11-20T11:03:46.719250", "lvl": "target", "msg": "<6>[    0.128791] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2024-11-20T11:03:46.719495", "lvl": "target", "msg": "<6>[    0.129030] CPU features: detected: 32-bit EL1 Support"}
- {"dt": "2024-11-20T11:03:46.719793", "lvl": "target", "msg": "<6>[    0.129257] CPU features: detected: ARMv8.4 Translation Table Level"}
- {"dt": "2024-11-20T11:03:46.720373", "lvl": "target", "msg": "<6>[    0.129804] CPU features: detected: Instruction cache invalidation not required for I/D coherence"}
- {"dt": "2024-11-20T11:03:46.720696", "lvl": "target", "msg": "<6>[    0.130154] CPU features: detected: Data cache clean to the PoU not required for I/D coherence"}
- {"dt": "2024-11-20T11:03:46.721003", "lvl": "target", "msg": "<6>[    0.130509] CPU features: detected: Common not Private translations"}
- {"dt": "2024-11-20T11:03:46.721251", "lvl": "target", "msg": "<6>[    0.130768] CPU features: detected: CRC32 instructions"}
- {"dt": "2024-11-20T11:03:46.721496", "lvl": "target", "msg": "<6>[    0.131000] CPU features: detected: Data independent timing control (DIT)"}
- {"dt": "2024-11-20T11:03:46.721739", "lvl": "target", "msg": "<6>[    0.131265] CPU features: detected: E0PD"}
- {"dt": "2024-11-20T11:03:46.721942", "lvl": "target", "msg": "<6>[    0.131460] CPU features: detected: Enhanced Counter Virtualization"}
- {"dt": "2024-11-20T11:03:46.722218", "lvl": "target", "msg": "<6>[    0.131710] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)"}
- {"dt": "2024-11-20T11:03:46.722470", "lvl": "target", "msg": "<6>[    0.131987] CPU features: detected: Enhanced Privileged Access Never"}
- {"dt": "2024-11-20T11:03:46.722718", "lvl": "target", "msg": "<6>[    0.132239] CPU features: detected: Enhanced Virtualization Traps"}
- {"dt": "2024-11-20T11:03:46.722959", "lvl": "target", "msg": "<6>[    0.132488] CPU features: detected: Fine Grained Traps"}
- {"dt": "2024-11-20T11:03:46.723304", "lvl": "target", "msg": "<6>[    0.132792] CPU features: detected: Generic authentication (IMP DEF algorithm)"}
- {"dt": "2024-11-20T11:03:46.723634", "lvl": "target", "msg": "<6>[    0.133159] CPU features: detected: RCpc load-acquire (LDAPR)"}
- {"dt": "2024-11-20T11:03:46.723903", "lvl": "target", "msg": "<6>[    0.133411] CPU features: detected: LSE atomic instructions"}
- {"dt": "2024-11-20T11:03:46.724668", "lvl": "target", "msg": "<6>[    0.133965] CPU features: detected: Memory Copy and Memory Set instructions"}
- {"dt": "2024-11-20T11:03:46.724919", "lvl": "target", "msg": "<6>[    0.134287] CPU features: detected: Privileged Access Never"}
- {"dt": "2024-11-20T11:03:46.725017", "lvl": "target", "msg": "<6>[    0.134565] CPU features: detected: RAS Extension Support"}
- {"dt": "2024-11-20T11:03:46.725298", "lvl": "target", "msg": "<6>[    0.134804] CPU features: detected: Random Number Generator"}
- {"dt": "2024-11-20T11:03:46.725536", "lvl": "target", "msg": "<6>[    0.135060] CPU features: detected: Speculation barrier (SB)"}
- {"dt": "2024-11-20T11:03:46.725779", "lvl": "target", "msg": "<6>[    0.135304] CPU features: detected: Stage-2 Force Write-Back"}
- {"dt": "2024-11-20T11:03:46.726075", "lvl": "target", "msg": "<6>[    0.135548] CPU features: detected: Trap EL0 IMPLEMENTATION DEFINED functionality"}
- {"dt": "2024-11-20T11:03:46.726344", "lvl": "target", "msg": "<6>[    0.135844] CPU features: detected: TLB range maintenance instructions"}
- {"dt": "2024-11-20T11:03:46.726604", "lvl": "target", "msg": "<6>[    0.136112] CPU features: detected: WFx with timeout"}
- {"dt": "2024-11-20T11:03:46.726782", "lvl": "target", "msg": "<6>[    0.136336] CPU features: detected: VHE for hypervisor only"}
- {"dt": "2024-11-20T11:03:46.727033", "lvl": "target", "msg": "<6>[    0.136564] CPU features: detected: Protected KVM"}
- {"dt": "2024-11-20T11:03:46.727220", "lvl": "target", "msg": "<6>[    0.136745] CPU features: detected: Speculative Store Bypassing Safe (SSBS)"}
- {"dt": "2024-11-20T11:03:46.727421", "lvl": "target", "msg": "<6>[    0.136982] CPU features: detected: Scalable Vector Extension"}
- {"dt": "2024-11-20T11:03:46.739814", "lvl": "target", "msg": "<6>[    0.146825] alternatives: applying system-wide alternatives"}
- {"dt": "2024-11-20T11:03:46.750717", "lvl": "target", "msg": "<6>[    0.159742] CPU features: detected: Hardware dirty bit management on CPU0-1"}
- {"dt": "2024-11-20T11:03:46.751162", "lvl": "target", "msg": "<6>[    0.160661] SVE: maximum available vector length 256 bytes per vector"}
- {"dt": "2024-11-20T11:03:46.751422", "lvl": "target", "msg": "<6>[    0.160932] SVE: default vector length 64 bytes per vector"}
- {"dt": "2024-11-20T11:03:46.753297", "lvl": "target", "msg": "**"}
- {"dt": "2024-11-20T11:03:46.753383", "lvl": "target", "msg": "ERROR:target/arm/internals.h:959:regime_is_user: code should not be reached"}
- {"dt": "2024-11-20T11:03:46.753460", "lvl": "target", "msg": "Bail out! ERROR:target/arm/internals.h:959:regime_is_user: code should not be reached"}
- {"dt": "2024-11-20T11:03:46.756680", "lvl": "exception", "msg": "Connection closed"}
- {"dt": "2024-11-20T11:03:46.756773", "lvl": "debug", "msg": "end: 2.2.1 login-action (duration 00:00:01) [common]"}
- {"dt": "2024-11-20T11:03:46.756850", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "login-action", "level": "2.2.1", "duration": "1.30", "result": "fail", "extra": {"fail": "Connection closed"}}}
- {"dt": "2024-11-20T11:03:46.756969", "lvl": "error", "msg": "auto-login-action failed: 1 of 1 attempts. 'Connection closed'"}
- {"dt": "2024-11-20T11:03:46.757057", "lvl": "exception", "msg": "Connection closed"}
- {"dt": "2024-11-20T11:03:46.757120", "lvl": "debug", "msg": "end: 2.2 auto-login-action (duration 00:00:01) [common]"}
- {"dt": "2024-11-20T11:03:46.757191", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "auto-login-action", "level": "2.2", "duration": "1.42", "result": "fail", "extra": {"fail": "Connection closed"}}}
- {"dt": "2024-11-20T11:03:46.757309", "lvl": "error", "msg": "boot-image-retry failed: 1 of 1 attempts. 'Connection closed'"}
- {"dt": "2024-11-20T11:03:46.757391", "lvl": "exception", "msg": "Connection closed"}
- {"dt": "2024-11-20T11:03:46.757441", "lvl": "info", "msg": "end: 2 boot-image-retry (duration 00:00:01) [common]"}
- {"dt": "2024-11-20T11:03:46.757501", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "boot-image-retry", "level": "2", "duration": "1.42", "result": "fail", "extra": {"fail": "Connection closed"}}}
- {"dt": "2024-11-20T11:03:46.757628", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-11-20T11:03:46.757719", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/url-repo-action-j78ii7ri/url_repo"}
- {"dt": "2024-11-20T11:03:46.765968", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/kernel"}
- {"dt": "2024-11-20T11:03:46.774167", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs"}
- {"dt": "2024-11-20T11:03:46.956117", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs.modules"}
- {"dt": "2024-11-20T11:03:46.968359", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1/deployimages-wau6da78/rootfs.overlay-00"}
- {"dt": "2024-11-20T11:03:46.970697", "lvl": "debug", "msg": "start: 4.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2024-11-20T11:03:46.970794", "lvl": "debug", "msg": "end: 4.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:46.970874", "lvl": "debug", "msg": "start: 4.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2024-11-20T11:03:46.971048", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2024-11-20T11:03:46.971144", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2024-11-20T11:03:47.071329", "lvl": "debug", "msg": "end: 4.2 read-feedback (duration 00:00:00) [common]"}
- {"dt": "2024-11-20T11:03:47.071445", "lvl": "info", "msg": "Removing root tmp directory at /var/lib/lava/dispatcher/tmp/tuxrun-199mz3u3-1"}
- {"dt": "2024-11-20T11:03:47.109071", "lvl": "error", "msg": "InfrastructureError: The Infrastructure is not working correctly. Please report this error to LAVA admins."}
- {"dt": "2024-11-20T11:03:47.109158", "lvl": "results", "msg": {"definition": "lava", "case": "job", "result": "fail", "error_msg": "Connection closed", "error_type": "Infrastructure"}}
