- {"dt": "2025-03-25T00:30:45.427257", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2024.09.dev0173"}
- {"dt": "2025-03-25T00:30:45.427344", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2025-03-25T00:30:45.427420", "lvl": "info", "msg": "Start time: 2025-03-25 00:30:45.427413+00:00 (UTC)"}
- {"dt": "2025-03-25T00:30:45.428448", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQXyscrgSHlaWB0Hp7reLPxB/Image.gz exists"}
- {"dt": "2025-03-25T00:30:45.771150", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2025-03-25T00:30:46.597656", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4.xz exists"}
- {"dt": "2025-03-25T00:30:46.597897", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQXyscrgSHlaWB0Hp7reLPxB/kselftest.tar.xz exists"}
- {"dt": "2025-03-25T00:30:46.729111", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2025-03-25T00:30:47.270863", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQXyscrgSHlaWB0Hp7reLPxB/modules.tar.xz exists"}
- {"dt": "2025-03-25T00:30:47.397701", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2025-03-25T00:30:47.997287", "lvl": "info", "msg": "qemu-system-arm, installed at version: 1:9.2.1+ds-1, host architecture: amd64"}
- {"dt": "2025-03-25T00:30:47.997532", "lvl": "warning", "msg": "Missing image arg for rootfs.kselftest"}
- {"dt": "2025-03-25T00:30:47.997617", "lvl": "warning", "msg": "Missing image arg for rootfs.modules"}
- {"dt": "2025-03-25T00:30:47.997777", "lvl": "info", "msg": "validate duration: 2.57"}
- {"dt": "2025-03-25T00:30:47.997837", "lvl": "results", "msg": {"definition": "lava", "case": "validate", "result": "pass"}}
- {"dt": "2025-03-25T00:30:47.997934", "lvl": "info", "msg": "start: 1 deployimages (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T00:30:47.997993", "lvl": "debug", "msg": "start: 1.1 lava-overlay (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T00:30:47.998187", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d"}
- {"dt": "2025-03-25T00:30:47.998335", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin"}
- {"dt": "2025-03-25T00:30:47.998445", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/tests"}
- {"dt": "2025-03-25T00:30:47.998542", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/results"}
- {"dt": "2025-03-25T00:30:47.998620", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-add-keys"}
- {"dt": "2025-03-25T00:30:47.998747", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-add-sources"}
- {"dt": "2025-03-25T00:30:47.998874", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-background-process-start"}
- {"dt": "2025-03-25T00:30:47.998996", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-background-process-stop"}
- {"dt": "2025-03-25T00:30:47.999119", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-common-functions"}
- {"dt": "2025-03-25T00:30:47.999236", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-echo-ipv4"}
- {"dt": "2025-03-25T00:30:47.999351", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-install-packages"}
- {"dt": "2025-03-25T00:30:47.999466", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-installed-packages"}
- {"dt": "2025-03-25T00:30:47.999581", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-os-build"}
- {"dt": "2025-03-25T00:30:47.999694", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-probe-channel"}
- {"dt": "2025-03-25T00:30:47.999815", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-probe-ip"}
- {"dt": "2025-03-25T00:30:47.999936", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-target-ip"}
- {"dt": "2025-03-25T00:30:48.000053", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-target-mac"}
- {"dt": "2025-03-25T00:30:48.000170", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-target-storage"}
- {"dt": "2025-03-25T00:30:48.000288", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-test-case"}
- {"dt": "2025-03-25T00:30:48.000405", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-test-event"}
- {"dt": "2025-03-25T00:30:48.000519", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-test-feedback"}
- {"dt": "2025-03-25T00:30:48.000633", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-test-raise"}
- {"dt": "2025-03-25T00:30:48.000748", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-test-reference"}
- {"dt": "2025-03-25T00:30:48.000861", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-test-runner"}
- {"dt": "2025-03-25T00:30:48.000975", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-test-set"}
- {"dt": "2025-03-25T00:30:48.001088", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-test-shell"}
- {"dt": "2025-03-25T00:30:48.001203", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-install-packages (oe)"}
- {"dt": "2025-03-25T00:30:48.001369", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/bin/lava-installed-packages (oe)"}
- {"dt": "2025-03-25T00:30:48.001492", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/environment"}
- {"dt": "2025-03-25T00:30:48.001576", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2025-03-25T00:30:48.001626", "lvl": "debug", "msg": "- LAVA_JOB_ID=1"}
- {"dt": "2025-03-25T00:30:48.001670", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.32.138"}
- {"dt": "2025-03-25T00:30:48.001745", "lvl": "debug", "msg": "start: 1.1.1 lava-vland-overlay (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T00:30:48.001799", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2025-03-25T00:30:48.001853", "lvl": "debug", "msg": "end: 1.1.1 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:30:48.001913", "lvl": "debug", "msg": "start: 1.1.2 lava-multinode-overlay (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T00:30:48.001956", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2025-03-25T00:30:48.002006", "lvl": "debug", "msg": "end: 1.1.2 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:30:48.002060", "lvl": "debug", "msg": "start: 1.1.3 test-definition (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T00:30:48.002110", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2025-03-25T00:30:48.002172", "lvl": "debug", "msg": "start: 1.1.3.1 git-repo-action (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T00:30:48.002218", "lvl": "debug", "msg": "Using /lava-1 at stage 0"}
- {"dt": "2025-03-25T00:30:48.002286", "lvl": "info", "msg": "Fetching tests from https://github.com/TheodoreRTG/test-definitions.git"}
- {"dt": "2025-03-25T00:30:48.002343", "lvl": "debug", "msg": "Running '/usr/bin/git clone -b kselftest-logs --depth=1 https://github.com/TheodoreRTG/test-definitions.git /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/0/tests/0_kselftest-rtc'"}
- {"dt": "2025-03-25T00:30:50.963942", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/0/tests/0_kselftest-rtc/automated/linux/kselftest/kselftest.yaml"}
- {"dt": "2025-03-25T00:30:50.964428", "lvl": "debug", "msg": "uuid=1_1.1.3.1 testdef=None"}
- {"dt": "2025-03-25T00:30:50.964518", "lvl": "debug", "msg": "end: 1.1.3.1 git-repo-action (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T00:30:50.964573", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "git-repo-action", "level": "1.1.3.1", "duration": "2.96", "result": "pass", "extra": {"commit": "450111580e70664ab07b21744eff0a1147707c44", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "path": "automated/linux/kselftest/kselftest.yaml"}}}
- {"dt": "2025-03-25T00:30:50.964678", "lvl": "debug", "msg": "start: 1.1.3.2 test-overlay (timeout 00:14:57) [common]"}
- {"dt": "2025-03-25T00:30:50.965288", "lvl": "debug", "msg": "end: 1.1.3.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:30:50.965342", "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": "kselftest-rtc", "path": "automated/linux/kselftest/kselftest.yaml", "from": "git", "repository": "https://github.com/TheodoreRTG/test-definitions.git"}}}
- {"dt": "2025-03-25T00:30:50.965451", "lvl": "debug", "msg": "start: 1.1.3.3 test-install-overlay (timeout 00:14:57) [common]"}
- {"dt": "2025-03-25T00:30:50.966328", "lvl": "debug", "msg": "end: 1.1.3.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:30:50.966385", "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": "kselftest-rtc", "path": "automated/linux/kselftest/kselftest.yaml", "from": "git", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "skipped test-install-overlay": "1_1.1.3.1"}}}
- {"dt": "2025-03-25T00:30:50.966496", "lvl": "debug", "msg": "start: 1.1.3.4 test-runscript-overlay (timeout 00:14:57) [common]"}
- {"dt": "2025-03-25T00:30:50.967417", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/0/tests/0_kselftest-rtc test_uuid 1_1.1.3.1"}
- {"dt": "2025-03-25T00:30:50.967521", "lvl": "debug", "msg": "TST_CMDFILES='rtc'"}
- {"dt": "2025-03-25T00:30:50.967596", "lvl": "debug", "msg": "KSELFTEST_PATH='/opt/kselftests/default-in-kernel'"}
- {"dt": "2025-03-25T00:30:50.967654", "lvl": "debug", "msg": "SKIPFILE='skipfile-lkft.yaml'"}
- {"dt": "2025-03-25T00:30:50.967707", "lvl": "debug", "msg": "ENVIRONMENT='production'"}
- {"dt": "2025-03-25T00:30:50.967759", "lvl": "debug", "msg": "SHARD_NUMBER='1'"}
- {"dt": "2025-03-25T00:30:50.967811", "lvl": "debug", "msg": "SHARD_INDEX='1'"}
- {"dt": "2025-03-25T00:30:50.967995", "lvl": "debug", "msg": "end: 1.1.3.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:30:50.968076", "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": "kselftest-rtc", "path": "automated/linux/kselftest/kselftest.yaml", "from": "git", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "filename": "/var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/0/tests/0_kselftest-rtc/run.sh"}}}
- {"dt": "2025-03-25T00:30:50.968218", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2025-03-25T00:30:50.968281", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/lava-overlay-sdak0v2d/lava-1/0 for stage 0"}
- {"dt": "2025-03-25T00:30:50.968384", "lvl": "debug", "msg": "- 0_kselftest-rtc"}
- {"dt": "2025-03-25T00:30:50.968465", "lvl": "debug", "msg": "end: 1.1.3 test-definition (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T00:30:50.968527", "lvl": "debug", "msg": "start: 1.1.4 compress-overlay (timeout 00:14:57) [common]"}
- {"dt": "2025-03-25T00:30:57.258430", "lvl": "debug", "msg": "end: 1.1.4 compress-overlay (duration 00:00:06) [common]"}
- {"dt": "2025-03-25T00:30:57.258603", "lvl": "debug", "msg": "end: 1.1 lava-overlay (duration 00:00:09) [common]"}
- {"dt": "2025-03-25T00:30:57.258676", "lvl": "debug", "msg": "start: 1.2 apply-overlay-guest (timeout 00:14:51) [common]"}
- {"dt": "2025-03-25T00:30:57.258728", "lvl": "debug", "msg": "Overlay already applied"}
- {"dt": "2025-03-25T00:30:57.258782", "lvl": "debug", "msg": "end: 1.2 apply-overlay-guest (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:30:57.258850", "lvl": "debug", "msg": "start: 1.3 deploy-device-env (timeout 00:14:51) [common]"}
- {"dt": "2025-03-25T00:30:57.258905", "lvl": "debug", "msg": "end: 1.3 deploy-device-env (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:30:57.258960", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:14:51) [common]"}
- {"dt": "2025-03-25T00:30:57.259017", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T00:30:57.259203", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQXyscrgSHlaWB0Hp7reLPxB/Image.gz"}
- {"dt": "2025-03-25T00:30:57.259260", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/kernel/Image"}
- {"dt": "2025-03-25T00:30:57.259306", "lvl": "debug", "msg": "total size: 14769955 (14\u202FMB)"}
- {"dt": "2025-03-25T00:30:57.259351", "lvl": "info", "msg": "Using gunzip to decompress gz"}
- {"dt": "2025-03-25T00:30:58.150640", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T00:30:58.531161", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T00:30:58.634584", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2025-03-25T00:30:58.735861", "lvl": "debug", "msg": "progress  15\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T00:30:58.839744", "lvl": "debug", "msg": "progress  21\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T00:30:58.941097", "lvl": "debug", "msg": "progress  27\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.041153", "lvl": "debug", "msg": "progress  32\u202F% (4\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.143070", "lvl": "debug", "msg": "progress  38\u202F% (5\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.243562", "lvl": "debug", "msg": "progress  44\u202F% (6\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.347637", "lvl": "debug", "msg": "progress  50\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.448671", "lvl": "debug", "msg": "progress  55\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.549525", "lvl": "debug", "msg": "progress  61\u202F% (8\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.652742", "lvl": "debug", "msg": "progress  67\u202F% (9\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.754881", "lvl": "debug", "msg": "progress  72\u202F% (10\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.858808", "lvl": "debug", "msg": "progress  78\u202F% (11\u202FMB)"}
- {"dt": "2025-03-25T00:30:59.960296", "lvl": "debug", "msg": "progress  84\u202F% (11\u202FMB)"}
- {"dt": "2025-03-25T00:31:00.063059", "lvl": "debug", "msg": "progress  89\u202F% (12\u202FMB)"}
- {"dt": "2025-03-25T00:31:00.164433", "lvl": "debug", "msg": "progress  95\u202F% (13\u202FMB)"}
- {"dt": "2025-03-25T00:31:00.240247", "lvl": "info", "msg": "14\u202FMB downloaded in 2.98\u202Fs (4.73\u202FMB/s)"}
- {"dt": "2025-03-25T00:31:00.240446", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T00:31:00.240546", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.4.1", "duration": "2.98", "result": "pass", "extra": {"label": "kernel", "size": ! "14769955", "sha256sum": "afa7db045f365288f5f33d688877cfb265b08fa4adb0f0c703a6ba501bbd0302"}}}
- {"dt": "2025-03-25T00:31:00.240726", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T00:31:00.240830", "lvl": "debug", "msg": "start: 1.5 download-retry (timeout 00:14:48) [common]"}
- {"dt": "2025-03-25T00:31:00.240930", "lvl": "debug", "msg": "start: 1.5.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T00:31:00.241134", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4.xz"}
- {"dt": "2025-03-25T00:31:00.241192", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4"}
- {"dt": "2025-03-25T00:31:00.241245", "lvl": "debug", "msg": "total size: 111407012 (106\u202FMB)"}
- {"dt": "2025-03-25T00:31:00.241297", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-03-25T00:31:00.341722", "lvl": "debug", "msg": "progress   2\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T00:31:00.510412", "lvl": "debug", "msg": "progress   7\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T00:31:00.685856", "lvl": "debug", "msg": "progress  12\u202F% (12\u202FMB)"}
- {"dt": "2025-03-25T00:31:00.850932", "lvl": "debug", "msg": "progress  17\u202F% (18\u202FMB)"}
- {"dt": "2025-03-25T00:31:01.016016", "lvl": "debug", "msg": "progress  22\u202F% (23\u202FMB)"}
- {"dt": "2025-03-25T00:31:01.194346", "lvl": "debug", "msg": "progress  27\u202F% (28\u202FMB)"}
- {"dt": "2025-03-25T00:31:01.331843", "lvl": "debug", "msg": "progress  32\u202F% (34\u202FMB)"}
- {"dt": "2025-03-25T00:31:01.497617", "lvl": "debug", "msg": "progress  37\u202F% (39\u202FMB)"}
- {"dt": "2025-03-25T00:31:01.670321", "lvl": "debug", "msg": "progress  42\u202F% (44\u202FMB)"}
- {"dt": "2025-03-25T00:31:01.838031", "lvl": "debug", "msg": "progress  47\u202F% (49\u202FMB)"}
- {"dt": "2025-03-25T00:31:02.008596", "lvl": "debug", "msg": "progress  52\u202F% (55\u202FMB)"}
- {"dt": "2025-03-25T00:31:02.182349", "lvl": "debug", "msg": "progress  57\u202F% (60\u202FMB)"}
- {"dt": "2025-03-25T00:31:02.373255", "lvl": "debug", "msg": "progress  62\u202F% (65\u202FMB)"}
- {"dt": "2025-03-25T00:31:02.544280", "lvl": "debug", "msg": "progress  67\u202F% (71\u202FMB)"}
- {"dt": "2025-03-25T00:31:02.697793", "lvl": "debug", "msg": "progress  72\u202F% (76\u202FMB)"}
- {"dt": "2025-03-25T00:31:02.869598", "lvl": "debug", "msg": "progress  77\u202F% (81\u202FMB)"}
- {"dt": "2025-03-25T00:31:03.039658", "lvl": "debug", "msg": "progress  82\u202F% (87\u202FMB)"}
- {"dt": "2025-03-25T00:31:03.209500", "lvl": "debug", "msg": "progress  87\u202F% (92\u202FMB)"}
- {"dt": "2025-03-25T00:31:03.313304", "lvl": "debug", "msg": "progress  92\u202F% (97\u202FMB)"}
- {"dt": "2025-03-25T00:31:03.439913", "lvl": "debug", "msg": "progress  97\u202F% (103\u202FMB)"}
- {"dt": "2025-03-25T00:31:06.842880", "lvl": "info", "msg": "106\u202FMB downloaded in 6.60\u202Fs (16.09\u202FMB/s)"}
- {"dt": "2025-03-25T00:31:06.843131", "lvl": "debug", "msg": "end: 1.5.1 file-download (duration 00:00:07) [common]"}
- {"dt": "2025-03-25T00:31:06.843225", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.5.1", "duration": "6.60", "result": "pass", "extra": {"label": "rootfs", "size": ! "111407012", "sha256sum": "71bcc7bc8dbd4ac7d02d52aed8886662999d6e6c790f9b9e5220beaf580ccfc1"}}}
- {"dt": "2025-03-25T00:31:06.843391", "lvl": "debug", "msg": "start: 1.5.2 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T00:31:06.843481", "lvl": "debug", "msg": "start: 1.5.2.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-03-25T00:31:06.843674", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQXyscrgSHlaWB0Hp7reLPxB/kselftest.tar.xz"}
- {"dt": "2025-03-25T00:31:06.843728", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs.kselftest/kselftest.tar"}
- {"dt": "2025-03-25T00:31:06.843772", "lvl": "debug", "msg": "total size: 5347700 (5\u202FMB)"}
- {"dt": "2025-03-25T00:31:06.843815", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-03-25T00:31:07.447118", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T00:31:07.646412", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T00:31:07.750420", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T00:31:07.853078", "lvl": "debug", "msg": "progress  18\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T00:31:07.957734", "lvl": "debug", "msg": "progress  33\u202F% (1\u202FMB)"}
- {"dt": "2025-03-25T00:31:08.057896", "lvl": "debug", "msg": "progress  52\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T00:31:08.249483", "lvl": "debug", "msg": "progress  71\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T00:31:08.345768", "lvl": "info", "msg": "5\u202FMB downloaded in 1.50\u202Fs (3.40\u202FMB/s)"}
- {"dt": "2025-03-25T00:31:08.345986", "lvl": "debug", "msg": "end: 1.5.2.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T00:31:08.346071", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.5.2.1", "duration": "1.50", "result": "pass", "extra": {"label": "rootfs.kselftest", "size": ! "5347700", "sha256sum": "389b1b28bbef37f052209a087aa04574c4e75093494743437bc71175e0cd0a57"}}}
- {"dt": "2025-03-25T00:31:08.346225", "lvl": "debug", "msg": "end: 1.5.2 download-retry (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T00:31:08.346311", "lvl": "debug", "msg": "start: 1.5.3 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T00:31:08.346377", "lvl": "debug", "msg": "start: 1.5.3.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-03-25T00:31:08.346569", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQXyscrgSHlaWB0Hp7reLPxB/modules.tar.xz"}
- {"dt": "2025-03-25T00:31:08.346623", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs.modules/modules.tar"}
- {"dt": "2025-03-25T00:31:08.346667", "lvl": "debug", "msg": "total size: 11756424 (11\u202FMB)"}
- {"dt": "2025-03-25T00:31:08.346708", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-03-25T00:31:08.677036", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T00:31:08.829176", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T00:31:08.930741", "lvl": "debug", "msg": "progress  12\u202F% (1\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.033871", "lvl": "debug", "msg": "progress  25\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.137130", "lvl": "debug", "msg": "progress  34\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.239430", "lvl": "debug", "msg": "progress  44\u202F% (4\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.340651", "lvl": "debug", "msg": "progress  53\u202F% (5\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.441321", "lvl": "debug", "msg": "progress  62\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.543640", "lvl": "debug", "msg": "progress  71\u202F% (8\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.644946", "lvl": "debug", "msg": "progress  80\u202F% (9\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.747015", "lvl": "debug", "msg": "progress  88\u202F% (9\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.847216", "lvl": "debug", "msg": "progress  97\u202F% (10\u202FMB)"}
- {"dt": "2025-03-25T00:31:09.876719", "lvl": "info", "msg": "11\u202FMB downloaded in 1.53\u202Fs (7.33\u202FMB/s)"}
- {"dt": "2025-03-25T00:31:09.876862", "lvl": "debug", "msg": "end: 1.5.3.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T00:31:09.876919", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.5.3.1", "duration": "1.53", "result": "pass", "extra": {"label": "rootfs.modules", "size": ! "11756424", "sha256sum": "900fc1dfcf7120e4e57ce701811ff77a9b2a0ede0c7ba65bae533ae9d4f53e15"}}}
- {"dt": "2025-03-25T00:31:09.877024", "lvl": "debug", "msg": "end: 1.5.3 download-retry (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T00:31:09.877085", "lvl": "debug", "msg": "start: 1.5.4 append-overlays (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T00:31:09.877135", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4'"}
- {"dt": "2025-03-25T00:31:11.584551", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2025-03-25T00:31:11.585396", "lvl": "debug", "msg": "- rootfs.lava: '/var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/compress-overlay-94vf5lmj/overlay-1.1.4.tar.gz' to '/'"}
- {"dt": "2025-03-25T00:31:12.092170", "lvl": "debug", "msg": "- rootfs.kselftest: '/var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs.kselftest/kselftest.tar' to '/opt/kselftests/default-in-kernel/'"}
- {"dt": "2025-03-25T00:31:12.375663", "lvl": "debug", "msg": "- rootfs.modules: '/var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs.modules/modules.tar' to '/usr/'"}
- {"dt": "2025-03-25T00:31:12.830329", "lvl": "debug", "msg": "end: 1.5.4 append-overlays (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T00:31:12.830746", "lvl": "debug", "msg": "end: 1.5 download-retry (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T00:31:12.830834", "lvl": "info", "msg": "end: 1 deployimages (duration 00:00:25) [common]"}
- {"dt": "2025-03-25T00:31:12.830920", "lvl": "info", "msg": "start: 2 boot-image-retry (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T00:31:12.830991", "lvl": "debug", "msg": "start: 2.1 boot-qemu-image (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T00:31:12.831053", "lvl": "debug", "msg": "start: 2.1.1 execute-qemu (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T00:31:12.831300", "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-5_fdlez8-1/deployimages-23alfzoy/kernel/Image -append \"console=ttyAMA0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog systemd.log_level=warning rw earlycon\" -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4,format=raw,id=hd0,if=virtio"}
- {"dt": "2025-03-25T00:31:12.834480", "lvl": "debug", "msg": "started a shell command"}
- {"dt": "2025-03-25T00:31:12.834768", "lvl": "debug", "msg": "end: 2.1.1 execute-qemu (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:31:12.834865", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "execute-qemu", "level": "2.1.1", "duration": "0.00", "result": "pass", "extra": {"qemu_version": "1:9.2.1+ds-1", "host_arch": "amd64", "job_arch": "arm64"}}}
- {"dt": "2025-03-25T00:31:12.835042", "lvl": "debug", "msg": "end: 2.1 boot-qemu-image (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:31:12.835156", "lvl": "debug", "msg": "start: 2.2 auto-login-action (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T00:31:12.835263", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2025-03-25T00:31:12.835350", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:30:00)"}
- {"dt": "2025-03-25T00:31:12.947101", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x000f0510]"}
- {"dt": "2025-03-25T00:31:12.947462", "lvl": "target", "msg": "[    0.000000] Linux version 6.14.0-rc7-next-20250324 (tuxmake@tuxmake) (Debian clang version 20.1.0 (++20250225053057+098492a228f7-1~exp1~20250225053219.63), Debian LLD 20.1.0) #1 SMP PREEMPT @1742818530"}
- {"dt": "2025-03-25T00:31:12.947558", "lvl": "target", "msg": "[    0.000000] KASLR enabled"}
- {"dt": "2025-03-25T00:31:12.947644", "lvl": "target", "msg": "[    0.000000] random: crng init done"}
- {"dt": "2025-03-25T00:31:12.947715", "lvl": "target", "msg": "[    0.000000] Machine model: linux,dummy-virt"}
- {"dt": "2025-03-25T00:31:12.947785", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2025-03-25T00:31:12.947935", "lvl": "target", "msg": "[    0.000000] earlycon: pl11 at MMIO 0x0000000009000000 (options '')"}
- {"dt": "2025-03-25T00:31:12.948073", "lvl": "target", "msg": "[    0.000000] printk: legacy bootconsole [pl11] enabled"}
- {"dt": "2025-03-25T00:31:12.948337", "lvl": "debug", "msg": "start: 2.2.1 login-action (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T00:31:12.948406", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2025-03-25T00:31:12.948480", "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": "2025-03-25T00:31:12.948554", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2025-03-25T00:31:12.948610", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2025-03-25T00:31:12.948670", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2025-03-25T00:31:12.948714", "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": "2025-03-25T00:31:12.948799", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:30:00)"}
- {"dt": "2025-03-25T00:31:12.948847", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:15:00)"}
- {"dt": "2025-03-25T00:31:12.949234", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT"}
- {"dt": "2025-03-25T00:31:12.952090", "lvl": "target", "msg": "[    0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T00:31:12.952880", "lvl": "target", "msg": "[    0.000000] NODE_DATA(0) allocated [mem 0x13f7f9000-0x13f7fb77f]"}
- {"dt": "2025-03-25T00:31:12.955328", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2025-03-25T00:31:12.955853", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000040000000-0x00000000ffffffff]"}
- {"dt": "2025-03-25T00:31:12.955962", "lvl": "target", "msg": "[    0.000000]   DMA32    empty"}
- {"dt": "2025-03-25T00:31:12.956080", "lvl": "target", "msg": "[    0.000000]   Normal   [mem 0x0000000100000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T00:31:12.956194", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2025-03-25T00:31:12.956325", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2025-03-25T00:31:12.956503", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T00:31:12.956869", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T00:31:12.983812", "lvl": "target", "msg": "[    0.000000] cma: Reserved 32 MiB at 0x0000000000000000"}
- {"dt": "2025-03-25T00:31:12.984683", "lvl": "target", "msg": "[    0.000000] psci: probing for conduit method from DT."}
- {"dt": "2025-03-25T00:31:12.984858", "lvl": "target", "msg": "[    0.000000] psci: PSCIv1.1 detected in firmware."}
- {"dt": "2025-03-25T00:31:12.985014", "lvl": "target", "msg": "[    0.000000] psci: Using standard PSCI v0.2 function IDs"}
- {"dt": "2025-03-25T00:31:12.985290", "lvl": "target", "msg": "[    0.000000] psci: Trusted OS migration not required"}
- {"dt": "2025-03-25T00:31:12.985389", "lvl": "target", "msg": "[    0.000000] psci: SMC Calling Convention v1.0"}
- {"dt": "2025-03-25T00:31:12.987658", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 25 pages/cpu s62680 r8192 d31528 u102400"}
- {"dt": "2025-03-25T00:31:12.988147", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: s62680 r8192 d31528 u102400 alloc=25*4096"}
- {"dt": "2025-03-25T00:31:12.988385", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: [0] 0 [0] 1 "}
- {"dt": "2025-03-25T00:31:12.989533", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2025-03-25T00:31:12.990976", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Branch Target Identification"}
- {"dt": "2025-03-25T00:31:12.991198", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Address authentication (IMP DEF algorithm)"}
- {"dt": "2025-03-25T00:31:12.991405", "lvl": "target", "msg": "[    0.000000] CPU features: detected: GIC system register CPU interface"}
- {"dt": "2025-03-25T00:31:12.991567", "lvl": "target", "msg": "[    0.000000] CPU features: detected: HCRX_EL2 register"}
- {"dt": "2025-03-25T00:31:12.991752", "lvl": "target", "msg": "[    0.000000] CPU features: detected: 52-bit Virtual Addressing (LPA2)"}
- {"dt": "2025-03-25T00:31:12.991910", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Virtualization Host Extensions"}
- {"dt": "2025-03-25T00:31:12.992091", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Memory Tagging Extension"}
- {"dt": "2025-03-25T00:31:12.992248", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Asymmetric MTE Tag Check Fault"}
- {"dt": "2025-03-25T00:31:12.992519", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v4"}
- {"dt": "2025-03-25T00:31:12.995706", "lvl": "target", "msg": "[    0.000000] alternatives: applying boot alternatives"}
- {"dt": "2025-03-25T00:31:12.998386", "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 earlycon"}
- {"dt": "2025-03-25T00:31:13.000427", "lvl": "target", "msg": "<5>[    0.000000] Unknown kernel command line parameters \"verbose\", will be passed to user space."}
- {"dt": "2025-03-25T00:31:13.002906", "lvl": "target", "msg": "<6>[    0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes"}
- {"dt": "2025-03-25T00:31:13.005056", "lvl": "target", "msg": "<6>[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.006312", "lvl": "target", "msg": "<6>[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.006632", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: area num 2."}
- {"dt": "2025-03-25T00:31:13.057019", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: mapped [mem 0x00000000fa000000-0x00000000fe000000] (64MB)"}
- {"dt": "2025-03-25T00:31:13.058424", "lvl": "target", "msg": "<6>[    0.000000] Fallback order for Node 0: 0 "}
- {"dt": "2025-03-25T00:31:13.058491", "lvl": "target", "msg": "<6>[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1048576"}
- {"dt": "2025-03-25T00:31:13.058579", "lvl": "target", "msg": "<6>[    0.000000] Policy zone: Normal"}
- {"dt": "2025-03-25T00:31:13.059115", "lvl": "target", "msg": "<6>[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off"}
- {"dt": "2025-03-25T00:31:13.078772", "lvl": "target", "msg": "<6>[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1"}
- {"dt": "2025-03-25T00:31:13.085628", "lvl": "target", "msg": "<6>[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2025-03-25T00:31:13.085717", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2025-03-25T00:31:13.085864", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=2."}
- {"dt": "2025-03-25T00:31:13.086175", "lvl": "target", "msg": "<6>[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2025-03-25T00:31:13.086288", "lvl": "target", "msg": "<6>[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2025-03-25T00:31:13.086610", "lvl": "target", "msg": "<6>[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2025-03-25T00:31:13.086852", "lvl": "target", "msg": "<6>[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2"}
- {"dt": "2025-03-25T00:31:13.088138", "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": "2025-03-25T00:31:13.088413", "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": "2025-03-25T00:31:13.088754", "lvl": "target", "msg": "<6>[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2025-03-25T00:31:13.094316", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GIC: Using split EOI/Deactivate mode"}
- {"dt": "2025-03-25T00:31:13.094514", "lvl": "target", "msg": "<6>[    0.000000] GICv3: 256 SPIs implemented"}
- {"dt": "2025-03-25T00:31:13.094657", "lvl": "target", "msg": "<6>[    0.000000] GICv3: 0 Extended SPIs implemented"}
- {"dt": "2025-03-25T00:31:13.096161", "lvl": "target", "msg": "<6>[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2025-03-25T00:31:13.096323", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GICv3 features: 16 PPIs"}
- {"dt": "2025-03-25T00:31:13.096635", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GICD_CTRL.DS=1, SCR_EL3.FIQ=0"}
- {"dt": "2025-03-25T00:31:13.097196", "lvl": "target", "msg": "<6>[    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000"}
- {"dt": "2025-03-25T00:31:13.102071", "lvl": "target", "msg": "<6>[    0.000000] ITS [mem 0x08080000-0x0809ffff]"}
- {"dt": "2025-03-25T00:31:13.102906", "lvl": "target", "msg": "<6>[    0.000000] ITS@0x0000000008080000: allocated 8192 Devices @100050000 (indirect, esz 8, psz 64K, shr 1)"}
- {"dt": "2025-03-25T00:31:13.103311", "lvl": "target", "msg": "<6>[    0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @100060000 (flat, esz 8, psz 64K, shr 1)"}
- {"dt": "2025-03-25T00:31:13.104169", "lvl": "target", "msg": "<6>[    0.000000] GICv3: using LPI property table @0x0000000100070000"}
- {"dt": "2025-03-25T00:31:13.104925", "lvl": "target", "msg": "<6>[    0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000100080000"}
- {"dt": "2025-03-25T00:31:13.106881", "lvl": "target", "msg": "<6>[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention."}
- {"dt": "2025-03-25T00:31:13.112999", "lvl": "target", "msg": "<6>[    0.000000] arch_timer: cp15 timer(s) running at 1000.00MHz (phys)."}
- {"dt": "2025-03-25T00:31:13.113499", "lvl": "target", "msg": "<6>[    0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns"}
- {"dt": "2025-03-25T00:31:13.114062", "lvl": "target", "msg": "<6>[    0.000047] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns"}
- {"dt": "2025-03-25T00:31:13.129421", "lvl": "target", "msg": "<6>[    0.013533] Console: colour dummy device 80x25"}
- {"dt": "2025-03-25T00:31:13.133041", "lvl": "target", "msg": "<6>[    0.018385] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)"}
- {"dt": "2025-03-25T00:31:13.133250", "lvl": "target", "msg": "<6>[    0.019393] pid_max: default: 32768 minimum: 301"}
- {"dt": "2025-03-25T00:31:13.135833", "lvl": "target", "msg": "<6>[    0.021782] LSM: initializing lsm=capability"}
- {"dt": "2025-03-25T00:31:13.138988", "lvl": "target", "msg": "<6>[    0.025000] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.139246", "lvl": "target", "msg": "<6>[    0.025283] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.166754", "lvl": "target", "msg": "<4>[    0.052770] cacheinfo: Unable to detect cache hierarchy for CPU 0"}
- {"dt": "2025-03-25T00:31:13.190644", "lvl": "target", "msg": "<6>[    0.076668] rcu: Hierarchical SRCU implementation."}
- {"dt": "2025-03-25T00:31:13.190735", "lvl": "target", "msg": "<6>[    0.076851] rcu: \tMax phase no-delay instances is 1000."}
- {"dt": "2025-03-25T00:31:13.192562", "lvl": "target", "msg": "<6>[    0.078580] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level"}
- {"dt": "2025-03-25T00:31:13.196347", "lvl": "target", "msg": "<6>[    0.082373] fsl-mc MSI: its@8080000 domain created"}
- {"dt": "2025-03-25T00:31:13.199178", "lvl": "target", "msg": "<6>[    0.085206] EFI services will not be available."}
- {"dt": "2025-03-25T00:31:13.201297", "lvl": "target", "msg": "<6>[    0.087353] smp: Bringing up secondary CPUs ..."}
- {"dt": "2025-03-25T00:31:13.213122", "lvl": "target", "msg": "<6>[    0.092173] Detected PIPT I-cache on CPU1"}
- {"dt": "2025-03-25T00:31:13.213459", "lvl": "target", "msg": "<6>[    0.093582] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000"}
- {"dt": "2025-03-25T00:31:13.213793", "lvl": "target", "msg": "<6>[    0.094299] GICv3: CPU1: using allocated LPI pending table @0x0000000100090000"}
- {"dt": "2025-03-25T00:31:13.213963", "lvl": "target", "msg": "<6>[    0.095979] CPU1: Booted secondary processor 0x0000000001 [0x000f0510]"}
- {"dt": "2025-03-25T00:31:13.214090", "lvl": "target", "msg": "<6>[    0.099106] smp: Brought up 1 node, 2 CPUs"}
- {"dt": "2025-03-25T00:31:13.214263", "lvl": "target", "msg": "<6>[    0.100424] SMP: Total of 2 processors activated."}
- {"dt": "2025-03-25T00:31:13.214436", "lvl": "target", "msg": "<6>[    0.100604] CPU: All CPU(s) started at EL2"}
- {"dt": "2025-03-25T00:31:13.214734", "lvl": "target", "msg": "<6>[    0.100865] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2025-03-25T00:31:13.214927", "lvl": "target", "msg": "<6>[    0.101069] CPU features: detected: 32-bit EL1 Support"}
- {"dt": "2025-03-25T00:31:13.215134", "lvl": "target", "msg": "<6>[    0.101247] CPU features: detected: ARMv8.4 Translation Table Level"}
- {"dt": "2025-03-25T00:31:13.215423", "lvl": "target", "msg": "<6>[    0.101459] CPU features: detected: Instruction cache invalidation not required for I/D coherence"}
- {"dt": "2025-03-25T00:31:13.215720", "lvl": "target", "msg": "<6>[    0.101750] CPU features: detected: Data cache clean to the PoU not required for I/D coherence"}
- {"dt": "2025-03-25T00:31:13.215957", "lvl": "target", "msg": "<6>[    0.102057] CPU features: detected: Common not Private translations"}
- {"dt": "2025-03-25T00:31:13.216139", "lvl": "target", "msg": "<6>[    0.102272] CPU features: detected: CRC32 instructions"}
- {"dt": "2025-03-25T00:31:13.216366", "lvl": "target", "msg": "<6>[    0.102455] CPU features: detected: Data independent timing control (DIT)"}
- {"dt": "2025-03-25T00:31:13.216506", "lvl": "target", "msg": "<6>[    0.102679] CPU features: detected: E0PD"}
- {"dt": "2025-03-25T00:31:13.216721", "lvl": "target", "msg": "<6>[    0.102820] CPU features: detected: Enhanced Counter Virtualization"}
- {"dt": "2025-03-25T00:31:13.216961", "lvl": "target", "msg": "<6>[    0.103036] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)"}
- {"dt": "2025-03-25T00:31:13.217170", "lvl": "target", "msg": "<6>[    0.103277] CPU features: detected: Enhanced Privileged Access Never"}
- {"dt": "2025-03-25T00:31:13.217374", "lvl": "target", "msg": "<6>[    0.103487] CPU features: detected: Enhanced Virtualization Traps"}
- {"dt": "2025-03-25T00:31:13.217680", "lvl": "target", "msg": "<6>[    0.103692] CPU features: detected: Fine Grained Traps"}
- {"dt": "2025-03-25T00:31:13.218180", "lvl": "target", "msg": "<6>[    0.104249] CPU features: detected: Generic authentication (IMP DEF algorithm)"}
- {"dt": "2025-03-25T00:31:13.218449", "lvl": "target", "msg": "<6>[    0.104555] CPU features: detected: RCpc load-acquire (LDAPR)"}
- {"dt": "2025-03-25T00:31:13.218716", "lvl": "target", "msg": "<6>[    0.104792] CPU features: detected: 52-bit Virtual Addressing for KVM (LPA2)"}
- {"dt": "2025-03-25T00:31:13.218893", "lvl": "target", "msg": "<6>[    0.105035] CPU features: detected: LSE atomic instructions"}
- {"dt": "2025-03-25T00:31:13.219122", "lvl": "target", "msg": "<6>[    0.105207] CPU features: detected: Memory Copy and Memory Set instructions"}
- {"dt": "2025-03-25T00:31:13.219310", "lvl": "target", "msg": "<6>[    0.105438] CPU features: detected: Privileged Access Never"}
- {"dt": "2025-03-25T00:31:13.219571", "lvl": "target", "msg": "<6>[    0.105662] CPU features: detected: PMUv3"}
- {"dt": "2025-03-25T00:31:13.219655", "lvl": "target", "msg": "<6>[    0.105791] CPU features: detected: RAS Extension Support"}
- {"dt": "2025-03-25T00:31:13.219842", "lvl": "target", "msg": "<6>[    0.105973] CPU features: detected: Random Number Generator"}
- {"dt": "2025-03-25T00:31:13.220029", "lvl": "target", "msg": "<6>[    0.106159] CPU features: detected: Speculation barrier (SB)"}
- {"dt": "2025-03-25T00:31:13.220214", "lvl": "target", "msg": "<6>[    0.106343] CPU features: detected: Stage-2 Force Write-Back"}
- {"dt": "2025-03-25T00:31:13.220462", "lvl": "target", "msg": "<6>[    0.106531] CPU features: detected: Trap EL0 IMPLEMENTATION DEFINED functionality"}
- {"dt": "2025-03-25T00:31:13.220681", "lvl": "target", "msg": "<6>[    0.106781] CPU features: detected: TLB range maintenance instructions"}
- {"dt": "2025-03-25T00:31:13.220859", "lvl": "target", "msg": "<6>[    0.106998] CPU features: detected: WFx with timeout"}
- {"dt": "2025-03-25T00:31:13.221157", "lvl": "target", "msg": "<6>[    0.107229] CPU features: detected: Speculative Store Bypassing Safe (SSBS)"}
- {"dt": "2025-03-25T00:31:13.221446", "lvl": "target", "msg": "<6>[    0.107474] CPU features: detected: Scalable Vector Extension"}
- {"dt": "2025-03-25T00:31:13.233971", "lvl": "target", "msg": "<6>[    0.117718] alternatives: applying system-wide alternatives"}
- {"dt": "2025-03-25T00:31:13.244775", "lvl": "target", "msg": "<6>[    0.130359] CPU features: detected: Hardware dirty bit management on CPU0-1"}
- {"dt": "2025-03-25T00:31:13.245173", "lvl": "target", "msg": "<6>[    0.131246] SVE: maximum available vector length 256 bytes per vector"}
- {"dt": "2025-03-25T00:31:13.245297", "lvl": "target", "msg": "<6>[    0.131443] SVE: default vector length 64 bytes per vector"}
- {"dt": "2025-03-25T00:31:13.256380", "lvl": "target", "msg": "<6>[    0.142291] Memory: 3969140K/4194304K available (18624K kernel code, 5288K rwdata, 12184K rodata, 2688K init, 750K bss, 188216K reserved, 32768K cma-reserved)"}
- {"dt": "2025-03-25T00:31:13.280512", "lvl": "target", "msg": "<6>[    0.166512] devtmpfs: initialized"}
- {"dt": "2025-03-25T00:31:13.307451", "lvl": "target", "msg": "<6>[    0.193398] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2025-03-25T00:31:13.307906", "lvl": "target", "msg": "<6>[    0.193980] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.308235", "lvl": "target", "msg": "<6>[    0.194305] futex hash table entries: 512 (order: 3, 32768 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.310290", "lvl": "target", "msg": "<6>[    0.196321] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL"}
- {"dt": "2025-03-25T00:31:13.310456", "lvl": "target", "msg": "<6>[    0.196539] 0 pages in range for non-PLT usage"}
- {"dt": "2025-03-25T00:31:13.313198", "lvl": "target", "msg": "<6>[    0.196602] 514336 pages in range for PLT usage"}
- {"dt": "2025-03-25T00:31:13.313284", "lvl": "target", "msg": "<6>[    0.199214] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2025-03-25T00:31:13.323127", "lvl": "target", "msg": "<6>[    0.209181] DMI not present or invalid."}
- {"dt": "2025-03-25T00:31:13.336423", "lvl": "target", "msg": "<6>[    0.222427] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2025-03-25T00:31:13.345053", "lvl": "target", "msg": "<6>[    0.231005] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations"}
- {"dt": "2025-03-25T00:31:13.345832", "lvl": "target", "msg": "<6>[    0.231802] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations"}
- {"dt": "2025-03-25T00:31:13.346619", "lvl": "target", "msg": "<6>[    0.232650] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations"}
- {"dt": "2025-03-25T00:31:13.347038", "lvl": "target", "msg": "<6>[    0.233155] audit: initializing netlink subsys (disabled)"}
- {"dt": "2025-03-25T00:31:13.348707", "lvl": "target", "msg": "<5>[    0.234774] audit: type=2000 audit(0.208:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2025-03-25T00:31:13.353256", "lvl": "target", "msg": "<6>[    0.239181] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2025-03-25T00:31:13.353987", "lvl": "target", "msg": "<6>[    0.239227] thermal_sys: Registered thermal governor 'power_allocator'"}
- {"dt": "2025-03-25T00:31:13.354343", "lvl": "target", "msg": "<6>[    0.240035] cpuidle: using governor menu"}
- {"dt": "2025-03-25T00:31:13.355777", "lvl": "target", "msg": "<6>[    0.241845] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2025-03-25T00:31:13.356654", "lvl": "target", "msg": "<6>[    0.242679] ASID allocator initialised with 65536 entries"}
- {"dt": "2025-03-25T00:31:13.364478", "lvl": "target", "msg": "<6>[    0.250506] Serial: AMBA PL011 UART driver"}
- {"dt": "2025-03-25T00:31:13.425546", "lvl": "target", "msg": "<6>[    0.311539] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 15, base_baud = 0) is a PL011 rev1"}
- {"dt": "2025-03-25T00:31:13.427688", "lvl": "target", "msg": "<6>[    0.313284] printk: console [ttyAMA0] enabled"}
- {"dt": "2025-03-25T00:31:13.428030", "lvl": "target", "msg": "<6>[    0.313284] printk: console [ttyAMA0] enabled"}
- {"dt": "2025-03-25T00:31:13.428397", "lvl": "target", "msg": "<6>[    0.314417] printk: legacy bootconsole [pl11] disabled"}
- {"dt": "2025-03-25T00:31:13.428483", "lvl": "target", "msg": "<6>[    0.314417] printk: legacy bootconsole [pl11] disabled"}
- {"dt": "2025-03-25T00:31:13.445743", "lvl": "target", "msg": "<6>[    0.331416] HugeTLB: allocation took 0ms with hugepage_allocation_threads=1"}
- {"dt": "2025-03-25T00:31:13.446074", "lvl": "target", "msg": "<6>[    0.331698] HugeTLB: allocation took 0ms with hugepage_allocation_threads=1"}
- {"dt": "2025-03-25T00:31:13.446346", "lvl": "target", "msg": "<6>[    0.332031] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T00:31:13.446750", "lvl": "target", "msg": "<6>[    0.332047] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page"}
- {"dt": "2025-03-25T00:31:13.446852", "lvl": "target", "msg": "<6>[    0.332106] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T00:31:13.447104", "lvl": "target", "msg": "<6>[    0.332134] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page"}
- {"dt": "2025-03-25T00:31:13.447378", "lvl": "target", "msg": "<6>[    0.332159] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T00:31:13.447628", "lvl": "target", "msg": "<6>[    0.332171] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page"}
- {"dt": "2025-03-25T00:31:13.447907", "lvl": "target", "msg": "<6>[    0.332187] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T00:31:13.448294", "lvl": "target", "msg": "<6>[    0.332210] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page"}
- {"dt": "2025-03-25T00:31:13.457020", "lvl": "target", "msg": "<6>[    0.342936] ACPI: Interpreter disabled."}
- {"dt": "2025-03-25T00:31:13.466171", "lvl": "target", "msg": "<6>[    0.352107] iommu: Default domain type: Translated"}
- {"dt": "2025-03-25T00:31:13.466271", "lvl": "target", "msg": "<6>[    0.352187] iommu: DMA domain TLB invalidation policy: strict mode"}
- {"dt": "2025-03-25T00:31:13.467802", "lvl": "target", "msg": "<5>[    0.353807] SCSI subsystem initialized"}
- {"dt": "2025-03-25T00:31:13.468706", "lvl": "target", "msg": "<7>[    0.354688] libata version 3.00 loaded."}
- {"dt": "2025-03-25T00:31:13.469957", "lvl": "target", "msg": "<6>[    0.355923] usbcore: registered new interface driver usbfs"}
- {"dt": "2025-03-25T00:31:13.470110", "lvl": "target", "msg": "<6>[    0.356145] usbcore: registered new interface driver hub"}
- {"dt": "2025-03-25T00:31:13.470565", "lvl": "target", "msg": "<6>[    0.356269] usbcore: registered new device driver usb"}
- {"dt": "2025-03-25T00:31:13.473087", "lvl": "target", "msg": "<6>[    0.359033] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2025-03-25T00:31:13.473526", "lvl": "target", "msg": "<6>[    0.359092] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2025-03-25T00:31:13.473718", "lvl": "target", "msg": "<6>[    0.359193] PTP clock support registered"}
- {"dt": "2025-03-25T00:31:13.473898", "lvl": "target", "msg": "<6>[    0.359669] EDAC MC: Ver: 3.0.0"}
- {"dt": "2025-03-25T00:31:13.475187", "lvl": "target", "msg": "<6>[    0.361156] scmi_core: SCMI protocol bus registered"}
- {"dt": "2025-03-25T00:31:13.478582", "lvl": "target", "msg": "<6>[    0.364501] FPGA manager framework"}
- {"dt": "2025-03-25T00:31:13.479199", "lvl": "target", "msg": "<6>[    0.365189] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2025-03-25T00:31:13.488444", "lvl": "target", "msg": "<6>[    0.374411] vgaarb: loaded"}
- {"dt": "2025-03-25T00:31:13.490527", "lvl": "target", "msg": "<6>[    0.376480] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2025-03-25T00:31:13.493291", "lvl": "target", "msg": "<5>[    0.379134] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2025-03-25T00:31:13.493546", "lvl": "target", "msg": "<6>[    0.379254] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2025-03-25T00:31:13.495394", "lvl": "target", "msg": "<6>[    0.381092] pnp: PnP ACPI: disabled"}
- {"dt": "2025-03-25T00:31:13.524285", "lvl": "target", "msg": "<6>[    0.410195] NET: Registered PF_INET protocol family"}
- {"dt": "2025-03-25T00:31:13.525211", "lvl": "target", "msg": "<6>[    0.411148] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.530381", "lvl": "target", "msg": "<6>[    0.415973] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.530478", "lvl": "target", "msg": "<6>[    0.416066] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.530765", "lvl": "target", "msg": "<6>[    0.416211] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.531025", "lvl": "target", "msg": "<6>[    0.416718] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.531245", "lvl": "target", "msg": "<6>[    0.417259] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2025-03-25T00:31:13.532099", "lvl": "target", "msg": "<6>[    0.418078] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.532347", "lvl": "target", "msg": "<6>[    0.418402] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear)"}
- {"dt": "2025-03-25T00:31:13.533205", "lvl": "target", "msg": "<6>[    0.419214] NET: Registered PF_UNIX/PF_LOCAL protocol family"}
- {"dt": "2025-03-25T00:31:13.535498", "lvl": "target", "msg": "<6>[    0.421386] RPC: Registered named UNIX socket transport module."}
- {"dt": "2025-03-25T00:31:13.535615", "lvl": "target", "msg": "<6>[    0.421455] RPC: Registered udp transport module."}
- {"dt": "2025-03-25T00:31:13.535723", "lvl": "target", "msg": "<6>[    0.421477] RPC: Registered tcp transport module."}
- {"dt": "2025-03-25T00:31:13.536123", "lvl": "target", "msg": "<6>[    0.421487] RPC: Registered tcp-with-tls transport module."}
- {"dt": "2025-03-25T00:31:13.536179", "lvl": "target", "msg": "<6>[    0.421503] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2025-03-25T00:31:13.536439", "lvl": "target", "msg": "<6>[    0.421603] PCI: CLS 0 bytes, default 64"}
- {"dt": "2025-03-25T00:31:13.546710", "lvl": "target", "msg": "<6>[    0.432622] kvm [1]: nv: 566 coarse grained trap handlers"}
- {"dt": "2025-03-25T00:31:13.547810", "lvl": "target", "msg": "<6>[    0.433769] kvm [1]: nv: 669 fine grained trap handlers"}
- {"dt": "2025-03-25T00:31:13.548951", "lvl": "target", "msg": "<6>[    0.434930] kvm [1]: IPA Size Limit: 52 bits"}
- {"dt": "2025-03-25T00:31:13.550133", "lvl": "target", "msg": "<6>[    0.435784] kvm [1]: GICv3: no GICV resource entry"}
- {"dt": "2025-03-25T00:31:13.550654", "lvl": "target", "msg": "<6>[    0.435967] kvm [1]: disabling GICv2 emulation"}
- {"dt": "2025-03-25T00:31:13.551049", "lvl": "target", "msg": "<6>[    0.436988] kvm [1]: GIC system register CPU interface enabled"}
- {"dt": "2025-03-25T00:31:13.551925", "lvl": "target", "msg": "<6>[    0.437866] kvm [1]: vgic interrupt IRQ9"}
- {"dt": "2025-03-25T00:31:13.552636", "lvl": "target", "msg": "<6>[    0.438574] kvm [1]: VHE mode initialized successfully"}
- {"dt": "2025-03-25T00:31:13.557640", "lvl": "target", "msg": "<5>[    0.443554] Initialise system trusted keyrings"}
- {"dt": "2025-03-25T00:31:13.559448", "lvl": "target", "msg": "<6>[    0.445245] workingset: timestamp_bits=42 max_order=20 bucket_order=0"}
- {"dt": "2025-03-25T00:31:13.561404", "lvl": "target", "msg": "<6>[    0.447293] squashfs: version 4.0 (2009/01/31) Phillip Lougher"}
- {"dt": "2025-03-25T00:31:13.563114", "lvl": "target", "msg": "<5>[    0.449072] NFS: Registering the id_resolver key type"}
- {"dt": "2025-03-25T00:31:13.563431", "lvl": "target", "msg": "<5>[    0.449336] Key type id_resolver registered"}
- {"dt": "2025-03-25T00:31:13.563509", "lvl": "target", "msg": "<5>[    0.449374] Key type id_legacy registered"}
- {"dt": "2025-03-25T00:31:13.563896", "lvl": "target", "msg": "<6>[    0.449621] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2025-03-25T00:31:13.563975", "lvl": "target", "msg": "<6>[    0.449684] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering..."}
- {"dt": "2025-03-25T00:31:13.564335", "lvl": "target", "msg": "<6>[    0.450374] 9p: Installing v9fs 9p2000 file system support"}
- {"dt": "2025-03-25T00:31:13.598300", "lvl": "target", "msg": "<5>[    0.484183] Key type asymmetric registered"}
- {"dt": "2025-03-25T00:31:13.598476", "lvl": "target", "msg": "<5>[    0.484565] Asymmetric key parser 'x509' registered"}
- {"dt": "2025-03-25T00:31:13.598843", "lvl": "target", "msg": "<6>[    0.484798] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)"}
- {"dt": "2025-03-25T00:31:13.598999", "lvl": "target", "msg": "<6>[    0.484933] io scheduler mq-deadline registered"}
- {"dt": "2025-03-25T00:31:13.599150", "lvl": "target", "msg": "<6>[    0.485007] io scheduler kyber registered"}
- {"dt": "2025-03-25T00:31:13.599461", "lvl": "target", "msg": "<6>[    0.485296] io scheduler bfq registered"}
- {"dt": "2025-03-25T00:31:13.627076", "lvl": "target", "msg": "<6>[    0.512969] pl061_gpio 9030000.pl061: PL061 GPIO chip registered"}
- {"dt": "2025-03-25T00:31:13.631359", "lvl": "target", "msg": "<6>[    0.517294] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2025-03-25T00:31:13.634743", "lvl": "target", "msg": "<6>[    0.520205] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:"}
- {"dt": "2025-03-25T00:31:13.635352", "lvl": "target", "msg": "<6>[    0.520846] pci-host-generic 4010000000.pcie:       IO 0x003eff0000..0x003effffff -> 0x0000000000"}
- {"dt": "2025-03-25T00:31:13.635507", "lvl": "target", "msg": "<6>[    0.521314] pci-host-generic 4010000000.pcie:      MEM 0x0010000000..0x003efeffff -> 0x0010000000"}
- {"dt": "2025-03-25T00:31:13.635806", "lvl": "target", "msg": "<6>[    0.521357] pci-host-generic 4010000000.pcie:      MEM 0x8000000000..0xffffffffff -> 0x8000000000"}
- {"dt": "2025-03-25T00:31:13.636079", "lvl": "target", "msg": "<4>[    0.521772] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits"}
- {"dt": "2025-03-25T00:31:13.636390", "lvl": "target", "msg": "<6>[    0.522145] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]"}
- {"dt": "2025-03-25T00:31:13.637340", "lvl": "target", "msg": "<6>[    0.523327] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2025-03-25T00:31:13.637617", "lvl": "target", "msg": "<6>[    0.523635] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2025-03-25T00:31:13.637962", "lvl": "target", "msg": "<6>[    0.523688] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]"}
- {"dt": "2025-03-25T00:31:13.638145", "lvl": "target", "msg": "<6>[    0.523740] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]"}
- {"dt": "2025-03-25T00:31:13.638708", "lvl": "target", "msg": "<6>[    0.523759] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]"}
- {"dt": "2025-03-25T00:31:13.639461", "lvl": "target", "msg": "<6>[    0.525098] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint"}
- {"dt": "2025-03-25T00:31:13.643134", "lvl": "target", "msg": "<6>[    0.528732] pci 0000:00:01.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint"}
- {"dt": "2025-03-25T00:31:13.643564", "lvl": "target", "msg": "<6>[    0.528991] pci 0000:00:01.0: BAR 0 [io  0x0000-0x007f]"}
- {"dt": "2025-03-25T00:31:13.643993", "lvl": "target", "msg": "<6>[    0.529037] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]"}
- {"dt": "2025-03-25T00:31:13.644436", "lvl": "target", "msg": "<6>[    0.529083] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]"}
- {"dt": "2025-03-25T00:31:13.647257", "lvl": "target", "msg": "<6>[    0.532950] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned"}
- {"dt": "2025-03-25T00:31:13.647647", "lvl": "target", "msg": "<6>[    0.533626] pci 0000:00:01.0: BAR 1 [mem 0x10000000-0x10000fff]: assigned"}
- {"dt": "2025-03-25T00:31:13.648005", "lvl": "target", "msg": "<6>[    0.533681] pci 0000:00:01.0: BAR 0 [io  0x1000-0x107f]: assigned"}
- {"dt": "2025-03-25T00:31:13.648081", "lvl": "target", "msg": "<6>[    0.533957] pci_bus 0000:00: resource 4 [io  0x0000-0xffff]"}
- {"dt": "2025-03-25T00:31:13.648433", "lvl": "target", "msg": "<6>[    0.533984] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]"}
- {"dt": "2025-03-25T00:31:13.648497", "lvl": "target", "msg": "<6>[    0.533997] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]"}
- {"dt": "2025-03-25T00:31:13.714222", "lvl": "target", "msg": "<6>[    0.599536] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)"}
- {"dt": "2025-03-25T00:31:13.735441", "lvl": "target", "msg": "<6>[    0.621279] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled"}
- {"dt": "2025-03-25T00:31:13.744699", "lvl": "target", "msg": "<6>[    0.630603] msm_serial: driver initialized"}
- {"dt": "2025-03-25T00:31:13.745782", "lvl": "target", "msg": "<6>[    0.631730] SuperH (H)SCI(F) driver initialized"}
- {"dt": "2025-03-25T00:31:13.746538", "lvl": "target", "msg": "<6>[    0.632513] STM32 USART driver initialized"}
- {"dt": "2025-03-25T00:31:13.772578", "lvl": "target", "msg": "<6>[    0.658457] loop: module loaded"}
- {"dt": "2025-03-25T00:31:13.773324", "lvl": "target", "msg": "<6>[    0.659292] virtio_blk virtio0: 2/0/0 default/read/poll queues"}
- {"dt": "2025-03-25T00:31:13.781920", "lvl": "target", "msg": "<5>[    0.667580] virtio_blk virtio0: [vda] 5345376 512-byte logical blocks (2.74 GB/2.55 GiB)"}
- {"dt": "2025-03-25T00:31:13.793195", "lvl": "target", "msg": "<6>[    0.679146] megasas: 07.727.03.00-rc1"}
- {"dt": "2025-03-25T00:31:13.798412", "lvl": "target", "msg": "<5>[    0.684125] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]"}
- {"dt": "2025-03-25T00:31:13.800619", "lvl": "target", "msg": "<6>[    0.686076] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000"}
- {"dt": "2025-03-25T00:31:13.800935", "lvl": "target", "msg": "<6>[    0.686420] Intel/Sharp Extended Query Table at 0x0031"}
- {"dt": "2025-03-25T00:31:13.801068", "lvl": "target", "msg": "<6>[    0.687194] Using buffer write method"}
- {"dt": "2025-03-25T00:31:13.801972", "lvl": "target", "msg": "<7>[    0.687450] erase region 0: offset=0x0,size=0x40000,blocks=256"}
- {"dt": "2025-03-25T00:31:13.802244", "lvl": "target", "msg": "<5>[    0.687698] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]"}
- {"dt": "2025-03-25T00:31:13.803435", "lvl": "target", "msg": "<6>[    0.688814] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000"}
- {"dt": "2025-03-25T00:31:13.803619", "lvl": "target", "msg": "<6>[    0.688921] Intel/Sharp Extended Query Table at 0x0031"}
- {"dt": "2025-03-25T00:31:13.803744", "lvl": "target", "msg": "<6>[    0.689469] Using buffer write method"}
- {"dt": "2025-03-25T00:31:13.803941", "lvl": "target", "msg": "<7>[    0.689492] erase region 0: offset=0x0,size=0x40000,blocks=256"}
- {"dt": "2025-03-25T00:31:13.804078", "lvl": "target", "msg": "<5>[    0.689556] Concatenating MTD devices:"}
- {"dt": "2025-03-25T00:31:13.804358", "lvl": "target", "msg": "<5>[    0.689576] (0): \"0.flash\""}
- {"dt": "2025-03-25T00:31:13.804402", "lvl": "target", "msg": "<5>[    0.689609] (1): \"0.flash\""}
- {"dt": "2025-03-25T00:31:13.804448", "lvl": "target", "msg": "<5>[    0.689626] into device \"0.flash\""}
- {"dt": "2025-03-25T00:31:13.828541", "lvl": "target", "msg": "<6>[    0.714422] tun: Universal TUN/TAP device driver, 1.6"}
- {"dt": "2025-03-25T00:31:13.831801", "lvl": "target", "msg": "<6>[    0.717742] thunder_xcv, ver 1.0"}
- {"dt": "2025-03-25T00:31:13.831891", "lvl": "target", "msg": "<6>[    0.717884] thunder_bgx, ver 1.0"}
- {"dt": "2025-03-25T00:31:13.831975", "lvl": "target", "msg": "<6>[    0.717990] nicpf, ver 1.0"}
- {"dt": "2025-03-25T00:31:13.835170", "lvl": "target", "msg": "<6>[    0.721122] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version"}
- {"dt": "2025-03-25T00:31:13.835299", "lvl": "target", "msg": "<6>[    0.721159] hns3: Copyright (c) 2017 Huawei Corporation."}
- {"dt": "2025-03-25T00:31:13.835428", "lvl": "target", "msg": "<6>[    0.721393] hclge is initializing"}
- {"dt": "2025-03-25T00:31:13.835762", "lvl": "target", "msg": "<6>[    0.721543] e1000: Intel(R) PRO/1000 Network Driver"}
- {"dt": "2025-03-25T00:31:13.835816", "lvl": "target", "msg": "<6>[    0.721561] e1000: Copyright (c) 1999-2006 Intel Corporation."}
- {"dt": "2025-03-25T00:31:13.835948", "lvl": "target", "msg": "<6>[    0.721702] e1000e: Intel(R) PRO/1000 Network Driver"}
- {"dt": "2025-03-25T00:31:13.836140", "lvl": "target", "msg": "<6>[    0.721734] e1000e: Copyright(c) 1999 - 2015 Intel Corporation."}
- {"dt": "2025-03-25T00:31:13.836332", "lvl": "target", "msg": "<6>[    0.721890] igb: Intel(R) Gigabit Ethernet Network Driver"}
- {"dt": "2025-03-25T00:31:13.836646", "lvl": "target", "msg": "<6>[    0.721912] igb: Copyright (c) 2007-2014 Intel Corporation."}
- {"dt": "2025-03-25T00:31:13.836737", "lvl": "target", "msg": "<6>[    0.722047] igbvf: Intel(R) Gigabit Virtual Function Network Driver"}
- {"dt": "2025-03-25T00:31:13.836944", "lvl": "target", "msg": "<6>[    0.722063] igbvf: Copyright (c) 2009 - 2012 Intel Corporation."}
- {"dt": "2025-03-25T00:31:13.837074", "lvl": "target", "msg": "<6>[    0.723091] sky2: driver version 1.30"}
- {"dt": "2025-03-25T00:31:13.841671", "lvl": "target", "msg": "<6>[    0.727645] VFIO - User Level meta-driver version: 0.3"}
- {"dt": "2025-03-25T00:31:13.849787", "lvl": "target", "msg": "<6>[    0.735697] usbcore: registered new interface driver usb-storage"}
- {"dt": "2025-03-25T00:31:13.859093", "lvl": "target", "msg": "<6>[    0.745057] rtc-pl031 9010000.pl031: registered as rtc0"}
- {"dt": "2025-03-25T00:31:13.859850", "lvl": "target", "msg": "<6>[    0.745570] rtc-pl031 9010000.pl031: setting system clock to 2025-03-25T00:31:13 UTC (1742862673)"}
- {"dt": "2025-03-25T00:31:13.861546", "lvl": "target", "msg": "<6>[    0.747552] i2c_dev: i2c /dev entries driver"}
- {"dt": "2025-03-25T00:31:13.880107", "lvl": "target", "msg": "<6>[    0.765995] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2025-03-25T00:31:13.880344", "lvl": "target", "msg": "<6>[    0.766033] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2025-03-25T00:31:13.881880", "lvl": "target", "msg": "<6>[    0.767872] Synopsys Designware Multimedia Card Interface Driver"}
- {"dt": "2025-03-25T00:31:13.884343", "lvl": "target", "msg": "<6>[    0.770260] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2025-03-25T00:31:13.893282", "lvl": "target", "msg": "<6>[    0.779197] usbcore: registered new interface driver usbhid"}
- {"dt": "2025-03-25T00:31:13.893683", "lvl": "target", "msg": "<6>[    0.779240] usbhid: USB HID core driver"}
- {"dt": "2025-03-25T00:31:13.903138", "lvl": "target", "msg": "<6>[    0.788988] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 (0,8000003f) counters available"}
- {"dt": "2025-03-25T00:31:13.915133", "lvl": "target", "msg": "<6>[    0.801079] NET: Registered PF_INET6 protocol family"}
- {"dt": "2025-03-25T00:31:13.920496", "lvl": "target", "msg": "<6>[    0.806460] Segment Routing with IPv6"}
- {"dt": "2025-03-25T00:31:13.920568", "lvl": "target", "msg": "<6>[    0.806633] In-situ OAM (IOAM) with IPv6"}
- {"dt": "2025-03-25T00:31:13.921096", "lvl": "target", "msg": "<6>[    0.807103] NET: Registered PF_PACKET protocol family"}
- {"dt": "2025-03-25T00:31:13.922257", "lvl": "target", "msg": "<6>[    0.808197] 9pnet: Installing 9P2000 support"}
- {"dt": "2025-03-25T00:31:13.922438", "lvl": "target", "msg": "<5>[    0.808543] Key type dns_resolver registered"}
- {"dt": "2025-03-25T00:31:13.950136", "lvl": "target", "msg": "<6>[    0.836045] registered taskstats version 1"}
- {"dt": "2025-03-25T00:31:13.951308", "lvl": "target", "msg": "<5>[    0.837314] Loading compiled-in X.509 certificates"}
- {"dt": "2025-03-25T00:31:13.977269", "lvl": "target", "msg": "<6>[    0.863159] Demotion targets for Node 0: null"}
- {"dt": "2025-03-25T00:31:13.985110", "lvl": "target", "msg": "<6>[    0.870964] input: gpio-keys as /devices/platform/gpio-keys/input/input0"}
- {"dt": "2025-03-25T00:31:13.990630", "lvl": "target", "msg": "<6>[    0.876561] clk: Disabling unused clocks"}
- {"dt": "2025-03-25T00:31:13.991220", "lvl": "target", "msg": "<6>[    0.876967] PM: genpd: Disabling unused power domains"}
- {"dt": "2025-03-25T00:31:13.991312", "lvl": "target", "msg": "<6>[    0.877348] ALSA device list:"}
- {"dt": "2025-03-25T00:31:13.991636", "lvl": "target", "msg": "<6>[    0.877505]   No soundcards found."}
- {"dt": "2025-03-25T00:31:14.020759", "lvl": "target", "msg": "<6>[    0.906231] EXT4-fs (vda): mounted filesystem db78a389-4e12-4f05-bb8b-e7b25b5f99d9 r/w with ordered data mode. Quota mode: none."}
- {"dt": "2025-03-25T00:31:14.021077", "lvl": "target", "msg": "<6>[    0.906725] VFS: Mounted root (ext4 filesystem) on device 254:0."}
- {"dt": "2025-03-25T00:31:14.022623", "lvl": "target", "msg": "<6>[    0.908583] devtmpfs: mounted"}
- {"dt": "2025-03-25T00:31:14.338626", "lvl": "target", "msg": "<6>[    1.224426] Freeing unused kernel memory: 2688K"}
- {"dt": "2025-03-25T00:31:14.339685", "lvl": "target", "msg": "<6>[    1.225550] Run /sbin/init as init process"}
- {"dt": "2025-03-25T00:31:14.339806", "lvl": "target", "msg": "<7>[    1.225639]   with arguments:"}
- {"dt": "2025-03-25T00:31:14.340096", "lvl": "target", "msg": "<7>[    1.225684]     /sbin/init"}
- {"dt": "2025-03-25T00:31:14.340155", "lvl": "target", "msg": "<7>[    1.225733]     verbose"}
- {"dt": "2025-03-25T00:31:14.340283", "lvl": "target", "msg": "<7>[    1.225752]   with environment:"}
- {"dt": "2025-03-25T00:31:14.340426", "lvl": "target", "msg": "<7>[    1.225785]     HOME=/"}
- {"dt": "2025-03-25T00:31:14.340576", "lvl": "target", "msg": "<7>[    1.225818]     TERM=linux"}
- {"dt": "2025-03-25T00:31:14.679388", "lvl": "target", "msg": "[!p]104\a[?7h"}
- {"dt": "2025-03-25T00:31:14.679796", "lvl": "target", "msg": "[0;1;39mWelcome to [0m[1mDebian GNU/Linux trixie/sid[0m[0;1;39m![0m"}
- {"dt": "2025-03-25T00:31:14.679879", "lvl": "target", "msg": "\r"}
- {"dt": "2025-03-25T00:31:16.380077", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-getty.slice[0m - Slice /system/getty.\r"}
- {"dt": "2025-03-25T00:31:16.385641", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-modprobe.slice[0m - Slice /system/modprobe.\r"}
- {"dt": "2025-03-25T00:31:16.390677", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-serial\\x2dget\u2026slice[0m - Slice /system/serial-getty.\r"}
- {"dt": "2025-03-25T00:31:16.396229", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-xfs_scrub.sli\u2026[0mxfs_scrub background service slice.\r"}
- {"dt": "2025-03-25T00:31:16.400592", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39muser.slice[0m - User and Session Slice.\r"}
- {"dt": "2025-03-25T00:31:16.402869", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-ask-password-conso\u2026[0mequests to Console Directory Watch.\r"}
- {"dt": "2025-03-25T00:31:16.404037", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-ask-password-wall.\u2026[0md Requests to Wall Directory Watch.\r"}
- {"dt": "2025-03-25T00:31:16.406400", "lvl": "target", "msg": "         Expecting device [0;1;39mdev-ttyAMA0.device[0m - /dev/ttyAMA0...\r"}
- {"dt": "2025-03-25T00:31:16.407204", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mpaths.target[0m - Path Units.\r"}
- {"dt": "2025-03-25T00:31:16.408049", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mremote-fs.target[0m - Remote File Systems.\r"}
- {"dt": "2025-03-25T00:31:16.408809", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mslices.target[0m - Slice Units.\r"}
- {"dt": "2025-03-25T00:31:16.409594", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mswap.target[0m - Swaps.\r"}
- {"dt": "2025-03-25T00:31:16.422374", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-creds.socket[0m - Credential Encryption/Decryption.\r"}
- {"dt": "2025-03-25T00:31:16.424818", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-initctl.socke\u2026[0m- initctl Compatibility Named Pipe.\r"}
- {"dt": "2025-03-25T00:31:16.426861", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-journald-dev-\u2026socket[0m - Journal Socket (/dev/log).\r"}
- {"dt": "2025-03-25T00:31:16.428525", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-journald.socket[0m - Journal Sockets.\r"}
- {"dt": "2025-03-25T00:31:16.430861", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-udevd-control.socket[0m - udev Control Socket.\r"}
- {"dt": "2025-03-25T00:31:16.432238", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-udevd-kernel.socket[0m - udev Kernel Socket.\r"}
- {"dt": "2025-03-25T00:31:16.455718", "lvl": "target", "msg": "         Mounting [0;1;39mdev-hugepages.mount[0m - Huge Pages File System...\r"}
- {"dt": "2025-03-25T00:31:16.471220", "lvl": "target", "msg": "         Mounting [0;1;39mdev-mqueue.mount[0m - POSIX Message Queue File System...\r"}
- {"dt": "2025-03-25T00:31:16.484131", "lvl": "target", "msg": "         Mounting [0;1;39mrun-lock.mount[0m - Legacy Locks Directory /run/lock...\r"}
- {"dt": "2025-03-25T00:31:16.499628", "lvl": "target", "msg": "         Mounting [0;1;39msys-kernel-debug.mount[0m - Kernel Debug File System...\r"}
- {"dt": "2025-03-25T00:31:16.539959", "lvl": "target", "msg": "         Mounting [0;1;39mtmp.mount[0m - Temporary Directory /tmp...\r"}
- {"dt": "2025-03-25T00:31:16.598474", "lvl": "target", "msg": "         Starting [0;1;39mkmod-static-nodes.service[0m\u2026eate List of Static Device Nodes...\r"}
- {"dt": "2025-03-25T00:31:16.655858", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@configfs.service[0m - Load Kernel Module configfs...\r"}
- {"dt": "2025-03-25T00:31:16.680764", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@drm.service[0m - Load Kernel Module drm...\r"}
- {"dt": "2025-03-25T00:31:16.700613", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@efi_pstore.servi\u2026[0m - Load Kernel Module efi_pstore...\r"}
- {"dt": "2025-03-25T00:31:16.722268", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@fuse.service[0m - Load Kernel Module fuse...\r"}
- {"dt": "2025-03-25T00:31:16.760301", "lvl": "target", "msg": "         Starting [0;1;39msystemd-journald.service[0m - Journal Service...\r"}
- {"dt": "2025-03-25T00:31:16.798900", "lvl": "target", "msg": "         Starting [0;1;39msystemd-modules-load.service[0m - Load Kernel Modules...\r"}
- {"dt": "2025-03-25T00:31:16.812605", "lvl": "target", "msg": "         Starting [0;1;39msystemd-remount-fs.servic\u2026[0munt Root and Kernel File Systems...\r"}
- {"dt": "2025-03-25T00:31:16.828585", "lvl": "target", "msg": "         Starting [0;1;39msystemd-udev-load-credent\u2026[0mLoad udev Rules from Credentials...\r"}
- {"dt": "2025-03-25T00:31:16.852366", "lvl": "target", "msg": "         Starting [0;1;39msystemd-udev-trigger.service[0m - Coldplug All udev Devices...\r"}
- {"dt": "2025-03-25T00:31:16.885861", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mdev-hugepages.mount[0m - Huge Pages File System.\r"}
- {"dt": "2025-03-25T00:31:16.887911", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mdev-mqueue.mount[0m - POSIX Message Queue File System.\r"}
- {"dt": "2025-03-25T00:31:16.889664", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mrun-lock.mount[0m - Legacy Locks Directory /run/lock.\r"}
- {"dt": "2025-03-25T00:31:16.891716", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39msys-kernel-debug.mount[0m - Kernel Debug File System.\r"}
- {"dt": "2025-03-25T00:31:16.893242", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mtmp.mount[0m - Temporary Directory /tmp.\r"}
- {"dt": "2025-03-25T00:31:16.900364", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mkmod-static-nodes.service[0m\u2026Create List of Static Device Nodes.\r"}
- {"dt": "2025-03-25T00:31:16.924134", "lvl": "target", "msg": "         Starting [0;1;39msystemd-tmpfiles-setup-de\u2026[0m Device Nodes in /dev gracefully...\r"}
- {"dt": "2025-03-25T00:31:17.201164", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-remount-fs.servic\u2026[0mmount Root and Kernel File Systems.\r"}
- {"dt": "2025-03-25T00:31:17.220817", "lvl": "target", "msg": "         Starting [0;1;39msystemd-random-seed.service[0m - Load/Save OS Random Seed...\r"}
- {"dt": "2025-03-25T00:31:17.227015", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-modules-load.service[0m - Load Kernel Modules.\r"}
- {"dt": "2025-03-25T00:31:17.257392", "lvl": "target", "msg": "         Starting [0;1;39msystemd-sysctl.service[0m - Apply Kernel Variables...\r"}
- {"dt": "2025-03-25T00:31:17.292504", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@configfs.service[0m - Load Kernel Module configfs.\r"}
- {"dt": "2025-03-25T00:31:17.304165", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-udev-load-credent\u2026[0m- Load udev Rules from Credentials.\r"}
- {"dt": "2025-03-25T00:31:17.322504", "lvl": "target", "msg": "         Mounting [0;1;39msys-kernel-config.mount[0m - Kernel Configuration File System...\r"}
- {"dt": "2025-03-25T00:31:17.373788", "lvl": "target", "msg": "<6>[    4.259618] fuse: init (API version 7.43)"}
- {"dt": "2025-03-25T00:31:17.391583", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@drm.service[0m - Load Kernel Module drm.\r"}
- {"dt": "2025-03-25T00:31:17.403100", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@fuse.service[0m - Load Kernel Module fuse.\r"}
- {"dt": "2025-03-25T00:31:17.424010", "lvl": "target", "msg": "         Mounting [0;1;39msys-fs-fuse-connections.mount[0m - FUSE Control File System...\r"}
- {"dt": "2025-03-25T00:31:17.435432", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39msys-kernel-config.mount[0m - Kernel Configuration File System.\r"}
- {"dt": "2025-03-25T00:31:17.454948", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@efi_pstore.service[0m - Load Kernel Module efi_pstore.\r"}
- {"dt": "2025-03-25T00:31:17.512347", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-tmpfiles-setup-de\u2026[0mic Device Nodes in /dev gracefully.\r"}
- {"dt": "2025-03-25T00:31:17.542904", "lvl": "target", "msg": "         Starting [0;1;39msystemd-sysusers.service[0m - Create System Users...\r"}
- {"dt": "2025-03-25T00:31:17.552945", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39msys-fs-fuse-connections.mount[0m - FUSE Control File System.\r"}
- {"dt": "2025-03-25T00:31:17.633766", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-random-seed.service[0m - Load/Save OS Random Seed.\r"}
- {"dt": "2025-03-25T00:31:17.676396", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-sysctl.service[0m - Apply Kernel Variables.\r"}
- {"dt": "2025-03-25T00:31:17.835638", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-sysusers.service[0m - Create System Users.\r"}
- {"dt": "2025-03-25T00:31:17.847381", "lvl": "target", "msg": "         Starting [0;1;39msystemd-tmpfiles-setup-de\u2026[0meate Static Device Nodes in /dev...\r"}
- {"dt": "2025-03-25T00:31:17.873781", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-journald.service[0m - Journal Service.\r"}
- {"dt": "2025-03-25T00:31:18.028213", "lvl": "target", "msg": "         Starting [0;1;39msystemd-journal-flush.ser\u2026[0msh Journal to Persistent Storage...\r"}
- {"dt": "2025-03-25T00:31:18.127451", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-tmpfiles-setup-de\u2026[0mCreate Static Device Nodes in /dev.\r"}
- {"dt": "2025-03-25T00:31:18.139069", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mlocal-fs-pre.target[0m\u2026Preparation for Local File Systems.\r"}
- {"dt": "2025-03-25T00:31:18.140342", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mlocal-fs.target[0m - Local File Systems.\r"}
- {"dt": "2025-03-25T00:31:18.157416", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-sysext.socket[0m\u2026 System Extension Image Management.\r"}
- {"dt": "2025-03-25T00:31:18.187779", "lvl": "target", "msg": "         Starting [0;1;39msystemd-udevd.service[0m - R\u2026ager for Device Events and Files...\r"}
- {"dt": "2025-03-25T00:31:18.314843", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-journal-flush.ser\u2026[0mlush Journal to Persistent Storage.\r"}
- {"dt": "2025-03-25T00:31:18.342206", "lvl": "target", "msg": "         Starting [0;1;39msystemd-tmpfiles-setup.se\u2026[0mate System Files and Directories...\r"}
- {"dt": "2025-03-25T00:31:18.765440", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-tmpfiles-setup.se\u2026[0mreate System Files and Directories.\r"}
- {"dt": "2025-03-25T00:31:18.788003", "lvl": "target", "msg": "         Starting [0;1;39mldconfig.service[0m - Rebuild Dynamic Linker Cache...\r"}
- {"dt": "2025-03-25T00:31:18.803904", "lvl": "target", "msg": "         Starting [0;1;39msystemd-journal-catalog-u\u2026ervice[0m - Rebuild Journal Catalog...\r"}
- {"dt": "2025-03-25T00:31:18.903104", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-udevd.service[0m - Ru\u2026anager for Device Events and Files.\r"}
- {"dt": "2025-03-25T00:31:19.467078", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-journal-catalog-u\u2026.service[0m - Rebuild Journal Catalog.\r"}
- {"dt": "2025-03-25T00:31:19.488191", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mldconfig.service[0m - Rebuild Dynamic Linker Cache.\r"}
- {"dt": "2025-03-25T00:31:19.504548", "lvl": "target", "msg": "         Starting [0;1;39msystemd-update-done.service[0m - Update is Completed...\r"}
- {"dt": "2025-03-25T00:31:19.608798", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-update-done.service[0m - Update is Completed.\r"}
- {"dt": "2025-03-25T00:31:20.755068", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-udev-trigger.service[0m - Coldplug All udev Devices.\r"}
- {"dt": "2025-03-25T00:31:20.759987", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39msysinit.target[0m - System Initialization.\r"}
- {"dt": "2025-03-25T00:31:20.768062", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mapt-daily.timer[0m - Daily apt download activities.\r"}
- {"dt": "2025-03-25T00:31:20.770044", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mapt-daily-upgrade.timer[0m - \u2026y apt upgrade and clean activities.\r"}
- {"dt": "2025-03-25T00:31:20.772251", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mdpkg-db-backup.timer[0m - Daily dpkg database backup timer.\r"}
- {"dt": "2025-03-25T00:31:20.776460", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39me2scrub_all.timer[0m - Period\u2026Metadata Check for All Filesystems.\r"}
- {"dt": "2025-03-25T00:31:20.777846", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mfstrim.timer[0m - Discard unused filesystem blocks once a week.\r"}
- {"dt": "2025-03-25T00:31:20.783461", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mlogrotate.timer[0m - Daily rotation of log files.\r"}
- {"dt": "2025-03-25T00:31:20.784679", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-tmpfiles-clean.tim\u2026[0my Cleanup of Temporary Directories.\r"}
- {"dt": "2025-03-25T00:31:20.786473", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mxfs_scrub_all.timer[0m - Peri\u2026Metadata Check for All Filesystems.\r"}
- {"dt": "2025-03-25T00:31:20.787628", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mtimers.target[0m - Timer Units.\r"}
- {"dt": "2025-03-25T00:31:20.789328", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39mdbus.socket[0m - D-Bus System Message Bus Socket.\r"}
- {"dt": "2025-03-25T00:31:20.790988", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-hostnamed.socket[0m - Hostname Service Socket.\r"}
- {"dt": "2025-03-25T00:31:20.795059", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39msockets.target[0m - Socket Units.\r"}
- {"dt": "2025-03-25T00:31:20.796220", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mbasic.target[0m - Basic System.\r"}
- {"dt": "2025-03-25T00:31:20.816818", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mcron.service[0m - Regular background program processing daemon.\r"}
- {"dt": "2025-03-25T00:31:20.828571", "lvl": "target", "msg": "         Starting [0;1;39mdbus.service[0m - D-Bus System Message Bus...\r"}
- {"dt": "2025-03-25T00:31:20.852745", "lvl": "target", "msg": "         Starting [0;1;39me2scrub_reap.service[0m - Re\u2026ne ext4 Metadata Check Snapshots...\r"}
- {"dt": "2025-03-25T00:31:20.900626", "lvl": "target", "msg": "         Starting [0;1;39msystemd-logind.service[0m - User Login Management...\r"}
- {"dt": "2025-03-25T00:31:20.920293", "lvl": "target", "msg": "         Starting [0;1;39msystemd-user-sessions.service[0m - Permit User Sessions...\r"}
- {"dt": "2025-03-25T00:31:21.150227", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-user-sessions.service[0m - Permit User Sessions.\r"}
- {"dt": "2025-03-25T00:31:21.174722", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mgetty@tty1.service[0m - Getty on tty1.\r"}
- {"dt": "2025-03-25T00:31:21.215155", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mdbus.service[0m - D-Bus System Message Bus.\r"}
- {"dt": "2025-03-25T00:31:21.370412", "lvl": "target", "msg": "[[0;32m  OK  [0m] Found device [0;1;39mdev-ttyAMA0.device[0m - /dev/ttyAMA0.\r"}
- {"dt": "2025-03-25T00:31:21.384749", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mserial-getty@ttyAMA0.service[0m - Serial Getty on ttyAMA0.\r"}
- {"dt": "2025-03-25T00:31:21.390126", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mgetty.target[0m - Login Prompts.\r"}
- {"dt": "2025-03-25T00:31:21.619887", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39me2scrub_reap.service[0m - Re\u2026line ext4 Metadata Check Snapshots.\r"}
- {"dt": "2025-03-25T00:31:21.857420", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-logind.service[0m - User Login Management.\r"}
- {"dt": "2025-03-25T00:31:22.040241", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mmulti-user.target[0m - Multi-User System.\r"}
- {"dt": "2025-03-25T00:31:22.044053", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mgraphical.target[0m - Graphical Interface.\r"}
- {"dt": "2025-03-25T00:31:23.835922", "lvl": "target", "msg": "[!p]104\a[?7h[6n[32766;32766H[6n[!p]104\a[?7h[6n[32766;32766H[6n\r"}
- {"dt": "2025-03-25T00:31:23.836096", "lvl": "target", "msg": "Debian GNU/Linux trixie/sid runner-ykxhnyexq-project-40964107-concurrent-0 ttyAMA0"}
- {"dt": "2025-03-25T00:31:23.836177", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T00:31:23.836641", "lvl": "debug", "msg": "Matched prompt #11: login:"}
- {"dt": "2025-03-25T00:31:23.836735", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "kernel-messages", "level": "2.2.1", "duration": "10.89", "result": "pass", "extra": {"extra": []}}}
- {"dt": "2025-03-25T00:31:23.836869", "lvl": "debug", "msg": "Sending username root"}
- {"dt": "2025-03-25T00:31:23.836946", "lvl": "debug", "msg": "Sending line: 'root'"}
- {"dt": "2025-03-25T00:31:23.937216", "lvl": "input", "msg": "root"}
- {"dt": "2025-03-25T00:31:23.937343", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T00:31:23.937429", "lvl": "debug", "msg": "login-action: Wait for prompt ['root@(.*):[/~]#', 'Login incorrect', 'Login timed out'] (timeout 00:29:49)"}
- {"dt": "2025-03-25T00:31:23.937520", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:14:54)"}
- {"dt": "2025-03-25T00:31:23.937910", "lvl": "target", "msg": "runner-ykxhnyexq-project-40964107-concurrent-0 login: root\r"}
- {"dt": "2025-03-25T00:31:24.126361", "lvl": "target", "msg": "Linux runner-ykxhnyexq-project-40964107-concurrent-0 6.14.0-rc7-next-20250324 #1 SMP PREEMPT @1742818530 aarch64"}
- {"dt": "2025-03-25T00:31:24.127581", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T00:31:24.127841", "lvl": "target", "msg": "The programs included with the Debian GNU/Linux system are free software;"}
- {"dt": "2025-03-25T00:31:24.128109", "lvl": "target", "msg": "the exact distribution terms for each program are described in the"}
- {"dt": "2025-03-25T00:31:24.128173", "lvl": "target", "msg": "individual files in /usr/share/doc/*/copyright."}
- {"dt": "2025-03-25T00:31:24.128238", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T00:31:24.128484", "lvl": "target", "msg": "Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent"}
- {"dt": "2025-03-25T00:31:24.128532", "lvl": "target", "msg": "permitted by applicable law."}
- {"dt": "2025-03-25T00:31:26.113555", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T00:31:26.113750", "lvl": "debug", "msg": "end: 2.2.1 login-action (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T00:31:26.113862", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "login-action", "level": "2.2.1", "duration": "13.17", "result": "pass", "extra": {"success": "No kernel warnings or errors detected."}}}
- {"dt": "2025-03-25T00:31:26.114027", "lvl": "debug", "msg": "end: 2.2 auto-login-action (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T00:31:26.114104", "lvl": "debug", "msg": "start: 2.3 expect-shell-connection (timeout 00:29:47) [common]"}
- {"dt": "2025-03-25T00:31:26.114163", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T00:31:26.114214", "lvl": "debug", "msg": "Forcing a shell prompt, looking for ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T00:31:26.114262", "lvl": "debug", "msg": "Sending line: ''"}
- {"dt": "2025-03-25T00:31:26.164398", "lvl": "input", "msg": ""}
- {"dt": "2025-03-25T00:31:26.164526", "lvl": "debug", "msg": "expect-shell-connection: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:30:00)"}
- {"dt": "2025-03-25T00:31:26.164620", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:15:00)"}
- {"dt": "2025-03-25T00:31:26.165456", "lvl": "target", "msg": "[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# "}
- {"dt": "2025-03-25T00:31:26.167403", "lvl": "debug", "msg": "end: 2.3 expect-shell-connection (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:31:26.167510", "lvl": "debug", "msg": "start: 2.4 export-device-env (timeout 00:29:47) [common]"}
- {"dt": "2025-03-25T00:31:26.167625", "lvl": "debug", "msg": "end: 2.4 export-device-env (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:31:26.167726", "lvl": "info", "msg": "end: 2 boot-image-retry (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T00:31:26.167836", "lvl": "info", "msg": "start: 3 lava-test-retry (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T00:31:26.167947", "lvl": "debug", "msg": "start: 3.1 lava-test-shell (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T00:31:26.168034", "lvl": "debug", "msg": "Using namespace: common"}
- {"dt": "2025-03-25T00:31:26.168097", "lvl": "debug", "msg": "Sending line: '#'"}
- {"dt": "2025-03-25T00:31:26.268315", "lvl": "input", "msg": "#"}
- {"dt": "2025-03-25T00:31:26.268449", "lvl": "debug", "msg": "lava-test-shell: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:15:00)"}
- {"dt": "2025-03-25T00:31:26.268983", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# #"}
- {"dt": "2025-03-25T00:31:26.270561", "lvl": "debug", "msg": "Using /lava-1"}
- {"dt": "2025-03-25T00:31:26.270615", "lvl": "debug", "msg": "Sending line: 'export SHELL=/bin/sh'"}
- {"dt": "2025-03-25T00:31:26.370832", "lvl": "input", "msg": "export SHELL=/bin/sh"}
- {"dt": "2025-03-25T00:31:26.371547", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# export SHELL=/bin/sh"}
- {"dt": "2025-03-25T00:31:26.373275", "lvl": "debug", "msg": "Sending line: '. /lava-1/environment'"}
- {"dt": "2025-03-25T00:31:26.473513", "lvl": "input", "msg": ". /lava-1/environment"}
- {"dt": "2025-03-25T00:31:26.474267", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# . /lava-1/environment"}
- {"dt": "2025-03-25T00:31:26.478285", "lvl": "debug", "msg": "Sending line: '/lava-1/bin/lava-test-runner /lava-1/0'"}
- {"dt": "2025-03-25T00:31:26.578546", "lvl": "input", "msg": "/lava-1/bin/lava-test-runner /lava-1/0"}
- {"dt": "2025-03-25T00:31:26.578665", "lvl": "info", "msg": "Test shell timeout: 10s (minimum of the action and connection timeout)"}
- {"dt": "2025-03-25T00:31:26.579377", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# /lava-1/bin/lava-test-runn\rner /lava-1/0"}
- {"dt": "2025-03-25T00:31:26.682124", "lvl": "target", "msg": "[?2004l\r+ export TESTRUN_ID=0_kselftest-rtc"}
- {"dt": "2025-03-25T00:31:26.682460", "lvl": "target", "msg": "+ cd /lava-1/0/tests/0_kselftest-rtc"}
- {"dt": "2025-03-25T00:31:26.684394", "lvl": "target", "msg": "+ cat uuid"}
- {"dt": "2025-03-25T00:31:26.690329", "lvl": "target", "msg": "+ UUID=1_1.1.3.1"}
- {"dt": "2025-03-25T00:31:26.690434", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2025-03-25T00:31:26.691354", "lvl": "target", "msg": "<8>[   13.577253] <LAVA_SIGNAL_STARTRUN 0_kselftest-rtc 1_1.1.3.1>"}
- {"dt": "2025-03-25T00:31:26.691627", "lvl": "debug", "msg": "Received signal: <STARTRUN> 0_kselftest-rtc 1_1.1.3.1"}
- {"dt": "2025-03-25T00:31:26.691697", "lvl": "info", "msg": "Starting test lava.0_kselftest-rtc (1_1.1.3.1)"}
- {"dt": "2025-03-25T00:31:26.691770", "lvl": "info", "msg": "Skipping test definition patterns."}
- {"dt": "2025-03-25T00:31:26.691855", "lvl": "target", "msg": "+ cd ./automated/linux/kselftest/"}
- {"dt": "2025-03-25T00:31:26.695763", "lvl": "target", "msg": "+ ./kselftest.sh -c rtc -T  -t kselftest_armhf.tar.gz -s false -u  -L  -S skipfile-lkft.yaml -b  -g  -e production -p /opt/kselftests/default-in-kernel -n 1 -i 1 -E "}
- {"dt": "2025-03-25T00:31:26.741515", "lvl": "target", "msg": "INFO: Generating a skipfile based on /lava-1/0/tests/0_kselftest-rtc/automated/linux/kselftest/skipfile-lkft.yaml"}
- {"dt": "2025-03-25T00:31:26.899235", "lvl": "target", "msg": "INFO: Using the following generated skipfile contents (until EOF):"}
- {"dt": "2025-03-25T00:31:26.903796", "lvl": "target", "msg": "bpf:test_btf"}
- {"dt": "2025-03-25T00:31:26.904070", "lvl": "target", "msg": "bpf:test_progs"}
- {"dt": "2025-03-25T00:31:26.904152", "lvl": "target", "msg": "breakpoints:breakpoint_test"}
- {"dt": "2025-03-25T00:31:26.904224", "lvl": "target", "msg": "breakpoints:breakpoint_test_arm64"}
- {"dt": "2025-03-25T00:31:26.904310", "lvl": "target", "msg": "breakpoints:step_after_suspend_test"}
- {"dt": "2025-03-25T00:31:26.904377", "lvl": "target", "msg": "kmod:test_kmod.sh"}
- {"dt": "2025-03-25T00:31:26.904441", "lvl": "target", "msg": "kvm:get-reg-list"}
- {"dt": "2025-03-25T00:31:26.904502", "lvl": "target", "msg": "kvm:kvm_create_max_vcpus"}
- {"dt": "2025-03-25T00:31:26.904556", "lvl": "target", "msg": "mqueue:mq_open_tests"}
- {"dt": "2025-03-25T00:31:26.904600", "lvl": "target", "msg": "mqueue:mq_perf_tests"}
- {"dt": "2025-03-25T00:31:26.904645", "lvl": "target", "msg": "net:fib_nexthops.sh"}
- {"dt": "2025-03-25T00:31:26.904684", "lvl": "target", "msg": "net:msg_zerocopy.sh"}
- {"dt": "2025-03-25T00:31:26.904742", "lvl": "target", "msg": "net:rtnetlink.sh"}
- {"dt": "2025-03-25T00:31:26.904785", "lvl": "target", "msg": "net:run_afpackettests"}
- {"dt": "2025-03-25T00:31:26.904829", "lvl": "target", "msg": "net:tls"}
- {"dt": "2025-03-25T00:31:26.904866", "lvl": "target", "msg": "net:udpgro.sh"}
- {"dt": "2025-03-25T00:31:26.904921", "lvl": "target", "msg": "net:xfrm_policy.sh"}
- {"dt": "2025-03-25T00:31:26.904963", "lvl": "target", "msg": "netfilter:bridge_brouter.sh"}
- {"dt": "2025-03-25T00:31:26.905008", "lvl": "target", "msg": "netfilter:conntrack_icmp_related.sh"}
- {"dt": "2025-03-25T00:31:26.905057", "lvl": "target", "msg": "netfilter:nft_flowtable.sh"}
- {"dt": "2025-03-25T00:31:26.905100", "lvl": "target", "msg": "netfilter:nft_nat.sh"}
- {"dt": "2025-03-25T00:31:26.905150", "lvl": "target", "msg": "netfilter:nft_trans_stress.sh"}
- {"dt": "2025-03-25T00:31:26.905204", "lvl": "target", "msg": "pidfd:pidfd_wait"}
- {"dt": "2025-03-25T00:31:26.905256", "lvl": "target", "msg": "proc:proc-pid-vm"}
- {"dt": "2025-03-25T00:31:26.905309", "lvl": "target", "msg": "ptrace:vmaccess"}
- {"dt": "2025-03-25T00:31:26.905361", "lvl": "target", "msg": "rseq:run_param_test.sh"}
- {"dt": "2025-03-25T00:31:26.905413", "lvl": "target", "msg": "sync:sync_test"}
- {"dt": "2025-03-25T00:31:26.905463", "lvl": "target", "msg": "vm:run_vmtests"}
- {"dt": "2025-03-25T00:31:26.905516", "lvl": "target", "msg": "zram:zram.sh"}
- {"dt": "2025-03-25T00:31:26.906912", "lvl": "target", "msg": "INFO: EOF"}
- {"dt": "2025-03-25T00:31:26.950943", "lvl": "target", "msg": "INFO: Installing sed perl wget xz-utils iproute2 python3-tap"}
- {"dt": "2025-03-25T00:31:27.260322", "lvl": "target", "msg": "Ign:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T00:31:28.267361", "lvl": "target", "msg": "Ign:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T00:31:30.271821", "lvl": "target", "msg": "Ign:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T00:31:34.278467", "lvl": "target", "msg": "Err:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T00:31:34.278637", "lvl": "target", "msg": "  Temporary failure resolving 'deb.debian.org'"}
- {"dt": "2025-03-25T00:31:34.389231", "lvl": "target", "msg": "Reading package lists..."}
- {"dt": "2025-03-25T00:31:34.407800", "lvl": "target", "msg": "W: Failed to fetch https://deb.debian.org/debian/dists/trixie/InRelease  Temporary failure resolving 'deb.debian.org'"}
- {"dt": "2025-03-25T00:31:34.408243", "lvl": "target", "msg": "W: Some index files failed to download. They have been ignored, or old ones used instead."}
- {"dt": "2025-03-25T00:31:34.498673", "lvl": "target", "msg": "Reading package lists..."}
- {"dt": "2025-03-25T00:31:34.521950", "lvl": "target", "msg": "Building dependency tree..."}
- {"dt": "2025-03-25T00:31:34.525343", "lvl": "target", "msg": "Reading state information..."}
- {"dt": "2025-03-25T00:31:34.544918", "lvl": "target", "msg": "sed is already the newest version (4.9-2+b1)."}
- {"dt": "2025-03-25T00:31:34.545273", "lvl": "target", "msg": "perl is already the newest version (5.40.0-8)."}
- {"dt": "2025-03-25T00:31:34.545361", "lvl": "target", "msg": "wget is already the newest version (1.24.5-2)."}
- {"dt": "2025-03-25T00:31:34.545662", "lvl": "target", "msg": "xz-utils is already the newest version (5.6.3-1+b1)."}
- {"dt": "2025-03-25T00:31:34.545742", "lvl": "target", "msg": "iproute2 is already the newest version (6.13.0-1)."}
- {"dt": "2025-03-25T00:31:34.546013", "lvl": "target", "msg": "python3-tap is already the newest version (3.2.1-1)."}
- {"dt": "2025-03-25T00:31:34.635331", "lvl": "target", "msg": "0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded."}
- {"dt": "2025-03-25T00:31:34.662704", "lvl": "target", "msg": "kselftests found on rootfs"}
- {"dt": "2025-03-25T00:31:34.697544", "lvl": "target", "msg": "skiplist:"}
- {"dt": "2025-03-25T00:31:34.697885", "lvl": "target", "msg": "========================================"}
- {"dt": "2025-03-25T00:31:34.698480", "lvl": "target", "msg": "bpf:test_btf"}
- {"dt": "2025-03-25T00:31:34.795059", "lvl": "target", "msg": "bpf:test_progs"}
- {"dt": "2025-03-25T00:31:34.817516", "lvl": "target", "msg": "breakpoints:breakpoint_test"}
- {"dt": "2025-03-25T00:31:34.838836", "lvl": "target", "msg": "breakpoints:breakpoint_test_arm64"}
- {"dt": "2025-03-25T00:31:34.863405", "lvl": "target", "msg": "breakpoints:step_after_suspend_test"}
- {"dt": "2025-03-25T00:31:34.885004", "lvl": "target", "msg": "kmod:test_kmod.sh"}
- {"dt": "2025-03-25T00:31:34.906026", "lvl": "target", "msg": "kvm:get-reg-list"}
- {"dt": "2025-03-25T00:31:34.926932", "lvl": "target", "msg": "kvm:kvm_create_max_vcpus"}
- {"dt": "2025-03-25T00:31:34.948104", "lvl": "target", "msg": "mqueue:mq_open_tests"}
- {"dt": "2025-03-25T00:31:34.969841", "lvl": "target", "msg": "mqueue:mq_perf_tests"}
- {"dt": "2025-03-25T00:31:34.991668", "lvl": "target", "msg": "net:fib_nexthops.sh"}
- {"dt": "2025-03-25T00:31:35.013234", "lvl": "target", "msg": "net:msg_zerocopy.sh"}
- {"dt": "2025-03-25T00:31:35.034867", "lvl": "target", "msg": "net:rtnetlink.sh"}
- {"dt": "2025-03-25T00:31:35.055208", "lvl": "target", "msg": "net:run_afpackettests"}
- {"dt": "2025-03-25T00:31:35.075708", "lvl": "target", "msg": "net:tls"}
- {"dt": "2025-03-25T00:31:35.096076", "lvl": "target", "msg": "net:udpgro.sh"}
- {"dt": "2025-03-25T00:31:35.116367", "lvl": "target", "msg": "net:xfrm_policy.sh"}
- {"dt": "2025-03-25T00:31:35.136529", "lvl": "target", "msg": "netfilter:bridge_brouter.sh"}
- {"dt": "2025-03-25T00:31:35.156717", "lvl": "target", "msg": "netfilter:conntrack_icmp_related.sh"}
- {"dt": "2025-03-25T00:31:35.176853", "lvl": "target", "msg": "netfilter:nft_flowtable.sh"}
- {"dt": "2025-03-25T00:31:35.197313", "lvl": "target", "msg": "netfilter:nft_nat.sh"}
- {"dt": "2025-03-25T00:31:35.217347", "lvl": "target", "msg": "netfilter:nft_trans_stress.sh"}
- {"dt": "2025-03-25T00:31:35.236757", "lvl": "target", "msg": "pidfd:pidfd_wait"}
- {"dt": "2025-03-25T00:31:35.258020", "lvl": "target", "msg": "proc:proc-pid-vm"}
- {"dt": "2025-03-25T00:31:35.278799", "lvl": "target", "msg": "ptrace:vmaccess"}
- {"dt": "2025-03-25T00:31:35.300407", "lvl": "target", "msg": "rseq:run_param_test.sh"}
- {"dt": "2025-03-25T00:31:35.321229", "lvl": "target", "msg": "sync:sync_test"}
- {"dt": "2025-03-25T00:31:35.342898", "lvl": "target", "msg": "vm:run_vmtests"}
- {"dt": "2025-03-25T00:31:35.362733", "lvl": "target", "msg": "zram:zram.sh"}
- {"dt": "2025-03-25T00:31:35.383294", "lvl": "target", "msg": "========================================"}
- {"dt": "2025-03-25T00:31:35.423482", "lvl": "target", "msg": "rtc:rtctest"}
- {"dt": "2025-03-25T00:31:35.433212", "lvl": "target", "msg": "============== Tests to run ==============="}
- {"dt": "2025-03-25T00:31:35.437346", "lvl": "target", "msg": "rtc:rtctest"}
- {"dt": "2025-03-25T00:31:35.438488", "lvl": "target", "msg": "===========End Tests to run ==============="}
- {"dt": "2025-03-25T00:31:35.445038", "lvl": "target", "msg": "shardfile-rtc pass"}
- {"dt": "2025-03-25T00:31:35.562208", "lvl": "target", "msg": "<12>[   22.448089] kselftest: Running tests in rtc"}
- {"dt": "2025-03-25T00:31:35.579094", "lvl": "target", "msg": "TAP version 13"}
- {"dt": "2025-03-25T00:31:35.591658", "lvl": "target", "msg": "1..1"}
- {"dt": "2025-03-25T00:31:35.649701", "lvl": "target", "msg": "# timeout set to 210"}
- {"dt": "2025-03-25T00:31:35.649830", "lvl": "target", "msg": "# selftests: rtc: rtctest"}
- {"dt": "2025-03-25T00:31:35.873790", "lvl": "target", "msg": "# TAP version 13"}
- {"dt": "2025-03-25T00:31:35.873944", "lvl": "target", "msg": "# 1..8"}
- {"dt": "2025-03-25T00:31:35.874770", "lvl": "target", "msg": "# # Starting 8 tests from 1 test cases."}
- {"dt": "2025-03-25T00:31:35.875519", "lvl": "target", "msg": "# #  RUN           rtc.date_read ..."}
- {"dt": "2025-03-25T00:31:35.877374", "lvl": "target", "msg": "# # rtctest.c:60:date_read:Current RTC date/time is 25/03/2025 00:31:35."}
- {"dt": "2025-03-25T00:31:35.877816", "lvl": "target", "msg": "# #            OK  rtc.date_read"}
- {"dt": "2025-03-25T00:31:35.878540", "lvl": "target", "msg": "# ok 1 rtc.date_read"}
- {"dt": "2025-03-25T00:31:35.879147", "lvl": "target", "msg": "# #  RUN           rtc.date_read_loop ..."}
- {"dt": "2025-03-25T00:31:35.881425", "lvl": "target", "msg": "# # rtctest.c:120:date_read_loop:Continuously reading RTC time for 30s (with 11ms breaks after every read)."}
- {"dt": "2025-03-25T00:32:06.020674", "lvl": "target", "msg": "# # rtctest.c:146:date_read_loop:Performed 2652 RTC time reads."}
- {"dt": "2025-03-25T00:32:06.024544", "lvl": "target", "msg": "# #            OK  rtc.date_read_loop"}
- {"dt": "2025-03-25T00:32:06.024644", "lvl": "target", "msg": "# ok 2 rtc.date_read_loop"}
- {"dt": "2025-03-25T00:32:06.024760", "lvl": "target", "msg": "# #  RUN           rtc.uie_read ..."}
- {"dt": "2025-03-25T00:32:09.036088", "lvl": "target", "msg": "# #            OK  rtc.uie_read"}
- {"dt": "2025-03-25T00:32:09.036236", "lvl": "target", "msg": "# ok 3 rtc.uie_read"}
- {"dt": "2025-03-25T00:32:09.036318", "lvl": "target", "msg": "# #  RUN           rtc.uie_select ..."}
- {"dt": "2025-03-25T00:32:12.044568", "lvl": "target", "msg": "# #            OK  rtc.uie_select"}
- {"dt": "2025-03-25T00:32:12.044725", "lvl": "target", "msg": "# ok 4 rtc.uie_select"}
- {"dt": "2025-03-25T00:32:12.044811", "lvl": "target", "msg": "# #  RUN           rtc.alarm_alm_set ..."}
- {"dt": "2025-03-25T00:32:12.050291", "lvl": "target", "msg": "# # rtctest.c:256:alarm_alm_set:Alarm time now set to 00:32:15."}
- {"dt": "2025-03-25T00:32:12.054289", "lvl": "target", "msg": "# # rtctest.c:267:alarm_alm_set:Expected 0 (0) != rc (0)"}
- {"dt": "2025-03-25T00:32:12.058502", "lvl": "target", "msg": "# # alarm_alm_set: Test terminated by assertion"}
- {"dt": "2025-03-25T00:32:12.058573", "lvl": "target", "msg": "# #          FAIL  rtc.alarm_alm_set"}
- {"dt": "2025-03-25T00:32:12.058648", "lvl": "target", "msg": "# not ok 5 rtc.alarm_alm_set"}
- {"dt": "2025-03-25T00:32:12.066255", "lvl": "target", "msg": "# #  RUN           rtc.alarm_wkalm_set ..."}
- {"dt": "2025-03-25T00:32:12.066792", "lvl": "target", "msg": "# # rtctest.c:328:alarm_wkalm_set:Alarm time now set to 25/03/2025 00:32:15."}
- {"dt": "2025-03-25T00:32:12.067069", "lvl": "target", "msg": "# # rtctest.c:334:alarm_wkalm_set:Expected -1 (-1) != rc (-1)"}
- {"dt": "2025-03-25T00:32:12.074318", "lvl": "target", "msg": "# # alarm_wkalm_set: Test terminated by assertion"}
- {"dt": "2025-03-25T00:32:12.074398", "lvl": "target", "msg": "# #          FAIL  rtc.alarm_wkalm_set"}
- {"dt": "2025-03-25T00:32:12.074472", "lvl": "target", "msg": "# not ok 6 rtc.alarm_wkalm_set"}
- {"dt": "2025-03-25T00:32:12.076907", "lvl": "target", "msg": "# #  RUN           rtc.alarm_alm_set_minute ..."}
- {"dt": "2025-03-25T00:32:12.078700", "lvl": "target", "msg": "# # rtctest.c:386:alarm_alm_set_minute:Alarm time now set to 00:33:00."}
- {"dt": "2025-03-25T00:32:12.080190", "lvl": "target", "msg": "# # rtctest.c:397:alarm_alm_set_minute:Expected 0 (0) != rc (0)"}
- {"dt": "2025-03-25T00:32:12.081631", "lvl": "target", "msg": "# # alarm_alm_set_minute: Test terminated by assertion"}
- {"dt": "2025-03-25T00:32:12.082761", "lvl": "target", "msg": "# #          FAIL  rtc.alarm_alm_set_minute"}
- {"dt": "2025-03-25T00:32:12.083342", "lvl": "target", "msg": "# not ok 7 rtc.alarm_alm_set_minute"}
- {"dt": "2025-03-25T00:32:12.084613", "lvl": "target", "msg": "# #  RUN           rtc.alarm_wkalm_set_minute ..."}
- {"dt": "2025-03-25T00:32:12.086775", "lvl": "target", "msg": "# # rtctest.c:458:alarm_wkalm_set_minute:Alarm time now set to 25/03/2025 00:33:00."}
- {"dt": "2025-03-25T00:32:12.088367", "lvl": "target", "msg": "# # rtctest.c:464:alarm_wkalm_set_minute:Expected -1 (-1) != rc (-1)"}
- {"dt": "2025-03-25T00:32:12.089638", "lvl": "target", "msg": "# # alarm_wkalm_set_minute: Test terminated by assertion"}
- {"dt": "2025-03-25T00:32:12.091282", "lvl": "target", "msg": "# #          FAIL  rtc.alarm_wkalm_set_minute"}
- {"dt": "2025-03-25T00:32:12.092117", "lvl": "target", "msg": "# not ok 8 rtc.alarm_wkalm_set_minute"}
- {"dt": "2025-03-25T00:32:12.092705", "lvl": "target", "msg": "# # FAILED: 4 / 8 tests passed."}
- {"dt": "2025-03-25T00:32:12.093949", "lvl": "target", "msg": "# # Totals: pass:4 fail:4 xfail:0 xpass:0 skip:0 error:0"}
- {"dt": "2025-03-25T00:32:12.104709", "lvl": "target", "msg": "not ok 1 selftests: rtc: rtctest # exit=1"}
- {"dt": "2025-03-25T00:32:13.059624", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T00:32:13.060038", "lvl": "target", "msg": "WARNING: Optional imports not found, TAP 13 output will be"}
- {"dt": "2025-03-25T00:32:13.060150", "lvl": "target", "msg": "    ignored. To parse yaml, see requirements in docs:"}
- {"dt": "2025-03-25T00:32:13.060422", "lvl": "target", "msg": "    https://tappy.readthedocs.io/en/latest/consumers.html#tap-version-13"}
- {"dt": "2025-03-25T00:32:13.067090", "lvl": "target", "msg": "Traceback (most recent call last):"}
- {"dt": "2025-03-25T00:32:13.079345", "lvl": "target", "msg": "  File [35m\"/lava-1/0/tests/0_kselftest-rtc/automated/linux/kselftest/./parse-output.py\"[0m, line [35m93[0m, in [35m<module>[0m"}
- {"dt": "2025-03-25T00:32:13.079439", "lvl": "target", "msg": "    results = parse_nested_tap(sys.stdin.read())"}
- {"dt": "2025-03-25T00:32:13.079935", "lvl": "target", "msg": "  File [35m\"/lava-1/0/tests/0_kselftest-rtc/automated/linux/kselftest/./parse-output.py\"[0m, line [35m51[0m, in [35mparse_nested_tap[0m"}
- {"dt": "2025-03-25T00:32:13.080008", "lvl": "target", "msg": "    \"children\": [31mparse_nested_tap[0m[1;31m(output)[0m,"}
- {"dt": "2025-03-25T00:32:13.080067", "lvl": "target", "msg": "                [31m~~~~~~~~~~~~~~~~[0m[1;31m^^^^^^^^[0m"}
- {"dt": "2025-03-25T00:32:13.080711", "lvl": "target", "msg": "  File [35m\"/lava-1/0/tests/0_kselftest-rtc/automated/linux/kselftest/./parse-output.py\"[0m, line [35m59[0m, in [35mparse_nested_tap[0m"}
- {"dt": "2025-03-25T00:32:13.080758", "lvl": "target", "msg": "    [31mr[0m[1;31m[\"logs\"][0m += f\"{uncomment(l.text)}\\n\""}
- {"dt": "2025-03-25T00:32:13.080805", "lvl": "target", "msg": "    [31m~[0m[1;31m^^^^^^^^[0m"}
- {"dt": "2025-03-25T00:32:13.081256", "lvl": "target", "msg": "[1;35mKeyError[0m: [35m'logs'[0m"}
- {"dt": "2025-03-25T00:32:13.151107", "lvl": "target", "msg": "+ ../../utils/send-to-lava.sh ./output/result.txt"}
- {"dt": "2025-03-25T00:32:13.183941", "lvl": "target", "msg": "WARNING: no log file found for breakpoints:breakpoint_test_arm64 at ./output/breakpoints:breakpoint_test_arm64.log"}
- {"dt": "2025-03-25T00:32:13.200803", "lvl": "target", "msg": "<8>[   60.086470] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=breakpoints:breakpoint_test_arm64 RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.201124", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=breakpoints:breakpoint_test_arm64 RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.201245", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "breakpoints:breakpoint_test_arm64", "result": "skip", "starttc": ! "876", "endtc": ! "876"}}
- {"dt": "2025-03-25T00:32:13.214996", "lvl": "target", "msg": "WARNING: no log file found for breakpoints:step_after_suspend_test at ./output/breakpoints:step_after_suspend_test.log"}
- {"dt": "2025-03-25T00:32:13.229054", "lvl": "target", "msg": "<8>[   60.114936] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=breakpoints:step_after_suspend_test RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.229340", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=breakpoints:step_after_suspend_test RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.229438", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "breakpoints:step_after_suspend_test", "result": "skip", "starttc": ! "880", "endtc": ! "880"}}
- {"dt": "2025-03-25T00:32:13.242423", "lvl": "target", "msg": "WARNING: no log file found for kvm:get-reg-list at ./output/kvm:get-reg-list.log"}
- {"dt": "2025-03-25T00:32:13.256721", "lvl": "target", "msg": "<8>[   60.142660] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=kvm:get-reg-list RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.257009", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=kvm:get-reg-list RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.257104", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "kvm:get-reg-list", "result": "skip", "starttc": ! "884", "endtc": ! "884"}}
- {"dt": "2025-03-25T00:32:13.268535", "lvl": "target", "msg": "WARNING: no log file found for kvm:kvm_create_max_vcpus at ./output/kvm:kvm_create_max_vcpus.log"}
- {"dt": "2025-03-25T00:32:13.282173", "lvl": "target", "msg": "<8>[   60.168034] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=kvm:kvm_create_max_vcpus RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.282452", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=kvm:kvm_create_max_vcpus RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.282518", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "kvm:kvm_create_max_vcpus", "result": "skip", "starttc": ! "888", "endtc": ! "888"}}
- {"dt": "2025-03-25T00:32:13.295123", "lvl": "target", "msg": "WARNING: no log file found for mqueue:mq_open_tests at ./output/mqueue:mq_open_tests.log"}
- {"dt": "2025-03-25T00:32:13.309346", "lvl": "target", "msg": "<8>[   60.195262] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=mqueue:mq_open_tests RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.309630", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=mqueue:mq_open_tests RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.309723", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "mqueue:mq_open_tests", "result": "skip", "starttc": ! "892", "endtc": ! "892"}}
- {"dt": "2025-03-25T00:32:13.321153", "lvl": "target", "msg": "WARNING: no log file found for mqueue:mq_perf_tests at ./output/mqueue:mq_perf_tests.log"}
- {"dt": "2025-03-25T00:32:13.335439", "lvl": "target", "msg": "<8>[   60.221385] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=mqueue:mq_perf_tests RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.335733", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=mqueue:mq_perf_tests RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.335825", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "mqueue:mq_perf_tests", "result": "skip", "starttc": ! "896", "endtc": ! "896"}}
- {"dt": "2025-03-25T00:32:13.347580", "lvl": "target", "msg": "WARNING: no log file found for net:fib_nexthops.sh at ./output/net:fib_nexthops.sh.log"}
- {"dt": "2025-03-25T00:32:13.361500", "lvl": "target", "msg": "<8>[   60.247420] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:fib_nexthops.sh RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.361798", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:fib_nexthops.sh RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.361900", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "net:fib_nexthops.sh", "result": "skip", "starttc": ! "900", "endtc": ! "900"}}
- {"dt": "2025-03-25T00:32:13.372892", "lvl": "target", "msg": "WARNING: no log file found for net:msg_zerocopy.sh at ./output/net:msg_zerocopy.sh.log"}
- {"dt": "2025-03-25T00:32:13.387176", "lvl": "target", "msg": "<8>[   60.273122] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:msg_zerocopy.sh RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.387482", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:msg_zerocopy.sh RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.387604", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "net:msg_zerocopy.sh", "result": "skip", "starttc": ! "904", "endtc": ! "904"}}
- {"dt": "2025-03-25T00:32:13.400291", "lvl": "target", "msg": "WARNING: no log file found for net:rtnetlink.sh at ./output/net:rtnetlink.sh.log"}
- {"dt": "2025-03-25T00:32:13.415340", "lvl": "target", "msg": "<8>[   60.301210] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:rtnetlink.sh RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.415628", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:rtnetlink.sh RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.415709", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "net:rtnetlink.sh", "result": "skip", "starttc": ! "908", "endtc": ! "908"}}
- {"dt": "2025-03-25T00:32:13.427519", "lvl": "target", "msg": "WARNING: no log file found for net:run_afpackettests at ./output/net:run_afpackettests.log"}
- {"dt": "2025-03-25T00:32:13.442397", "lvl": "target", "msg": "<8>[   60.328196] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:run_afpackettests RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.442711", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:run_afpackettests RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.442823", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "net:run_afpackettests", "result": "skip", "starttc": ! "912", "endtc": ! "912"}}
- {"dt": "2025-03-25T00:32:13.453971", "lvl": "target", "msg": "WARNING: no log file found for net:tls at ./output/net:tls.log"}
- {"dt": "2025-03-25T00:32:13.468716", "lvl": "target", "msg": "<8>[   60.354600] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:tls RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.469033", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:tls RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.469141", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "net:tls", "result": "skip", "starttc": ! "916", "endtc": ! "916"}}
- {"dt": "2025-03-25T00:32:13.480942", "lvl": "target", "msg": "WARNING: no log file found for net:udpgro.sh at ./output/net:udpgro.sh.log"}
- {"dt": "2025-03-25T00:32:13.495475", "lvl": "target", "msg": "<8>[   60.381434] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:udpgro.sh RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.495743", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:udpgro.sh RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.495825", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "net:udpgro.sh", "result": "skip", "starttc": ! "920", "endtc": ! "920"}}
- {"dt": "2025-03-25T00:32:13.507199", "lvl": "target", "msg": "WARNING: no log file found for net:xfrm_policy.sh at ./output/net:xfrm_policy.sh.log"}
- {"dt": "2025-03-25T00:32:13.521537", "lvl": "target", "msg": "<8>[   60.407216] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:xfrm_policy.sh RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.521793", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:xfrm_policy.sh RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.521889", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "net:xfrm_policy.sh", "result": "skip", "starttc": ! "924", "endtc": ! "924"}}
- {"dt": "2025-03-25T00:32:13.532849", "lvl": "target", "msg": "WARNING: no log file found for pidfd:pidfd_wait at ./output/pidfd:pidfd_wait.log"}
- {"dt": "2025-03-25T00:32:13.547381", "lvl": "target", "msg": "<8>[   60.433309] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=pidfd:pidfd_wait RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.547685", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=pidfd:pidfd_wait RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.547782", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "pidfd:pidfd_wait", "result": "skip", "starttc": ! "928", "endtc": ! "928"}}
- {"dt": "2025-03-25T00:32:13.561162", "lvl": "target", "msg": "WARNING: no log file found for proc:proc-pid-vm at ./output/proc:proc-pid-vm.log"}
- {"dt": "2025-03-25T00:32:13.575724", "lvl": "target", "msg": "<8>[   60.461662] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=proc:proc-pid-vm RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.576019", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=proc:proc-pid-vm RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.576113", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "proc:proc-pid-vm", "result": "skip", "starttc": ! "932", "endtc": ! "932"}}
- {"dt": "2025-03-25T00:32:13.587297", "lvl": "target", "msg": "WARNING: no log file found for ptrace:vmaccess at ./output/ptrace:vmaccess.log"}
- {"dt": "2025-03-25T00:32:13.601659", "lvl": "target", "msg": "<8>[   60.487582] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=ptrace:vmaccess RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.601977", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=ptrace:vmaccess RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.602061", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "ptrace:vmaccess", "result": "skip", "starttc": ! "936", "endtc": ! "936"}}
- {"dt": "2025-03-25T00:32:13.613849", "lvl": "target", "msg": "WARNING: no log file found for rseq:run_param_test.sh at ./output/rseq:run_param_test.sh.log"}
- {"dt": "2025-03-25T00:32:13.628547", "lvl": "target", "msg": "<8>[   60.514452] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=rseq:run_param_test.sh RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.628827", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=rseq:run_param_test.sh RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.628916", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "rseq:run_param_test.sh", "result": "skip", "starttc": ! "940", "endtc": ! "940"}}
- {"dt": "2025-03-25T00:32:13.640964", "lvl": "target", "msg": "WARNING: no log file found for sync:sync_test at ./output/sync:sync_test.log"}
- {"dt": "2025-03-25T00:32:13.655356", "lvl": "target", "msg": "<8>[   60.541310] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=sync:sync_test RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.655635", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=sync:sync_test RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.655724", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "sync:sync_test", "result": "skip", "starttc": ! "944", "endtc": ! "944"}}
- {"dt": "2025-03-25T00:32:13.667225", "lvl": "target", "msg": "WARNING: no log file found for zram:zram.sh at ./output/zram:zram.sh.log"}
- {"dt": "2025-03-25T00:32:13.681209", "lvl": "target", "msg": "<8>[   60.567143] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=zram:zram.sh RESULT=skip>"}
- {"dt": "2025-03-25T00:32:13.681492", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=zram:zram.sh RESULT=skip"}
- {"dt": "2025-03-25T00:32:13.681589", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "zram:zram.sh", "result": "skip", "starttc": ! "948", "endtc": ! "948"}}
- {"dt": "2025-03-25T00:32:13.693077", "lvl": "target", "msg": "WARNING: no log file found for shardfile-rtc at ./output/shardfile-rtc.log"}
- {"dt": "2025-03-25T00:32:13.707447", "lvl": "target", "msg": "<8>[   60.593387] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=shardfile-rtc RESULT=pass>"}
- {"dt": "2025-03-25T00:32:13.707729", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=shardfile-rtc RESULT=pass"}
- {"dt": "2025-03-25T00:32:13.707819", "lvl": "results", "msg": {"definition": "0_kselftest-rtc", "case": "shardfile-rtc", "result": "pass", "starttc": ! "952", "endtc": ! "952"}}
- {"dt": "2025-03-25T00:32:13.832518", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2025-03-25T00:32:13.833058", "lvl": "target", "msg": "<8>[   60.718992] <LAVA_SIGNAL_ENDRUN 0_kselftest-rtc 1_1.1.3.1>"}
- {"dt": "2025-03-25T00:32:13.833323", "lvl": "debug", "msg": "Received signal: <ENDRUN> 0_kselftest-rtc 1_1.1.3.1"}
- {"dt": "2025-03-25T00:32:13.833437", "lvl": "info", "msg": "Ending use of test pattern."}
- {"dt": "2025-03-25T00:32:13.833499", "lvl": "info", "msg": "Ending test lava.0_kselftest-rtc (1_1.1.3.1), duration 47.14"}
- {"dt": "2025-03-25T00:32:13.833579", "lvl": "results", "msg": {"definition": "lava", "case": "0_kselftest-rtc", "uuid": "1_1.1.3.1", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "path": "automated/linux/kselftest/kselftest.yaml", "duration": "47.14", "result": "pass", "revision": "unspecified", "namespace": "common", "commit_id": "450111580e70664ab07b21744eff0a1147707c44"}}
- {"dt": "2025-03-25T00:32:13.835798", "lvl": "target", "msg": "<LAVA_TEST_RUNNER EXIT>"}
- {"dt": "2025-03-25T00:32:13.836050", "lvl": "info", "msg": "ok: lava_test_shell seems to have completed"}
- {"dt": "2025-03-25T00:32:13.836263", "lvl": "debug", "msg": "breakpoints:breakpoint_test_arm64: skip\nbreakpoints:step_after_suspend_test: skip\nkvm:get-reg-list: skip\nkvm:kvm_create_max_vcpus: skip\nmqueue:mq_open_tests: skip\nmqueue:mq_perf_tests: skip\nnet:fib_nexthops.sh: skip\nnet:msg_zerocopy.sh: skip\nnet:rtnetlink.sh: skip\nnet:run_afpackettests: skip\nnet:tls: skip\nnet:udpgro.sh: skip\nnet:xfrm_policy.sh: skip\npidfd:pidfd_wait: skip\nproc:proc-pid-vm: skip\nptrace:vmaccess: skip\nrseq:run_param_test.sh: skip\nsync:sync_test: skip\nzram:zram.sh: skip\nshardfile-rtc: pass\n"}
- {"dt": "2025-03-25T00:32:13.836386", "lvl": "debug", "msg": "end: 3.1 lava-test-shell (duration 00:00:48) [common]"}
- {"dt": "2025-03-25T00:32:13.836478", "lvl": "info", "msg": "end: 3 lava-test-retry (duration 00:00:48) [common]"}
- {"dt": "2025-03-25T00:32:13.836554", "lvl": "info", "msg": "start: 4 finalize (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T00:32:13.836628", "lvl": "debug", "msg": "start: 4.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2025-03-25T00:32:13.836697", "lvl": "debug", "msg": "end: 4.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T00:32:13.836765", "lvl": "debug", "msg": "start: 4.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T00:32:13.836887", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T00:32:13.837696", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T00:32:13.838032", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T00:32:13.838268", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T00:32:14.837842", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2025-03-25T00:32:14.838017", "lvl": "debug", "msg": "Sending line: 'poweroff'"}
- {"dt": "2025-03-25T00:32:14.938266", "lvl": "input", "msg": "poweroff"}
- {"dt": "2025-03-25T00:32:14.938677", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2025-03-25T00:32:14.938775", "lvl": "target", "msg": "[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# poweroff"}
- {"dt": "2025-03-25T00:32:15.039032", "lvl": "debug", "msg": "end: 4.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2025-03-25T00:32:15.039164", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2025-03-25T00:32:15.039256", "lvl": "info", "msg": "end: 4 finalize (duration 00:00:01) [common]"}
- {"dt": "2025-03-25T00:32:15.039364", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2025-03-25T00:32:15.039497", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/kernel/Image"}
- {"dt": "2025-03-25T00:32:15.045025", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4"}
- {"dt": "2025-03-25T00:32:15.154046", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs.kselftest/kselftest.tar"}
- {"dt": "2025-03-25T00:32:15.165900", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1/deployimages-23alfzoy/rootfs.modules/modules.tar"}
- {"dt": "2025-03-25T00:32:15.175482", "lvl": "info", "msg": "Removing root tmp directory at /var/lib/lava/dispatcher/tmp/tuxrun-5_fdlez8-1"}
- {"dt": "2025-03-25T00:32:15.219680", "lvl": "info", "msg": "Job finished correctly"}
- {"dt": "2025-03-25T00:32:15.219800", "lvl": "results", "msg": {"definition": "lava", "case": "job", "result": "pass"}}
