- {"dt": "2025-03-25T13:57:56.729394", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2024.09.dev0173"}
- {"dt": "2025-03-25T13:57:56.729476", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2025-03-25T13:57:56.729545", "lvl": "info", "msg": "Start time: 2025-03-25 13:57:56.729538+00:00 (UTC)"}
- {"dt": "2025-03-25T13:57:56.730329", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/Image.gz exists"}
- {"dt": "2025-03-25T13:57:57.145220", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2025-03-25T13:57:57.775503", "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-25T13:57:57.775671", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/kselftest.tar.xz exists"}
- {"dt": "2025-03-25T13:57:57.898405", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2025-03-25T13:57:58.490803", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/modules.tar.xz exists"}
- {"dt": "2025-03-25T13:57:58.620665", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2025-03-25T13:57:59.234354", "lvl": "info", "msg": "qemu-system-arm, installed at version: 1:9.2.1+ds-1, host architecture: amd64"}
- {"dt": "2025-03-25T13:57:59.234611", "lvl": "warning", "msg": "Missing image arg for rootfs.kselftest"}
- {"dt": "2025-03-25T13:57:59.234727", "lvl": "warning", "msg": "Missing image arg for rootfs.modules"}
- {"dt": "2025-03-25T13:57:59.234964", "lvl": "info", "msg": "validate duration: 2.51"}
- {"dt": "2025-03-25T13:57:59.235084", "lvl": "results", "msg": {"definition": "lava", "case": "validate", "result": "pass"}}
- {"dt": "2025-03-25T13:57:59.235272", "lvl": "info", "msg": "start: 1 deployimages (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T13:57:59.235380", "lvl": "debug", "msg": "start: 1.1 lava-overlay (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T13:57:59.235629", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on"}
- {"dt": "2025-03-25T13:57:59.235802", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin"}
- {"dt": "2025-03-25T13:57:59.235926", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/tests"}
- {"dt": "2025-03-25T13:57:59.236071", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/results"}
- {"dt": "2025-03-25T13:57:59.236180", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-add-keys"}
- {"dt": "2025-03-25T13:57:59.236370", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-add-sources"}
- {"dt": "2025-03-25T13:57:59.236524", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-background-process-start"}
- {"dt": "2025-03-25T13:57:59.236687", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-background-process-stop"}
- {"dt": "2025-03-25T13:57:59.236853", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-common-functions"}
- {"dt": "2025-03-25T13:57:59.237011", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-echo-ipv4"}
- {"dt": "2025-03-25T13:57:59.237169", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-install-packages"}
- {"dt": "2025-03-25T13:57:59.237326", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-installed-packages"}
- {"dt": "2025-03-25T13:57:59.237483", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-os-build"}
- {"dt": "2025-03-25T13:57:59.237643", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-probe-channel"}
- {"dt": "2025-03-25T13:57:59.237842", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-probe-ip"}
- {"dt": "2025-03-25T13:57:59.238034", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-target-ip"}
- {"dt": "2025-03-25T13:57:59.238192", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-target-mac"}
- {"dt": "2025-03-25T13:57:59.238316", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-target-storage"}
- {"dt": "2025-03-25T13:57:59.238438", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-test-case"}
- {"dt": "2025-03-25T13:57:59.238561", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-test-event"}
- {"dt": "2025-03-25T13:57:59.238677", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-test-feedback"}
- {"dt": "2025-03-25T13:57:59.238791", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-test-raise"}
- {"dt": "2025-03-25T13:57:59.238902", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-test-reference"}
- {"dt": "2025-03-25T13:57:59.239019", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-test-runner"}
- {"dt": "2025-03-25T13:57:59.239133", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-test-set"}
- {"dt": "2025-03-25T13:57:59.239245", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-test-shell"}
- {"dt": "2025-03-25T13:57:59.239358", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-install-packages (oe)"}
- {"dt": "2025-03-25T13:57:59.239507", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/bin/lava-installed-packages (oe)"}
- {"dt": "2025-03-25T13:57:59.239618", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/environment"}
- {"dt": "2025-03-25T13:57:59.239702", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2025-03-25T13:57:59.239751", "lvl": "debug", "msg": "- LAVA_JOB_ID=1"}
- {"dt": "2025-03-25T13:57:59.239795", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.32.138"}
- {"dt": "2025-03-25T13:57:59.239869", "lvl": "debug", "msg": "start: 1.1.1 lava-vland-overlay (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T13:57:59.239913", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2025-03-25T13:57:59.239964", "lvl": "debug", "msg": "end: 1.1.1 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:57:59.240019", "lvl": "debug", "msg": "start: 1.1.2 lava-multinode-overlay (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T13:57:59.240058", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2025-03-25T13:57:59.240105", "lvl": "debug", "msg": "end: 1.1.2 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:57:59.240156", "lvl": "debug", "msg": "start: 1.1.3 test-definition (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T13:57:59.240203", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2025-03-25T13:57:59.240259", "lvl": "debug", "msg": "start: 1.1.3.1 git-repo-action (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T13:57:59.240303", "lvl": "debug", "msg": "Using /lava-1 at stage 0"}
- {"dt": "2025-03-25T13:57:59.240371", "lvl": "info", "msg": "Fetching tests from https://github.com/TheodoreRTG/test-definitions.git"}
- {"dt": "2025-03-25T13:57:59.240426", "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-5oznpv4t-1/lava-overlay-snga41on/lava-1/0/tests/0_kselftest-core'"}
- {"dt": "2025-03-25T13:58:02.785341", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/0/tests/0_kselftest-core/automated/linux/kselftest/kselftest.yaml"}
- {"dt": "2025-03-25T13:58:02.785885", "lvl": "debug", "msg": "uuid=1_1.1.3.1 testdef=None"}
- {"dt": "2025-03-25T13:58:02.786011", "lvl": "debug", "msg": "end: 1.1.3.1 git-repo-action (duration 00:00:04) [common]"}
- {"dt": "2025-03-25T13:58:02.786099", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "git-repo-action", "level": "1.1.3.1", "duration": "3.55", "result": "pass", "extra": {"commit": "e61633ff1a396344dd4e98f24b8873ed7b9d6182", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "path": "automated/linux/kselftest/kselftest.yaml"}}}
- {"dt": "2025-03-25T13:58:02.786243", "lvl": "debug", "msg": "start: 1.1.3.2 test-overlay (timeout 00:14:56) [common]"}
- {"dt": "2025-03-25T13:58:02.786989", "lvl": "debug", "msg": "end: 1.1.3.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:02.787041", "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-core", "path": "automated/linux/kselftest/kselftest.yaml", "from": "git", "repository": "https://github.com/TheodoreRTG/test-definitions.git"}}}
- {"dt": "2025-03-25T13:58:02.787145", "lvl": "debug", "msg": "start: 1.1.3.3 test-install-overlay (timeout 00:14:56) [common]"}
- {"dt": "2025-03-25T13:58:02.787936", "lvl": "debug", "msg": "end: 1.1.3.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:02.787989", "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-core", "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-25T13:58:02.788096", "lvl": "debug", "msg": "start: 1.1.3.4 test-runscript-overlay (timeout 00:14:56) [common]"}
- {"dt": "2025-03-25T13:58:02.796275", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/0/tests/0_kselftest-core test_uuid 1_1.1.3.1"}
- {"dt": "2025-03-25T13:58:02.796350", "lvl": "debug", "msg": "TST_CMDFILES='core'"}
- {"dt": "2025-03-25T13:58:02.796395", "lvl": "debug", "msg": "KSELFTEST_PATH='/opt/kselftests/default-in-kernel'"}
- {"dt": "2025-03-25T13:58:02.796433", "lvl": "debug", "msg": "SKIPFILE='skipfile-lkft.yaml'"}
- {"dt": "2025-03-25T13:58:02.796469", "lvl": "debug", "msg": "ENVIRONMENT='production'"}
- {"dt": "2025-03-25T13:58:02.796502", "lvl": "debug", "msg": "SHARD_NUMBER='1'"}
- {"dt": "2025-03-25T13:58:02.796537", "lvl": "debug", "msg": "SHARD_INDEX='1'"}
- {"dt": "2025-03-25T13:58:02.796673", "lvl": "debug", "msg": "end: 1.1.3.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:02.796729", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "test-runscript-overlay", "level": "1.1.3.4", "duration": "0.01", "result": "pass", "extra": {"uuid": "1_1.1.3.1", "name": "kselftest-core", "path": "automated/linux/kselftest/kselftest.yaml", "from": "git", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "filename": "/var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/0/tests/0_kselftest-core/run.sh"}}}
- {"dt": "2025-03-25T13:58:02.796821", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2025-03-25T13:58:02.796862", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/lava-overlay-snga41on/lava-1/0 for stage 0"}
- {"dt": "2025-03-25T13:58:02.796937", "lvl": "debug", "msg": "- 0_kselftest-core"}
- {"dt": "2025-03-25T13:58:02.797022", "lvl": "debug", "msg": "end: 1.1.3 test-definition (duration 00:00:04) [common]"}
- {"dt": "2025-03-25T13:58:02.797085", "lvl": "debug", "msg": "start: 1.1.4 compress-overlay (timeout 00:14:56) [common]"}
- {"dt": "2025-03-25T13:58:08.618240", "lvl": "debug", "msg": "end: 1.1.4 compress-overlay (duration 00:00:06) [common]"}
- {"dt": "2025-03-25T13:58:08.618403", "lvl": "debug", "msg": "end: 1.1 lava-overlay (duration 00:00:09) [common]"}
- {"dt": "2025-03-25T13:58:08.618480", "lvl": "debug", "msg": "start: 1.2 apply-overlay-guest (timeout 00:14:51) [common]"}
- {"dt": "2025-03-25T13:58:08.618539", "lvl": "debug", "msg": "Overlay already applied"}
- {"dt": "2025-03-25T13:58:08.618610", "lvl": "debug", "msg": "end: 1.2 apply-overlay-guest (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:08.618688", "lvl": "debug", "msg": "start: 1.3 deploy-device-env (timeout 00:14:51) [common]"}
- {"dt": "2025-03-25T13:58:08.618752", "lvl": "debug", "msg": "end: 1.3 deploy-device-env (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:08.618816", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:14:51) [common]"}
- {"dt": "2025-03-25T13:58:08.618883", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T13:58:08.619070", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/Image.gz"}
- {"dt": "2025-03-25T13:58:08.619125", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/kernel/Image"}
- {"dt": "2025-03-25T13:58:08.619175", "lvl": "debug", "msg": "total size: 14569912 (13\u202FMB)"}
- {"dt": "2025-03-25T13:58:08.619222", "lvl": "info", "msg": "Using gunzip to decompress gz"}
- {"dt": "2025-03-25T13:58:09.279246", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T13:58:09.628955", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T13:58:09.769744", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2025-03-25T13:58:09.877896", "lvl": "debug", "msg": "progress  15\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T13:58:09.988103", "lvl": "debug", "msg": "progress  20\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T13:58:10.104595", "lvl": "debug", "msg": "progress  25\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T13:58:10.209551", "lvl": "debug", "msg": "progress  30\u202F% (4\u202FMB)"}
- {"dt": "2025-03-25T13:58:10.334223", "lvl": "debug", "msg": "progress  35\u202F% (4\u202FMB)"}
- {"dt": "2025-03-25T13:58:10.444695", "lvl": "debug", "msg": "progress  40\u202F% (5\u202FMB)"}
- {"dt": "2025-03-25T13:58:10.545611", "lvl": "debug", "msg": "progress  45\u202F% (6\u202FMB)"}
- {"dt": "2025-03-25T13:58:10.667645", "lvl": "debug", "msg": "progress  50\u202F% (6\u202FMB)"}
- {"dt": "2025-03-25T13:58:10.769562", "lvl": "debug", "msg": "progress  56\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T13:58:10.887928", "lvl": "debug", "msg": "progress  61\u202F% (8\u202FMB)"}
- {"dt": "2025-03-25T13:58:10.988004", "lvl": "debug", "msg": "progress  66\u202F% (9\u202FMB)"}
- {"dt": "2025-03-25T13:58:11.088449", "lvl": "debug", "msg": "progress  71\u202F% (9\u202FMB)"}
- {"dt": "2025-03-25T13:58:11.198047", "lvl": "debug", "msg": "progress  76\u202F% (10\u202FMB)"}
- {"dt": "2025-03-25T13:58:11.300765", "lvl": "debug", "msg": "progress  81\u202F% (11\u202FMB)"}
- {"dt": "2025-03-25T13:58:11.401301", "lvl": "debug", "msg": "progress  86\u202F% (12\u202FMB)"}
- {"dt": "2025-03-25T13:58:11.504488", "lvl": "debug", "msg": "progress  91\u202F% (12\u202FMB)"}
- {"dt": "2025-03-25T13:58:11.605416", "lvl": "debug", "msg": "progress  96\u202F% (13\u202FMB)"}
- {"dt": "2025-03-25T13:58:11.678493", "lvl": "info", "msg": "13\u202FMB downloaded in 3.06\u202Fs (4.54\u202FMB/s)"}
- {"dt": "2025-03-25T13:58:11.678693", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T13:58:11.678773", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.4.1", "duration": "3.06", "result": "pass", "extra": {"label": "kernel", "size": ! "14569912", "sha256sum": "9f49bfcc793ea5bd9c25dd5d8f9bde6fc589925ccb5bc96b4191d327c0e34c8a"}}}
- {"dt": "2025-03-25T13:58:11.678919", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T13:58:11.679001", "lvl": "debug", "msg": "start: 1.5 download-retry (timeout 00:14:48) [common]"}
- {"dt": "2025-03-25T13:58:11.679080", "lvl": "debug", "msg": "start: 1.5.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T13:58:11.679301", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4.xz"}
- {"dt": "2025-03-25T13:58:11.679376", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4"}
- {"dt": "2025-03-25T13:58:11.679436", "lvl": "debug", "msg": "total size: 111407012 (106\u202FMB)"}
- {"dt": "2025-03-25T13:58:11.679496", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-03-25T13:58:11.779632", "lvl": "debug", "msg": "progress   2\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T13:58:11.933891", "lvl": "debug", "msg": "progress   7\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T13:58:12.099581", "lvl": "debug", "msg": "progress  12\u202F% (12\u202FMB)"}
- {"dt": "2025-03-25T13:58:12.255748", "lvl": "debug", "msg": "progress  17\u202F% (18\u202FMB)"}
- {"dt": "2025-03-25T13:58:12.414451", "lvl": "debug", "msg": "progress  22\u202F% (23\u202FMB)"}
- {"dt": "2025-03-25T13:58:12.583413", "lvl": "debug", "msg": "progress  27\u202F% (28\u202FMB)"}
- {"dt": "2025-03-25T13:58:12.711850", "lvl": "debug", "msg": "progress  32\u202F% (34\u202FMB)"}
- {"dt": "2025-03-25T13:58:12.861892", "lvl": "debug", "msg": "progress  37\u202F% (39\u202FMB)"}
- {"dt": "2025-03-25T13:58:13.023025", "lvl": "debug", "msg": "progress  42\u202F% (44\u202FMB)"}
- {"dt": "2025-03-25T13:58:13.178490", "lvl": "debug", "msg": "progress  47\u202F% (49\u202FMB)"}
- {"dt": "2025-03-25T13:58:13.336934", "lvl": "debug", "msg": "progress  52\u202F% (55\u202FMB)"}
- {"dt": "2025-03-25T13:58:13.501872", "lvl": "debug", "msg": "progress  57\u202F% (60\u202FMB)"}
- {"dt": "2025-03-25T13:58:13.679635", "lvl": "debug", "msg": "progress  62\u202F% (65\u202FMB)"}
- {"dt": "2025-03-25T13:58:13.836255", "lvl": "debug", "msg": "progress  67\u202F% (71\u202FMB)"}
- {"dt": "2025-03-25T13:58:13.979568", "lvl": "debug", "msg": "progress  72\u202F% (76\u202FMB)"}
- {"dt": "2025-03-25T13:58:14.140651", "lvl": "debug", "msg": "progress  77\u202F% (81\u202FMB)"}
- {"dt": "2025-03-25T13:58:14.298957", "lvl": "debug", "msg": "progress  82\u202F% (87\u202FMB)"}
- {"dt": "2025-03-25T13:58:14.458025", "lvl": "debug", "msg": "progress  87\u202F% (92\u202FMB)"}
- {"dt": "2025-03-25T13:58:14.558206", "lvl": "debug", "msg": "progress  92\u202F% (97\u202FMB)"}
- {"dt": "2025-03-25T13:58:14.670215", "lvl": "debug", "msg": "progress  97\u202F% (103\u202FMB)"}
- {"dt": "2025-03-25T13:58:17.844043", "lvl": "info", "msg": "106\u202FMB downloaded in 6.16\u202Fs (17.23\u202FMB/s)"}
- {"dt": "2025-03-25T13:58:17.844276", "lvl": "debug", "msg": "end: 1.5.1 file-download (duration 00:00:06) [common]"}
- {"dt": "2025-03-25T13:58:17.844354", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.5.1", "duration": "6.17", "result": "pass", "extra": {"label": "rootfs", "size": ! "111407012", "sha256sum": "71bcc7bc8dbd4ac7d02d52aed8886662999d6e6c790f9b9e5220beaf580ccfc1"}}}
- {"dt": "2025-03-25T13:58:17.844501", "lvl": "debug", "msg": "start: 1.5.2 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T13:58:17.844580", "lvl": "debug", "msg": "start: 1.5.2.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-03-25T13:58:17.844792", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/kselftest.tar.xz"}
- {"dt": "2025-03-25T13:58:17.844863", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/rootfs.kselftest/kselftest.tar"}
- {"dt": "2025-03-25T13:58:17.844918", "lvl": "debug", "msg": "total size: 8023924 (7\u202FMB)"}
- {"dt": "2025-03-25T13:58:17.844975", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-03-25T13:58:18.573993", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T13:58:18.860337", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T13:58:18.960886", "lvl": "debug", "msg": "progress  11\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T13:58:19.063380", "lvl": "debug", "msg": "progress  20\u202F% (1\u202FMB)"}
- {"dt": "2025-03-25T13:58:19.166306", "lvl": "debug", "msg": "progress  32\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T13:58:19.447361", "lvl": "debug", "msg": "progress  44\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T13:58:19.548600", "lvl": "debug", "msg": "progress  74\u202F% (5\u202FMB)"}
- {"dt": "2025-03-25T13:58:19.651122", "lvl": "debug", "msg": "progress  95\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T13:58:19.726110", "lvl": "info", "msg": "7\u202FMB downloaded in 1.88\u202Fs (4.07\u202FMB/s)"}
- {"dt": "2025-03-25T13:58:19.726356", "lvl": "debug", "msg": "end: 1.5.2.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T13:58:19.726436", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.5.2.1", "duration": "1.88", "result": "pass", "extra": {"label": "rootfs.kselftest", "size": ! "8023924", "sha256sum": "fdb75542f4323788281ca32df629e3017778f9558f5d778749209d759868253b"}}}
- {"dt": "2025-03-25T13:58:19.726608", "lvl": "debug", "msg": "end: 1.5.2 download-retry (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T13:58:19.726723", "lvl": "debug", "msg": "start: 1.5.3 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T13:58:19.726836", "lvl": "debug", "msg": "start: 1.5.3.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-03-25T13:58:19.727115", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/modules.tar.xz"}
- {"dt": "2025-03-25T13:58:19.727174", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/rootfs.modules/modules.tar"}
- {"dt": "2025-03-25T13:58:19.727219", "lvl": "debug", "msg": "total size: 11798000 (11\u202FMB)"}
- {"dt": "2025-03-25T13:58:19.727281", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-03-25T13:58:20.004593", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T13:58:20.155344", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T13:58:20.256276", "lvl": "debug", "msg": "progress  12\u202F% (1\u202FMB)"}
- {"dt": "2025-03-25T13:58:20.357767", "lvl": "debug", "msg": "progress  23\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T13:58:20.459632", "lvl": "debug", "msg": "progress  32\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T13:58:20.560203", "lvl": "debug", "msg": "progress  40\u202F% (4\u202FMB)"}
- {"dt": "2025-03-25T13:58:20.660593", "lvl": "debug", "msg": "progress  49\u202F% (5\u202FMB)"}
- {"dt": "2025-03-25T13:58:20.760646", "lvl": "debug", "msg": "progress  58\u202F% (6\u202FMB)"}
- {"dt": "2025-03-25T13:58:20.860862", "lvl": "debug", "msg": "progress  66\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T13:58:20.961286", "lvl": "debug", "msg": "progress  74\u202F% (8\u202FMB)"}
- {"dt": "2025-03-25T13:58:21.061903", "lvl": "debug", "msg": "progress  81\u202F% (9\u202FMB)"}
- {"dt": "2025-03-25T13:58:21.164600", "lvl": "debug", "msg": "progress  91\u202F% (10\u202FMB)"}
- {"dt": "2025-03-25T13:58:21.267280", "lvl": "debug", "msg": "progress  99\u202F% (11\u202FMB)"}
- {"dt": "2025-03-25T13:58:21.302812", "lvl": "info", "msg": "11\u202FMB downloaded in 1.58\u202Fs (7.14\u202FMB/s)"}
- {"dt": "2025-03-25T13:58:21.303061", "lvl": "debug", "msg": "end: 1.5.3.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T13:58:21.303176", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.5.3.1", "duration": "1.58", "result": "pass", "extra": {"label": "rootfs.modules", "size": ! "11798000", "sha256sum": "5b6c182841b9377518b1324e207cfbc57ed8d4eefa14147b0bf6dd6d83c68de5"}}}
- {"dt": "2025-03-25T13:58:21.303439", "lvl": "debug", "msg": "end: 1.5.3 download-retry (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T13:58:21.303587", "lvl": "debug", "msg": "start: 1.5.4 append-overlays (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T13:58:21.303709", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4'"}
- {"dt": "2025-03-25T13:58:22.951561", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2025-03-25T13:58:22.952544", "lvl": "debug", "msg": "- rootfs.lava: '/var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/compress-overlay-0uozk2o4/overlay-1.1.4.tar.gz' to '/'"}
- {"dt": "2025-03-25T13:58:23.424818", "lvl": "debug", "msg": "- rootfs.kselftest: '/var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/rootfs.kselftest/kselftest.tar' to '/opt/kselftests/default-in-kernel/'"}
- {"dt": "2025-03-25T13:58:23.719961", "lvl": "debug", "msg": "- rootfs.modules: '/var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/rootfs.modules/modules.tar' to '/usr/'"}
- {"dt": "2025-03-25T13:58:24.140481", "lvl": "debug", "msg": "end: 1.5.4 append-overlays (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T13:58:24.140851", "lvl": "debug", "msg": "end: 1.5 download-retry (duration 00:00:12) [common]"}
- {"dt": "2025-03-25T13:58:24.140961", "lvl": "info", "msg": "end: 1 deployimages (duration 00:00:25) [common]"}
- {"dt": "2025-03-25T13:58:24.141072", "lvl": "info", "msg": "start: 2 boot-image-retry (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T13:58:24.141171", "lvl": "debug", "msg": "start: 2.1 boot-qemu-image (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T13:58:24.141250", "lvl": "debug", "msg": "start: 2.1.1 execute-qemu (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T13:58:24.141516", "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-5oznpv4t-1/deployimages-b431l7pi/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-5oznpv4t-1/deployimages-b431l7pi/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4,format=raw,id=hd0,if=virtio"}
- {"dt": "2025-03-25T13:58:24.145324", "lvl": "debug", "msg": "started a shell command"}
- {"dt": "2025-03-25T13:58:24.145702", "lvl": "debug", "msg": "end: 2.1.1 execute-qemu (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:24.145813", "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-25T13:58:24.146000", "lvl": "debug", "msg": "end: 2.1 boot-qemu-image (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:24.146108", "lvl": "debug", "msg": "start: 2.2 auto-login-action (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T13:58:24.146211", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2025-03-25T13:58:24.146292", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:30:00)"}
- {"dt": "2025-03-25T13:58:24.250108", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x000f0510]"}
- {"dt": "2025-03-25T13:58:24.250519", "lvl": "target", "msg": "[    0.000000] Linux version 6.14.0-rc7-next-20250324 (tuxmake@tuxmake) (aarch64-linux-gnu-gcc (Debian 13.3.0-12) 13.3.0, GNU ld (GNU Binutils for Debian) 2.44) #1 SMP PREEMPT @1742818529"}
- {"dt": "2025-03-25T13:58:24.250609", "lvl": "target", "msg": "[    0.000000] KASLR enabled"}
- {"dt": "2025-03-25T13:58:24.250663", "lvl": "target", "msg": "[    0.000000] random: crng init done"}
- {"dt": "2025-03-25T13:58:24.250782", "lvl": "target", "msg": "[    0.000000] Machine model: linux,dummy-virt"}
- {"dt": "2025-03-25T13:58:24.250876", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2025-03-25T13:58:24.251053", "lvl": "target", "msg": "[    0.000000] earlycon: pl11 at MMIO 0x0000000009000000 (options '')"}
- {"dt": "2025-03-25T13:58:24.251194", "lvl": "target", "msg": "[    0.000000] printk: legacy bootconsole [pl11] enabled"}
- {"dt": "2025-03-25T13:58:24.251442", "lvl": "debug", "msg": "start: 2.2.1 login-action (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T13:58:24.251509", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2025-03-25T13:58:24.251566", "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-25T13:58:24.251618", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2025-03-25T13:58:24.251656", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2025-03-25T13:58:24.251695", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2025-03-25T13:58:24.251729", "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-25T13:58:24.251800", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:30:00)"}
- {"dt": "2025-03-25T13:58:24.251844", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:15:00)"}
- {"dt": "2025-03-25T13:58:24.252187", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT"}
- {"dt": "2025-03-25T13:58:24.255150", "lvl": "target", "msg": "[    0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T13:58:24.255823", "lvl": "target", "msg": "[    0.000000] NODE_DATA(0) allocated [mem 0x13f7f9000-0x13f7fb77f]"}
- {"dt": "2025-03-25T13:58:24.258029", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2025-03-25T13:58:24.258439", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000040000000-0x00000000ffffffff]"}
- {"dt": "2025-03-25T13:58:24.258528", "lvl": "target", "msg": "[    0.000000]   DMA32    empty"}
- {"dt": "2025-03-25T13:58:24.258713", "lvl": "target", "msg": "[    0.000000]   Normal   [mem 0x0000000100000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T13:58:24.258828", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2025-03-25T13:58:24.258945", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2025-03-25T13:58:24.259146", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T13:58:24.259546", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T13:58:24.284566", "lvl": "target", "msg": "[    0.000000] cma: Reserved 32 MiB at 0x0000000000000000"}
- {"dt": "2025-03-25T13:58:24.285616", "lvl": "target", "msg": "[    0.000000] psci: probing for conduit method from DT."}
- {"dt": "2025-03-25T13:58:24.285775", "lvl": "target", "msg": "[    0.000000] psci: PSCIv1.1 detected in firmware."}
- {"dt": "2025-03-25T13:58:24.285929", "lvl": "target", "msg": "[    0.000000] psci: Using standard PSCI v0.2 function IDs"}
- {"dt": "2025-03-25T13:58:24.286172", "lvl": "target", "msg": "[    0.000000] psci: Trusted OS migration not required"}
- {"dt": "2025-03-25T13:58:24.286275", "lvl": "target", "msg": "[    0.000000] psci: SMC Calling Convention v1.0"}
- {"dt": "2025-03-25T13:58:24.288426", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 25 pages/cpu s62808 r8192 d31400 u102400"}
- {"dt": "2025-03-25T13:58:24.288906", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: s62808 r8192 d31400 u102400 alloc=25*4096"}
- {"dt": "2025-03-25T13:58:24.289069", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: [0] 0 [0] 1 "}
- {"dt": "2025-03-25T13:58:24.290233", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2025-03-25T13:58:24.291524", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Address authentication (IMP DEF algorithm)"}
- {"dt": "2025-03-25T13:58:24.291777", "lvl": "target", "msg": "[    0.000000] CPU features: detected: GIC system register CPU interface"}
- {"dt": "2025-03-25T13:58:24.291933", "lvl": "target", "msg": "[    0.000000] CPU features: detected: HCRX_EL2 register"}
- {"dt": "2025-03-25T13:58:24.292143", "lvl": "target", "msg": "[    0.000000] CPU features: detected: 52-bit Virtual Addressing (LPA2)"}
- {"dt": "2025-03-25T13:58:24.292304", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Virtualization Host Extensions"}
- {"dt": "2025-03-25T13:58:24.292504", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Memory Tagging Extension"}
- {"dt": "2025-03-25T13:58:24.292671", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Asymmetric MTE Tag Check Fault"}
- {"dt": "2025-03-25T13:58:24.292932", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v4"}
- {"dt": "2025-03-25T13:58:24.295924", "lvl": "target", "msg": "[    0.000000] alternatives: applying boot alternatives"}
- {"dt": "2025-03-25T13:58:24.298248", "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-25T13:58:24.300162", "lvl": "target", "msg": "<5>[    0.000000] Unknown kernel command line parameters \"verbose\", will be passed to user space."}
- {"dt": "2025-03-25T13:58:24.302002", "lvl": "target", "msg": "<6>[    0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes"}
- {"dt": "2025-03-25T13:58:24.304152", "lvl": "target", "msg": "<6>[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.305304", "lvl": "target", "msg": "<6>[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.305639", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: area num 2."}
- {"dt": "2025-03-25T13:58:24.353304", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: mapped [mem 0x00000000fa000000-0x00000000fe000000] (64MB)"}
- {"dt": "2025-03-25T13:58:24.354577", "lvl": "target", "msg": "<6>[    0.000000] Fallback order for Node 0: 0 "}
- {"dt": "2025-03-25T13:58:24.354689", "lvl": "target", "msg": "<6>[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1048576"}
- {"dt": "2025-03-25T13:58:24.354807", "lvl": "target", "msg": "<6>[    0.000000] Policy zone: Normal"}
- {"dt": "2025-03-25T13:58:24.355282", "lvl": "target", "msg": "<6>[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off"}
- {"dt": "2025-03-25T13:58:24.374286", "lvl": "target", "msg": "<6>[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1"}
- {"dt": "2025-03-25T13:58:24.381197", "lvl": "target", "msg": "<6>[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2025-03-25T13:58:24.381299", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2025-03-25T13:58:24.381468", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=2."}
- {"dt": "2025-03-25T13:58:24.381682", "lvl": "target", "msg": "<6>[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2025-03-25T13:58:24.381838", "lvl": "target", "msg": "<6>[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2025-03-25T13:58:24.382145", "lvl": "target", "msg": "<6>[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2025-03-25T13:58:24.382357", "lvl": "target", "msg": "<6>[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2"}
- {"dt": "2025-03-25T13:58:24.383569", "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-25T13:58:24.383884", "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-25T13:58:24.384254", "lvl": "target", "msg": "<6>[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2025-03-25T13:58:24.389676", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GIC: Using split EOI/Deactivate mode"}
- {"dt": "2025-03-25T13:58:24.390016", "lvl": "target", "msg": "<6>[    0.000000] GICv3: 256 SPIs implemented"}
- {"dt": "2025-03-25T13:58:24.390268", "lvl": "target", "msg": "<6>[    0.000000] GICv3: 0 Extended SPIs implemented"}
- {"dt": "2025-03-25T13:58:24.391933", "lvl": "target", "msg": "<6>[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2025-03-25T13:58:24.392112", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GICv3 features: 16 PPIs"}
- {"dt": "2025-03-25T13:58:24.392417", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GICD_CTRL.DS=1, SCR_EL3.FIQ=0"}
- {"dt": "2025-03-25T13:58:24.392848", "lvl": "target", "msg": "<6>[    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000"}
- {"dt": "2025-03-25T13:58:24.397448", "lvl": "target", "msg": "<6>[    0.000000] ITS [mem 0x08080000-0x0809ffff]"}
- {"dt": "2025-03-25T13:58:24.398296", "lvl": "target", "msg": "<6>[    0.000000] ITS@0x0000000008080000: allocated 8192 Devices @100050000 (indirect, esz 8, psz 64K, shr 1)"}
- {"dt": "2025-03-25T13:58:24.398637", "lvl": "target", "msg": "<6>[    0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @100060000 (flat, esz 8, psz 64K, shr 1)"}
- {"dt": "2025-03-25T13:58:24.399294", "lvl": "target", "msg": "<6>[    0.000000] GICv3: using LPI property table @0x0000000100070000"}
- {"dt": "2025-03-25T13:58:24.399996", "lvl": "target", "msg": "<6>[    0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000100080000"}
- {"dt": "2025-03-25T13:58:24.402025", "lvl": "target", "msg": "<6>[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention."}
- {"dt": "2025-03-25T13:58:24.408697", "lvl": "target", "msg": "<6>[    0.000000] arch_timer: cp15 timer(s) running at 1000.00MHz (phys)."}
- {"dt": "2025-03-25T13:58:24.409104", "lvl": "target", "msg": "<6>[    0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns"}
- {"dt": "2025-03-25T13:58:24.409628", "lvl": "target", "msg": "<6>[    0.000054] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns"}
- {"dt": "2025-03-25T13:58:24.424473", "lvl": "target", "msg": "<6>[    0.013228] Console: colour dummy device 80x25"}
- {"dt": "2025-03-25T13:58:24.427882", "lvl": "target", "msg": "<6>[    0.017898] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)"}
- {"dt": "2025-03-25T13:58:24.428232", "lvl": "target", "msg": "<6>[    0.018798] pid_max: default: 32768 minimum: 301"}
- {"dt": "2025-03-25T13:58:24.430584", "lvl": "target", "msg": "<6>[    0.020894] LSM: initializing lsm=capability"}
- {"dt": "2025-03-25T13:58:24.433592", "lvl": "target", "msg": "<6>[    0.024018] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.433791", "lvl": "target", "msg": "<6>[    0.024275] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.458734", "lvl": "target", "msg": "<4>[    0.049158] cacheinfo: Unable to detect cache hierarchy for CPU 0"}
- {"dt": "2025-03-25T13:58:24.468534", "lvl": "target", "msg": "<6>[    0.058958] rcu: Hierarchical SRCU implementation."}
- {"dt": "2025-03-25T13:58:24.468617", "lvl": "target", "msg": "<6>[    0.059133] rcu: \tMax phase no-delay instances is 1000."}
- {"dt": "2025-03-25T13:58:24.470613", "lvl": "target", "msg": "<6>[    0.061078] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level"}
- {"dt": "2025-03-25T13:58:24.474208", "lvl": "target", "msg": "<6>[    0.064636] fsl-mc MSI: its@8080000 domain created"}
- {"dt": "2025-03-25T13:58:24.476270", "lvl": "target", "msg": "<6>[    0.066712] EFI services will not be available."}
- {"dt": "2025-03-25T13:58:24.477614", "lvl": "target", "msg": "<6>[    0.068087] smp: Bringing up secondary CPUs ..."}
- {"dt": "2025-03-25T13:58:24.489501", "lvl": "target", "msg": "<6>[    0.073168] Detected PIPT I-cache on CPU1"}
- {"dt": "2025-03-25T13:58:24.489653", "lvl": "target", "msg": "<6>[    0.074679] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000"}
- {"dt": "2025-03-25T13:58:24.490212", "lvl": "target", "msg": "<6>[    0.075397] GICv3: CPU1: using allocated LPI pending table @0x0000000100090000"}
- {"dt": "2025-03-25T13:58:24.490584", "lvl": "target", "msg": "<6>[    0.076963] CPU1: Booted secondary processor 0x0000000001 [0x000f0510]"}
- {"dt": "2025-03-25T13:58:24.490745", "lvl": "target", "msg": "<6>[    0.079894] smp: Brought up 1 node, 2 CPUs"}
- {"dt": "2025-03-25T13:58:24.490931", "lvl": "target", "msg": "<6>[    0.081477] SMP: Total of 2 processors activated."}
- {"dt": "2025-03-25T13:58:24.491094", "lvl": "target", "msg": "<6>[    0.081663] CPU: All CPU(s) started at EL2"}
- {"dt": "2025-03-25T13:58:24.491369", "lvl": "target", "msg": "<6>[    0.081873] CPU features: detected: Branch Target Identification"}
- {"dt": "2025-03-25T13:58:24.491566", "lvl": "target", "msg": "<6>[    0.082111] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2025-03-25T13:58:24.491735", "lvl": "target", "msg": "<6>[    0.082289] CPU features: detected: 32-bit EL1 Support"}
- {"dt": "2025-03-25T13:58:24.491947", "lvl": "target", "msg": "<6>[    0.082451] CPU features: detected: ARMv8.4 Translation Table Level"}
- {"dt": "2025-03-25T13:58:24.492246", "lvl": "target", "msg": "<6>[    0.082672] CPU features: detected: Instruction cache invalidation not required for I/D coherence"}
- {"dt": "2025-03-25T13:58:24.492519", "lvl": "target", "msg": "<6>[    0.082969] CPU features: detected: Data cache clean to the PoU not required for I/D coherence"}
- {"dt": "2025-03-25T13:58:24.492742", "lvl": "target", "msg": "<6>[    0.083263] CPU features: detected: Common not Private translations"}
- {"dt": "2025-03-25T13:58:24.492906", "lvl": "target", "msg": "<6>[    0.083458] CPU features: detected: CRC32 instructions"}
- {"dt": "2025-03-25T13:58:24.493108", "lvl": "target", "msg": "<6>[    0.083621] CPU features: detected: Data independent timing control (DIT)"}
- {"dt": "2025-03-25T13:58:24.493244", "lvl": "target", "msg": "<6>[    0.083822] CPU features: detected: E0PD"}
- {"dt": "2025-03-25T13:58:24.493443", "lvl": "target", "msg": "<6>[    0.083960] CPU features: detected: Enhanced Counter Virtualization"}
- {"dt": "2025-03-25T13:58:24.493672", "lvl": "target", "msg": "<6>[    0.084157] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)"}
- {"dt": "2025-03-25T13:58:24.494042", "lvl": "target", "msg": "<6>[    0.084388] CPU features: detected: Enhanced Privileged Access Never"}
- {"dt": "2025-03-25T13:58:24.494134", "lvl": "target", "msg": "<6>[    0.084641] CPU features: detected: Enhanced Virtualization Traps"}
- {"dt": "2025-03-25T13:58:24.494742", "lvl": "target", "msg": "<6>[    0.085216] CPU features: detected: Fine Grained Traps"}
- {"dt": "2025-03-25T13:58:24.494982", "lvl": "target", "msg": "<6>[    0.085462] CPU features: detected: Generic authentication (IMP DEF algorithm)"}
- {"dt": "2025-03-25T13:58:24.495249", "lvl": "target", "msg": "<6>[    0.085748] CPU features: detected: RCpc load-acquire (LDAPR)"}
- {"dt": "2025-03-25T13:58:24.495471", "lvl": "target", "msg": "<6>[    0.085967] CPU features: detected: 52-bit Virtual Addressing for KVM (LPA2)"}
- {"dt": "2025-03-25T13:58:24.495646", "lvl": "target", "msg": "<6>[    0.086186] CPU features: detected: LSE atomic instructions"}
- {"dt": "2025-03-25T13:58:24.495862", "lvl": "target", "msg": "<6>[    0.086360] CPU features: detected: Memory Copy and Memory Set instructions"}
- {"dt": "2025-03-25T13:58:24.496028", "lvl": "target", "msg": "<6>[    0.086575] CPU features: detected: Privileged Access Never"}
- {"dt": "2025-03-25T13:58:24.496193", "lvl": "target", "msg": "<6>[    0.086767] CPU features: detected: PMUv3"}
- {"dt": "2025-03-25T13:58:24.496364", "lvl": "target", "msg": "<6>[    0.086908] CPU features: detected: RAS Extension Support"}
- {"dt": "2025-03-25T13:58:24.496535", "lvl": "target", "msg": "<6>[    0.087075] CPU features: detected: Random Number Generator"}
- {"dt": "2025-03-25T13:58:24.496702", "lvl": "target", "msg": "<6>[    0.087245] CPU features: detected: Speculation barrier (SB)"}
- {"dt": "2025-03-25T13:58:24.496880", "lvl": "target", "msg": "<6>[    0.087414] CPU features: detected: Stage-2 Force Write-Back"}
- {"dt": "2025-03-25T13:58:24.497115", "lvl": "target", "msg": "<6>[    0.087593] CPU features: detected: Trap EL0 IMPLEMENTATION DEFINED functionality"}
- {"dt": "2025-03-25T13:58:24.497316", "lvl": "target", "msg": "<6>[    0.087827] CPU features: detected: TLB range maintenance instructions"}
- {"dt": "2025-03-25T13:58:24.497463", "lvl": "target", "msg": "<6>[    0.088031] CPU features: detected: WFx with timeout"}
- {"dt": "2025-03-25T13:58:24.497767", "lvl": "target", "msg": "<6>[    0.088239] CPU features: detected: Speculative Store Bypassing Safe (SSBS)"}
- {"dt": "2025-03-25T13:58:24.497917", "lvl": "target", "msg": "<6>[    0.088463] CPU features: detected: Scalable Vector Extension"}
- {"dt": "2025-03-25T13:58:24.510483", "lvl": "target", "msg": "<6>[    0.098780] alternatives: applying system-wide alternatives"}
- {"dt": "2025-03-25T13:58:24.521051", "lvl": "target", "msg": "<6>[    0.111071] CPU features: detected: Hardware dirty bit management on CPU0-1"}
- {"dt": "2025-03-25T13:58:24.521367", "lvl": "target", "msg": "<6>[    0.111856] SVE: maximum available vector length 256 bytes per vector"}
- {"dt": "2025-03-25T13:58:24.521535", "lvl": "target", "msg": "<6>[    0.112068] SVE: default vector length 64 bytes per vector"}
- {"dt": "2025-03-25T13:58:24.532367", "lvl": "target", "msg": "<6>[    0.122689] Memory: 3968692K/4194304K available (18240K kernel code, 5264K rwdata, 12488K rodata, 3264K init, 748K bss, 188664K reserved, 32768K cma-reserved)"}
- {"dt": "2025-03-25T13:58:24.554665", "lvl": "target", "msg": "<6>[    0.145066] devtmpfs: initialized"}
- {"dt": "2025-03-25T13:58:24.580256", "lvl": "target", "msg": "<6>[    0.170627] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2025-03-25T13:58:24.580841", "lvl": "target", "msg": "<6>[    0.171272] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.581065", "lvl": "target", "msg": "<6>[    0.171580] futex hash table entries: 512 (order: 3, 32768 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.582848", "lvl": "target", "msg": "<6>[    0.173315] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL"}
- {"dt": "2025-03-25T13:58:24.583007", "lvl": "target", "msg": "<6>[    0.173539] 0 pages in range for non-PLT usage"}
- {"dt": "2025-03-25T13:58:24.585606", "lvl": "target", "msg": "<6>[    0.173582] 514224 pages in range for PLT usage"}
- {"dt": "2025-03-25T13:58:24.585672", "lvl": "target", "msg": "<6>[    0.176043] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2025-03-25T13:58:24.595441", "lvl": "target", "msg": "<6>[    0.185820] DMI not present or invalid."}
- {"dt": "2025-03-25T13:58:24.609166", "lvl": "target", "msg": "<6>[    0.199534] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2025-03-25T13:58:24.617922", "lvl": "target", "msg": "<6>[    0.208253] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations"}
- {"dt": "2025-03-25T13:58:24.618850", "lvl": "target", "msg": "<6>[    0.209243] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations"}
- {"dt": "2025-03-25T13:58:24.619685", "lvl": "target", "msg": "<6>[    0.210094] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations"}
- {"dt": "2025-03-25T13:58:24.620165", "lvl": "target", "msg": "<6>[    0.210629] audit: initializing netlink subsys (disabled)"}
- {"dt": "2025-03-25T13:58:24.622146", "lvl": "target", "msg": "<5>[    0.212549] audit: type=2000 audit(0.188:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2025-03-25T13:58:24.626377", "lvl": "target", "msg": "<6>[    0.216758] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2025-03-25T13:58:24.626886", "lvl": "target", "msg": "<6>[    0.216800] thermal_sys: Registered thermal governor 'power_allocator'"}
- {"dt": "2025-03-25T13:58:24.626998", "lvl": "target", "msg": "<6>[    0.217413] cpuidle: using governor menu"}
- {"dt": "2025-03-25T13:58:24.628432", "lvl": "target", "msg": "<6>[    0.218895] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2025-03-25T13:58:24.629209", "lvl": "target", "msg": "<6>[    0.219610] ASID allocator initialised with 65536 entries"}
- {"dt": "2025-03-25T13:58:24.636654", "lvl": "target", "msg": "<6>[    0.227082] Serial: AMBA PL011 UART driver"}
- {"dt": "2025-03-25T13:58:24.693318", "lvl": "target", "msg": "<6>[    0.283726] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 15, base_baud = 0) is a PL011 rev1"}
- {"dt": "2025-03-25T13:58:24.695542", "lvl": "target", "msg": "<6>[    0.285216] printk: console [ttyAMA0] enabled"}
- {"dt": "2025-03-25T13:58:24.695862", "lvl": "target", "msg": "<6>[    0.285216] printk: console [ttyAMA0] enabled"}
- {"dt": "2025-03-25T13:58:24.696055", "lvl": "target", "msg": "<6>[    0.286606] printk: legacy bootconsole [pl11] disabled"}
- {"dt": "2025-03-25T13:58:24.696194", "lvl": "target", "msg": "<6>[    0.286606] printk: legacy bootconsole [pl11] disabled"}
- {"dt": "2025-03-25T13:58:24.711098", "lvl": "target", "msg": "<6>[    0.301171] HugeTLB: allocation took 0ms with hugepage_allocation_threads=1"}
- {"dt": "2025-03-25T13:58:24.711445", "lvl": "target", "msg": "<6>[    0.301454] HugeTLB: allocation took 0ms with hugepage_allocation_threads=1"}
- {"dt": "2025-03-25T13:58:24.711726", "lvl": "target", "msg": "<6>[    0.301762] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T13:58:24.712083", "lvl": "target", "msg": "<6>[    0.301782] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page"}
- {"dt": "2025-03-25T13:58:24.712467", "lvl": "target", "msg": "<6>[    0.301814] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T13:58:24.712591", "lvl": "target", "msg": "<6>[    0.301822] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page"}
- {"dt": "2025-03-25T13:58:24.712876", "lvl": "target", "msg": "<6>[    0.301831] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T13:58:24.713166", "lvl": "target", "msg": "<6>[    0.301838] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page"}
- {"dt": "2025-03-25T13:58:24.713343", "lvl": "target", "msg": "<6>[    0.301848] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T13:58:24.713724", "lvl": "target", "msg": "<6>[    0.301855] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page"}
- {"dt": "2025-03-25T13:58:24.722297", "lvl": "target", "msg": "<6>[    0.312619] ACPI: Interpreter disabled."}
- {"dt": "2025-03-25T13:58:24.731264", "lvl": "target", "msg": "<6>[    0.321616] iommu: Default domain type: Translated"}
- {"dt": "2025-03-25T13:58:24.731453", "lvl": "target", "msg": "<6>[    0.321697] iommu: DMA domain TLB invalidation policy: strict mode"}
- {"dt": "2025-03-25T13:58:24.732873", "lvl": "target", "msg": "<5>[    0.323283] SCSI subsystem initialized"}
- {"dt": "2025-03-25T13:58:24.733564", "lvl": "target", "msg": "<7>[    0.323984] libata version 3.00 loaded."}
- {"dt": "2025-03-25T13:58:24.735007", "lvl": "target", "msg": "<6>[    0.325338] usbcore: registered new interface driver usbfs"}
- {"dt": "2025-03-25T13:58:24.735289", "lvl": "target", "msg": "<6>[    0.325537] usbcore: registered new interface driver hub"}
- {"dt": "2025-03-25T13:58:24.735561", "lvl": "target", "msg": "<6>[    0.325696] usbcore: registered new device driver usb"}
- {"dt": "2025-03-25T13:58:24.737815", "lvl": "target", "msg": "<6>[    0.328225] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2025-03-25T13:58:24.738098", "lvl": "target", "msg": "<6>[    0.328267] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2025-03-25T13:58:24.738251", "lvl": "target", "msg": "<6>[    0.328361] PTP clock support registered"}
- {"dt": "2025-03-25T13:58:24.738420", "lvl": "target", "msg": "<6>[    0.328705] EDAC MC: Ver: 3.0.0"}
- {"dt": "2025-03-25T13:58:24.740120", "lvl": "target", "msg": "<6>[    0.330224] scmi_core: SCMI protocol bus registered"}
- {"dt": "2025-03-25T13:58:24.742916", "lvl": "target", "msg": "<6>[    0.333189] FPGA manager framework"}
- {"dt": "2025-03-25T13:58:24.743429", "lvl": "target", "msg": "<6>[    0.333822] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2025-03-25T13:58:24.752295", "lvl": "target", "msg": "<6>[    0.342657] vgaarb: loaded"}
- {"dt": "2025-03-25T13:58:24.754468", "lvl": "target", "msg": "<6>[    0.344816] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2025-03-25T13:58:24.755755", "lvl": "target", "msg": "<5>[    0.346101] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2025-03-25T13:58:24.756532", "lvl": "target", "msg": "<6>[    0.346427] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2025-03-25T13:58:24.759191", "lvl": "target", "msg": "<6>[    0.349191] pnp: PnP ACPI: disabled"}
- {"dt": "2025-03-25T13:58:24.785868", "lvl": "target", "msg": "<6>[    0.376200] NET: Registered PF_INET protocol family"}
- {"dt": "2025-03-25T13:58:24.786998", "lvl": "target", "msg": "<6>[    0.377349] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.791586", "lvl": "target", "msg": "<6>[    0.381814] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.791886", "lvl": "target", "msg": "<6>[    0.381915] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.792199", "lvl": "target", "msg": "<6>[    0.382066] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.792633", "lvl": "target", "msg": "<6>[    0.382451] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.792742", "lvl": "target", "msg": "<6>[    0.382982] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2025-03-25T13:58:24.793496", "lvl": "target", "msg": "<6>[    0.383839] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.793826", "lvl": "target", "msg": "<6>[    0.384162] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear)"}
- {"dt": "2025-03-25T13:58:24.794711", "lvl": "target", "msg": "<6>[    0.385106] NET: Registered PF_UNIX/PF_LOCAL protocol family"}
- {"dt": "2025-03-25T13:58:24.796921", "lvl": "target", "msg": "<6>[    0.387265] RPC: Registered named UNIX socket transport module."}
- {"dt": "2025-03-25T13:58:24.797082", "lvl": "target", "msg": "<6>[    0.387337] RPC: Registered udp transport module."}
- {"dt": "2025-03-25T13:58:24.797280", "lvl": "target", "msg": "<6>[    0.387370] RPC: Registered tcp transport module."}
- {"dt": "2025-03-25T13:58:24.797501", "lvl": "target", "msg": "<6>[    0.387387] RPC: Registered tcp-with-tls transport module."}
- {"dt": "2025-03-25T13:58:24.797887", "lvl": "target", "msg": "<6>[    0.387398] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2025-03-25T13:58:24.797937", "lvl": "target", "msg": "<6>[    0.387498] PCI: CLS 0 bytes, default 64"}
- {"dt": "2025-03-25T13:58:24.807886", "lvl": "target", "msg": "<6>[    0.398196] kvm [1]: nv: 566 coarse grained trap handlers"}
- {"dt": "2025-03-25T13:58:24.809191", "lvl": "target", "msg": "<6>[    0.399137] kvm [1]: nv: 669 fine grained trap handlers"}
- {"dt": "2025-03-25T13:58:24.809750", "lvl": "target", "msg": "<6>[    0.400164] kvm [1]: IPA Size Limit: 52 bits"}
- {"dt": "2025-03-25T13:58:24.810614", "lvl": "target", "msg": "<6>[    0.400879] kvm [1]: GICv3: no GICV resource entry"}
- {"dt": "2025-03-25T13:58:24.810757", "lvl": "target", "msg": "<6>[    0.400970] kvm [1]: disabling GICv2 emulation"}
- {"dt": "2025-03-25T13:58:24.811073", "lvl": "target", "msg": "<6>[    0.401280] kvm [1]: GIC system register CPU interface enabled"}
- {"dt": "2025-03-25T13:58:24.811559", "lvl": "target", "msg": "<6>[    0.401942] kvm [1]: vgic interrupt IRQ9"}
- {"dt": "2025-03-25T13:58:24.812129", "lvl": "target", "msg": "<6>[    0.402541] kvm [1]: VHE mode initialized successfully"}
- {"dt": "2025-03-25T13:58:24.816650", "lvl": "target", "msg": "<5>[    0.406996] Initialise system trusted keyrings"}
- {"dt": "2025-03-25T13:58:24.818068", "lvl": "target", "msg": "<6>[    0.408402] workingset: timestamp_bits=42 max_order=20 bucket_order=0"}
- {"dt": "2025-03-25T13:58:24.819975", "lvl": "target", "msg": "<6>[    0.410281] squashfs: version 4.0 (2009/01/31) Phillip Lougher"}
- {"dt": "2025-03-25T13:58:24.821516", "lvl": "target", "msg": "<5>[    0.411912] NFS: Registering the id_resolver key type"}
- {"dt": "2025-03-25T13:58:24.821818", "lvl": "target", "msg": "<5>[    0.412186] Key type id_resolver registered"}
- {"dt": "2025-03-25T13:58:24.821899", "lvl": "target", "msg": "<5>[    0.412271] Key type id_legacy registered"}
- {"dt": "2025-03-25T13:58:24.822228", "lvl": "target", "msg": "<6>[    0.412594] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2025-03-25T13:58:24.822671", "lvl": "target", "msg": "<6>[    0.412798] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering..."}
- {"dt": "2025-03-25T13:58:24.823240", "lvl": "target", "msg": "<6>[    0.413645] 9p: Installing v9fs 9p2000 file system support"}
- {"dt": "2025-03-25T13:58:24.884202", "lvl": "target", "msg": "<5>[    0.474484] Key type asymmetric registered"}
- {"dt": "2025-03-25T13:58:24.884393", "lvl": "target", "msg": "<5>[    0.474572] Asymmetric key parser 'x509' registered"}
- {"dt": "2025-03-25T13:58:24.884904", "lvl": "target", "msg": "<6>[    0.474788] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)"}
- {"dt": "2025-03-25T13:58:24.885017", "lvl": "target", "msg": "<6>[    0.474892] io scheduler mq-deadline registered"}
- {"dt": "2025-03-25T13:58:24.885203", "lvl": "target", "msg": "<6>[    0.474951] io scheduler kyber registered"}
- {"dt": "2025-03-25T13:58:24.885377", "lvl": "target", "msg": "<6>[    0.475197] io scheduler bfq registered"}
- {"dt": "2025-03-25T13:58:24.912168", "lvl": "target", "msg": "<6>[    0.502391] pl061_gpio 9030000.pl061: PL061 GPIO chip registered"}
- {"dt": "2025-03-25T13:58:24.916518", "lvl": "target", "msg": "<6>[    0.506509] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2025-03-25T13:58:24.919314", "lvl": "target", "msg": "<6>[    0.509556] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:"}
- {"dt": "2025-03-25T13:58:24.919936", "lvl": "target", "msg": "<6>[    0.510054] pci-host-generic 4010000000.pcie:       IO 0x003eff0000..0x003effffff -> 0x0000000000"}
- {"dt": "2025-03-25T13:58:24.920415", "lvl": "target", "msg": "<6>[    0.510483] pci-host-generic 4010000000.pcie:      MEM 0x0010000000..0x003efeffff -> 0x0010000000"}
- {"dt": "2025-03-25T13:58:24.920836", "lvl": "target", "msg": "<6>[    0.510543] pci-host-generic 4010000000.pcie:      MEM 0x8000000000..0xffffffffff -> 0x8000000000"}
- {"dt": "2025-03-25T13:58:24.921249", "lvl": "target", "msg": "<4>[    0.510959] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits"}
- {"dt": "2025-03-25T13:58:24.921702", "lvl": "target", "msg": "<6>[    0.511386] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]"}
- {"dt": "2025-03-25T13:58:24.922242", "lvl": "target", "msg": "<6>[    0.512570] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2025-03-25T13:58:24.922434", "lvl": "target", "msg": "<6>[    0.512892] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2025-03-25T13:58:24.922720", "lvl": "target", "msg": "<6>[    0.512951] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]"}
- {"dt": "2025-03-25T13:58:24.922917", "lvl": "target", "msg": "<6>[    0.512998] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]"}
- {"dt": "2025-03-25T13:58:24.923170", "lvl": "target", "msg": "<6>[    0.513013] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]"}
- {"dt": "2025-03-25T13:58:24.923945", "lvl": "target", "msg": "<6>[    0.514134] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint"}
- {"dt": "2025-03-25T13:58:24.927356", "lvl": "target", "msg": "<6>[    0.517488] pci 0000:00:01.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint"}
- {"dt": "2025-03-25T13:58:24.927710", "lvl": "target", "msg": "<6>[    0.517742] pci 0000:00:01.0: BAR 0 [io  0x0000-0x007f]"}
- {"dt": "2025-03-25T13:58:24.928027", "lvl": "target", "msg": "<6>[    0.517790] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]"}
- {"dt": "2025-03-25T13:58:24.928246", "lvl": "target", "msg": "<6>[    0.517855] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]"}
- {"dt": "2025-03-25T13:58:24.930877", "lvl": "target", "msg": "<6>[    0.521072] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned"}
- {"dt": "2025-03-25T13:58:24.931131", "lvl": "target", "msg": "<6>[    0.521355] pci 0000:00:01.0: BAR 1 [mem 0x10000000-0x10000fff]: assigned"}
- {"dt": "2025-03-25T13:58:24.931352", "lvl": "target", "msg": "<6>[    0.521409] pci 0000:00:01.0: BAR 0 [io  0x1000-0x107f]: assigned"}
- {"dt": "2025-03-25T13:58:24.931575", "lvl": "target", "msg": "<6>[    0.521677] pci_bus 0000:00: resource 4 [io  0x0000-0xffff]"}
- {"dt": "2025-03-25T13:58:24.931816", "lvl": "target", "msg": "<6>[    0.521708] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]"}
- {"dt": "2025-03-25T13:58:24.932238", "lvl": "target", "msg": "<6>[    0.521723] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]"}
- {"dt": "2025-03-25T13:58:24.996869", "lvl": "target", "msg": "<6>[    0.586634] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)"}
- {"dt": "2025-03-25T13:58:25.015732", "lvl": "target", "msg": "<6>[    0.606050] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled"}
- {"dt": "2025-03-25T13:58:25.024305", "lvl": "target", "msg": "<6>[    0.614646] msm_serial: driver initialized"}
- {"dt": "2025-03-25T13:58:25.025206", "lvl": "target", "msg": "<6>[    0.615598] SuperH (H)SCI(F) driver initialized"}
- {"dt": "2025-03-25T13:58:25.025700", "lvl": "target", "msg": "<6>[    0.616020] STM32 USART driver initialized"}
- {"dt": "2025-03-25T13:58:25.049564", "lvl": "target", "msg": "<6>[    0.639905] loop: module loaded"}
- {"dt": "2025-03-25T13:58:25.050413", "lvl": "target", "msg": "<6>[    0.640753] virtio_blk virtio0: 2/0/0 default/read/poll queues"}
- {"dt": "2025-03-25T13:58:25.058383", "lvl": "target", "msg": "<5>[    0.648554] virtio_blk virtio0: [vda] 5345376 512-byte logical blocks (2.74 GB/2.55 GiB)"}
- {"dt": "2025-03-25T13:58:25.069363", "lvl": "target", "msg": "<6>[    0.659659] megasas: 07.727.03.00-rc1"}
- {"dt": "2025-03-25T13:58:25.074300", "lvl": "target", "msg": "<5>[    0.664123] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]"}
- {"dt": "2025-03-25T13:58:25.076113", "lvl": "target", "msg": "<6>[    0.665658] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000"}
- {"dt": "2025-03-25T13:58:25.076194", "lvl": "target", "msg": "<6>[    0.666002] Intel/Sharp Extended Query Table at 0x0031"}
- {"dt": "2025-03-25T13:58:25.076326", "lvl": "target", "msg": "<6>[    0.666739] Using buffer write method"}
- {"dt": "2025-03-25T13:58:25.077068", "lvl": "target", "msg": "<7>[    0.666979] erase region 0: offset=0x0,size=0x40000,blocks=256"}
- {"dt": "2025-03-25T13:58:25.077902", "lvl": "target", "msg": "<5>[    0.667139] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]"}
- {"dt": "2025-03-25T13:58:25.078370", "lvl": "target", "msg": "<6>[    0.667729] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000"}
- {"dt": "2025-03-25T13:58:25.078723", "lvl": "target", "msg": "<6>[    0.667769] Intel/Sharp Extended Query Table at 0x0031"}
- {"dt": "2025-03-25T13:58:25.078917", "lvl": "target", "msg": "<6>[    0.668247] Using buffer write method"}
- {"dt": "2025-03-25T13:58:25.079190", "lvl": "target", "msg": "<7>[    0.668264] erase region 0: offset=0x0,size=0x40000,blocks=256"}
- {"dt": "2025-03-25T13:58:25.079389", "lvl": "target", "msg": "<5>[    0.668321] Concatenating MTD devices:"}
- {"dt": "2025-03-25T13:58:25.079691", "lvl": "target", "msg": "<5>[    0.668349] (0): \"0.flash\""}
- {"dt": "2025-03-25T13:58:25.079750", "lvl": "target", "msg": "<5>[    0.668377] (1): \"0.flash\""}
- {"dt": "2025-03-25T13:58:25.079916", "lvl": "target", "msg": "<5>[    0.668389] into device \"0.flash\""}
- {"dt": "2025-03-25T13:58:25.103711", "lvl": "target", "msg": "<6>[    0.694026] tun: Universal TUN/TAP device driver, 1.6"}
- {"dt": "2025-03-25T13:58:25.106721", "lvl": "target", "msg": "<6>[    0.696978] thunder_xcv, ver 1.0"}
- {"dt": "2025-03-25T13:58:25.106823", "lvl": "target", "msg": "<6>[    0.697198] thunder_bgx, ver 1.0"}
- {"dt": "2025-03-25T13:58:25.106959", "lvl": "target", "msg": "<6>[    0.697307] nicpf, ver 1.0"}
- {"dt": "2025-03-25T13:58:25.110549", "lvl": "target", "msg": "<6>[    0.700775] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version"}
- {"dt": "2025-03-25T13:58:25.110907", "lvl": "target", "msg": "<6>[    0.700835] hns3: Copyright (c) 2017 Huawei Corporation."}
- {"dt": "2025-03-25T13:58:25.110989", "lvl": "target", "msg": "<6>[    0.701184] hclge is initializing"}
- {"dt": "2025-03-25T13:58:25.111157", "lvl": "target", "msg": "<6>[    0.701373] e1000: Intel(R) PRO/1000 Network Driver"}
- {"dt": "2025-03-25T13:58:25.111527", "lvl": "target", "msg": "<6>[    0.701395] e1000: Copyright (c) 1999-2006 Intel Corporation."}
- {"dt": "2025-03-25T13:58:25.111842", "lvl": "target", "msg": "<6>[    0.701624] e1000e: Intel(R) PRO/1000 Network Driver"}
- {"dt": "2025-03-25T13:58:25.111893", "lvl": "target", "msg": "<6>[    0.701649] e1000e: Copyright(c) 1999 - 2015 Intel Corporation."}
- {"dt": "2025-03-25T13:58:25.112162", "lvl": "target", "msg": "<6>[    0.701795] igb: Intel(R) Gigabit Ethernet Network Driver"}
- {"dt": "2025-03-25T13:58:25.112431", "lvl": "target", "msg": "<6>[    0.701838] igb: Copyright (c) 2007-2014 Intel Corporation."}
- {"dt": "2025-03-25T13:58:25.112737", "lvl": "target", "msg": "<6>[    0.702037] igbvf: Intel(R) Gigabit Virtual Function Network Driver"}
- {"dt": "2025-03-25T13:58:25.112852", "lvl": "target", "msg": "<6>[    0.702064] igbvf: Copyright (c) 2009 - 2012 Intel Corporation."}
- {"dt": "2025-03-25T13:58:25.113134", "lvl": "target", "msg": "<6>[    0.703020] sky2: driver version 1.30"}
- {"dt": "2025-03-25T13:58:25.117356", "lvl": "target", "msg": "<6>[    0.707714] VFIO - User Level meta-driver version: 0.3"}
- {"dt": "2025-03-25T13:58:25.125337", "lvl": "target", "msg": "<6>[    0.715606] usbcore: registered new interface driver usb-storage"}
- {"dt": "2025-03-25T13:58:25.134828", "lvl": "target", "msg": "<6>[    0.725119] rtc-pl031 9010000.pl031: registered as rtc0"}
- {"dt": "2025-03-25T13:58:25.135879", "lvl": "target", "msg": "<6>[    0.725798] rtc-pl031 9010000.pl031: setting system clock to 2025-03-25T13:58:25 UTC (1742911105)"}
- {"dt": "2025-03-25T13:58:25.137605", "lvl": "target", "msg": "<6>[    0.727949] i2c_dev: i2c /dev entries driver"}
- {"dt": "2025-03-25T13:58:25.154958", "lvl": "target", "msg": "<6>[    0.745154] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2025-03-25T13:58:25.155219", "lvl": "target", "msg": "<6>[    0.745193] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2025-03-25T13:58:25.156511", "lvl": "target", "msg": "<6>[    0.746868] Synopsys Designware Multimedia Card Interface Driver"}
- {"dt": "2025-03-25T13:58:25.158734", "lvl": "target", "msg": "<6>[    0.749061] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2025-03-25T13:58:25.167236", "lvl": "target", "msg": "<6>[    0.757437] usbcore: registered new interface driver usbhid"}
- {"dt": "2025-03-25T13:58:25.167445", "lvl": "target", "msg": "<6>[    0.757480] usbhid: USB HID core driver"}
- {"dt": "2025-03-25T13:58:25.176716", "lvl": "target", "msg": "<6>[    0.766553] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 (0,8000003f) counters available"}
- {"dt": "2025-03-25T13:58:25.187509", "lvl": "target", "msg": "<6>[    0.777777] NET: Registered PF_INET6 protocol family"}
- {"dt": "2025-03-25T13:58:25.193043", "lvl": "target", "msg": "<6>[    0.783369] Segment Routing with IPv6"}
- {"dt": "2025-03-25T13:58:25.193238", "lvl": "target", "msg": "<6>[    0.783656] In-situ OAM (IOAM) with IPv6"}
- {"dt": "2025-03-25T13:58:25.193856", "lvl": "target", "msg": "<6>[    0.784191] NET: Registered PF_PACKET protocol family"}
- {"dt": "2025-03-25T13:58:25.195018", "lvl": "target", "msg": "<6>[    0.785398] 9pnet: Installing 9P2000 support"}
- {"dt": "2025-03-25T13:58:25.195402", "lvl": "target", "msg": "<5>[    0.785764] Key type dns_resolver registered"}
- {"dt": "2025-03-25T13:58:25.223870", "lvl": "target", "msg": "<6>[    0.814182] registered taskstats version 1"}
- {"dt": "2025-03-25T13:58:25.225135", "lvl": "target", "msg": "<5>[    0.815453] Loading compiled-in X.509 certificates"}
- {"dt": "2025-03-25T13:58:25.250389", "lvl": "target", "msg": "<6>[    0.840710] Demotion targets for Node 0: null"}
- {"dt": "2025-03-25T13:58:25.257810", "lvl": "target", "msg": "<6>[    0.848008] input: gpio-keys as /devices/platform/gpio-keys/input/input0"}
- {"dt": "2025-03-25T13:58:25.263776", "lvl": "target", "msg": "<6>[    0.854090] clk: Disabling unused clocks"}
- {"dt": "2025-03-25T13:58:25.264129", "lvl": "target", "msg": "<6>[    0.854432] PM: genpd: Disabling unused power domains"}
- {"dt": "2025-03-25T13:58:25.264442", "lvl": "target", "msg": "<6>[    0.854797] ALSA device list:"}
- {"dt": "2025-03-25T13:58:25.264788", "lvl": "target", "msg": "<6>[    0.854937]   No soundcards found."}
- {"dt": "2025-03-25T13:58:25.293820", "lvl": "target", "msg": "<6>[    0.883643] EXT4-fs (vda): mounted filesystem db78a389-4e12-4f05-bb8b-e7b25b5f99d9 r/w with ordered data mode. Quota mode: none."}
- {"dt": "2025-03-25T13:58:25.294308", "lvl": "target", "msg": "<6>[    0.883980] VFS: Mounted root (ext4 filesystem) on device 254:0."}
- {"dt": "2025-03-25T13:58:25.295490", "lvl": "target", "msg": "<6>[    0.885889] devtmpfs: mounted"}
- {"dt": "2025-03-25T13:58:25.583235", "lvl": "target", "msg": "<6>[    1.173114] Freeing unused kernel memory: 3264K"}
- {"dt": "2025-03-25T13:58:25.583634", "lvl": "target", "msg": "<6>[    1.173990] Run /sbin/init as init process"}
- {"dt": "2025-03-25T13:58:25.583807", "lvl": "target", "msg": "<7>[    1.174056]   with arguments:"}
- {"dt": "2025-03-25T13:58:25.583961", "lvl": "target", "msg": "<7>[    1.174082]     /sbin/init"}
- {"dt": "2025-03-25T13:58:25.584094", "lvl": "target", "msg": "<7>[    1.174095]     verbose"}
- {"dt": "2025-03-25T13:58:25.584393", "lvl": "target", "msg": "<7>[    1.174345]   with environment:"}
- {"dt": "2025-03-25T13:58:25.584437", "lvl": "target", "msg": "<7>[    1.174359]     HOME=/"}
- {"dt": "2025-03-25T13:58:25.584699", "lvl": "target", "msg": "<7>[    1.174371]     TERM=linux"}
- {"dt": "2025-03-25T13:58:25.905681", "lvl": "target", "msg": "[!p]104\a[?7h"}
- {"dt": "2025-03-25T13:58:25.906444", "lvl": "target", "msg": "[0;1;39mWelcome to [0m[1mDebian GNU/Linux trixie/sid[0m[0;1;39m![0m"}
- {"dt": "2025-03-25T13:58:25.906532", "lvl": "target", "msg": "\r"}
- {"dt": "2025-03-25T13:58:27.651579", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-getty.slice[0m - Slice /system/getty.\r"}
- {"dt": "2025-03-25T13:58:27.657262", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-modprobe.slice[0m - Slice /system/modprobe.\r"}
- {"dt": "2025-03-25T13:58:27.662603", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-serial\\x2dget\u2026slice[0m - Slice /system/serial-getty.\r"}
- {"dt": "2025-03-25T13:58:27.668197", "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-25T13:58:27.672680", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39muser.slice[0m - User and Session Slice.\r"}
- {"dt": "2025-03-25T13:58:27.674927", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-ask-password-conso\u2026[0mequests to Console Directory Watch.\r"}
- {"dt": "2025-03-25T13:58:27.676160", "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-25T13:58:27.678342", "lvl": "target", "msg": "         Expecting device [0;1;39mdev-ttyAMA0.device[0m - /dev/ttyAMA0...\r"}
- {"dt": "2025-03-25T13:58:27.679255", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mpaths.target[0m - Path Units.\r"}
- {"dt": "2025-03-25T13:58:27.680069", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mremote-fs.target[0m - Remote File Systems.\r"}
- {"dt": "2025-03-25T13:58:27.680845", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mslices.target[0m - Slice Units.\r"}
- {"dt": "2025-03-25T13:58:27.681645", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mswap.target[0m - Swaps.\r"}
- {"dt": "2025-03-25T13:58:27.694300", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-creds.socket[0m - Credential Encryption/Decryption.\r"}
- {"dt": "2025-03-25T13:58:27.696579", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-initctl.socke\u2026[0m- initctl Compatibility Named Pipe.\r"}
- {"dt": "2025-03-25T13:58:27.698731", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-journald-dev-\u2026socket[0m - Journal Socket (/dev/log).\r"}
- {"dt": "2025-03-25T13:58:27.700413", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-journald.socket[0m - Journal Sockets.\r"}
- {"dt": "2025-03-25T13:58:27.702914", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-udevd-control.socket[0m - udev Control Socket.\r"}
- {"dt": "2025-03-25T13:58:27.704258", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-udevd-kernel.socket[0m - udev Kernel Socket.\r"}
- {"dt": "2025-03-25T13:58:27.726984", "lvl": "target", "msg": "         Mounting [0;1;39mdev-hugepages.mount[0m - Huge Pages File System...\r"}
- {"dt": "2025-03-25T13:58:27.747422", "lvl": "target", "msg": "         Mounting [0;1;39mdev-mqueue.mount[0m - POSIX Message Queue File System...\r"}
- {"dt": "2025-03-25T13:58:27.769006", "lvl": "target", "msg": "         Mounting [0;1;39mrun-lock.mount[0m - Legacy Locks Directory /run/lock...\r"}
- {"dt": "2025-03-25T13:58:27.793597", "lvl": "target", "msg": "         Mounting [0;1;39msys-kernel-debug.mount[0m - Kernel Debug File System...\r"}
- {"dt": "2025-03-25T13:58:27.833156", "lvl": "target", "msg": "         Mounting [0;1;39mtmp.mount[0m - Temporary Directory /tmp...\r"}
- {"dt": "2025-03-25T13:58:27.878328", "lvl": "target", "msg": "         Starting [0;1;39mkmod-static-nodes.service[0m\u2026eate List of Static Device Nodes...\r"}
- {"dt": "2025-03-25T13:58:27.909521", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@configfs.service[0m - Load Kernel Module configfs...\r"}
- {"dt": "2025-03-25T13:58:27.951682", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@drm.service[0m - Load Kernel Module drm...\r"}
- {"dt": "2025-03-25T13:58:27.980638", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@efi_pstore.servi\u2026[0m - Load Kernel Module efi_pstore...\r"}
- {"dt": "2025-03-25T13:58:28.011751", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@fuse.service[0m - Load Kernel Module fuse...\r"}
- {"dt": "2025-03-25T13:58:28.050278", "lvl": "target", "msg": "         Starting [0;1;39msystemd-journald.service[0m - Journal Service...\r"}
- {"dt": "2025-03-25T13:58:28.068654", "lvl": "target", "msg": "         Starting [0;1;39msystemd-modules-load.service[0m - Load Kernel Modules...\r"}
- {"dt": "2025-03-25T13:58:28.096340", "lvl": "target", "msg": "         Starting [0;1;39msystemd-remount-fs.servic\u2026[0munt Root and Kernel File Systems...\r"}
- {"dt": "2025-03-25T13:58:28.108031", "lvl": "target", "msg": "         Starting [0;1;39msystemd-udev-load-credent\u2026[0mLoad udev Rules from Credentials...\r"}
- {"dt": "2025-03-25T13:58:28.128438", "lvl": "target", "msg": "         Starting [0;1;39msystemd-udev-trigger.service[0m - Coldplug All udev Devices...\r"}
- {"dt": "2025-03-25T13:58:28.163147", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mdev-hugepages.mount[0m - Huge Pages File System.\r"}
- {"dt": "2025-03-25T13:58:28.165089", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mdev-mqueue.mount[0m - POSIX Message Queue File System.\r"}
- {"dt": "2025-03-25T13:58:28.172237", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mrun-lock.mount[0m - Legacy Locks Directory /run/lock.\r"}
- {"dt": "2025-03-25T13:58:28.174339", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39msys-kernel-debug.mount[0m - Kernel Debug File System.\r"}
- {"dt": "2025-03-25T13:58:28.176062", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mtmp.mount[0m - Temporary Directory /tmp.\r"}
- {"dt": "2025-03-25T13:58:28.187296", "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-25T13:58:28.212998", "lvl": "target", "msg": "         Starting [0;1;39msystemd-tmpfiles-setup-de\u2026[0m Device Nodes in /dev gracefully...\r"}
- {"dt": "2025-03-25T13:58:28.484029", "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-25T13:58:28.488757", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-modules-load.service[0m - Load Kernel Modules.\r"}
- {"dt": "2025-03-25T13:58:28.512535", "lvl": "target", "msg": "         Starting [0;1;39msystemd-random-seed.service[0m - Load/Save OS Random Seed...\r"}
- {"dt": "2025-03-25T13:58:28.532266", "lvl": "target", "msg": "         Starting [0;1;39msystemd-sysctl.service[0m - Apply Kernel Variables...\r"}
- {"dt": "2025-03-25T13:58:28.547886", "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-25T13:58:28.631776", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@efi_pstore.service[0m - Load Kernel Module efi_pstore.\r"}
- {"dt": "2025-03-25T13:58:28.724740", "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-25T13:58:28.754553", "lvl": "target", "msg": "         Starting [0;1;39msystemd-sysusers.service[0m - Create System Users...\r"}
- {"dt": "2025-03-25T13:58:28.793413", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@configfs.service[0m - Load Kernel Module configfs.\r"}
- {"dt": "2025-03-25T13:58:28.839490", "lvl": "target", "msg": "<6>[    4.429121] fuse: init (API version 7.43)"}
- {"dt": "2025-03-25T13:58:28.864272", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@fuse.service[0m - Load Kernel Module fuse.\r"}
- {"dt": "2025-03-25T13:58:28.899247", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-random-seed.service[0m - Load/Save OS Random Seed.\r"}
- {"dt": "2025-03-25T13:58:28.955293", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-sysctl.service[0m - Apply Kernel Variables.\r"}
- {"dt": "2025-03-25T13:58:28.963530", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@drm.service[0m - Load Kernel Module drm.\r"}
- {"dt": "2025-03-25T13:58:29.103728", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-sysusers.service[0m - Create System Users.\r"}
- {"dt": "2025-03-25T13:58:29.119499", "lvl": "target", "msg": "         Starting [0;1;39msystemd-tmpfiles-setup-de\u2026[0meate Static Device Nodes in /dev...\r"}
- {"dt": "2025-03-25T13:58:29.163426", "lvl": "target", "msg": "         Mounting [0;1;39msys-fs-fuse-connections.mount[0m - FUSE Control File System...\r"}
- {"dt": "2025-03-25T13:58:29.191270", "lvl": "target", "msg": "         Mounting [0;1;39msys-kernel-config.mount[0m - Kernel Configuration File System...\r"}
- {"dt": "2025-03-25T13:58:29.257132", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-journald.service[0m - Journal Service.\r"}
- {"dt": "2025-03-25T13:58:29.316196", "lvl": "target", "msg": "         Starting [0;1;39msystemd-journal-flush.ser\u2026[0msh Journal to Persistent Storage...\r"}
- {"dt": "2025-03-25T13:58:29.350893", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39msys-fs-fuse-connections.mount[0m - FUSE Control File System.\r"}
- {"dt": "2025-03-25T13:58:29.352939", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39msys-kernel-config.mount[0m - Kernel Configuration File System.\r"}
- {"dt": "2025-03-25T13:58:29.491741", "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-25T13:58:29.510954", "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-25T13:58:29.511950", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mlocal-fs.target[0m - Local File Systems.\r"}
- {"dt": "2025-03-25T13:58:29.525941", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-sysext.socket[0m\u2026 System Extension Image Management.\r"}
- {"dt": "2025-03-25T13:58:29.548512", "lvl": "target", "msg": "         Starting [0;1;39msystemd-udevd.service[0m - R\u2026ager for Device Events and Files...\r"}
- {"dt": "2025-03-25T13:58:29.853240", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-journal-flush.ser\u2026[0mlush Journal to Persistent Storage.\r"}
- {"dt": "2025-03-25T13:58:29.872039", "lvl": "target", "msg": "         Starting [0;1;39msystemd-tmpfiles-setup.se\u2026[0mate System Files and Directories...\r"}
- {"dt": "2025-03-25T13:58:30.189812", "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-25T13:58:30.279982", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-tmpfiles-setup.se\u2026[0mreate System Files and Directories.\r"}
- {"dt": "2025-03-25T13:58:30.308141", "lvl": "target", "msg": "         Starting [0;1;39mldconfig.service[0m - Rebuild Dynamic Linker Cache...\r"}
- {"dt": "2025-03-25T13:58:30.324177", "lvl": "target", "msg": "         Starting [0;1;39msystemd-journal-catalog-u\u2026ervice[0m - Rebuild Journal Catalog...\r"}
- {"dt": "2025-03-25T13:58:30.979608", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-journal-catalog-u\u2026.service[0m - Rebuild Journal Catalog.\r"}
- {"dt": "2025-03-25T13:58:31.011185", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mldconfig.service[0m - Rebuild Dynamic Linker Cache.\r"}
- {"dt": "2025-03-25T13:58:31.028182", "lvl": "target", "msg": "         Starting [0;1;39msystemd-update-done.service[0m - Update is Completed...\r"}
- {"dt": "2025-03-25T13:58:31.139142", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-update-done.service[0m - Update is Completed.\r"}
- {"dt": "2025-03-25T13:58:32.159819", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-udev-trigger.service[0m - Coldplug All udev Devices.\r"}
- {"dt": "2025-03-25T13:58:32.165242", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39msysinit.target[0m - System Initialization.\r"}
- {"dt": "2025-03-25T13:58:32.172976", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mapt-daily.timer[0m - Daily apt download activities.\r"}
- {"dt": "2025-03-25T13:58:32.175107", "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-25T13:58:32.179083", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mdpkg-db-backup.timer[0m - Daily dpkg database backup timer.\r"}
- {"dt": "2025-03-25T13:58:32.180925", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39me2scrub_all.timer[0m - Period\u2026Metadata Check for All Filesystems.\r"}
- {"dt": "2025-03-25T13:58:32.183527", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mfstrim.timer[0m - Discard unused filesystem blocks once a week.\r"}
- {"dt": "2025-03-25T13:58:32.185105", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mlogrotate.timer[0m - Daily rotation of log files.\r"}
- {"dt": "2025-03-25T13:58:32.186467", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-tmpfiles-clean.tim\u2026[0my Cleanup of Temporary Directories.\r"}
- {"dt": "2025-03-25T13:58:32.188478", "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-25T13:58:32.190844", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mtimers.target[0m - Timer Units.\r"}
- {"dt": "2025-03-25T13:58:32.192787", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39mdbus.socket[0m - D-Bus System Message Bus Socket.\r"}
- {"dt": "2025-03-25T13:58:32.198375", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-hostnamed.socket[0m - Hostname Service Socket.\r"}
- {"dt": "2025-03-25T13:58:32.199202", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39msockets.target[0m - Socket Units.\r"}
- {"dt": "2025-03-25T13:58:32.200289", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mbasic.target[0m - Basic System.\r"}
- {"dt": "2025-03-25T13:58:32.213704", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mcron.service[0m - Regular background program processing daemon.\r"}
- {"dt": "2025-03-25T13:58:32.228786", "lvl": "target", "msg": "         Starting [0;1;39mdbus.service[0m - D-Bus System Message Bus...\r"}
- {"dt": "2025-03-25T13:58:32.252761", "lvl": "target", "msg": "         Starting [0;1;39me2scrub_reap.service[0m - Re\u2026ne ext4 Metadata Check Snapshots...\r"}
- {"dt": "2025-03-25T13:58:32.300522", "lvl": "target", "msg": "         Starting [0;1;39msystemd-logind.service[0m - User Login Management...\r"}
- {"dt": "2025-03-25T13:58:32.320004", "lvl": "target", "msg": "         Starting [0;1;39msystemd-user-sessions.service[0m - Permit User Sessions...\r"}
- {"dt": "2025-03-25T13:58:32.542788", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-user-sessions.service[0m - Permit User Sessions.\r"}
- {"dt": "2025-03-25T13:58:32.559341", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mgetty@tty1.service[0m - Getty on tty1.\r"}
- {"dt": "2025-03-25T13:58:32.618866", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mdbus.service[0m - D-Bus System Message Bus.\r"}
- {"dt": "2025-03-25T13:58:32.706159", "lvl": "target", "msg": "[[0;32m  OK  [0m] Found device [0;1;39mdev-ttyAMA0.device[0m - /dev/ttyAMA0.\r"}
- {"dt": "2025-03-25T13:58:32.724249", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mserial-getty@ttyAMA0.service[0m - Serial Getty on ttyAMA0.\r"}
- {"dt": "2025-03-25T13:58:32.727115", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mgetty.target[0m - Login Prompts.\r"}
- {"dt": "2025-03-25T13:58:32.954325", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39me2scrub_reap.service[0m - Re\u2026line ext4 Metadata Check Snapshots.\r"}
- {"dt": "2025-03-25T13:58:33.313977", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-logind.service[0m - User Login Management.\r"}
- {"dt": "2025-03-25T13:58:33.399237", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mmulti-user.target[0m - Multi-User System.\r"}
- {"dt": "2025-03-25T13:58:33.401632", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mgraphical.target[0m - Graphical Interface.\r"}
- {"dt": "2025-03-25T13:58:35.159827", "lvl": "target", "msg": "[!p]104\a[?7h[6n[32766;32766H[6n[!p]104\a[?7h[6n[32766;32766H[6n\r"}
- {"dt": "2025-03-25T13:58:35.160001", "lvl": "target", "msg": "Debian GNU/Linux trixie/sid runner-ykxhnyexq-project-40964107-concurrent-0 ttyAMA0"}
- {"dt": "2025-03-25T13:58:35.160086", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T13:58:35.160478", "lvl": "debug", "msg": "Matched prompt #11: login:"}
- {"dt": "2025-03-25T13:58:35.160547", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "kernel-messages", "level": "2.2.1", "duration": "10.91", "result": "pass", "extra": {"extra": []}}}
- {"dt": "2025-03-25T13:58:35.160650", "lvl": "debug", "msg": "Sending username root"}
- {"dt": "2025-03-25T13:58:35.160711", "lvl": "debug", "msg": "Sending line: 'root'"}
- {"dt": "2025-03-25T13:58:35.260955", "lvl": "input", "msg": "root"}
- {"dt": "2025-03-25T13:58:35.261083", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T13:58:35.261179", "lvl": "debug", "msg": "login-action: Wait for prompt ['root@(.*):[/~]#', 'Login incorrect', 'Login timed out'] (timeout 00:29:49)"}
- {"dt": "2025-03-25T13:58:35.261263", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:14:54)"}
- {"dt": "2025-03-25T13:58:35.261791", "lvl": "target", "msg": "runner-ykxhnyexq-project-40964107-concurrent-0 login: root\r"}
- {"dt": "2025-03-25T13:58:35.448320", "lvl": "target", "msg": "Linux runner-ykxhnyexq-project-40964107-concurrent-0 6.14.0-rc7-next-20250324 #1 SMP PREEMPT @1742818529 aarch64"}
- {"dt": "2025-03-25T13:58:35.449899", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T13:58:35.450194", "lvl": "target", "msg": "The programs included with the Debian GNU/Linux system are free software;"}
- {"dt": "2025-03-25T13:58:35.450525", "lvl": "target", "msg": "the exact distribution terms for each program are described in the"}
- {"dt": "2025-03-25T13:58:35.450603", "lvl": "target", "msg": "individual files in /usr/share/doc/*/copyright."}
- {"dt": "2025-03-25T13:58:35.450696", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T13:58:35.450775", "lvl": "target", "msg": "Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent"}
- {"dt": "2025-03-25T13:58:35.450841", "lvl": "target", "msg": "permitted by applicable law."}
- {"dt": "2025-03-25T13:58:37.462882", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T13:58:37.463084", "lvl": "debug", "msg": "end: 2.2.1 login-action (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T13:58:37.463179", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "login-action", "level": "2.2.1", "duration": "13.21", "result": "pass", "extra": {"success": "No kernel warnings or errors detected."}}}
- {"dt": "2025-03-25T13:58:37.463335", "lvl": "debug", "msg": "end: 2.2 auto-login-action (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T13:58:37.463444", "lvl": "debug", "msg": "start: 2.3 expect-shell-connection (timeout 00:29:47) [common]"}
- {"dt": "2025-03-25T13:58:37.463527", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T13:58:37.463604", "lvl": "debug", "msg": "Forcing a shell prompt, looking for ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T13:58:37.463658", "lvl": "debug", "msg": "Sending line: ''"}
- {"dt": "2025-03-25T13:58:37.513799", "lvl": "input", "msg": ""}
- {"dt": "2025-03-25T13:58:37.513958", "lvl": "debug", "msg": "expect-shell-connection: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:30:00)"}
- {"dt": "2025-03-25T13:58:37.514041", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:15:00)"}
- {"dt": "2025-03-25T13:58:37.514851", "lvl": "target", "msg": "[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# "}
- {"dt": "2025-03-25T13:58:37.516343", "lvl": "debug", "msg": "end: 2.3 expect-shell-connection (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:37.516459", "lvl": "debug", "msg": "start: 2.4 export-device-env (timeout 00:29:47) [common]"}
- {"dt": "2025-03-25T13:58:37.516570", "lvl": "debug", "msg": "end: 2.4 export-device-env (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:37.516675", "lvl": "info", "msg": "end: 2 boot-image-retry (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T13:58:37.516772", "lvl": "info", "msg": "start: 3 lava-test-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T13:58:37.516874", "lvl": "debug", "msg": "start: 3.1 lava-test-shell (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T13:58:37.516956", "lvl": "debug", "msg": "Using namespace: common"}
- {"dt": "2025-03-25T13:58:37.517044", "lvl": "debug", "msg": "Sending line: '#'"}
- {"dt": "2025-03-25T13:58:37.617279", "lvl": "input", "msg": "#"}
- {"dt": "2025-03-25T13:58:37.617465", "lvl": "debug", "msg": "lava-test-shell: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:05:00)"}
- {"dt": "2025-03-25T13:58:37.618156", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# #"}
- {"dt": "2025-03-25T13:58:37.619801", "lvl": "debug", "msg": "Using /lava-1"}
- {"dt": "2025-03-25T13:58:37.619855", "lvl": "debug", "msg": "Sending line: 'export SHELL=/bin/sh'"}
- {"dt": "2025-03-25T13:58:37.720077", "lvl": "input", "msg": "export SHELL=/bin/sh"}
- {"dt": "2025-03-25T13:58:37.720692", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# export SHELL=/bin/sh"}
- {"dt": "2025-03-25T13:58:37.722587", "lvl": "debug", "msg": "Sending line: '. /lava-1/environment'"}
- {"dt": "2025-03-25T13:58:37.822812", "lvl": "input", "msg": ". /lava-1/environment"}
- {"dt": "2025-03-25T13:58:37.823515", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# . /lava-1/environment"}
- {"dt": "2025-03-25T13:58:37.827737", "lvl": "debug", "msg": "Sending line: '/lava-1/bin/lava-test-runner /lava-1/0'"}
- {"dt": "2025-03-25T13:58:37.927988", "lvl": "input", "msg": "/lava-1/bin/lava-test-runner /lava-1/0"}
- {"dt": "2025-03-25T13:58:37.928135", "lvl": "info", "msg": "Test shell timeout: 10s (minimum of the action and connection timeout)"}
- {"dt": "2025-03-25T13:58:37.929062", "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-25T13:58:38.040246", "lvl": "target", "msg": "[?2004l\r+ export TESTRUN_ID=0_kselftest-core"}
- {"dt": "2025-03-25T13:58:38.040415", "lvl": "target", "msg": "+ cd /lava-1/0/tests/0_kselftest-core"}
- {"dt": "2025-03-25T13:58:38.043493", "lvl": "target", "msg": "+ cat uuid"}
- {"dt": "2025-03-25T13:58:38.051361", "lvl": "target", "msg": "+ UUID=1_1.1.3.1"}
- {"dt": "2025-03-25T13:58:38.051671", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2025-03-25T13:58:38.052551", "lvl": "target", "msg": "<8>[   13.642746] <LAVA_SIGNAL_STARTRUN 0_kselftest-core 1_1.1.3.1>"}
- {"dt": "2025-03-25T13:58:38.052816", "lvl": "debug", "msg": "Received signal: <STARTRUN> 0_kselftest-core 1_1.1.3.1"}
- {"dt": "2025-03-25T13:58:38.052873", "lvl": "info", "msg": "Starting test lava.0_kselftest-core (1_1.1.3.1)"}
- {"dt": "2025-03-25T13:58:38.052945", "lvl": "info", "msg": "Skipping test definition patterns."}
- {"dt": "2025-03-25T13:58:38.053038", "lvl": "target", "msg": "+ cd ./automated/linux/kselftest/"}
- {"dt": "2025-03-25T13:58:38.057141", "lvl": "target", "msg": "+ ./kselftest.sh -c core -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-25T13:58:38.106835", "lvl": "target", "msg": "INFO: Generating a skipfile based on /lava-1/0/tests/0_kselftest-core/automated/linux/kselftest/skipfile-lkft.yaml"}
- {"dt": "2025-03-25T13:58:38.259661", "lvl": "target", "msg": "INFO: Using the following generated skipfile contents (until EOF):"}
- {"dt": "2025-03-25T13:58:38.264534", "lvl": "target", "msg": "bpf:test_btf"}
- {"dt": "2025-03-25T13:58:38.264624", "lvl": "target", "msg": "bpf:test_progs"}
- {"dt": "2025-03-25T13:58:38.264703", "lvl": "target", "msg": "breakpoints:breakpoint_test"}
- {"dt": "2025-03-25T13:58:38.264801", "lvl": "target", "msg": "breakpoints:breakpoint_test_arm64"}
- {"dt": "2025-03-25T13:58:38.264878", "lvl": "target", "msg": "breakpoints:step_after_suspend_test"}
- {"dt": "2025-03-25T13:58:38.264950", "lvl": "target", "msg": "kmod:test_kmod.sh"}
- {"dt": "2025-03-25T13:58:38.265018", "lvl": "target", "msg": "kvm:get-reg-list"}
- {"dt": "2025-03-25T13:58:38.265103", "lvl": "target", "msg": "kvm:kvm_create_max_vcpus"}
- {"dt": "2025-03-25T13:58:38.265151", "lvl": "target", "msg": "mqueue:mq_open_tests"}
- {"dt": "2025-03-25T13:58:38.265196", "lvl": "target", "msg": "mqueue:mq_perf_tests"}
- {"dt": "2025-03-25T13:58:38.265246", "lvl": "target", "msg": "net:fib_nexthops.sh"}
- {"dt": "2025-03-25T13:58:38.265291", "lvl": "target", "msg": "net:msg_zerocopy.sh"}
- {"dt": "2025-03-25T13:58:38.265349", "lvl": "target", "msg": "net:rtnetlink.sh"}
- {"dt": "2025-03-25T13:58:38.265392", "lvl": "target", "msg": "net:run_afpackettests"}
- {"dt": "2025-03-25T13:58:38.265438", "lvl": "target", "msg": "net:tls"}
- {"dt": "2025-03-25T13:58:38.265483", "lvl": "target", "msg": "net:udpgro.sh"}
- {"dt": "2025-03-25T13:58:38.265528", "lvl": "target", "msg": "net:xfrm_policy.sh"}
- {"dt": "2025-03-25T13:58:38.265586", "lvl": "target", "msg": "netfilter:bridge_brouter.sh"}
- {"dt": "2025-03-25T13:58:38.265630", "lvl": "target", "msg": "netfilter:conntrack_icmp_related.sh"}
- {"dt": "2025-03-25T13:58:38.265676", "lvl": "target", "msg": "netfilter:nft_flowtable.sh"}
- {"dt": "2025-03-25T13:58:38.265735", "lvl": "target", "msg": "netfilter:nft_nat.sh"}
- {"dt": "2025-03-25T13:58:38.265791", "lvl": "target", "msg": "netfilter:nft_trans_stress.sh"}
- {"dt": "2025-03-25T13:58:38.265854", "lvl": "target", "msg": "pidfd:pidfd_wait"}
- {"dt": "2025-03-25T13:58:38.265894", "lvl": "target", "msg": "proc:proc-pid-vm"}
- {"dt": "2025-03-25T13:58:38.265942", "lvl": "target", "msg": "ptrace:vmaccess"}
- {"dt": "2025-03-25T13:58:38.266168", "lvl": "target", "msg": "rseq:run_param_test.sh"}
- {"dt": "2025-03-25T13:58:38.266213", "lvl": "target", "msg": "sync:sync_test"}
- {"dt": "2025-03-25T13:58:38.266250", "lvl": "target", "msg": "vm:run_vmtests"}
- {"dt": "2025-03-25T13:58:38.266295", "lvl": "target", "msg": "zram:zram.sh"}
- {"dt": "2025-03-25T13:58:38.267761", "lvl": "target", "msg": "INFO: EOF"}
- {"dt": "2025-03-25T13:58:38.315005", "lvl": "target", "msg": "INFO: Installing sed perl wget xz-utils iproute2 python3-tap"}
- {"dt": "2025-03-25T13:58:38.615070", "lvl": "target", "msg": "Ign:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T13:58:39.619581", "lvl": "target", "msg": "Ign:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T13:58:41.624669", "lvl": "target", "msg": "Ign:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T13:58:45.631433", "lvl": "target", "msg": "Err:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T13:58:45.631594", "lvl": "target", "msg": "  Temporary failure resolving 'deb.debian.org'"}
- {"dt": "2025-03-25T13:58:45.745659", "lvl": "target", "msg": "Reading package lists..."}
- {"dt": "2025-03-25T13:58:45.763837", "lvl": "target", "msg": "W: Failed to fetch https://deb.debian.org/debian/dists/trixie/InRelease  Temporary failure resolving 'deb.debian.org'"}
- {"dt": "2025-03-25T13:58:45.764286", "lvl": "target", "msg": "W: Some index files failed to download. They have been ignored, or old ones used instead."}
- {"dt": "2025-03-25T13:58:45.851064", "lvl": "target", "msg": "Reading package lists..."}
- {"dt": "2025-03-25T13:58:45.873289", "lvl": "target", "msg": "Building dependency tree..."}
- {"dt": "2025-03-25T13:58:45.876566", "lvl": "target", "msg": "Reading state information..."}
- {"dt": "2025-03-25T13:58:45.895473", "lvl": "target", "msg": "sed is already the newest version (4.9-2+b1)."}
- {"dt": "2025-03-25T13:58:45.895747", "lvl": "target", "msg": "perl is already the newest version (5.40.0-8)."}
- {"dt": "2025-03-25T13:58:45.896042", "lvl": "target", "msg": "wget is already the newest version (1.24.5-2)."}
- {"dt": "2025-03-25T13:58:45.896135", "lvl": "target", "msg": "xz-utils is already the newest version (5.6.3-1+b1)."}
- {"dt": "2025-03-25T13:58:45.896403", "lvl": "target", "msg": "iproute2 is already the newest version (6.13.0-1)."}
- {"dt": "2025-03-25T13:58:45.896476", "lvl": "target", "msg": "python3-tap is already the newest version (3.2.1-1)."}
- {"dt": "2025-03-25T13:58:45.980090", "lvl": "target", "msg": "0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded."}
- {"dt": "2025-03-25T13:58:46.006563", "lvl": "target", "msg": "kselftests found on rootfs"}
- {"dt": "2025-03-25T13:58:46.042380", "lvl": "target", "msg": "skiplist:"}
- {"dt": "2025-03-25T13:58:46.042530", "lvl": "target", "msg": "========================================"}
- {"dt": "2025-03-25T13:58:46.043173", "lvl": "target", "msg": "bpf:test_btf"}
- {"dt": "2025-03-25T13:58:46.124022", "lvl": "target", "msg": "bpf:test_progs"}
- {"dt": "2025-03-25T13:58:46.146278", "lvl": "target", "msg": "breakpoints:breakpoint_test"}
- {"dt": "2025-03-25T13:58:46.166956", "lvl": "target", "msg": "breakpoints:breakpoint_test_arm64"}
- {"dt": "2025-03-25T13:58:46.189714", "lvl": "target", "msg": "breakpoints:step_after_suspend_test"}
- {"dt": "2025-03-25T13:58:46.209676", "lvl": "target", "msg": "kmod:test_kmod.sh"}
- {"dt": "2025-03-25T13:58:46.229395", "lvl": "target", "msg": "kvm:get-reg-list"}
- {"dt": "2025-03-25T13:58:46.248682", "lvl": "target", "msg": "kvm:kvm_create_max_vcpus"}
- {"dt": "2025-03-25T13:58:46.269271", "lvl": "target", "msg": "mqueue:mq_open_tests"}
- {"dt": "2025-03-25T13:58:46.289347", "lvl": "target", "msg": "mqueue:mq_perf_tests"}
- {"dt": "2025-03-25T13:58:46.310714", "lvl": "target", "msg": "net:fib_nexthops.sh"}
- {"dt": "2025-03-25T13:58:46.330789", "lvl": "target", "msg": "net:msg_zerocopy.sh"}
- {"dt": "2025-03-25T13:58:46.350987", "lvl": "target", "msg": "net:rtnetlink.sh"}
- {"dt": "2025-03-25T13:58:46.370916", "lvl": "target", "msg": "net:run_afpackettests"}
- {"dt": "2025-03-25T13:58:46.390730", "lvl": "target", "msg": "net:tls"}
- {"dt": "2025-03-25T13:58:46.410476", "lvl": "target", "msg": "net:udpgro.sh"}
- {"dt": "2025-03-25T13:58:46.430293", "lvl": "target", "msg": "net:xfrm_policy.sh"}
- {"dt": "2025-03-25T13:58:46.450465", "lvl": "target", "msg": "netfilter:bridge_brouter.sh"}
- {"dt": "2025-03-25T13:58:46.469161", "lvl": "target", "msg": "netfilter:conntrack_icmp_related.sh"}
- {"dt": "2025-03-25T13:58:46.489022", "lvl": "target", "msg": "netfilter:nft_flowtable.sh"}
- {"dt": "2025-03-25T13:58:46.508712", "lvl": "target", "msg": "netfilter:nft_nat.sh"}
- {"dt": "2025-03-25T13:58:46.528258", "lvl": "target", "msg": "netfilter:nft_trans_stress.sh"}
- {"dt": "2025-03-25T13:58:46.547798", "lvl": "target", "msg": "pidfd:pidfd_wait"}
- {"dt": "2025-03-25T13:58:46.567008", "lvl": "target", "msg": "proc:proc-pid-vm"}
- {"dt": "2025-03-25T13:58:46.587844", "lvl": "target", "msg": "ptrace:vmaccess"}
- {"dt": "2025-03-25T13:58:46.606938", "lvl": "target", "msg": "rseq:run_param_test.sh"}
- {"dt": "2025-03-25T13:58:46.626414", "lvl": "target", "msg": "sync:sync_test"}
- {"dt": "2025-03-25T13:58:46.646789", "lvl": "target", "msg": "vm:run_vmtests"}
- {"dt": "2025-03-25T13:58:46.666319", "lvl": "target", "msg": "zram:zram.sh"}
- {"dt": "2025-03-25T13:58:46.685447", "lvl": "target", "msg": "========================================"}
- {"dt": "2025-03-25T13:58:46.722931", "lvl": "target", "msg": "core:close_range_test"}
- {"dt": "2025-03-25T13:58:46.723057", "lvl": "target", "msg": "core:unshare_test"}
- {"dt": "2025-03-25T13:58:46.734980", "lvl": "target", "msg": "============== Tests to run ==============="}
- {"dt": "2025-03-25T13:58:46.738878", "lvl": "target", "msg": "core:close_range_test"}
- {"dt": "2025-03-25T13:58:46.738962", "lvl": "target", "msg": "core:unshare_test"}
- {"dt": "2025-03-25T13:58:46.740310", "lvl": "target", "msg": "===========End Tests to run ==============="}
- {"dt": "2025-03-25T13:58:46.747411", "lvl": "target", "msg": "shardfile-core pass"}
- {"dt": "2025-03-25T13:58:46.877071", "lvl": "target", "msg": "<12>[   22.466683] kselftest: Running tests in core"}
- {"dt": "2025-03-25T13:58:46.892647", "lvl": "target", "msg": "TAP version 13"}
- {"dt": "2025-03-25T13:58:46.905686", "lvl": "target", "msg": "1..2"}
- {"dt": "2025-03-25T13:58:46.937935", "lvl": "target", "msg": "# timeout set to 45"}
- {"dt": "2025-03-25T13:58:46.938265", "lvl": "target", "msg": "# selftests: core: close_range_test"}
- {"dt": "2025-03-25T13:58:47.214367", "lvl": "target", "msg": "# TAP version 13"}
- {"dt": "2025-03-25T13:58:47.214520", "lvl": "target", "msg": "# 1..9"}
- {"dt": "2025-03-25T13:58:47.214587", "lvl": "target", "msg": "# # Starting 9 tests from 1 test cases."}
- {"dt": "2025-03-25T13:58:47.214658", "lvl": "target", "msg": "# #  RUN           global.core_close_range ..."}
- {"dt": "2025-03-25T13:58:47.214720", "lvl": "target", "msg": "# #            OK  global.core_close_range"}
- {"dt": "2025-03-25T13:58:47.222113", "lvl": "target", "msg": "# ok 1 global.core_close_range"}
- {"dt": "2025-03-25T13:58:47.222441", "lvl": "target", "msg": "# #  RUN           global.close_range_unshare ..."}
- {"dt": "2025-03-25T13:58:47.222522", "lvl": "target", "msg": "# #            OK  global.close_range_unshare"}
- {"dt": "2025-03-25T13:58:47.222595", "lvl": "target", "msg": "# ok 2 global.close_range_unshare"}
- {"dt": "2025-03-25T13:58:47.225834", "lvl": "target", "msg": "# #  RUN           global.close_range_unshare_capped ..."}
- {"dt": "2025-03-25T13:58:47.230260", "lvl": "target", "msg": "# #            OK  global.close_range_unshare_capped"}
- {"dt": "2025-03-25T13:58:47.230346", "lvl": "target", "msg": "# ok 3 global.close_range_unshare_capped"}
- {"dt": "2025-03-25T13:58:47.230622", "lvl": "target", "msg": "# #  RUN           global.close_range_cloexec ..."}
- {"dt": "2025-03-25T13:58:47.238137", "lvl": "target", "msg": "# #            OK  global.close_range_cloexec"}
- {"dt": "2025-03-25T13:58:47.238419", "lvl": "target", "msg": "# ok 4 global.close_range_cloexec"}
- {"dt": "2025-03-25T13:58:47.238497", "lvl": "target", "msg": "# #  RUN           global.close_range_cloexec_unshare ..."}
- {"dt": "2025-03-25T13:58:47.240000", "lvl": "target", "msg": "# #            OK  global.close_range_cloexec_unshare"}
- {"dt": "2025-03-25T13:58:47.246254", "lvl": "target", "msg": "# ok 5 global.close_range_cloexec_unshare"}
- {"dt": "2025-03-25T13:58:47.246346", "lvl": "target", "msg": "# #  RUN           global.close_range_cloexec_syzbot ..."}
- {"dt": "2025-03-25T13:58:47.246421", "lvl": "target", "msg": "# #            OK  global.close_range_cloexec_syzbot"}
- {"dt": "2025-03-25T13:58:47.246680", "lvl": "target", "msg": "# ok 6 global.close_range_cloexec_syzbot"}
- {"dt": "2025-03-25T13:58:47.252589", "lvl": "target", "msg": "# #  RUN           global.close_range_cloexec_unshare_syzbot ..."}
- {"dt": "2025-03-25T13:58:47.290372", "lvl": "target", "msg": "# #            OK  global.close_range_cloexec_unshare_syzbot"}
- {"dt": "2025-03-25T13:58:47.293957", "lvl": "target", "msg": "# ok 7 global.close_range_cloexec_unshare_syzbot"}
- {"dt": "2025-03-25T13:58:47.294344", "lvl": "target", "msg": "# #  RUN           global.close_range_bitmap_corruption ..."}
- {"dt": "2025-03-25T13:58:47.298335", "lvl": "target", "msg": "# #            OK  global.close_range_bitmap_corruption"}
- {"dt": "2025-03-25T13:58:47.301240", "lvl": "target", "msg": "# ok 8 global.close_range_bitmap_corruption"}
- {"dt": "2025-03-25T13:58:47.301334", "lvl": "target", "msg": "# #  RUN           global.fcntl_created ..."}
- {"dt": "2025-03-25T13:58:47.334836", "lvl": "target", "msg": "# #            OK  global.fcntl_created"}
- {"dt": "2025-03-25T13:58:47.335471", "lvl": "target", "msg": "# ok 9 global.fcntl_created"}
- {"dt": "2025-03-25T13:58:47.337106", "lvl": "target", "msg": "# # PASSED: 9 / 9 tests passed."}
- {"dt": "2025-03-25T13:58:47.339936", "lvl": "target", "msg": "# # Totals: pass:9 fail:0 xfail:0 xpass:0 skip:0 error:0"}
- {"dt": "2025-03-25T13:58:47.349535", "lvl": "target", "msg": "ok 1 selftests: core: close_range_test"}
- {"dt": "2025-03-25T13:58:47.382359", "lvl": "target", "msg": "# timeout set to 45"}
- {"dt": "2025-03-25T13:58:47.382468", "lvl": "target", "msg": "# selftests: core: unshare_test"}
- {"dt": "2025-03-25T13:58:47.420710", "lvl": "target", "msg": "<4>[   23.010534] ------------[ cut here ]------------"}
- {"dt": "2025-03-25T13:58:47.421270", "lvl": "target", "msg": "<4>[   23.010625] WARNING: CPU: 0 PID: 474 at mm/slub.c:5028 __kvmalloc_node_noprof+0x408/0x490"}
- {"dt": "2025-03-25T13:58:47.422245", "lvl": "target", "msg": "<4>[   23.012093] Modules linked in: sm3_ce sm3 sha3_ce sha512_ce sha512_arm64 drm fuse backlight ip_tables x_tables"}
- {"dt": "2025-03-25T13:58:47.423014", "lvl": "target", "msg": "<4>[   23.013195] CPU: 0 UID: 0 PID: 474 Comm: unshare_test Not tainted 6.14.0-rc7-next-20250324 #1 PREEMPT "}
- {"dt": "2025-03-25T13:58:47.423117", "lvl": "target", "msg": "<4>[   23.013634] Hardware name: linux,dummy-virt (DT)"}
- {"dt": "2025-03-25T13:58:47.423510", "lvl": "target", "msg": "<4>[   23.013916] pstate: 23402009 (nzCv daif +PAN -UAO +TCO +DIT -SSBS BTYPE=--)"}
- {"dt": "2025-03-25T13:58:47.423670", "lvl": "target", "msg": "<4>[   23.014223] pc : __kvmalloc_node_noprof+0x408/0x490"}
- {"dt": "2025-03-25T13:58:47.423836", "lvl": "target", "msg": "<4>[   23.014390] lr : __kvmalloc_node_noprof+0x394/0x490"}
- {"dt": "2025-03-25T13:58:47.423956", "lvl": "target", "msg": "<4>[   23.014561] sp : ffff8000809dbc80"}
- {"dt": "2025-03-25T13:58:47.424253", "lvl": "target", "msg": "<4>[   23.014679] x29: ffff8000809dbcb0 x28: fff00000c5363780 x27: 0000000000000000"}
- {"dt": "2025-03-25T13:58:47.424513", "lvl": "target", "msg": "<4>[   23.014973] x26: 0000000000000000 x25: 0000000000412cc0 x24: 33bfa3466a54f33c"}
- {"dt": "2025-03-25T13:58:47.424924", "lvl": "target", "msg": "<4>[   23.015226] x23: 0000000000000000 x22: 00000000ffffffff x21: 0000000000400cc0"}
- {"dt": "2025-03-25T13:58:47.425004", "lvl": "target", "msg": "<4>[   23.015492] x20: 0000000200001e00 x19: 0000000000000000 x18: 0000000000000000"}
- {"dt": "2025-03-25T13:58:47.425238", "lvl": "target", "msg": "<4>[   23.015710] x17: 0000000000000000 x16: 0000000000000000 x15: 0000000000000000"}
- {"dt": "2025-03-25T13:58:47.425481", "lvl": "target", "msg": "<4>[   23.015951] x14: 0000000000000000 x13: 0000000000000000 x12: 0000000000000000"}
- {"dt": "2025-03-25T13:58:47.425906", "lvl": "target", "msg": "<4>[   23.016195] x11: 0000000000000000 x10: 0000000000000000 x9 : 0000000000000000"}
- {"dt": "2025-03-25T13:58:47.426219", "lvl": "target", "msg": "<4>[   23.016511] x8 : 0000000000000001 x7 : 0000000000000001 x6 : 0000000000000005"}
- {"dt": "2025-03-25T13:58:47.426464", "lvl": "target", "msg": "<4>[   23.016832] x5 : 0000000000000000 x4 : fff00000c5363780 x3 : 0000000000000000"}
- {"dt": "2025-03-25T13:58:47.426734", "lvl": "target", "msg": "<4>[   23.017091] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 000000007fffffff"}
- {"dt": "2025-03-25T13:58:47.426806", "lvl": "target", "msg": "<4>[   23.017431] Call trace:"}
- {"dt": "2025-03-25T13:58:47.427097", "lvl": "target", "msg": "<4>[   23.017614]  __kvmalloc_node_noprof+0x408/0x490 (P)"}
- {"dt": "2025-03-25T13:58:47.427328", "lvl": "target", "msg": "<4>[   23.017862]  alloc_fdtable+0x84/0x128"}
- {"dt": "2025-03-25T13:58:47.427454", "lvl": "target", "msg": "<4>[   23.018030]  expand_files+0x74/0x2ec"}
- {"dt": "2025-03-25T13:58:47.427585", "lvl": "target", "msg": "<4>[   23.018169]  ksys_dup3+0x60/0x120"}
- {"dt": "2025-03-25T13:58:47.427728", "lvl": "target", "msg": "<4>[   23.018300]  __arm64_sys_dup3+0x20/0x30"}
- {"dt": "2025-03-25T13:58:47.427859", "lvl": "target", "msg": "<4>[   23.018442]  invoke_syscall+0x48/0x10c"}
- {"dt": "2025-03-25T13:58:47.428111", "lvl": "target", "msg": "<4>[   23.018574]  el0_svc_common.constprop.0+0x40/0xe0"}
- {"dt": "2025-03-25T13:58:47.428184", "lvl": "target", "msg": "<4>[   23.018763]  do_el0_svc+0x1c/0x28"}
- {"dt": "2025-03-25T13:58:47.428307", "lvl": "target", "msg": "<4>[   23.018898]  el0_svc+0x30/0xcc"}
- {"dt": "2025-03-25T13:58:47.428471", "lvl": "target", "msg": "<4>[   23.019022]  el0t_64_sync_handler+0x10c/0x138"}
- {"dt": "2025-03-25T13:58:47.428714", "lvl": "target", "msg": "<4>[   23.019186]  el0t_64_sync+0x198/0x19c"}
- {"dt": "2025-03-25T13:58:47.428887", "lvl": "target", "msg": "<4>[   23.019442] ---[ end trace 0000000000000000 ]---"}
- {"dt": "2025-03-25T13:58:47.524608", "lvl": "target", "msg": "# TAP version 13"}
- {"dt": "2025-03-25T13:58:47.524751", "lvl": "target", "msg": "# 1..1"}
- {"dt": "2025-03-25T13:58:47.525222", "lvl": "target", "msg": "# # Starting 1 tests from 1 test cases."}
- {"dt": "2025-03-25T13:58:47.526401", "lvl": "target", "msg": "# #  RUN           global.unshare_EMFILE ..."}
- {"dt": "2025-03-25T13:58:47.527921", "lvl": "target", "msg": "# # unshare_test.c:60:unshare_EMFILE:Expected dup2(2, nr_open + 64) (-1) >= 0 (0)"}
- {"dt": "2025-03-25T13:58:47.528594", "lvl": "target", "msg": "# # unshare_EMFILE: Test failed"}
- {"dt": "2025-03-25T13:58:47.529362", "lvl": "target", "msg": "# #          FAIL  global.unshare_EMFILE"}
- {"dt": "2025-03-25T13:58:47.530364", "lvl": "target", "msg": "# not ok 1 global.unshare_EMFILE"}
- {"dt": "2025-03-25T13:58:47.530870", "lvl": "target", "msg": "# # FAILED: 0 / 1 tests passed."}
- {"dt": "2025-03-25T13:58:47.532130", "lvl": "target", "msg": "# # Totals: pass:0 fail:1 xfail:0 xpass:0 skip:0 error:0"}
- {"dt": "2025-03-25T13:58:47.543941", "lvl": "target", "msg": "not ok 2 selftests: core: unshare_test # exit=1"}
- {"dt": "2025-03-25T13:58:48.480990", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T13:58:48.481340", "lvl": "target", "msg": "WARNING: Optional imports not found, TAP 13 output will be"}
- {"dt": "2025-03-25T13:58:48.481423", "lvl": "target", "msg": "    ignored. To parse yaml, see requirements in docs:"}
- {"dt": "2025-03-25T13:58:48.481515", "lvl": "target", "msg": "    https://tappy.readthedocs.io/en/latest/consumers.html#tap-version-13"}
- {"dt": "2025-03-25T13:58:48.481631", "lvl": "target", "msg": "core_close_range_test_global_core_close_range pass"}
- {"dt": "2025-03-25T13:58:48.481795", "lvl": "target", "msg": "core_close_range_test_global_close_range_unshare pass"}
- {"dt": "2025-03-25T13:58:48.482067", "lvl": "target", "msg": "core_close_range_test_global_close_range_unshare_capped pass"}
- {"dt": "2025-03-25T13:58:48.482189", "lvl": "target", "msg": "core_close_range_test_global_close_range_cloexec pass"}
- {"dt": "2025-03-25T13:58:48.482371", "lvl": "target", "msg": "core_close_range_test_global_close_range_cloexec_unshare pass"}
- {"dt": "2025-03-25T13:58:48.482548", "lvl": "target", "msg": "core_close_range_test_global_close_range_cloexec_syzbot pass"}
- {"dt": "2025-03-25T13:58:48.482754", "lvl": "target", "msg": "core_close_range_test_global_close_range_cloexec_unshare_syzbot pass"}
- {"dt": "2025-03-25T13:58:48.482957", "lvl": "target", "msg": "core_close_range_test_global_close_range_bitmap_corruption pass"}
- {"dt": "2025-03-25T13:58:48.483106", "lvl": "target", "msg": "core_close_range_test_global_fcntl_created pass"}
- {"dt": "2025-03-25T13:58:48.483203", "lvl": "target", "msg": "core_close_range_test pass"}
- {"dt": "2025-03-25T13:58:48.483323", "lvl": "target", "msg": "core_unshare_test_global_unshare_EMFILE fail"}
- {"dt": "2025-03-25T13:58:48.483401", "lvl": "target", "msg": "core_unshare_test fail"}
- {"dt": "2025-03-25T13:58:48.556920", "lvl": "target", "msg": "+ ../../utils/send-to-lava.sh ./output/result.txt"}
- {"dt": "2025-03-25T13:58:48.590021", "lvl": "target", "msg": "WARNING: no log file found for breakpoints:breakpoint_test_arm64 at ./output/breakpoints:breakpoint_test_arm64.log"}
- {"dt": "2025-03-25T13:58:48.607108", "lvl": "target", "msg": "<8>[   24.197349] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=breakpoints:breakpoint_test_arm64 RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.607436", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=breakpoints:breakpoint_test_arm64 RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.607554", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "breakpoints:breakpoint_test_arm64", "result": "skip", "starttc": ! "917", "endtc": ! "917"}}
- {"dt": "2025-03-25T13:58:48.619210", "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-25T13:58:48.634202", "lvl": "target", "msg": "<8>[   24.224267] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=breakpoints:step_after_suspend_test RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.634481", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=breakpoints:step_after_suspend_test RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.634566", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "breakpoints:step_after_suspend_test", "result": "skip", "starttc": ! "921", "endtc": ! "921"}}
- {"dt": "2025-03-25T13:58:48.647002", "lvl": "target", "msg": "WARNING: no log file found for kvm:get-reg-list at ./output/kvm:get-reg-list.log"}
- {"dt": "2025-03-25T13:58:48.661650", "lvl": "target", "msg": "<8>[   24.251924] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=kvm:get-reg-list RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.661928", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=kvm:get-reg-list RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.662037", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "kvm:get-reg-list", "result": "skip", "starttc": ! "925", "endtc": ! "925"}}
- {"dt": "2025-03-25T13:58:48.673940", "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-25T13:58:48.690040", "lvl": "target", "msg": "<8>[   24.280164] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=kvm:kvm_create_max_vcpus RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.690307", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=kvm:kvm_create_max_vcpus RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.690397", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "kvm:kvm_create_max_vcpus", "result": "skip", "starttc": ! "929", "endtc": ! "929"}}
- {"dt": "2025-03-25T13:58:48.702520", "lvl": "target", "msg": "WARNING: no log file found for mqueue:mq_open_tests at ./output/mqueue:mq_open_tests.log"}
- {"dt": "2025-03-25T13:58:48.718338", "lvl": "target", "msg": "<8>[   24.308244] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=mqueue:mq_open_tests RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.718614", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=mqueue:mq_open_tests RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.718718", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "mqueue:mq_open_tests", "result": "skip", "starttc": ! "933", "endtc": ! "933"}}
- {"dt": "2025-03-25T13:58:48.732879", "lvl": "target", "msg": "WARNING: no log file found for mqueue:mq_perf_tests at ./output/mqueue:mq_perf_tests.log"}
- {"dt": "2025-03-25T13:58:48.748031", "lvl": "target", "msg": "<8>[   24.338145] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=mqueue:mq_perf_tests RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.748307", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=mqueue:mq_perf_tests RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.748425", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "mqueue:mq_perf_tests", "result": "skip", "starttc": ! "937", "endtc": ! "937"}}
- {"dt": "2025-03-25T13:58:48.762259", "lvl": "target", "msg": "WARNING: no log file found for net:fib_nexthops.sh at ./output/net:fib_nexthops.sh.log"}
- {"dt": "2025-03-25T13:58:48.777035", "lvl": "target", "msg": "<8>[   24.367107] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:fib_nexthops.sh RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.777294", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:fib_nexthops.sh RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.777394", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "net:fib_nexthops.sh", "result": "skip", "starttc": ! "941", "endtc": ! "941"}}
- {"dt": "2025-03-25T13:58:48.790239", "lvl": "target", "msg": "WARNING: no log file found for net:msg_zerocopy.sh at ./output/net:msg_zerocopy.sh.log"}
- {"dt": "2025-03-25T13:58:48.804780", "lvl": "target", "msg": "<8>[   24.395042] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:msg_zerocopy.sh RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.805105", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:msg_zerocopy.sh RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.805238", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "net:msg_zerocopy.sh", "result": "skip", "starttc": ! "945", "endtc": ! "945"}}
- {"dt": "2025-03-25T13:58:48.816924", "lvl": "target", "msg": "WARNING: no log file found for net:rtnetlink.sh at ./output/net:rtnetlink.sh.log"}
- {"dt": "2025-03-25T13:58:48.831977", "lvl": "target", "msg": "<8>[   24.422116] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:rtnetlink.sh RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.832248", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:rtnetlink.sh RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.832336", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "net:rtnetlink.sh", "result": "skip", "starttc": ! "949", "endtc": ! "949"}}
- {"dt": "2025-03-25T13:58:48.843193", "lvl": "target", "msg": "WARNING: no log file found for net:run_afpackettests at ./output/net:run_afpackettests.log"}
- {"dt": "2025-03-25T13:58:48.856810", "lvl": "target", "msg": "<8>[   24.447098] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:run_afpackettests RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.857100", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:run_afpackettests RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.857185", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "net:run_afpackettests", "result": "skip", "starttc": ! "953", "endtc": ! "953"}}
- {"dt": "2025-03-25T13:58:48.867907", "lvl": "target", "msg": "WARNING: no log file found for net:tls at ./output/net:tls.log"}
- {"dt": "2025-03-25T13:58:48.881854", "lvl": "target", "msg": "<8>[   24.472163] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:tls RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.882153", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:tls RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.882235", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "net:tls", "result": "skip", "starttc": ! "957", "endtc": ! "957"}}
- {"dt": "2025-03-25T13:58:48.893368", "lvl": "target", "msg": "WARNING: no log file found for net:udpgro.sh at ./output/net:udpgro.sh.log"}
- {"dt": "2025-03-25T13:58:48.907460", "lvl": "target", "msg": "<8>[   24.497729] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:udpgro.sh RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.907743", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:udpgro.sh RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.907803", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "net:udpgro.sh", "result": "skip", "starttc": ! "961", "endtc": ! "961"}}
- {"dt": "2025-03-25T13:58:48.920227", "lvl": "target", "msg": "WARNING: no log file found for net:xfrm_policy.sh at ./output/net:xfrm_policy.sh.log"}
- {"dt": "2025-03-25T13:58:48.933946", "lvl": "target", "msg": "<8>[   24.524226] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:xfrm_policy.sh RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.934200", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:xfrm_policy.sh RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.934272", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "net:xfrm_policy.sh", "result": "skip", "starttc": ! "965", "endtc": ! "965"}}
- {"dt": "2025-03-25T13:58:48.945506", "lvl": "target", "msg": "WARNING: no log file found for pidfd:pidfd_wait at ./output/pidfd:pidfd_wait.log"}
- {"dt": "2025-03-25T13:58:48.959547", "lvl": "target", "msg": "<8>[   24.549850] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=pidfd:pidfd_wait RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.959804", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=pidfd:pidfd_wait RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.959890", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "pidfd:pidfd_wait", "result": "skip", "starttc": ! "969", "endtc": ! "969"}}
- {"dt": "2025-03-25T13:58:48.972350", "lvl": "target", "msg": "WARNING: no log file found for proc:proc-pid-vm at ./output/proc:proc-pid-vm.log"}
- {"dt": "2025-03-25T13:58:48.986827", "lvl": "target", "msg": "<8>[   24.577124] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=proc:proc-pid-vm RESULT=skip>"}
- {"dt": "2025-03-25T13:58:48.987091", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=proc:proc-pid-vm RESULT=skip"}
- {"dt": "2025-03-25T13:58:48.987175", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "proc:proc-pid-vm", "result": "skip", "starttc": ! "973", "endtc": ! "973"}}
- {"dt": "2025-03-25T13:58:48.998464", "lvl": "target", "msg": "WARNING: no log file found for ptrace:vmaccess at ./output/ptrace:vmaccess.log"}
- {"dt": "2025-03-25T13:58:49.012227", "lvl": "target", "msg": "<8>[   24.602315] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=ptrace:vmaccess RESULT=skip>"}
- {"dt": "2025-03-25T13:58:49.012482", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=ptrace:vmaccess RESULT=skip"}
- {"dt": "2025-03-25T13:58:49.012548", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "ptrace:vmaccess", "result": "skip", "starttc": ! "977", "endtc": ! "977"}}
- {"dt": "2025-03-25T13:58:49.024011", "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-25T13:58:49.038649", "lvl": "target", "msg": "<8>[   24.628524] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=rseq:run_param_test.sh RESULT=skip>"}
- {"dt": "2025-03-25T13:58:49.038892", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=rseq:run_param_test.sh RESULT=skip"}
- {"dt": "2025-03-25T13:58:49.038970", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "rseq:run_param_test.sh", "result": "skip", "starttc": ! "981", "endtc": ! "981"}}
- {"dt": "2025-03-25T13:58:49.049788", "lvl": "target", "msg": "WARNING: no log file found for sync:sync_test at ./output/sync:sync_test.log"}
- {"dt": "2025-03-25T13:58:49.064064", "lvl": "target", "msg": "<8>[   24.654379] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=sync:sync_test RESULT=skip>"}
- {"dt": "2025-03-25T13:58:49.064317", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=sync:sync_test RESULT=skip"}
- {"dt": "2025-03-25T13:58:49.064397", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "sync:sync_test", "result": "skip", "starttc": ! "985", "endtc": ! "985"}}
- {"dt": "2025-03-25T13:58:49.075056", "lvl": "target", "msg": "WARNING: no log file found for zram:zram.sh at ./output/zram:zram.sh.log"}
- {"dt": "2025-03-25T13:58:49.089191", "lvl": "target", "msg": "<8>[   24.679272] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=zram:zram.sh RESULT=skip>"}
- {"dt": "2025-03-25T13:58:49.089428", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=zram:zram.sh RESULT=skip"}
- {"dt": "2025-03-25T13:58:49.089505", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "zram:zram.sh", "result": "skip", "starttc": ! "989", "endtc": ! "989"}}
- {"dt": "2025-03-25T13:58:49.099579", "lvl": "target", "msg": "WARNING: no log file found for shardfile-core at ./output/shardfile-core.log"}
- {"dt": "2025-03-25T13:58:49.113186", "lvl": "target", "msg": "<8>[   24.703549] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=shardfile-core RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.113431", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=shardfile-core RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.113506", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "shardfile-core", "result": "pass", "starttc": ! "993", "endtc": ! "993"}}
- {"dt": "2025-03-25T13:58:49.243853", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test_global_core_close_range at ./output/core_close_range_test_global_core_close_range.log"}
- {"dt": "2025-03-25T13:58:49.257924", "lvl": "target", "msg": "<8>[   24.848032] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test_global_core_close_range RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.258179", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test_global_core_close_range RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.258257", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test_global_core_close_range", "result": "pass", "starttc": ! "997", "endtc": ! "997"}}
- {"dt": "2025-03-25T13:58:49.269651", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test_global_close_range_unshare at ./output/core_close_range_test_global_close_range_unshare.log"}
- {"dt": "2025-03-25T13:58:49.284125", "lvl": "target", "msg": "<8>[   24.874209] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test_global_close_range_unshare RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.284376", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test_global_close_range_unshare RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.284455", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test_global_close_range_unshare", "result": "pass", "starttc": ! "1001", "endtc": ! "1001"}}
- {"dt": "2025-03-25T13:58:49.297084", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test_global_close_range_unshare_capped at ./output/core_close_range_test_global_close_range_unshare_capped.log"}
- {"dt": "2025-03-25T13:58:49.311413", "lvl": "target", "msg": "<8>[   24.901493] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test_global_close_range_unshare_capped RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.311661", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test_global_close_range_unshare_capped RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.311746", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test_global_close_range_unshare_capped", "result": "pass", "starttc": ! "1005", "endtc": ! "1005"}}
- {"dt": "2025-03-25T13:58:49.323629", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test_global_close_range_cloexec at ./output/core_close_range_test_global_close_range_cloexec.log"}
- {"dt": "2025-03-25T13:58:49.338134", "lvl": "target", "msg": "<8>[   24.928283] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test_global_close_range_cloexec RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.338385", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test_global_close_range_cloexec RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.338460", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test_global_close_range_cloexec", "result": "pass", "starttc": ! "1009", "endtc": ! "1009"}}
- {"dt": "2025-03-25T13:58:49.350168", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test_global_close_range_cloexec_unshare at ./output/core_close_range_test_global_close_range_cloexec_unshare.log"}
- {"dt": "2025-03-25T13:58:49.364190", "lvl": "target", "msg": "<8>[   24.954378] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test_global_close_range_cloexec_unshare RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.364509", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test_global_close_range_cloexec_unshare RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.364595", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test_global_close_range_cloexec_unshare", "result": "pass", "starttc": ! "1013", "endtc": ! "1013"}}
- {"dt": "2025-03-25T13:58:49.376670", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test_global_close_range_cloexec_syzbot at ./output/core_close_range_test_global_close_range_cloexec_syzbot.log"}
- {"dt": "2025-03-25T13:58:49.391393", "lvl": "target", "msg": "<8>[   24.981586] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test_global_close_range_cloexec_syzbot RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.391664", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test_global_close_range_cloexec_syzbot RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.391750", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test_global_close_range_cloexec_syzbot", "result": "pass", "starttc": ! "1017", "endtc": ! "1017"}}
- {"dt": "2025-03-25T13:58:49.403548", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test_global_close_range_cloexec_unshare_syzbot at ./output/core_close_range_test_global_close_range_cloexec_unshare_syzbot.log"}
- {"dt": "2025-03-25T13:58:49.417385", "lvl": "target", "msg": "<8>[   25.007475] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test_global_close_range_cloexec_unshare_syzbot RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.417653", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test_global_close_range_cloexec_unshare_syzbot RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.417734", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test_global_close_range_cloexec_unshare_syzbot", "result": "pass", "starttc": ! "1021", "endtc": ! "1021"}}
- {"dt": "2025-03-25T13:58:49.429154", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test_global_close_range_bitmap_corruption at ./output/core_close_range_test_global_close_range_bitmap_corruption.log"}
- {"dt": "2025-03-25T13:58:49.443594", "lvl": "target", "msg": "<8>[   25.033695] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test_global_close_range_bitmap_corruption RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.443852", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test_global_close_range_bitmap_corruption RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.443931", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test_global_close_range_bitmap_corruption", "result": "pass", "starttc": ! "1025", "endtc": ! "1025"}}
- {"dt": "2025-03-25T13:58:49.456183", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test_global_fcntl_created at ./output/core_close_range_test_global_fcntl_created.log"}
- {"dt": "2025-03-25T13:58:49.470790", "lvl": "target", "msg": "<8>[   25.060605] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test_global_fcntl_created RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.471058", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test_global_fcntl_created RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.471142", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test_global_fcntl_created", "result": "pass", "starttc": ! "1029", "endtc": ! "1029"}}
- {"dt": "2025-03-25T13:58:49.482097", "lvl": "target", "msg": "WARNING: no log file found for core_close_range_test at ./output/core_close_range_test.log"}
- {"dt": "2025-03-25T13:58:49.496010", "lvl": "target", "msg": "<8>[   25.086098] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_close_range_test RESULT=pass>"}
- {"dt": "2025-03-25T13:58:49.496277", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_close_range_test RESULT=pass"}
- {"dt": "2025-03-25T13:58:49.496361", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_close_range_test", "result": "pass", "starttc": ! "1033", "endtc": ! "1033"}}
- {"dt": "2025-03-25T13:58:49.507830", "lvl": "debug", "msg": "Received signal: <STARTTC> core_unshare_test_global_unshare_EMFILE"}
- {"dt": "2025-03-25T13:58:49.507956", "lvl": "target", "msg": "<LAVA_SIGNAL_STARTTC core_unshare_test_global_unshare_EMFILE>"}
- {"dt": "2025-03-25T13:58:49.512099", "lvl": "target", "msg": "FAILED: 0 / 1 tests passed."}
- {"dt": "2025-03-25T13:58:49.512187", "lvl": "target", "msg": "Totals: pass:0 fail:1 xfail:0 xpass:0 skip:0 error:0"}
- {"dt": "2025-03-25T13:58:49.513762", "lvl": "debug", "msg": "Received signal: <ENDTC> core_unshare_test_global_unshare_EMFILE"}
- {"dt": "2025-03-25T13:58:49.513865", "lvl": "target", "msg": "<LAVA_SIGNAL_ENDTC core_unshare_test_global_unshare_EMFILE>"}
- {"dt": "2025-03-25T13:58:49.527986", "lvl": "target", "msg": "<8>[   25.118056] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_unshare_test_global_unshare_EMFILE RESULT=fail>"}
- {"dt": "2025-03-25T13:58:49.528253", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_unshare_test_global_unshare_EMFILE RESULT=fail"}
- {"dt": "2025-03-25T13:58:49.528336", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_unshare_test_global_unshare_EMFILE", "result": "fail", "starttc": ! "1035", "endtc": ! "1039"}}
- {"dt": "2025-03-25T13:58:49.540307", "lvl": "target", "msg": "<LAVA_SIGNAL_STARTTC core_unshare_test>"}
- {"dt": "2025-03-25T13:58:49.540581", "lvl": "debug", "msg": "Received signal: <STARTTC> core_unshare_test"}
- {"dt": "2025-03-25T13:58:49.545435", "lvl": "target", "msg": "exit=1<LAVA_SIGNAL_ENDTC core_unshare_test>"}
- {"dt": "2025-03-25T13:58:49.545681", "lvl": "debug", "msg": "Received signal: <ENDTC> core_unshare_test"}
- {"dt": "2025-03-25T13:58:49.560256", "lvl": "target", "msg": "<8>[   25.150543] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=core_unshare_test RESULT=fail>"}
- {"dt": "2025-03-25T13:58:49.560503", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=core_unshare_test RESULT=fail"}
- {"dt": "2025-03-25T13:58:49.560587", "lvl": "results", "msg": {"definition": "0_kselftest-core", "case": "core_unshare_test", "result": "fail", "starttc": ! "1045", "endtc": ! "1047"}}
- {"dt": "2025-03-25T13:58:49.562703", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2025-03-25T13:58:49.563863", "lvl": "target", "msg": "<8>[   25.153651] <LAVA_SIGNAL_ENDRUN 0_kselftest-core 1_1.1.3.1>"}
- {"dt": "2025-03-25T13:58:49.564096", "lvl": "debug", "msg": "Received signal: <ENDRUN> 0_kselftest-core 1_1.1.3.1"}
- {"dt": "2025-03-25T13:58:49.564170", "lvl": "info", "msg": "Ending use of test pattern."}
- {"dt": "2025-03-25T13:58:49.564217", "lvl": "info", "msg": "Ending test lava.0_kselftest-core (1_1.1.3.1), duration 11.51"}
- {"dt": "2025-03-25T13:58:49.564277", "lvl": "results", "msg": {"definition": "lava", "case": "0_kselftest-core", "uuid": "1_1.1.3.1", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "path": "automated/linux/kselftest/kselftest.yaml", "duration": "11.51", "result": "pass", "revision": "unspecified", "namespace": "common", "commit_id": "e61633ff1a396344dd4e98f24b8873ed7b9d6182"}}
- {"dt": "2025-03-25T13:58:49.565779", "lvl": "target", "msg": "<LAVA_TEST_RUNNER EXIT>"}
- {"dt": "2025-03-25T13:58:49.566015", "lvl": "info", "msg": "ok: lava_test_shell seems to have completed"}
- {"dt": "2025-03-25T13:58:49.566351", "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-core: pass\ncore_close_range_test_global_core_close_range: pass\ncore_close_range_test_global_close_range_unshare: pass\ncore_close_range_test_global_close_range_unshare_capped: pass\ncore_close_range_test_global_close_range_cloexec: pass\ncore_close_range_test_global_close_range_cloexec_unshare: pass\ncore_close_range_test_global_close_range_cloexec_syzbot: pass\ncore_close_range_test_global_close_range_cloexec_unshare_syzbot: pass\ncore_close_range_test_global_close_range_bitmap_corruption: pass\ncore_close_range_test_global_fcntl_created: pass\ncore_close_range_test: pass\ncore_unshare_test_global_unshare_EMFILE: fail\ncore_unshare_test: fail\n"}
- {"dt": "2025-03-25T13:58:49.566510", "lvl": "debug", "msg": "end: 3.1 lava-test-shell (duration 00:00:12) [common]"}
- {"dt": "2025-03-25T13:58:49.566593", "lvl": "info", "msg": "end: 3 lava-test-retry (duration 00:00:12) [common]"}
- {"dt": "2025-03-25T13:58:49.566664", "lvl": "info", "msg": "start: 4 finalize (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T13:58:49.566732", "lvl": "debug", "msg": "start: 4.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2025-03-25T13:58:49.566795", "lvl": "debug", "msg": "end: 4.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T13:58:49.566852", "lvl": "debug", "msg": "start: 4.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T13:58:49.566964", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T13:58:49.568492", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T13:58:49.568759", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T13:58:49.569017", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T13:58:50.568017", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2025-03-25T13:58:50.568189", "lvl": "debug", "msg": "Sending line: 'poweroff'"}
- {"dt": "2025-03-25T13:58:50.668456", "lvl": "input", "msg": "poweroff"}
- {"dt": "2025-03-25T13:58:50.668814", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2025-03-25T13:58:50.668910", "lvl": "target", "msg": "[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# poweroff"}
- {"dt": "2025-03-25T13:58:50.769183", "lvl": "debug", "msg": "end: 4.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2025-03-25T13:58:50.769319", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2025-03-25T13:58:50.769401", "lvl": "info", "msg": "end: 4 finalize (duration 00:00:01) [common]"}
- {"dt": "2025-03-25T13:58:50.769499", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2025-03-25T13:58:50.769618", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/kernel/Image"}
- {"dt": "2025-03-25T13:58:50.775217", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4"}
- {"dt": "2025-03-25T13:58:50.881178", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/rootfs.kselftest/kselftest.tar"}
- {"dt": "2025-03-25T13:58:50.895095", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1/deployimages-b431l7pi/rootfs.modules/modules.tar"}
- {"dt": "2025-03-25T13:58:50.905488", "lvl": "info", "msg": "Removing root tmp directory at /var/lib/lava/dispatcher/tmp/tuxrun-5oznpv4t-1"}
- {"dt": "2025-03-25T13:58:50.947504", "lvl": "info", "msg": "Job finished correctly"}
- {"dt": "2025-03-25T13:58:50.947605", "lvl": "results", "msg": {"definition": "lava", "case": "job", "result": "pass"}}
