- {"dt": "2025-03-25T10:24:47.922919", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2024.09.dev0173"}
- {"dt": "2025-03-25T10:24:47.923009", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2025-03-25T10:24:47.923090", "lvl": "info", "msg": "Start time: 2025-03-25 10:24:47.923083+00:00 (UTC)"}
- {"dt": "2025-03-25T10:24:47.923894", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/Image.gz exists"}
- {"dt": "2025-03-25T10:24:48.289004", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2025-03-25T10:24:48.880275", "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-25T10:24:48.880499", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/kselftest.tar.xz exists"}
- {"dt": "2025-03-25T10:24:49.012471", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2025-03-25T10:24:49.576091", "lvl": "debug", "msg": "Validating that https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/modules.tar.xz exists"}
- {"dt": "2025-03-25T10:24:49.711314", "lvl": "debug", "msg": "Using GET because HEAD is not supported properly"}
- {"dt": "2025-03-25T10:24:50.310531", "lvl": "info", "msg": "qemu-system-arm, installed at version: 1:9.2.1+ds-1, host architecture: amd64"}
- {"dt": "2025-03-25T10:24:50.310764", "lvl": "warning", "msg": "Missing image arg for rootfs.kselftest"}
- {"dt": "2025-03-25T10:24:50.310854", "lvl": "warning", "msg": "Missing image arg for rootfs.modules"}
- {"dt": "2025-03-25T10:24:50.311003", "lvl": "info", "msg": "validate duration: 2.39"}
- {"dt": "2025-03-25T10:24:50.311072", "lvl": "results", "msg": {"definition": "lava", "case": "validate", "result": "pass"}}
- {"dt": "2025-03-25T10:24:50.311197", "lvl": "info", "msg": "start: 1 deployimages (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T10:24:50.311282", "lvl": "debug", "msg": "start: 1.1 lava-overlay (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T10:24:50.311519", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml"}
- {"dt": "2025-03-25T10:24:50.311717", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin"}
- {"dt": "2025-03-25T10:24:50.311842", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/tests"}
- {"dt": "2025-03-25T10:24:50.311933", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/results"}
- {"dt": "2025-03-25T10:24:50.312007", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-add-keys"}
- {"dt": "2025-03-25T10:24:50.312132", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-add-sources"}
- {"dt": "2025-03-25T10:24:50.312251", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-background-process-start"}
- {"dt": "2025-03-25T10:24:50.312365", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-background-process-stop"}
- {"dt": "2025-03-25T10:24:50.312483", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-common-functions"}
- {"dt": "2025-03-25T10:24:50.312595", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-echo-ipv4"}
- {"dt": "2025-03-25T10:24:50.312706", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-install-packages"}
- {"dt": "2025-03-25T10:24:50.312818", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-installed-packages"}
- {"dt": "2025-03-25T10:24:50.312929", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-os-build"}
- {"dt": "2025-03-25T10:24:50.313041", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-probe-channel"}
- {"dt": "2025-03-25T10:24:50.313150", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-probe-ip"}
- {"dt": "2025-03-25T10:24:50.313262", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-target-ip"}
- {"dt": "2025-03-25T10:24:50.313374", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-target-mac"}
- {"dt": "2025-03-25T10:24:50.313486", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-target-storage"}
- {"dt": "2025-03-25T10:24:50.313600", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-test-case"}
- {"dt": "2025-03-25T10:24:50.313715", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-test-event"}
- {"dt": "2025-03-25T10:24:50.313839", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-test-feedback"}
- {"dt": "2025-03-25T10:24:50.313951", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-test-raise"}
- {"dt": "2025-03-25T10:24:50.314064", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-test-reference"}
- {"dt": "2025-03-25T10:24:50.314182", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-test-runner"}
- {"dt": "2025-03-25T10:24:50.314296", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-test-set"}
- {"dt": "2025-03-25T10:24:50.314408", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-test-shell"}
- {"dt": "2025-03-25T10:24:50.314523", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-install-packages (oe)"}
- {"dt": "2025-03-25T10:24:50.314682", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/bin/lava-installed-packages (oe)"}
- {"dt": "2025-03-25T10:24:50.314794", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/environment"}
- {"dt": "2025-03-25T10:24:50.314877", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2025-03-25T10:24:50.314928", "lvl": "debug", "msg": "- LAVA_JOB_ID=1"}
- {"dt": "2025-03-25T10:24:50.314971", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.32.138"}
- {"dt": "2025-03-25T10:24:50.315043", "lvl": "debug", "msg": "start: 1.1.1 lava-vland-overlay (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T10:24:50.315088", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2025-03-25T10:24:50.315139", "lvl": "debug", "msg": "end: 1.1.1 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:24:50.315194", "lvl": "debug", "msg": "start: 1.1.2 lava-multinode-overlay (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T10:24:50.315233", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2025-03-25T10:24:50.315280", "lvl": "debug", "msg": "end: 1.1.2 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:24:50.315330", "lvl": "debug", "msg": "start: 1.1.3 test-definition (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T10:24:50.315377", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2025-03-25T10:24:50.315435", "lvl": "debug", "msg": "start: 1.1.3.1 git-repo-action (timeout 00:15:00) [common]"}
- {"dt": "2025-03-25T10:24:50.315479", "lvl": "debug", "msg": "Using /lava-1 at stage 0"}
- {"dt": "2025-03-25T10:24:50.315546", "lvl": "info", "msg": "Fetching tests from https://github.com/TheodoreRTG/test-definitions.git"}
- {"dt": "2025-03-25T10:24:50.315603", "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-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/0/tests/0_kselftest-clone3'"}
- {"dt": "2025-03-25T10:24:53.305179", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/0/tests/0_kselftest-clone3/automated/linux/kselftest/kselftest.yaml"}
- {"dt": "2025-03-25T10:24:53.305651", "lvl": "debug", "msg": "uuid=1_1.1.3.1 testdef=None"}
- {"dt": "2025-03-25T10:24:53.305777", "lvl": "debug", "msg": "end: 1.1.3.1 git-repo-action (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T10:24:53.305896", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "git-repo-action", "level": "1.1.3.1", "duration": "2.99", "result": "pass", "extra": {"commit": "450111580e70664ab07b21744eff0a1147707c44", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "path": "automated/linux/kselftest/kselftest.yaml"}}}
- {"dt": "2025-03-25T10:24:53.306065", "lvl": "debug", "msg": "start: 1.1.3.2 test-overlay (timeout 00:14:57) [common]"}
- {"dt": "2025-03-25T10:24:53.306763", "lvl": "debug", "msg": "end: 1.1.3.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:24:53.306814", "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-clone3", "path": "automated/linux/kselftest/kselftest.yaml", "from": "git", "repository": "https://github.com/TheodoreRTG/test-definitions.git"}}}
- {"dt": "2025-03-25T10:24:53.306926", "lvl": "debug", "msg": "start: 1.1.3.3 test-install-overlay (timeout 00:14:57) [common]"}
- {"dt": "2025-03-25T10:24:53.307710", "lvl": "debug", "msg": "end: 1.1.3.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:24:53.307762", "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-clone3", "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-25T10:24:53.307868", "lvl": "debug", "msg": "start: 1.1.3.4 test-runscript-overlay (timeout 00:14:57) [common]"}
- {"dt": "2025-03-25T10:24:53.316194", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/0/tests/0_kselftest-clone3 test_uuid 1_1.1.3.1"}
- {"dt": "2025-03-25T10:24:53.316276", "lvl": "debug", "msg": "TST_CMDFILES='clone3'"}
- {"dt": "2025-03-25T10:24:53.316334", "lvl": "debug", "msg": "KSELFTEST_PATH='/opt/kselftests/default-in-kernel'"}
- {"dt": "2025-03-25T10:24:53.316384", "lvl": "debug", "msg": "SKIPFILE='skipfile-lkft.yaml'"}
- {"dt": "2025-03-25T10:24:53.316474", "lvl": "debug", "msg": "ENVIRONMENT='production'"}
- {"dt": "2025-03-25T10:24:53.316621", "lvl": "debug", "msg": "SHARD_NUMBER='1'"}
- {"dt": "2025-03-25T10:24:53.316695", "lvl": "debug", "msg": "SHARD_INDEX='1'"}
- {"dt": "2025-03-25T10:24:53.316816", "lvl": "debug", "msg": "end: 1.1.3.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:24:53.316868", "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-clone3", "path": "automated/linux/kselftest/kselftest.yaml", "from": "git", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "filename": "/var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/0/tests/0_kselftest-clone3/run.sh"}}}
- {"dt": "2025-03-25T10:24:53.316957", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2025-03-25T10:24:53.316998", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/lava-overlay-jgb6crml/lava-1/0 for stage 0"}
- {"dt": "2025-03-25T10:24:53.317070", "lvl": "debug", "msg": "- 0_kselftest-clone3"}
- {"dt": "2025-03-25T10:24:53.317180", "lvl": "debug", "msg": "end: 1.1.3 test-definition (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T10:24:53.317255", "lvl": "debug", "msg": "start: 1.1.4 compress-overlay (timeout 00:14:57) [common]"}
- {"dt": "2025-03-25T10:24:59.134635", "lvl": "debug", "msg": "end: 1.1.4 compress-overlay (duration 00:00:06) [common]"}
- {"dt": "2025-03-25T10:24:59.134795", "lvl": "debug", "msg": "end: 1.1 lava-overlay (duration 00:00:09) [common]"}
- {"dt": "2025-03-25T10:24:59.134863", "lvl": "debug", "msg": "start: 1.2 apply-overlay-guest (timeout 00:14:51) [common]"}
- {"dt": "2025-03-25T10:24:59.134920", "lvl": "debug", "msg": "Overlay already applied"}
- {"dt": "2025-03-25T10:24:59.134971", "lvl": "debug", "msg": "end: 1.2 apply-overlay-guest (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:24:59.135023", "lvl": "debug", "msg": "start: 1.3 deploy-device-env (timeout 00:14:51) [common]"}
- {"dt": "2025-03-25T10:24:59.135075", "lvl": "debug", "msg": "end: 1.3 deploy-device-env (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:24:59.135126", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:14:51) [common]"}
- {"dt": "2025-03-25T10:24:59.135179", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T10:24:59.135379", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/Image.gz"}
- {"dt": "2025-03-25T10:24:59.135434", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/kernel/Image"}
- {"dt": "2025-03-25T10:24:59.135476", "lvl": "debug", "msg": "total size: 14569912 (13\u202FMB)"}
- {"dt": "2025-03-25T10:24:59.135517", "lvl": "info", "msg": "Using gunzip to decompress gz"}
- {"dt": "2025-03-25T10:24:59.800545", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T10:25:00.167381", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T10:25:00.269790", "lvl": "debug", "msg": "progress  11\u202F% (1\u202FMB)"}
- {"dt": "2025-03-25T10:25:00.371521", "lvl": "debug", "msg": "progress  18\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T10:25:00.622171", "lvl": "debug", "msg": "progress  24\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T10:25:00.724256", "lvl": "debug", "msg": "progress  40\u202F% (5\u202FMB)"}
- {"dt": "2025-03-25T10:25:00.824445", "lvl": "debug", "msg": "progress  51\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T10:25:01.112702", "lvl": "debug", "msg": "progress  58\u202F% (8\u202FMB)"}
- {"dt": "2025-03-25T10:25:01.215181", "lvl": "debug", "msg": "progress  81\u202F% (11\u202FMB)"}
- {"dt": "2025-03-25T10:25:01.316656", "lvl": "debug", "msg": "progress  89\u202F% (12\u202FMB)"}
- {"dt": "2025-03-25T10:25:01.418080", "lvl": "debug", "msg": "progress  96\u202F% (13\u202FMB)"}
- {"dt": "2025-03-25T10:25:01.461458", "lvl": "info", "msg": "13\u202FMB downloaded in 2.33\u202Fs (5.97\u202FMB/s)"}
- {"dt": "2025-03-25T10:25:01.461620", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T10:25:01.461699", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.4.1", "duration": "2.33", "result": "pass", "extra": {"label": "kernel", "size": ! "14569912", "sha256sum": "9f49bfcc793ea5bd9c25dd5d8f9bde6fc589925ccb5bc96b4191d327c0e34c8a"}}}
- {"dt": "2025-03-25T10:25:01.461861", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T10:25:01.461945", "lvl": "debug", "msg": "start: 1.5 download-retry (timeout 00:14:49) [common]"}
- {"dt": "2025-03-25T10:25:01.462021", "lvl": "debug", "msg": "start: 1.5.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T10:25:01.462237", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4.xz"}
- {"dt": "2025-03-25T10:25:01.462311", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4"}
- {"dt": "2025-03-25T10:25:01.462368", "lvl": "debug", "msg": "total size: 111407012 (106\u202FMB)"}
- {"dt": "2025-03-25T10:25:01.462424", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-03-25T10:25:01.563046", "lvl": "debug", "msg": "progress   2\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T10:25:01.724827", "lvl": "debug", "msg": "progress   7\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T10:25:01.894044", "lvl": "debug", "msg": "progress  12\u202F% (12\u202FMB)"}
- {"dt": "2025-03-25T10:25:02.053486", "lvl": "debug", "msg": "progress  17\u202F% (18\u202FMB)"}
- {"dt": "2025-03-25T10:25:02.212800", "lvl": "debug", "msg": "progress  22\u202F% (23\u202FMB)"}
- {"dt": "2025-03-25T10:25:02.385397", "lvl": "debug", "msg": "progress  27\u202F% (28\u202FMB)"}
- {"dt": "2025-03-25T10:25:02.518728", "lvl": "debug", "msg": "progress  32\u202F% (34\u202FMB)"}
- {"dt": "2025-03-25T10:25:02.674139", "lvl": "debug", "msg": "progress  37\u202F% (39\u202FMB)"}
- {"dt": "2025-03-25T10:25:02.841240", "lvl": "debug", "msg": "progress  42\u202F% (44\u202FMB)"}
- {"dt": "2025-03-25T10:25:03.004211", "lvl": "debug", "msg": "progress  47\u202F% (49\u202FMB)"}
- {"dt": "2025-03-25T10:25:03.170422", "lvl": "debug", "msg": "progress  52\u202F% (55\u202FMB)"}
- {"dt": "2025-03-25T10:25:03.338975", "lvl": "debug", "msg": "progress  57\u202F% (60\u202FMB)"}
- {"dt": "2025-03-25T10:25:03.523450", "lvl": "debug", "msg": "progress  62\u202F% (65\u202FMB)"}
- {"dt": "2025-03-25T10:25:03.686193", "lvl": "debug", "msg": "progress  67\u202F% (71\u202FMB)"}
- {"dt": "2025-03-25T10:25:03.833554", "lvl": "debug", "msg": "progress  72\u202F% (76\u202FMB)"}
- {"dt": "2025-03-25T10:25:03.995663", "lvl": "debug", "msg": "progress  77\u202F% (81\u202FMB)"}
- {"dt": "2025-03-25T10:25:04.159387", "lvl": "debug", "msg": "progress  82\u202F% (87\u202FMB)"}
- {"dt": "2025-03-25T10:25:04.323441", "lvl": "debug", "msg": "progress  87\u202F% (92\u202FMB)"}
- {"dt": "2025-03-25T10:25:04.424000", "lvl": "debug", "msg": "progress  92\u202F% (97\u202FMB)"}
- {"dt": "2025-03-25T10:25:04.543095", "lvl": "debug", "msg": "progress  97\u202F% (103\u202FMB)"}
- {"dt": "2025-03-25T10:25:07.809730", "lvl": "info", "msg": "106\u202FMB downloaded in 6.35\u202Fs (16.74\u202FMB/s)"}
- {"dt": "2025-03-25T10:25:07.810004", "lvl": "debug", "msg": "end: 1.5.1 file-download (duration 00:00:06) [common]"}
- {"dt": "2025-03-25T10:25:07.810120", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.5.1", "duration": "6.35", "result": "pass", "extra": {"label": "rootfs", "size": ! "111407012", "sha256sum": "71bcc7bc8dbd4ac7d02d52aed8886662999d6e6c790f9b9e5220beaf580ccfc1"}}}
- {"dt": "2025-03-25T10:25:07.810396", "lvl": "debug", "msg": "start: 1.5.2 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T10:25:07.810525", "lvl": "debug", "msg": "start: 1.5.2.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-03-25T10:25:07.810767", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/kselftest.tar.xz"}
- {"dt": "2025-03-25T10:25:07.810850", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/rootfs.kselftest/kselftest.tar"}
- {"dt": "2025-03-25T10:25:07.810916", "lvl": "debug", "msg": "total size: 8023924 (7\u202FMB)"}
- {"dt": "2025-03-25T10:25:07.810969", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-03-25T10:25:08.555728", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T10:25:08.914884", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T10:25:09.017237", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T10:25:09.119801", "lvl": "debug", "msg": "progress  17\u202F% (1\u202FMB)"}
- {"dt": "2025-03-25T10:25:09.231631", "lvl": "debug", "msg": "progress  26\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T10:25:09.343524", "lvl": "debug", "msg": "progress  31\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T10:25:09.445085", "lvl": "debug", "msg": "progress  45\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T10:25:09.545203", "lvl": "debug", "msg": "progress  53\u202F% (4\u202FMB)"}
- {"dt": "2025-03-25T10:25:09.647386", "lvl": "debug", "msg": "progress  62\u202F% (4\u202FMB)"}
- {"dt": "2025-03-25T10:25:09.948510", "lvl": "debug", "msg": "progress  73\u202F% (5\u202FMB)"}
- {"dt": "2025-03-25T10:25:10.017027", "lvl": "info", "msg": "7\u202FMB downloaded in 2.21\u202Fs (3.47\u202FMB/s)"}
- {"dt": "2025-03-25T10:25:10.017277", "lvl": "debug", "msg": "end: 1.5.2.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T10:25:10.017371", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.5.2.1", "duration": "2.21", "result": "pass", "extra": {"label": "rootfs.kselftest", "size": ! "8023924", "sha256sum": "fdb75542f4323788281ca32df629e3017778f9558f5d778749209d759868253b"}}}
- {"dt": "2025-03-25T10:25:10.017539", "lvl": "debug", "msg": "end: 1.5.2 download-retry (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T10:25:10.017645", "lvl": "debug", "msg": "start: 1.5.3 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T10:25:10.017746", "lvl": "debug", "msg": "start: 1.5.3.1 http-download (timeout 00:01:40) [common]"}
- {"dt": "2025-03-25T10:25:10.018013", "lvl": "info", "msg": "downloading https://storage.tuxsuite.com/public/linaro/lkft/builds/2ulLQi70YHUMCevAw4vDWFVQfHN/modules.tar.xz"}
- {"dt": "2025-03-25T10:25:10.018094", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/rootfs.modules/modules.tar"}
- {"dt": "2025-03-25T10:25:10.018164", "lvl": "debug", "msg": "total size: 11798000 (11\u202FMB)"}
- {"dt": "2025-03-25T10:25:10.018234", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2025-03-25T10:25:10.369493", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T10:25:10.469679", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2025-03-25T10:25:10.703573", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2025-03-25T10:25:10.805886", "lvl": "debug", "msg": "progress  23\u202F% (2\u202FMB)"}
- {"dt": "2025-03-25T10:25:10.912285", "lvl": "debug", "msg": "progress  28\u202F% (3\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.013506", "lvl": "debug", "msg": "progress  36\u202F% (4\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.137337", "lvl": "debug", "msg": "progress  41\u202F% (4\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.238716", "lvl": "debug", "msg": "progress  48\u202F% (5\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.338979", "lvl": "debug", "msg": "progress  54\u202F% (6\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.442695", "lvl": "debug", "msg": "progress  59\u202F% (6\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.543633", "lvl": "debug", "msg": "progress  66\u202F% (7\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.671198", "lvl": "debug", "msg": "progress  71\u202F% (8\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.775045", "lvl": "debug", "msg": "progress  78\u202F% (8\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.876528", "lvl": "debug", "msg": "progress  83\u202F% (9\u202FMB)"}
- {"dt": "2025-03-25T10:25:11.979268", "lvl": "debug", "msg": "progress  90\u202F% (10\u202FMB)"}
- {"dt": "2025-03-25T10:25:12.080433", "lvl": "debug", "msg": "progress  98\u202F% (11\u202FMB)"}
- {"dt": "2025-03-25T10:25:12.136218", "lvl": "info", "msg": "11\u202FMB downloaded in 2.12\u202Fs (5.31\u202FMB/s)"}
- {"dt": "2025-03-25T10:25:12.136471", "lvl": "debug", "msg": "end: 1.5.3.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T10:25:12.136562", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "http-download", "level": "1.5.3.1", "duration": "2.12", "result": "pass", "extra": {"label": "rootfs.modules", "size": ! "11798000", "sha256sum": "5b6c182841b9377518b1324e207cfbc57ed8d4eefa14147b0bf6dd6d83c68de5"}}}
- {"dt": "2025-03-25T10:25:12.136726", "lvl": "debug", "msg": "end: 1.5.3 download-retry (duration 00:00:02) [common]"}
- {"dt": "2025-03-25T10:25:12.136825", "lvl": "debug", "msg": "start: 1.5.4 append-overlays (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T10:25:12.136903", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4'"}
- {"dt": "2025-03-25T10:25:13.761415", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2025-03-25T10:25:13.762338", "lvl": "debug", "msg": "- rootfs.lava: '/var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/compress-overlay-r1e807bl/overlay-1.1.4.tar.gz' to '/'"}
- {"dt": "2025-03-25T10:25:14.252451", "lvl": "debug", "msg": "- rootfs.kselftest: '/var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/rootfs.kselftest/kselftest.tar' to '/opt/kselftests/default-in-kernel/'"}
- {"dt": "2025-03-25T10:25:14.552190", "lvl": "debug", "msg": "- rootfs.modules: '/var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/rootfs.modules/modules.tar' to '/usr/'"}
- {"dt": "2025-03-25T10:25:14.972258", "lvl": "debug", "msg": "end: 1.5.4 append-overlays (duration 00:00:03) [common]"}
- {"dt": "2025-03-25T10:25:14.972632", "lvl": "debug", "msg": "end: 1.5 download-retry (duration 00:00:14) [common]"}
- {"dt": "2025-03-25T10:25:14.972747", "lvl": "info", "msg": "end: 1 deployimages (duration 00:00:25) [common]"}
- {"dt": "2025-03-25T10:25:14.972859", "lvl": "info", "msg": "start: 2 boot-image-retry (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T10:25:14.972946", "lvl": "debug", "msg": "start: 2.1 boot-qemu-image (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T10:25:14.973024", "lvl": "debug", "msg": "start: 2.1.1 execute-qemu (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T10:25:14.973369", "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-k4h5gx09-1/deployimages-6jgp3s3m/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-k4h5gx09-1/deployimages-6jgp3s3m/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4,format=raw,id=hd0,if=virtio"}
- {"dt": "2025-03-25T10:25:14.977506", "lvl": "debug", "msg": "started a shell command"}
- {"dt": "2025-03-25T10:25:14.977868", "lvl": "debug", "msg": "end: 2.1.1 execute-qemu (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:25:14.977940", "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-25T10:25:14.978079", "lvl": "debug", "msg": "end: 2.1 boot-qemu-image (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:25:14.978164", "lvl": "debug", "msg": "start: 2.2 auto-login-action (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T10:25:14.978245", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2025-03-25T10:25:14.978304", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:30:00)"}
- {"dt": "2025-03-25T10:25:15.087024", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x000f0510]"}
- {"dt": "2025-03-25T10:25:15.087461", "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-25T10:25:15.087549", "lvl": "target", "msg": "[    0.000000] KASLR enabled"}
- {"dt": "2025-03-25T10:25:15.087624", "lvl": "target", "msg": "[    0.000000] random: crng init done"}
- {"dt": "2025-03-25T10:25:15.087704", "lvl": "target", "msg": "[    0.000000] Machine model: linux,dummy-virt"}
- {"dt": "2025-03-25T10:25:15.087793", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2025-03-25T10:25:15.087972", "lvl": "target", "msg": "[    0.000000] earlycon: pl11 at MMIO 0x0000000009000000 (options '')"}
- {"dt": "2025-03-25T10:25:15.088106", "lvl": "target", "msg": "[    0.000000] printk: legacy bootconsole [pl11] enabled"}
- {"dt": "2025-03-25T10:25:15.088357", "lvl": "debug", "msg": "start: 2.2.1 login-action (timeout 00:30:00) [common]"}
- {"dt": "2025-03-25T10:25:15.088422", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2025-03-25T10:25:15.088479", "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-25T10:25:15.088531", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2025-03-25T10:25:15.088578", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2025-03-25T10:25:15.088618", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2025-03-25T10:25:15.088653", "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-25T10:25:15.088733", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:30:00)"}
- {"dt": "2025-03-25T10:25:15.088776", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:15:00)"}
- {"dt": "2025-03-25T10:25:15.089130", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: Reserved memory: No reserved-memory node in the DT"}
- {"dt": "2025-03-25T10:25:15.092098", "lvl": "target", "msg": "[    0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T10:25:15.092830", "lvl": "target", "msg": "[    0.000000] NODE_DATA(0) allocated [mem 0x13f7f9000-0x13f7fb77f]"}
- {"dt": "2025-03-25T10:25:15.095069", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2025-03-25T10:25:15.095459", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000040000000-0x00000000ffffffff]"}
- {"dt": "2025-03-25T10:25:15.095558", "lvl": "target", "msg": "[    0.000000]   DMA32    empty"}
- {"dt": "2025-03-25T10:25:15.095744", "lvl": "target", "msg": "[    0.000000]   Normal   [mem 0x0000000100000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T10:25:15.095846", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2025-03-25T10:25:15.095952", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2025-03-25T10:25:15.096152", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T10:25:15.096550", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000013fffffff]"}
- {"dt": "2025-03-25T10:25:15.121983", "lvl": "target", "msg": "[    0.000000] cma: Reserved 32 MiB at 0x0000000000000000"}
- {"dt": "2025-03-25T10:25:15.123019", "lvl": "target", "msg": "[    0.000000] psci: probing for conduit method from DT."}
- {"dt": "2025-03-25T10:25:15.123257", "lvl": "target", "msg": "[    0.000000] psci: PSCIv1.1 detected in firmware."}
- {"dt": "2025-03-25T10:25:15.123346", "lvl": "target", "msg": "[    0.000000] psci: Using standard PSCI v0.2 function IDs"}
- {"dt": "2025-03-25T10:25:15.123585", "lvl": "target", "msg": "[    0.000000] psci: Trusted OS migration not required"}
- {"dt": "2025-03-25T10:25:15.123694", "lvl": "target", "msg": "[    0.000000] psci: SMC Calling Convention v1.0"}
- {"dt": "2025-03-25T10:25:15.125829", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 25 pages/cpu s62808 r8192 d31400 u102400"}
- {"dt": "2025-03-25T10:25:15.126407", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: s62808 r8192 d31400 u102400 alloc=25*4096"}
- {"dt": "2025-03-25T10:25:15.126571", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: [0] 0 [0] 1 "}
- {"dt": "2025-03-25T10:25:15.127706", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2025-03-25T10:25:15.129048", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Address authentication (IMP DEF algorithm)"}
- {"dt": "2025-03-25T10:25:15.129316", "lvl": "target", "msg": "[    0.000000] CPU features: detected: GIC system register CPU interface"}
- {"dt": "2025-03-25T10:25:15.129439", "lvl": "target", "msg": "[    0.000000] CPU features: detected: HCRX_EL2 register"}
- {"dt": "2025-03-25T10:25:15.129647", "lvl": "target", "msg": "[    0.000000] CPU features: detected: 52-bit Virtual Addressing (LPA2)"}
- {"dt": "2025-03-25T10:25:15.129826", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Virtualization Host Extensions"}
- {"dt": "2025-03-25T10:25:15.130072", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Memory Tagging Extension"}
- {"dt": "2025-03-25T10:25:15.130223", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Asymmetric MTE Tag Check Fault"}
- {"dt": "2025-03-25T10:25:15.130516", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v4"}
- {"dt": "2025-03-25T10:25:15.133573", "lvl": "target", "msg": "[    0.000000] alternatives: applying boot alternatives"}
- {"dt": "2025-03-25T10:25:15.135951", "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-25T10:25:15.137936", "lvl": "target", "msg": "<5>[    0.000000] Unknown kernel command line parameters \"verbose\", will be passed to user space."}
- {"dt": "2025-03-25T10:25:15.139834", "lvl": "target", "msg": "<6>[    0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes"}
- {"dt": "2025-03-25T10:25:15.141965", "lvl": "target", "msg": "<6>[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.143135", "lvl": "target", "msg": "<6>[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.143432", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: area num 2."}
- {"dt": "2025-03-25T10:25:15.193509", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: mapped [mem 0x00000000fa000000-0x00000000fe000000] (64MB)"}
- {"dt": "2025-03-25T10:25:15.194818", "lvl": "target", "msg": "<6>[    0.000000] Fallback order for Node 0: 0 "}
- {"dt": "2025-03-25T10:25:15.194921", "lvl": "target", "msg": "<6>[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1048576"}
- {"dt": "2025-03-25T10:25:15.195026", "lvl": "target", "msg": "<6>[    0.000000] Policy zone: Normal"}
- {"dt": "2025-03-25T10:25:15.195572", "lvl": "target", "msg": "<6>[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off"}
- {"dt": "2025-03-25T10:25:15.214780", "lvl": "target", "msg": "<6>[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1"}
- {"dt": "2025-03-25T10:25:15.221740", "lvl": "target", "msg": "<6>[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2025-03-25T10:25:15.221849", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2025-03-25T10:25:15.221951", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=2."}
- {"dt": "2025-03-25T10:25:15.222267", "lvl": "target", "msg": "<6>[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2025-03-25T10:25:15.222347", "lvl": "target", "msg": "<6>[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2025-03-25T10:25:15.222643", "lvl": "target", "msg": "<6>[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2025-03-25T10:25:15.222810", "lvl": "target", "msg": "<6>[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2"}
- {"dt": "2025-03-25T10:25:15.224018", "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-25T10:25:15.224306", "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-25T10:25:15.224839", "lvl": "target", "msg": "<6>[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2025-03-25T10:25:15.230140", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GIC: Using split EOI/Deactivate mode"}
- {"dt": "2025-03-25T10:25:15.230454", "lvl": "target", "msg": "<6>[    0.000000] GICv3: 256 SPIs implemented"}
- {"dt": "2025-03-25T10:25:15.230517", "lvl": "target", "msg": "<6>[    0.000000] GICv3: 0 Extended SPIs implemented"}
- {"dt": "2025-03-25T10:25:15.231919", "lvl": "target", "msg": "<6>[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2025-03-25T10:25:15.232102", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GICv3 features: 16 PPIs"}
- {"dt": "2025-03-25T10:25:15.232409", "lvl": "target", "msg": "<6>[    0.000000] GICv3: GICD_CTRL.DS=1, SCR_EL3.FIQ=0"}
- {"dt": "2025-03-25T10:25:15.232821", "lvl": "target", "msg": "<6>[    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000"}
- {"dt": "2025-03-25T10:25:15.237483", "lvl": "target", "msg": "<6>[    0.000000] ITS [mem 0x08080000-0x0809ffff]"}
- {"dt": "2025-03-25T10:25:15.238314", "lvl": "target", "msg": "<6>[    0.000000] ITS@0x0000000008080000: allocated 8192 Devices @100050000 (indirect, esz 8, psz 64K, shr 1)"}
- {"dt": "2025-03-25T10:25:15.238654", "lvl": "target", "msg": "<6>[    0.000000] ITS@0x0000000008080000: allocated 8192 Interrupt Collections @100060000 (flat, esz 8, psz 64K, shr 1)"}
- {"dt": "2025-03-25T10:25:15.239336", "lvl": "target", "msg": "<6>[    0.000000] GICv3: using LPI property table @0x0000000100070000"}
- {"dt": "2025-03-25T10:25:15.240048", "lvl": "target", "msg": "<6>[    0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000100080000"}
- {"dt": "2025-03-25T10:25:15.242138", "lvl": "target", "msg": "<6>[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention."}
- {"dt": "2025-03-25T10:25:15.248212", "lvl": "target", "msg": "<6>[    0.000000] arch_timer: cp15 timer(s) running at 1000.00MHz (phys)."}
- {"dt": "2025-03-25T10:25:15.248626", "lvl": "target", "msg": "<6>[    0.000000] clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns"}
- {"dt": "2025-03-25T10:25:15.249149", "lvl": "target", "msg": "<6>[    0.000056] sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns"}
- {"dt": "2025-03-25T10:25:15.263691", "lvl": "target", "msg": "<6>[    0.012900] Console: colour dummy device 80x25"}
- {"dt": "2025-03-25T10:25:15.267194", "lvl": "target", "msg": "<6>[    0.017680] Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=4000000)"}
- {"dt": "2025-03-25T10:25:15.267575", "lvl": "target", "msg": "<6>[    0.018623] pid_max: default: 32768 minimum: 301"}
- {"dt": "2025-03-25T10:25:15.269900", "lvl": "target", "msg": "<6>[    0.020762] LSM: initializing lsm=capability"}
- {"dt": "2025-03-25T10:25:15.273023", "lvl": "target", "msg": "<6>[    0.023934] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.273220", "lvl": "target", "msg": "<6>[    0.024204] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.299425", "lvl": "target", "msg": "<4>[    0.050302] cacheinfo: Unable to detect cache hierarchy for CPU 0"}
- {"dt": "2025-03-25T10:25:15.309854", "lvl": "target", "msg": "<6>[    0.060750] rcu: Hierarchical SRCU implementation."}
- {"dt": "2025-03-25T10:25:15.309957", "lvl": "target", "msg": "<6>[    0.060934] rcu: \tMax phase no-delay instances is 1000."}
- {"dt": "2025-03-25T10:25:15.311843", "lvl": "target", "msg": "<6>[    0.062774] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level"}
- {"dt": "2025-03-25T10:25:15.315495", "lvl": "target", "msg": "<6>[    0.066389] fsl-mc MSI: its@8080000 domain created"}
- {"dt": "2025-03-25T10:25:15.317589", "lvl": "target", "msg": "<6>[    0.068509] EFI services will not be available."}
- {"dt": "2025-03-25T10:25:15.319118", "lvl": "target", "msg": "<6>[    0.070070] smp: Bringing up secondary CPUs ..."}
- {"dt": "2025-03-25T10:25:15.331338", "lvl": "target", "msg": "<6>[    0.074941] Detected PIPT I-cache on CPU1"}
- {"dt": "2025-03-25T10:25:15.331613", "lvl": "target", "msg": "<6>[    0.076285] GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000"}
- {"dt": "2025-03-25T10:25:15.331931", "lvl": "target", "msg": "<6>[    0.077060] GICv3: CPU1: using allocated LPI pending table @0x0000000100090000"}
- {"dt": "2025-03-25T10:25:15.332212", "lvl": "target", "msg": "<6>[    0.079074] CPU1: Booted secondary processor 0x0000000001 [0x000f0510]"}
- {"dt": "2025-03-25T10:25:15.332332", "lvl": "target", "msg": "<6>[    0.082252] smp: Brought up 1 node, 2 CPUs"}
- {"dt": "2025-03-25T10:25:15.332512", "lvl": "target", "msg": "<6>[    0.083546] SMP: Total of 2 processors activated."}
- {"dt": "2025-03-25T10:25:15.332675", "lvl": "target", "msg": "<6>[    0.083725] CPU: All CPU(s) started at EL2"}
- {"dt": "2025-03-25T10:25:15.332932", "lvl": "target", "msg": "<6>[    0.083936] CPU features: detected: Branch Target Identification"}
- {"dt": "2025-03-25T10:25:15.333098", "lvl": "target", "msg": "<6>[    0.084139] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2025-03-25T10:25:15.333284", "lvl": "target", "msg": "<6>[    0.084305] CPU features: detected: 32-bit EL1 Support"}
- {"dt": "2025-03-25T10:25:15.333506", "lvl": "target", "msg": "<6>[    0.084487] CPU features: detected: ARMv8.4 Translation Table Level"}
- {"dt": "2025-03-25T10:25:15.333816", "lvl": "target", "msg": "<6>[    0.084719] CPU features: detected: Instruction cache invalidation not required for I/D coherence"}
- {"dt": "2025-03-25T10:25:15.334117", "lvl": "target", "msg": "<6>[    0.085026] CPU features: detected: Data cache clean to the PoU not required for I/D coherence"}
- {"dt": "2025-03-25T10:25:15.334374", "lvl": "target", "msg": "<6>[    0.085350] CPU features: detected: Common not Private translations"}
- {"dt": "2025-03-25T10:25:15.334543", "lvl": "target", "msg": "<6>[    0.085573] CPU features: detected: CRC32 instructions"}
- {"dt": "2025-03-25T10:25:15.334937", "lvl": "target", "msg": "<6>[    0.085745] CPU features: detected: Data independent timing control (DIT)"}
- {"dt": "2025-03-25T10:25:15.335000", "lvl": "target", "msg": "<6>[    0.086053] CPU features: detected: E0PD"}
- {"dt": "2025-03-25T10:25:15.335203", "lvl": "target", "msg": "<6>[    0.086202] CPU features: detected: Enhanced Counter Virtualization"}
- {"dt": "2025-03-25T10:25:15.335638", "lvl": "target", "msg": "<6>[    0.086405] CPU features: detected: Enhanced Counter Virtualization (CNTPOFF)"}
- {"dt": "2025-03-25T10:25:15.335692", "lvl": "target", "msg": "<6>[    0.086651] CPU features: detected: Enhanced Privileged Access Never"}
- {"dt": "2025-03-25T10:25:15.335902", "lvl": "target", "msg": "<6>[    0.086894] CPU features: detected: Enhanced Virtualization Traps"}
- {"dt": "2025-03-25T10:25:15.336076", "lvl": "target", "msg": "<6>[    0.087104] CPU features: detected: Fine Grained Traps"}
- {"dt": "2025-03-25T10:25:15.336347", "lvl": "target", "msg": "<6>[    0.087335] CPU features: detected: Generic authentication (IMP DEF algorithm)"}
- {"dt": "2025-03-25T10:25:15.336601", "lvl": "target", "msg": "<6>[    0.087593] CPU features: detected: RCpc load-acquire (LDAPR)"}
- {"dt": "2025-03-25T10:25:15.336832", "lvl": "target", "msg": "<6>[    0.087812] CPU features: detected: 52-bit Virtual Addressing for KVM (LPA2)"}
- {"dt": "2025-03-25T10:25:15.337020", "lvl": "target", "msg": "<6>[    0.088035] CPU features: detected: LSE atomic instructions"}
- {"dt": "2025-03-25T10:25:15.337232", "lvl": "target", "msg": "<6>[    0.088218] CPU features: detected: Memory Copy and Memory Set instructions"}
- {"dt": "2025-03-25T10:25:15.337413", "lvl": "target", "msg": "<6>[    0.088433] CPU features: detected: Privileged Access Never"}
- {"dt": "2025-03-25T10:25:15.337586", "lvl": "target", "msg": "<6>[    0.088637] CPU features: detected: PMUv3"}
- {"dt": "2025-03-25T10:25:15.337781", "lvl": "target", "msg": "<6>[    0.088787] CPU features: detected: RAS Extension Support"}
- {"dt": "2025-03-25T10:25:15.337955", "lvl": "target", "msg": "<6>[    0.088983] CPU features: detected: Random Number Generator"}
- {"dt": "2025-03-25T10:25:15.338135", "lvl": "target", "msg": "<6>[    0.089151] CPU features: detected: Speculation barrier (SB)"}
- {"dt": "2025-03-25T10:25:15.338321", "lvl": "target", "msg": "<6>[    0.089338] CPU features: detected: Stage-2 Force Write-Back"}
- {"dt": "2025-03-25T10:25:15.338567", "lvl": "target", "msg": "<6>[    0.089519] CPU features: detected: Trap EL0 IMPLEMENTATION DEFINED functionality"}
- {"dt": "2025-03-25T10:25:15.338779", "lvl": "target", "msg": "<6>[    0.089769] CPU features: detected: TLB range maintenance instructions"}
- {"dt": "2025-03-25T10:25:15.339071", "lvl": "target", "msg": "<6>[    0.089980] CPU features: detected: WFx with timeout"}
- {"dt": "2025-03-25T10:25:15.339548", "lvl": "target", "msg": "<6>[    0.090431] CPU features: detected: Speculative Store Bypassing Safe (SSBS)"}
- {"dt": "2025-03-25T10:25:15.339858", "lvl": "target", "msg": "<6>[    0.090639] CPU features: detected: Scalable Vector Extension"}
- {"dt": "2025-03-25T10:25:15.349613", "lvl": "target", "msg": "<6>[    0.098669] alternatives: applying system-wide alternatives"}
- {"dt": "2025-03-25T10:25:15.360688", "lvl": "target", "msg": "<6>[    0.111048] CPU features: detected: Hardware dirty bit management on CPU0-1"}
- {"dt": "2025-03-25T10:25:15.360999", "lvl": "target", "msg": "<6>[    0.111962] SVE: maximum available vector length 256 bytes per vector"}
- {"dt": "2025-03-25T10:25:15.361133", "lvl": "target", "msg": "<6>[    0.112158] SVE: default vector length 64 bytes per vector"}
- {"dt": "2025-03-25T10:25:15.372278", "lvl": "target", "msg": "<6>[    0.122986] Memory: 3968692K/4194304K available (18240K kernel code, 5264K rwdata, 12488K rodata, 3264K init, 748K bss, 188664K reserved, 32768K cma-reserved)"}
- {"dt": "2025-03-25T10:25:15.395115", "lvl": "target", "msg": "<6>[    0.145983] devtmpfs: initialized"}
- {"dt": "2025-03-25T10:25:15.420098", "lvl": "target", "msg": "<6>[    0.170946] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2025-03-25T10:25:15.420573", "lvl": "target", "msg": "<6>[    0.171535] posixtimers hash table entries: 1024 (order: 2, 16384 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.420879", "lvl": "target", "msg": "<6>[    0.171855] futex hash table entries: 512 (order: 3, 32768 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.422778", "lvl": "target", "msg": "<6>[    0.173695] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL"}
- {"dt": "2025-03-25T10:25:15.422897", "lvl": "target", "msg": "<6>[    0.173916] 0 pages in range for non-PLT usage"}
- {"dt": "2025-03-25T10:25:15.425534", "lvl": "target", "msg": "<6>[    0.173959] 514224 pages in range for PLT usage"}
- {"dt": "2025-03-25T10:25:15.425611", "lvl": "target", "msg": "<6>[    0.176451] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2025-03-25T10:25:15.435511", "lvl": "target", "msg": "<6>[    0.186438] DMI not present or invalid."}
- {"dt": "2025-03-25T10:25:15.448821", "lvl": "target", "msg": "<6>[    0.199729] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2025-03-25T10:25:15.457399", "lvl": "target", "msg": "<6>[    0.208227] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations"}
- {"dt": "2025-03-25T10:25:15.458145", "lvl": "target", "msg": "<6>[    0.209044] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations"}
- {"dt": "2025-03-25T10:25:15.458808", "lvl": "target", "msg": "<6>[    0.209739] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations"}
- {"dt": "2025-03-25T10:25:15.459157", "lvl": "target", "msg": "<6>[    0.210181] audit: initializing netlink subsys (disabled)"}
- {"dt": "2025-03-25T10:25:15.460688", "lvl": "target", "msg": "<5>[    0.211637] audit: type=2000 audit(0.188:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2025-03-25T10:25:15.464819", "lvl": "target", "msg": "<6>[    0.215699] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2025-03-25T10:25:15.465399", "lvl": "target", "msg": "<6>[    0.215741] thermal_sys: Registered thermal governor 'power_allocator'"}
- {"dt": "2025-03-25T10:25:15.465450", "lvl": "target", "msg": "<6>[    0.216325] cpuidle: using governor menu"}
- {"dt": "2025-03-25T10:25:15.466919", "lvl": "target", "msg": "<6>[    0.217870] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2025-03-25T10:25:15.467637", "lvl": "target", "msg": "<6>[    0.218563] ASID allocator initialised with 65536 entries"}
- {"dt": "2025-03-25T10:25:15.475038", "lvl": "target", "msg": "<6>[    0.225952] Serial: AMBA PL011 UART driver"}
- {"dt": "2025-03-25T10:25:15.533512", "lvl": "target", "msg": "<6>[    0.284381] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 15, base_baud = 0) is a PL011 rev1"}
- {"dt": "2025-03-25T10:25:15.535438", "lvl": "target", "msg": "<6>[    0.285943] printk: console [ttyAMA0] enabled"}
- {"dt": "2025-03-25T10:25:15.535750", "lvl": "target", "msg": "<6>[    0.285943] printk: console [ttyAMA0] enabled"}
- {"dt": "2025-03-25T10:25:15.535961", "lvl": "target", "msg": "<6>[    0.286997] printk: legacy bootconsole [pl11] disabled"}
- {"dt": "2025-03-25T10:25:15.536110", "lvl": "target", "msg": "<6>[    0.286997] printk: legacy bootconsole [pl11] disabled"}
- {"dt": "2025-03-25T10:25:15.552165", "lvl": "target", "msg": "<6>[    0.302272] HugeTLB: allocation took 0ms with hugepage_allocation_threads=1"}
- {"dt": "2025-03-25T10:25:15.552505", "lvl": "target", "msg": "<6>[    0.302614] HugeTLB: allocation took 0ms with hugepage_allocation_threads=1"}
- {"dt": "2025-03-25T10:25:15.552870", "lvl": "target", "msg": "<6>[    0.303350] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T10:25:15.553307", "lvl": "target", "msg": "<6>[    0.303394] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page"}
- {"dt": "2025-03-25T10:25:15.553687", "lvl": "target", "msg": "<6>[    0.303454] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T10:25:15.554053", "lvl": "target", "msg": "<6>[    0.303478] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page"}
- {"dt": "2025-03-25T10:25:15.554353", "lvl": "target", "msg": "<6>[    0.303507] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T10:25:15.554655", "lvl": "target", "msg": "<6>[    0.303522] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page"}
- {"dt": "2025-03-25T10:25:15.555438", "lvl": "target", "msg": "<6>[    0.303542] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages"}
- {"dt": "2025-03-25T10:25:15.555760", "lvl": "target", "msg": "<6>[    0.303556] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page"}
- {"dt": "2025-03-25T10:25:15.564418", "lvl": "target", "msg": "<6>[    0.315232] ACPI: Interpreter disabled."}
- {"dt": "2025-03-25T10:25:15.573200", "lvl": "target", "msg": "<6>[    0.323926] iommu: Default domain type: Translated"}
- {"dt": "2025-03-25T10:25:15.573679", "lvl": "target", "msg": "<6>[    0.324010] iommu: DMA domain TLB invalidation policy: strict mode"}
- {"dt": "2025-03-25T10:25:15.575180", "lvl": "target", "msg": "<5>[    0.326059] SCSI subsystem initialized"}
- {"dt": "2025-03-25T10:25:15.576106", "lvl": "target", "msg": "<7>[    0.326971] libata version 3.00 loaded."}
- {"dt": "2025-03-25T10:25:15.577357", "lvl": "target", "msg": "<6>[    0.328248] usbcore: registered new interface driver usbfs"}
- {"dt": "2025-03-25T10:25:15.577587", "lvl": "target", "msg": "<6>[    0.328485] usbcore: registered new interface driver hub"}
- {"dt": "2025-03-25T10:25:15.578015", "lvl": "target", "msg": "<6>[    0.328613] usbcore: registered new device driver usb"}
- {"dt": "2025-03-25T10:25:15.580337", "lvl": "target", "msg": "<6>[    0.331139] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2025-03-25T10:25:15.580776", "lvl": "target", "msg": "<6>[    0.331182] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2025-03-25T10:25:15.581089", "lvl": "target", "msg": "<6>[    0.331307] PTP clock support registered"}
- {"dt": "2025-03-25T10:25:15.581163", "lvl": "target", "msg": "<6>[    0.331870] EDAC MC: Ver: 3.0.0"}
- {"dt": "2025-03-25T10:25:15.582465", "lvl": "target", "msg": "<6>[    0.333250] scmi_core: SCMI protocol bus registered"}
- {"dt": "2025-03-25T10:25:15.585924", "lvl": "target", "msg": "<6>[    0.336723] FPGA manager framework"}
- {"dt": "2025-03-25T10:25:15.586776", "lvl": "target", "msg": "<6>[    0.337535] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2025-03-25T10:25:15.595848", "lvl": "target", "msg": "<6>[    0.346663] vgaarb: loaded"}
- {"dt": "2025-03-25T10:25:15.598678", "lvl": "target", "msg": "<6>[    0.349416] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2025-03-25T10:25:15.601742", "lvl": "target", "msg": "<5>[    0.352300] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2025-03-25T10:25:15.602219", "lvl": "target", "msg": "<6>[    0.352472] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2025-03-25T10:25:15.604147", "lvl": "target", "msg": "<6>[    0.354775] pnp: PnP ACPI: disabled"}
- {"dt": "2025-03-25T10:25:15.633583", "lvl": "target", "msg": "<6>[    0.384355] NET: Registered PF_INET protocol family"}
- {"dt": "2025-03-25T10:25:15.635136", "lvl": "target", "msg": "<6>[    0.385821] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.640221", "lvl": "target", "msg": "<6>[    0.390788] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.640723", "lvl": "target", "msg": "<6>[    0.390945] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.641127", "lvl": "target", "msg": "<6>[    0.391133] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.641530", "lvl": "target", "msg": "<6>[    0.391682] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.641832", "lvl": "target", "msg": "<6>[    0.392380] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2025-03-25T10:25:15.642705", "lvl": "target", "msg": "<6>[    0.393540] UDP hash table entries: 2048 (order: 5, 131072 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.643161", "lvl": "target", "msg": "<6>[    0.393867] UDP-Lite hash table entries: 2048 (order: 5, 131072 bytes, linear)"}
- {"dt": "2025-03-25T10:25:15.644237", "lvl": "target", "msg": "<6>[    0.395109] NET: Registered PF_UNIX/PF_LOCAL protocol family"}
- {"dt": "2025-03-25T10:25:15.646717", "lvl": "target", "msg": "<6>[    0.397557] RPC: Registered named UNIX socket transport module."}
- {"dt": "2025-03-25T10:25:15.646897", "lvl": "target", "msg": "<6>[    0.397623] RPC: Registered udp transport module."}
- {"dt": "2025-03-25T10:25:15.647082", "lvl": "target", "msg": "<6>[    0.397646] RPC: Registered tcp transport module."}
- {"dt": "2025-03-25T10:25:15.647534", "lvl": "target", "msg": "<6>[    0.397656] RPC: Registered tcp-with-tls transport module."}
- {"dt": "2025-03-25T10:25:15.647615", "lvl": "target", "msg": "<6>[    0.397665] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2025-03-25T10:25:15.650299", "lvl": "target", "msg": "<6>[    0.397773] PCI: CLS 0 bytes, default 64"}
- {"dt": "2025-03-25T10:25:15.655212", "lvl": "target", "msg": "<6>[    0.406035] kvm [1]: nv: 566 coarse grained trap handlers"}
- {"dt": "2025-03-25T10:25:15.656052", "lvl": "target", "msg": "<6>[    0.406960] kvm [1]: nv: 669 fine grained trap handlers"}
- {"dt": "2025-03-25T10:25:15.657084", "lvl": "target", "msg": "<6>[    0.407991] kvm [1]: IPA Size Limit: 52 bits"}
- {"dt": "2025-03-25T10:25:15.657811", "lvl": "target", "msg": "<6>[    0.408559] kvm [1]: GICv3: no GICV resource entry"}
- {"dt": "2025-03-25T10:25:15.658096", "lvl": "target", "msg": "<6>[    0.408677] kvm [1]: disabling GICv2 emulation"}
- {"dt": "2025-03-25T10:25:15.658437", "lvl": "target", "msg": "<6>[    0.408964] kvm [1]: GIC system register CPU interface enabled"}
- {"dt": "2025-03-25T10:25:15.658836", "lvl": "target", "msg": "<6>[    0.409803] kvm [1]: vgic interrupt IRQ9"}
- {"dt": "2025-03-25T10:25:15.659436", "lvl": "target", "msg": "<6>[    0.410330] kvm [1]: VHE mode initialized successfully"}
- {"dt": "2025-03-25T10:25:15.664355", "lvl": "target", "msg": "<5>[    0.415183] Initialise system trusted keyrings"}
- {"dt": "2025-03-25T10:25:15.665475", "lvl": "target", "msg": "<6>[    0.416289] workingset: timestamp_bits=42 max_order=20 bucket_order=0"}
- {"dt": "2025-03-25T10:25:15.667322", "lvl": "target", "msg": "<6>[    0.418188] squashfs: version 4.0 (2009/01/31) Phillip Lougher"}
- {"dt": "2025-03-25T10:25:15.668671", "lvl": "target", "msg": "<5>[    0.419525] NFS: Registering the id_resolver key type"}
- {"dt": "2025-03-25T10:25:15.668845", "lvl": "target", "msg": "<5>[    0.419790] Key type id_resolver registered"}
- {"dt": "2025-03-25T10:25:15.668960", "lvl": "target", "msg": "<5>[    0.419842] Key type id_legacy registered"}
- {"dt": "2025-03-25T10:25:15.669420", "lvl": "target", "msg": "<6>[    0.420094] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2025-03-25T10:25:15.669509", "lvl": "target", "msg": "<6>[    0.420165] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering..."}
- {"dt": "2025-03-25T10:25:15.670121", "lvl": "target", "msg": "<6>[    0.420883] 9p: Installing v9fs 9p2000 file system support"}
- {"dt": "2025-03-25T10:25:15.735140", "lvl": "target", "msg": "<5>[    0.485877] Key type asymmetric registered"}
- {"dt": "2025-03-25T10:25:15.735396", "lvl": "target", "msg": "<5>[    0.485949] Asymmetric key parser 'x509' registered"}
- {"dt": "2025-03-25T10:25:15.735840", "lvl": "target", "msg": "<6>[    0.486164] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)"}
- {"dt": "2025-03-25T10:25:15.736045", "lvl": "target", "msg": "<6>[    0.486267] io scheduler mq-deadline registered"}
- {"dt": "2025-03-25T10:25:15.736193", "lvl": "target", "msg": "<6>[    0.486439] io scheduler kyber registered"}
- {"dt": "2025-03-25T10:25:15.736352", "lvl": "target", "msg": "<6>[    0.486704] io scheduler bfq registered"}
- {"dt": "2025-03-25T10:25:15.764023", "lvl": "target", "msg": "<6>[    0.514755] pl061_gpio 9030000.pl061: PL061 GPIO chip registered"}
- {"dt": "2025-03-25T10:25:15.768218", "lvl": "target", "msg": "<6>[    0.519048] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2025-03-25T10:25:15.771494", "lvl": "target", "msg": "<6>[    0.522186] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:"}
- {"dt": "2025-03-25T10:25:15.772067", "lvl": "target", "msg": "<6>[    0.522688] pci-host-generic 4010000000.pcie:       IO 0x003eff0000..0x003effffff -> 0x0000000000"}
- {"dt": "2025-03-25T10:25:15.772383", "lvl": "target", "msg": "<6>[    0.523113] pci-host-generic 4010000000.pcie:      MEM 0x0010000000..0x003efeffff -> 0x0010000000"}
- {"dt": "2025-03-25T10:25:15.772700", "lvl": "target", "msg": "<6>[    0.523173] pci-host-generic 4010000000.pcie:      MEM 0x8000000000..0xffffffffff -> 0x8000000000"}
- {"dt": "2025-03-25T10:25:15.772992", "lvl": "target", "msg": "<4>[    0.523614] pci-host-generic 4010000000.pcie: Memory resource size exceeds max for 32 bits"}
- {"dt": "2025-03-25T10:25:15.773441", "lvl": "target", "msg": "<6>[    0.524021] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]"}
- {"dt": "2025-03-25T10:25:15.774445", "lvl": "target", "msg": "<6>[    0.525325] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2025-03-25T10:25:15.774840", "lvl": "target", "msg": "<6>[    0.525562] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2025-03-25T10:25:15.774907", "lvl": "target", "msg": "<6>[    0.525621] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]"}
- {"dt": "2025-03-25T10:25:15.775324", "lvl": "target", "msg": "<6>[    0.525677] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]"}
- {"dt": "2025-03-25T10:25:15.775463", "lvl": "target", "msg": "<6>[    0.525693] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]"}
- {"dt": "2025-03-25T10:25:15.776244", "lvl": "target", "msg": "<6>[    0.526866] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 conventional PCI endpoint"}
- {"dt": "2025-03-25T10:25:15.779607", "lvl": "target", "msg": "<6>[    0.530248] pci 0000:00:01.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint"}
- {"dt": "2025-03-25T10:25:15.779964", "lvl": "target", "msg": "<6>[    0.530503] pci 0000:00:01.0: BAR 0 [io  0x0000-0x007f]"}
- {"dt": "2025-03-25T10:25:15.780264", "lvl": "target", "msg": "<6>[    0.530561] pci 0000:00:01.0: BAR 1 [mem 0x00000000-0x00000fff]"}
- {"dt": "2025-03-25T10:25:15.780637", "lvl": "target", "msg": "<6>[    0.530696] pci 0000:00:01.0: BAR 4 [mem 0x00000000-0x00003fff 64bit pref]"}
- {"dt": "2025-03-25T10:25:15.783179", "lvl": "target", "msg": "<6>[    0.533825] pci 0000:00:01.0: BAR 4 [mem 0x8000000000-0x8000003fff 64bit pref]: assigned"}
- {"dt": "2025-03-25T10:25:15.783632", "lvl": "target", "msg": "<6>[    0.534137] pci 0000:00:01.0: BAR 1 [mem 0x10000000-0x10000fff]: assigned"}
- {"dt": "2025-03-25T10:25:15.783957", "lvl": "target", "msg": "<6>[    0.534199] pci 0000:00:01.0: BAR 0 [io  0x1000-0x107f]: assigned"}
- {"dt": "2025-03-25T10:25:15.784172", "lvl": "target", "msg": "<6>[    0.534461] pci_bus 0000:00: resource 4 [io  0x0000-0xffff]"}
- {"dt": "2025-03-25T10:25:15.784394", "lvl": "target", "msg": "<6>[    0.534507] pci_bus 0000:00: resource 5 [mem 0x10000000-0x3efeffff]"}
- {"dt": "2025-03-25T10:25:15.784736", "lvl": "target", "msg": "<6>[    0.534820] pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff]"}
- {"dt": "2025-03-25T10:25:15.848818", "lvl": "target", "msg": "<6>[    0.599025] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)"}
- {"dt": "2025-03-25T10:25:15.869764", "lvl": "target", "msg": "<6>[    0.620542] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled"}
- {"dt": "2025-03-25T10:25:15.878795", "lvl": "target", "msg": "<6>[    0.629593] msm_serial: driver initialized"}
- {"dt": "2025-03-25T10:25:15.879639", "lvl": "target", "msg": "<6>[    0.630523] SuperH (H)SCI(F) driver initialized"}
- {"dt": "2025-03-25T10:25:15.880007", "lvl": "target", "msg": "<6>[    0.630988] STM32 USART driver initialized"}
- {"dt": "2025-03-25T10:25:15.905591", "lvl": "target", "msg": "<6>[    0.656358] loop: module loaded"}
- {"dt": "2025-03-25T10:25:15.906576", "lvl": "target", "msg": "<6>[    0.657341] virtio_blk virtio0: 2/0/0 default/read/poll queues"}
- {"dt": "2025-03-25T10:25:15.914945", "lvl": "target", "msg": "<5>[    0.665620] virtio_blk virtio0: [vda] 5345376 512-byte logical blocks (2.74 GB/2.55 GiB)"}
- {"dt": "2025-03-25T10:25:15.927480", "lvl": "target", "msg": "<6>[    0.678221] megasas: 07.727.03.00-rc1"}
- {"dt": "2025-03-25T10:25:15.932641", "lvl": "target", "msg": "<5>[    0.682835] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]"}
- {"dt": "2025-03-25T10:25:15.934114", "lvl": "target", "msg": "<6>[    0.684270] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000"}
- {"dt": "2025-03-25T10:25:15.934734", "lvl": "target", "msg": "<6>[    0.684747] Intel/Sharp Extended Query Table at 0x0031"}
- {"dt": "2025-03-25T10:25:15.935473", "lvl": "target", "msg": "<6>[    0.685648] Using buffer write method"}
- {"dt": "2025-03-25T10:25:15.936182", "lvl": "target", "msg": "<7>[    0.685905] erase region 0: offset=0x0,size=0x40000,blocks=256"}
- {"dt": "2025-03-25T10:25:15.936439", "lvl": "target", "msg": "<5>[    0.686078] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]"}
- {"dt": "2025-03-25T10:25:15.936786", "lvl": "target", "msg": "<6>[    0.686634] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000"}
- {"dt": "2025-03-25T10:25:15.936988", "lvl": "target", "msg": "<6>[    0.686668] Intel/Sharp Extended Query Table at 0x0031"}
- {"dt": "2025-03-25T10:25:15.937147", "lvl": "target", "msg": "<6>[    0.687296] Using buffer write method"}
- {"dt": "2025-03-25T10:25:15.937357", "lvl": "target", "msg": "<7>[    0.687315] erase region 0: offset=0x0,size=0x40000,blocks=256"}
- {"dt": "2025-03-25T10:25:15.937654", "lvl": "target", "msg": "<5>[    0.687379] Concatenating MTD devices:"}
- {"dt": "2025-03-25T10:25:15.938860", "lvl": "target", "msg": "<5>[    0.687411] (0): \"0.flash\""}
- {"dt": "2025-03-25T10:25:15.938920", "lvl": "target", "msg": "<5>[    0.687459] (1): \"0.flash\""}
- {"dt": "2025-03-25T10:25:15.939081", "lvl": "target", "msg": "<5>[    0.687479] into device \"0.flash\""}
- {"dt": "2025-03-25T10:25:15.962323", "lvl": "target", "msg": "<6>[    0.713093] tun: Universal TUN/TAP device driver, 1.6"}
- {"dt": "2025-03-25T10:25:15.965846", "lvl": "target", "msg": "<6>[    0.716564] thunder_xcv, ver 1.0"}
- {"dt": "2025-03-25T10:25:15.966307", "lvl": "target", "msg": "<6>[    0.716690] thunder_bgx, ver 1.0"}
- {"dt": "2025-03-25T10:25:15.966407", "lvl": "target", "msg": "<6>[    0.716785] nicpf, ver 1.0"}
- {"dt": "2025-03-25T10:25:15.969305", "lvl": "target", "msg": "<6>[    0.719924] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version"}
- {"dt": "2025-03-25T10:25:15.969688", "lvl": "target", "msg": "<6>[    0.719973] hns3: Copyright (c) 2017 Huawei Corporation."}
- {"dt": "2025-03-25T10:25:15.969957", "lvl": "target", "msg": "<6>[    0.720197] hclge is initializing"}
- {"dt": "2025-03-25T10:25:15.970295", "lvl": "target", "msg": "<6>[    0.720301] e1000: Intel(R) PRO/1000 Network Driver"}
- {"dt": "2025-03-25T10:25:15.970617", "lvl": "target", "msg": "<6>[    0.720313] e1000: Copyright (c) 1999-2006 Intel Corporation."}
- {"dt": "2025-03-25T10:25:15.971009", "lvl": "target", "msg": "<6>[    0.720430] e1000e: Intel(R) PRO/1000 Network Driver"}
- {"dt": "2025-03-25T10:25:15.971158", "lvl": "target", "msg": "<6>[    0.720443] e1000e: Copyright(c) 1999 - 2015 Intel Corporation."}
- {"dt": "2025-03-25T10:25:15.971482", "lvl": "target", "msg": "<6>[    0.720740] igb: Intel(R) Gigabit Ethernet Network Driver"}
- {"dt": "2025-03-25T10:25:15.971812", "lvl": "target", "msg": "<6>[    0.720877] igb: Copyright (c) 2007-2014 Intel Corporation."}
- {"dt": "2025-03-25T10:25:15.972181", "lvl": "target", "msg": "<6>[    0.721117] igbvf: Intel(R) Gigabit Virtual Function Network Driver"}
- {"dt": "2025-03-25T10:25:15.972444", "lvl": "target", "msg": "<6>[    0.721274] igbvf: Copyright (c) 2009 - 2012 Intel Corporation."}
- {"dt": "2025-03-25T10:25:15.972589", "lvl": "target", "msg": "<6>[    0.722065] sky2: driver version 1.30"}
- {"dt": "2025-03-25T10:25:15.975716", "lvl": "target", "msg": "<6>[    0.726573] VFIO - User Level meta-driver version: 0.3"}
- {"dt": "2025-03-25T10:25:15.983757", "lvl": "target", "msg": "<6>[    0.734555] usbcore: registered new interface driver usb-storage"}
- {"dt": "2025-03-25T10:25:15.992981", "lvl": "target", "msg": "<6>[    0.743832] rtc-pl031 9010000.pl031: registered as rtc0"}
- {"dt": "2025-03-25T10:25:15.993703", "lvl": "target", "msg": "<6>[    0.744319] rtc-pl031 9010000.pl031: setting system clock to 2025-03-25T10:25:15 UTC (1742898315)"}
- {"dt": "2025-03-25T10:25:15.995904", "lvl": "target", "msg": "<6>[    0.746738] i2c_dev: i2c /dev entries driver"}
- {"dt": "2025-03-25T10:25:16.014360", "lvl": "target", "msg": "<6>[    0.764948] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2025-03-25T10:25:16.014616", "lvl": "target", "msg": "<6>[    0.765004] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2025-03-25T10:25:16.016495", "lvl": "target", "msg": "<6>[    0.767265] Synopsys Designware Multimedia Card Interface Driver"}
- {"dt": "2025-03-25T10:25:16.019148", "lvl": "target", "msg": "<6>[    0.769929] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2025-03-25T10:25:16.028440", "lvl": "target", "msg": "<6>[    0.779210] usbcore: registered new interface driver usbhid"}
- {"dt": "2025-03-25T10:25:16.028572", "lvl": "target", "msg": "<6>[    0.779269] usbhid: USB HID core driver"}
- {"dt": "2025-03-25T10:25:16.039021", "lvl": "target", "msg": "<6>[    0.789536] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 (0,8000003f) counters available"}
- {"dt": "2025-03-25T10:25:16.051171", "lvl": "target", "msg": "<6>[    0.801966] NET: Registered PF_INET6 protocol family"}
- {"dt": "2025-03-25T10:25:16.056892", "lvl": "target", "msg": "<6>[    0.807708] Segment Routing with IPv6"}
- {"dt": "2025-03-25T10:25:16.057104", "lvl": "target", "msg": "<6>[    0.807994] In-situ OAM (IOAM) with IPv6"}
- {"dt": "2025-03-25T10:25:16.057939", "lvl": "target", "msg": "<6>[    0.808553] NET: Registered PF_PACKET protocol family"}
- {"dt": "2025-03-25T10:25:16.058975", "lvl": "target", "msg": "<6>[    0.809816] 9pnet: Installing 9P2000 support"}
- {"dt": "2025-03-25T10:25:16.059300", "lvl": "target", "msg": "<5>[    0.810187] Key type dns_resolver registered"}
- {"dt": "2025-03-25T10:25:16.087641", "lvl": "target", "msg": "<6>[    0.838434] registered taskstats version 1"}
- {"dt": "2025-03-25T10:25:16.088659", "lvl": "target", "msg": "<5>[    0.839529] Loading compiled-in X.509 certificates"}
- {"dt": "2025-03-25T10:25:16.115426", "lvl": "target", "msg": "<6>[    0.865340] Demotion targets for Node 0: null"}
- {"dt": "2025-03-25T10:25:16.123458", "lvl": "target", "msg": "<6>[    0.874174] input: gpio-keys as /devices/platform/gpio-keys/input/input0"}
- {"dt": "2025-03-25T10:25:16.128753", "lvl": "target", "msg": "<6>[    0.879544] clk: Disabling unused clocks"}
- {"dt": "2025-03-25T10:25:16.129000", "lvl": "target", "msg": "<6>[    0.879904] PM: genpd: Disabling unused power domains"}
- {"dt": "2025-03-25T10:25:16.129331", "lvl": "target", "msg": "<6>[    0.880240] ALSA device list:"}
- {"dt": "2025-03-25T10:25:16.129719", "lvl": "target", "msg": "<6>[    0.880378]   No soundcards found."}
- {"dt": "2025-03-25T10:25:16.157640", "lvl": "target", "msg": "<6>[    0.908202] EXT4-fs (vda): mounted filesystem db78a389-4e12-4f05-bb8b-e7b25b5f99d9 r/w with ordered data mode. Quota mode: none."}
- {"dt": "2025-03-25T10:25:16.157882", "lvl": "target", "msg": "<6>[    0.908548] VFS: Mounted root (ext4 filesystem) on device 254:0."}
- {"dt": "2025-03-25T10:25:16.159239", "lvl": "target", "msg": "<6>[    0.910114] devtmpfs: mounted"}
- {"dt": "2025-03-25T10:25:16.456133", "lvl": "target", "msg": "<6>[    1.206267] Freeing unused kernel memory: 3264K"}
- {"dt": "2025-03-25T10:25:16.456353", "lvl": "target", "msg": "<6>[    1.207193] Run /sbin/init as init process"}
- {"dt": "2025-03-25T10:25:16.456486", "lvl": "target", "msg": "<7>[    1.207275]   with arguments:"}
- {"dt": "2025-03-25T10:25:16.456613", "lvl": "target", "msg": "<7>[    1.207311]     /sbin/init"}
- {"dt": "2025-03-25T10:25:16.456726", "lvl": "target", "msg": "<7>[    1.207335]     verbose"}
- {"dt": "2025-03-25T10:25:16.456856", "lvl": "target", "msg": "<7>[    1.207345]   with environment:"}
- {"dt": "2025-03-25T10:25:16.457219", "lvl": "target", "msg": "<7>[    1.207364]     HOME=/"}
- {"dt": "2025-03-25T10:25:16.457283", "lvl": "target", "msg": "<7>[    1.207417]     TERM=linux"}
- {"dt": "2025-03-25T10:25:16.781333", "lvl": "target", "msg": "[!p]104\a[?7h"}
- {"dt": "2025-03-25T10:25:16.781490", "lvl": "target", "msg": "[0;1;39mWelcome to [0m[1mDebian GNU/Linux trixie/sid[0m[0;1;39m![0m"}
- {"dt": "2025-03-25T10:25:16.781559", "lvl": "target", "msg": "\r"}
- {"dt": "2025-03-25T10:25:18.522466", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-getty.slice[0m - Slice /system/getty.\r"}
- {"dt": "2025-03-25T10:25:18.528050", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-modprobe.slice[0m - Slice /system/modprobe.\r"}
- {"dt": "2025-03-25T10:25:18.533105", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39msystem-serial\\x2dget\u2026slice[0m - Slice /system/serial-getty.\r"}
- {"dt": "2025-03-25T10:25:18.538836", "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-25T10:25:18.543196", "lvl": "target", "msg": "[[0;32m  OK  [0m] Created slice [0;1;39muser.slice[0m - User and Session Slice.\r"}
- {"dt": "2025-03-25T10:25:18.545339", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-ask-password-conso\u2026[0mequests to Console Directory Watch.\r"}
- {"dt": "2025-03-25T10:25:18.546586", "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-25T10:25:18.548605", "lvl": "target", "msg": "         Expecting device [0;1;39mdev-ttyAMA0.device[0m - /dev/ttyAMA0...\r"}
- {"dt": "2025-03-25T10:25:18.549448", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mpaths.target[0m - Path Units.\r"}
- {"dt": "2025-03-25T10:25:18.550367", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mremote-fs.target[0m - Remote File Systems.\r"}
- {"dt": "2025-03-25T10:25:18.551126", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mslices.target[0m - Slice Units.\r"}
- {"dt": "2025-03-25T10:25:18.551930", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mswap.target[0m - Swaps.\r"}
- {"dt": "2025-03-25T10:25:18.563971", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-creds.socket[0m - Credential Encryption/Decryption.\r"}
- {"dt": "2025-03-25T10:25:18.566425", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-initctl.socke\u2026[0m- initctl Compatibility Named Pipe.\r"}
- {"dt": "2025-03-25T10:25:18.568373", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-journald-dev-\u2026socket[0m - Journal Socket (/dev/log).\r"}
- {"dt": "2025-03-25T10:25:18.570230", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-journald.socket[0m - Journal Sockets.\r"}
- {"dt": "2025-03-25T10:25:18.572276", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-udevd-control.socket[0m - udev Control Socket.\r"}
- {"dt": "2025-03-25T10:25:18.573596", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-udevd-kernel.socket[0m - udev Kernel Socket.\r"}
- {"dt": "2025-03-25T10:25:18.594417", "lvl": "target", "msg": "         Mounting [0;1;39mdev-hugepages.mount[0m - Huge Pages File System...\r"}
- {"dt": "2025-03-25T10:25:18.607274", "lvl": "target", "msg": "         Mounting [0;1;39mdev-mqueue.mount[0m - POSIX Message Queue File System...\r"}
- {"dt": "2025-03-25T10:25:18.623970", "lvl": "target", "msg": "         Mounting [0;1;39mrun-lock.mount[0m - Legacy Locks Directory /run/lock...\r"}
- {"dt": "2025-03-25T10:25:18.639578", "lvl": "target", "msg": "         Mounting [0;1;39msys-kernel-debug.mount[0m - Kernel Debug File System...\r"}
- {"dt": "2025-03-25T10:25:18.676226", "lvl": "target", "msg": "         Mounting [0;1;39mtmp.mount[0m - Temporary Directory /tmp...\r"}
- {"dt": "2025-03-25T10:25:18.717906", "lvl": "target", "msg": "         Starting [0;1;39mkmod-static-nodes.service[0m\u2026eate List of Static Device Nodes...\r"}
- {"dt": "2025-03-25T10:25:18.743978", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@configfs.service[0m - Load Kernel Module configfs...\r"}
- {"dt": "2025-03-25T10:25:18.771515", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@drm.service[0m - Load Kernel Module drm...\r"}
- {"dt": "2025-03-25T10:25:18.823936", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@efi_pstore.servi\u2026[0m - Load Kernel Module efi_pstore...\r"}
- {"dt": "2025-03-25T10:25:18.835228", "lvl": "target", "msg": "         Starting [0;1;39mmodprobe@fuse.service[0m - Load Kernel Module fuse...\r"}
- {"dt": "2025-03-25T10:25:18.862795", "lvl": "target", "msg": "         Starting [0;1;39msystemd-journald.service[0m - Journal Service...\r"}
- {"dt": "2025-03-25T10:25:18.884294", "lvl": "target", "msg": "         Starting [0;1;39msystemd-modules-load.service[0m - Load Kernel Modules...\r"}
- {"dt": "2025-03-25T10:25:18.900306", "lvl": "target", "msg": "         Starting [0;1;39msystemd-remount-fs.servic\u2026[0munt Root and Kernel File Systems...\r"}
- {"dt": "2025-03-25T10:25:18.956733", "lvl": "target", "msg": "         Starting [0;1;39msystemd-udev-load-credent\u2026[0mLoad udev Rules from Credentials...\r"}
- {"dt": "2025-03-25T10:25:18.980520", "lvl": "target", "msg": "         Starting [0;1;39msystemd-udev-trigger.service[0m - Coldplug All udev Devices...\r"}
- {"dt": "2025-03-25T10:25:19.017974", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mdev-hugepages.mount[0m - Huge Pages File System.\r"}
- {"dt": "2025-03-25T10:25:19.024600", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mdev-mqueue.mount[0m - POSIX Message Queue File System.\r"}
- {"dt": "2025-03-25T10:25:19.026906", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mrun-lock.mount[0m - Legacy Locks Directory /run/lock.\r"}
- {"dt": "2025-03-25T10:25:19.028477", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39msys-kernel-debug.mount[0m - Kernel Debug File System.\r"}
- {"dt": "2025-03-25T10:25:19.030303", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39mtmp.mount[0m - Temporary Directory /tmp.\r"}
- {"dt": "2025-03-25T10:25:19.057615", "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-25T10:25:19.074383", "lvl": "target", "msg": "         Starting [0;1;39msystemd-tmpfiles-setup-de\u2026[0m Device Nodes in /dev gracefully...\r"}
- {"dt": "2025-03-25T10:25:19.247821", "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-25T10:25:19.265403", "lvl": "target", "msg": "         Starting [0;1;39msystemd-random-seed.service[0m - Load/Save OS Random Seed...\r"}
- {"dt": "2025-03-25T10:25:19.334898", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-modules-load.service[0m - Load Kernel Modules.\r"}
- {"dt": "2025-03-25T10:25:19.352724", "lvl": "target", "msg": "         Starting [0;1;39msystemd-sysctl.service[0m - Apply Kernel Variables...\r"}
- {"dt": "2025-03-25T10:25:19.475974", "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-25T10:25:19.604058", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-random-seed.service[0m - Load/Save OS Random Seed.\r"}
- {"dt": "2025-03-25T10:25:19.617901", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@configfs.service[0m - Load Kernel Module configfs.\r"}
- {"dt": "2025-03-25T10:25:19.626172", "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-25T10:25:19.644621", "lvl": "target", "msg": "         Starting [0;1;39msystemd-sysusers.service[0m - Create System Users...\r"}
- {"dt": "2025-03-25T10:25:19.695961", "lvl": "target", "msg": "<6>[    4.446002] fuse: init (API version 7.43)"}
- {"dt": "2025-03-25T10:25:19.716008", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@efi_pstore.service[0m - Load Kernel Module efi_pstore.\r"}
- {"dt": "2025-03-25T10:25:19.731002", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@fuse.service[0m - Load Kernel Module fuse.\r"}
- {"dt": "2025-03-25T10:25:19.740838", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mmodprobe@drm.service[0m - Load Kernel Module drm.\r"}
- {"dt": "2025-03-25T10:25:19.803856", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-sysctl.service[0m - Apply Kernel Variables.\r"}
- {"dt": "2025-03-25T10:25:19.880550", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-journald.service[0m - Journal Service.\r"}
- {"dt": "2025-03-25T10:25:19.900314", "lvl": "target", "msg": "         Starting [0;1;39msystemd-journal-flush.ser\u2026[0msh Journal to Persistent Storage...\r"}
- {"dt": "2025-03-25T10:25:20.007326", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-sysusers.service[0m - Create System Users.\r"}
- {"dt": "2025-03-25T10:25:20.087401", "lvl": "target", "msg": "         Mounting [0;1;39msys-fs-fuse-connections.mount[0m - FUSE Control File System...\r"}
- {"dt": "2025-03-25T10:25:20.115334", "lvl": "target", "msg": "         Mounting [0;1;39msys-kernel-config.mount[0m - Kernel Configuration File System...\r"}
- {"dt": "2025-03-25T10:25:20.132315", "lvl": "target", "msg": "         Starting [0;1;39msystemd-tmpfiles-setup-de\u2026[0meate Static Device Nodes in /dev...\r"}
- {"dt": "2025-03-25T10:25:20.251332", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39msys-fs-fuse-connections.mount[0m - FUSE Control File System.\r"}
- {"dt": "2025-03-25T10:25:20.253369", "lvl": "target", "msg": "[[0;32m  OK  [0m] Mounted [0;1;39msys-kernel-config.mount[0m - Kernel Configuration File System.\r"}
- {"dt": "2025-03-25T10:25:20.391295", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-journal-flush.ser\u2026[0mlush Journal to Persistent Storage.\r"}
- {"dt": "2025-03-25T10:25:20.443853", "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-25T10:25:20.451425", "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-25T10:25:20.452378", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mlocal-fs.target[0m - Local File Systems.\r"}
- {"dt": "2025-03-25T10:25:20.466769", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-sysext.socket[0m\u2026 System Extension Image Management.\r"}
- {"dt": "2025-03-25T10:25:20.484020", "lvl": "target", "msg": "         Starting [0;1;39msystemd-tmpfiles-setup.se\u2026[0mate System Files and Directories...\r"}
- {"dt": "2025-03-25T10:25:20.501374", "lvl": "target", "msg": "         Starting [0;1;39msystemd-udevd.service[0m - R\u2026ager for Device Events and Files...\r"}
- {"dt": "2025-03-25T10:25:20.823573", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-tmpfiles-setup.se\u2026[0mreate System Files and Directories.\r"}
- {"dt": "2025-03-25T10:25:20.840564", "lvl": "target", "msg": "         Starting [0;1;39mldconfig.service[0m - Rebuild Dynamic Linker Cache...\r"}
- {"dt": "2025-03-25T10:25:20.864413", "lvl": "target", "msg": "         Starting [0;1;39msystemd-journal-catalog-u\u2026ervice[0m - Rebuild Journal Catalog...\r"}
- {"dt": "2025-03-25T10:25:21.272725", "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-25T10:25:21.479121", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-journal-catalog-u\u2026.service[0m - Rebuild Journal Catalog.\r"}
- {"dt": "2025-03-25T10:25:21.566986", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39mldconfig.service[0m - Rebuild Dynamic Linker Cache.\r"}
- {"dt": "2025-03-25T10:25:21.583822", "lvl": "target", "msg": "         Starting [0;1;39msystemd-update-done.service[0m - Update is Completed...\r"}
- {"dt": "2025-03-25T10:25:21.699190", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-update-done.service[0m - Update is Completed.\r"}
- {"dt": "2025-03-25T10:25:22.987337", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-udev-trigger.service[0m - Coldplug All udev Devices.\r"}
- {"dt": "2025-03-25T10:25:22.990990", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39msysinit.target[0m - System Initialization.\r"}
- {"dt": "2025-03-25T10:25:22.999603", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mapt-daily.timer[0m - Daily apt download activities.\r"}
- {"dt": "2025-03-25T10:25:23.001229", "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-25T10:25:23.003545", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mdpkg-db-backup.timer[0m - Daily dpkg database backup timer.\r"}
- {"dt": "2025-03-25T10:25:23.005813", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39me2scrub_all.timer[0m - Period\u2026Metadata Check for All Filesystems.\r"}
- {"dt": "2025-03-25T10:25:23.008148", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mfstrim.timer[0m - Discard unused filesystem blocks once a week.\r"}
- {"dt": "2025-03-25T10:25:23.009494", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mlogrotate.timer[0m - Daily rotation of log files.\r"}
- {"dt": "2025-03-25T10:25:23.010971", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-tmpfiles-clean.tim\u2026[0my Cleanup of Temporary Directories.\r"}
- {"dt": "2025-03-25T10:25:23.013078", "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-25T10:25:23.013785", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mtimers.target[0m - Timer Units.\r"}
- {"dt": "2025-03-25T10:25:23.015842", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39mdbus.socket[0m - D-Bus System Message Bus Socket.\r"}
- {"dt": "2025-03-25T10:25:23.017432", "lvl": "target", "msg": "[[0;32m  OK  [0m] Listening on [0;1;39msystemd-hostnamed.socket[0m - Hostname Service Socket.\r"}
- {"dt": "2025-03-25T10:25:23.018294", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39msockets.target[0m - Socket Units.\r"}
- {"dt": "2025-03-25T10:25:23.019754", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mbasic.target[0m - Basic System.\r"}
- {"dt": "2025-03-25T10:25:23.039499", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mcron.service[0m - Regular background program processing daemon.\r"}
- {"dt": "2025-03-25T10:25:23.053919", "lvl": "target", "msg": "         Starting [0;1;39mdbus.service[0m - D-Bus System Message Bus...\r"}
- {"dt": "2025-03-25T10:25:23.076883", "lvl": "target", "msg": "         Starting [0;1;39me2scrub_reap.service[0m - Re\u2026ne ext4 Metadata Check Snapshots...\r"}
- {"dt": "2025-03-25T10:25:23.124196", "lvl": "target", "msg": "         Starting [0;1;39msystemd-logind.service[0m - User Login Management...\r"}
- {"dt": "2025-03-25T10:25:23.138733", "lvl": "target", "msg": "         Starting [0;1;39msystemd-user-sessions.service[0m - Permit User Sessions...\r"}
- {"dt": "2025-03-25T10:25:23.432773", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39msystemd-user-sessions.service[0m - Permit User Sessions.\r"}
- {"dt": "2025-03-25T10:25:23.456690", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mgetty@tty1.service[0m - Getty on tty1.\r"}
- {"dt": "2025-03-25T10:25:23.479040", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mdbus.service[0m - D-Bus System Message Bus.\r"}
- {"dt": "2025-03-25T10:25:23.727071", "lvl": "target", "msg": "[[0;32m  OK  [0m] Finished [0;1;39me2scrub_reap.service[0m - Re\u2026line ext4 Metadata Check Snapshots.\r"}
- {"dt": "2025-03-25T10:25:23.776919", "lvl": "target", "msg": "[[0;32m  OK  [0m] Found device [0;1;39mdev-ttyAMA0.device[0m - /dev/ttyAMA0.\r"}
- {"dt": "2025-03-25T10:25:23.793334", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39mserial-getty@ttyAMA0.service[0m - Serial Getty on ttyAMA0.\r"}
- {"dt": "2025-03-25T10:25:23.795185", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mgetty.target[0m - Login Prompts.\r"}
- {"dt": "2025-03-25T10:25:24.103868", "lvl": "target", "msg": "[[0;32m  OK  [0m] Started [0;1;39msystemd-logind.service[0m - User Login Management.\r"}
- {"dt": "2025-03-25T10:25:24.105730", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mmulti-user.target[0m - Multi-User System.\r"}
- {"dt": "2025-03-25T10:25:24.109610", "lvl": "target", "msg": "[[0;32m  OK  [0m] Reached target [0;1;39mgraphical.target[0m - Graphical Interface.\r"}
- {"dt": "2025-03-25T10:25:25.882850", "lvl": "target", "msg": "[!p]104\a[?7h[6n[32766;32766H[6n[!p]104\a[?7h[6n[32766;32766H[6n\r"}
- {"dt": "2025-03-25T10:25:25.883012", "lvl": "target", "msg": "Debian GNU/Linux trixie/sid runner-ykxhnyexq-project-40964107-concurrent-0 ttyAMA0"}
- {"dt": "2025-03-25T10:25:25.883082", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T10:25:25.883710", "lvl": "debug", "msg": "Matched prompt #11: login:"}
- {"dt": "2025-03-25T10:25:25.883795", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "kernel-messages", "level": "2.2.1", "duration": "10.80", "result": "pass", "extra": {"extra": []}}}
- {"dt": "2025-03-25T10:25:25.883926", "lvl": "debug", "msg": "Sending username root"}
- {"dt": "2025-03-25T10:25:25.883993", "lvl": "debug", "msg": "Sending line: 'root'"}
- {"dt": "2025-03-25T10:25:25.984734", "lvl": "input", "msg": "root"}
- {"dt": "2025-03-25T10:25:25.984896", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T10:25:25.984989", "lvl": "debug", "msg": "login-action: Wait for prompt ['root@(.*):[/~]#', 'Login incorrect', 'Login timed out'] (timeout 00:29:49)"}
- {"dt": "2025-03-25T10:25:25.985058", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:14:54)"}
- {"dt": "2025-03-25T10:25:25.985722", "lvl": "target", "msg": "runner-ykxhnyexq-project-40964107-concurrent-0 login: root\r"}
- {"dt": "2025-03-25T10:25:26.186952", "lvl": "target", "msg": "Linux runner-ykxhnyexq-project-40964107-concurrent-0 6.14.0-rc7-next-20250324 #1 SMP PREEMPT @1742818529 aarch64"}
- {"dt": "2025-03-25T10:25:26.188888", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T10:25:26.189157", "lvl": "target", "msg": "The programs included with the Debian GNU/Linux system are free software;"}
- {"dt": "2025-03-25T10:25:26.189464", "lvl": "target", "msg": "the exact distribution terms for each program are described in the"}
- {"dt": "2025-03-25T10:25:26.189533", "lvl": "target", "msg": "individual files in /usr/share/doc/*/copyright."}
- {"dt": "2025-03-25T10:25:26.189592", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T10:25:26.189829", "lvl": "target", "msg": "Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent"}
- {"dt": "2025-03-25T10:25:26.189879", "lvl": "target", "msg": "permitted by applicable law."}
- {"dt": "2025-03-25T10:25:28.152075", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T10:25:28.152232", "lvl": "debug", "msg": "end: 2.2.1 login-action (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T10:25:28.152288", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "login-action", "level": "2.2.1", "duration": "13.06", "result": "pass", "extra": {"success": "No kernel warnings or errors detected."}}}
- {"dt": "2025-03-25T10:25:28.152384", "lvl": "debug", "msg": "end: 2.2 auto-login-action (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T10:25:28.152453", "lvl": "debug", "msg": "start: 2.3 expect-shell-connection (timeout 00:29:47) [common]"}
- {"dt": "2025-03-25T10:25:28.152525", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T10:25:28.152582", "lvl": "debug", "msg": "Forcing a shell prompt, looking for ['root@(.*):[/~]#']"}
- {"dt": "2025-03-25T10:25:28.152641", "lvl": "debug", "msg": "Sending line: ''"}
- {"dt": "2025-03-25T10:25:28.202791", "lvl": "input", "msg": ""}
- {"dt": "2025-03-25T10:25:28.202950", "lvl": "debug", "msg": "expect-shell-connection: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:30:00)"}
- {"dt": "2025-03-25T10:25:28.203031", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:15:00)"}
- {"dt": "2025-03-25T10:25:28.203879", "lvl": "target", "msg": "[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# "}
- {"dt": "2025-03-25T10:25:28.205615", "lvl": "debug", "msg": "end: 2.3 expect-shell-connection (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:25:28.205714", "lvl": "debug", "msg": "start: 2.4 export-device-env (timeout 00:29:47) [common]"}
- {"dt": "2025-03-25T10:25:28.205827", "lvl": "debug", "msg": "end: 2.4 export-device-env (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:25:28.205918", "lvl": "info", "msg": "end: 2 boot-image-retry (duration 00:00:13) [common]"}
- {"dt": "2025-03-25T10:25:28.205996", "lvl": "info", "msg": "start: 3 lava-test-retry (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T10:25:28.206076", "lvl": "debug", "msg": "start: 3.1 lava-test-shell (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T10:25:28.206145", "lvl": "debug", "msg": "Using namespace: common"}
- {"dt": "2025-03-25T10:25:28.206214", "lvl": "debug", "msg": "Sending line: '#'"}
- {"dt": "2025-03-25T10:25:28.306441", "lvl": "input", "msg": "#"}
- {"dt": "2025-03-25T10:25:28.306589", "lvl": "debug", "msg": "lava-test-shell: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:05:00)"}
- {"dt": "2025-03-25T10:25:28.307601", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# #"}
- {"dt": "2025-03-25T10:25:28.309773", "lvl": "debug", "msg": "Using /lava-1"}
- {"dt": "2025-03-25T10:25:28.309881", "lvl": "debug", "msg": "Sending line: 'export SHELL=/bin/sh'"}
- {"dt": "2025-03-25T10:25:28.410400", "lvl": "input", "msg": "export SHELL=/bin/sh"}
- {"dt": "2025-03-25T10:25:28.411523", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# export SHELL=/bin/sh"}
- {"dt": "2025-03-25T10:25:28.413374", "lvl": "debug", "msg": "Sending line: '. /lava-1/environment'"}
- {"dt": "2025-03-25T10:25:28.513651", "lvl": "input", "msg": ". /lava-1/environment"}
- {"dt": "2025-03-25T10:25:28.514873", "lvl": "target", "msg": "[?2004l\r[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# . /lava-1/environment"}
- {"dt": "2025-03-25T10:25:28.519742", "lvl": "debug", "msg": "Sending line: '/lava-1/bin/lava-test-runner /lava-1/0'"}
- {"dt": "2025-03-25T10:25:28.620067", "lvl": "input", "msg": "/lava-1/bin/lava-test-runner /lava-1/0"}
- {"dt": "2025-03-25T10:25:28.620265", "lvl": "info", "msg": "Test shell timeout: 10s (minimum of the action and connection timeout)"}
- {"dt": "2025-03-25T10:25:28.620904", "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-25T10:25:28.728959", "lvl": "target", "msg": "[?2004l\r+ export TESTRUN_ID=0_kselftest-clone3"}
- {"dt": "2025-03-25T10:25:28.729122", "lvl": "target", "msg": "+ cd /lava-1/0/tests/0_kselftest-clone3"}
- {"dt": "2025-03-25T10:25:28.731310", "lvl": "target", "msg": "+ cat uuid"}
- {"dt": "2025-03-25T10:25:28.738505", "lvl": "target", "msg": "+ UUID=1_1.1.3.1"}
- {"dt": "2025-03-25T10:25:28.738772", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2025-03-25T10:25:28.739722", "lvl": "target", "msg": "<8>[   13.490409] <LAVA_SIGNAL_STARTRUN 0_kselftest-clone3 1_1.1.3.1>"}
- {"dt": "2025-03-25T10:25:28.739956", "lvl": "debug", "msg": "Received signal: <STARTRUN> 0_kselftest-clone3 1_1.1.3.1"}
- {"dt": "2025-03-25T10:25:28.740009", "lvl": "info", "msg": "Starting test lava.0_kselftest-clone3 (1_1.1.3.1)"}
- {"dt": "2025-03-25T10:25:28.740077", "lvl": "info", "msg": "Skipping test definition patterns."}
- {"dt": "2025-03-25T10:25:28.740161", "lvl": "target", "msg": "+ cd ./automated/linux/kselftest/"}
- {"dt": "2025-03-25T10:25:28.744376", "lvl": "target", "msg": "+ ./kselftest.sh -c clone3 -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-25T10:25:28.792582", "lvl": "target", "msg": "INFO: Generating a skipfile based on /lava-1/0/tests/0_kselftest-clone3/automated/linux/kselftest/skipfile-lkft.yaml"}
- {"dt": "2025-03-25T10:25:28.947227", "lvl": "target", "msg": "INFO: Using the following generated skipfile contents (until EOF):"}
- {"dt": "2025-03-25T10:25:28.952670", "lvl": "target", "msg": "bpf:test_btf"}
- {"dt": "2025-03-25T10:25:28.952967", "lvl": "target", "msg": "bpf:test_progs"}
- {"dt": "2025-03-25T10:25:28.953051", "lvl": "target", "msg": "breakpoints:breakpoint_test"}
- {"dt": "2025-03-25T10:25:28.953124", "lvl": "target", "msg": "breakpoints:breakpoint_test_arm64"}
- {"dt": "2025-03-25T10:25:28.953195", "lvl": "target", "msg": "breakpoints:step_after_suspend_test"}
- {"dt": "2025-03-25T10:25:28.953266", "lvl": "target", "msg": "kmod:test_kmod.sh"}
- {"dt": "2025-03-25T10:25:28.953320", "lvl": "target", "msg": "kvm:get-reg-list"}
- {"dt": "2025-03-25T10:25:28.953370", "lvl": "target", "msg": "kvm:kvm_create_max_vcpus"}
- {"dt": "2025-03-25T10:25:28.953419", "lvl": "target", "msg": "mqueue:mq_open_tests"}
- {"dt": "2025-03-25T10:25:28.953479", "lvl": "target", "msg": "mqueue:mq_perf_tests"}
- {"dt": "2025-03-25T10:25:28.953533", "lvl": "target", "msg": "net:fib_nexthops.sh"}
- {"dt": "2025-03-25T10:25:28.953583", "lvl": "target", "msg": "net:msg_zerocopy.sh"}
- {"dt": "2025-03-25T10:25:28.953630", "lvl": "target", "msg": "net:rtnetlink.sh"}
- {"dt": "2025-03-25T10:25:28.953689", "lvl": "target", "msg": "net:run_afpackettests"}
- {"dt": "2025-03-25T10:25:28.953742", "lvl": "target", "msg": "net:tls"}
- {"dt": "2025-03-25T10:25:28.953818", "lvl": "target", "msg": "net:udpgro.sh"}
- {"dt": "2025-03-25T10:25:28.953869", "lvl": "target", "msg": "net:xfrm_policy.sh"}
- {"dt": "2025-03-25T10:25:28.953932", "lvl": "target", "msg": "netfilter:bridge_brouter.sh"}
- {"dt": "2025-03-25T10:25:28.953984", "lvl": "target", "msg": "netfilter:conntrack_icmp_related.sh"}
- {"dt": "2025-03-25T10:25:28.954196", "lvl": "target", "msg": "netfilter:nft_flowtable.sh"}
- {"dt": "2025-03-25T10:25:28.954238", "lvl": "target", "msg": "netfilter:nft_nat.sh"}
- {"dt": "2025-03-25T10:25:28.954283", "lvl": "target", "msg": "netfilter:nft_trans_stress.sh"}
- {"dt": "2025-03-25T10:25:28.954328", "lvl": "target", "msg": "pidfd:pidfd_wait"}
- {"dt": "2025-03-25T10:25:28.954375", "lvl": "target", "msg": "proc:proc-pid-vm"}
- {"dt": "2025-03-25T10:25:28.954593", "lvl": "target", "msg": "ptrace:vmaccess"}
- {"dt": "2025-03-25T10:25:28.954637", "lvl": "target", "msg": "rseq:run_param_test.sh"}
- {"dt": "2025-03-25T10:25:28.954674", "lvl": "target", "msg": "sync:sync_test"}
- {"dt": "2025-03-25T10:25:28.954716", "lvl": "target", "msg": "vm:run_vmtests"}
- {"dt": "2025-03-25T10:25:28.954752", "lvl": "target", "msg": "zram:zram.sh"}
- {"dt": "2025-03-25T10:25:28.955990", "lvl": "target", "msg": "INFO: EOF"}
- {"dt": "2025-03-25T10:25:29.003505", "lvl": "target", "msg": "INFO: Installing sed perl wget xz-utils iproute2 python3-tap"}
- {"dt": "2025-03-25T10:25:29.318683", "lvl": "target", "msg": "Ign:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T10:25:30.323758", "lvl": "target", "msg": "Ign:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T10:25:32.328735", "lvl": "target", "msg": "Ign:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T10:25:36.334731", "lvl": "target", "msg": "Err:1 https://deb.debian.org/debian trixie InRelease"}
- {"dt": "2025-03-25T10:25:36.334897", "lvl": "target", "msg": "  Temporary failure resolving 'deb.debian.org'"}
- {"dt": "2025-03-25T10:25:36.441163", "lvl": "target", "msg": "Reading package lists..."}
- {"dt": "2025-03-25T10:25:36.458305", "lvl": "target", "msg": "W: Failed to fetch https://deb.debian.org/debian/dists/trixie/InRelease  Temporary failure resolving 'deb.debian.org'"}
- {"dt": "2025-03-25T10:25:36.458767", "lvl": "target", "msg": "W: Some index files failed to download. They have been ignored, or old ones used instead."}
- {"dt": "2025-03-25T10:25:36.545619", "lvl": "target", "msg": "Reading package lists..."}
- {"dt": "2025-03-25T10:25:36.568048", "lvl": "target", "msg": "Building dependency tree..."}
- {"dt": "2025-03-25T10:25:36.571283", "lvl": "target", "msg": "Reading state information..."}
- {"dt": "2025-03-25T10:25:36.589745", "lvl": "target", "msg": "sed is already the newest version (4.9-2+b1)."}
- {"dt": "2025-03-25T10:25:36.590083", "lvl": "target", "msg": "perl is already the newest version (5.40.0-8)."}
- {"dt": "2025-03-25T10:25:36.590214", "lvl": "target", "msg": "wget is already the newest version (1.24.5-2)."}
- {"dt": "2025-03-25T10:25:36.590400", "lvl": "target", "msg": "xz-utils is already the newest version (5.6.3-1+b1)."}
- {"dt": "2025-03-25T10:25:36.590736", "lvl": "target", "msg": "iproute2 is already the newest version (6.13.0-1)."}
- {"dt": "2025-03-25T10:25:36.590810", "lvl": "target", "msg": "python3-tap is already the newest version (3.2.1-1)."}
- {"dt": "2025-03-25T10:25:36.673118", "lvl": "target", "msg": "0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded."}
- {"dt": "2025-03-25T10:25:36.699758", "lvl": "target", "msg": "kselftests found on rootfs"}
- {"dt": "2025-03-25T10:25:36.732644", "lvl": "target", "msg": "skiplist:"}
- {"dt": "2025-03-25T10:25:36.732739", "lvl": "target", "msg": "========================================"}
- {"dt": "2025-03-25T10:25:36.733314", "lvl": "target", "msg": "bpf:test_btf"}
- {"dt": "2025-03-25T10:25:36.826016", "lvl": "target", "msg": "bpf:test_progs"}
- {"dt": "2025-03-25T10:25:36.846613", "lvl": "target", "msg": "breakpoints:breakpoint_test"}
- {"dt": "2025-03-25T10:25:36.865683", "lvl": "target", "msg": "breakpoints:breakpoint_test_arm64"}
- {"dt": "2025-03-25T10:25:36.888416", "lvl": "target", "msg": "breakpoints:step_after_suspend_test"}
- {"dt": "2025-03-25T10:25:36.907752", "lvl": "target", "msg": "kmod:test_kmod.sh"}
- {"dt": "2025-03-25T10:25:36.926280", "lvl": "target", "msg": "kvm:get-reg-list"}
- {"dt": "2025-03-25T10:25:36.945828", "lvl": "target", "msg": "kvm:kvm_create_max_vcpus"}
- {"dt": "2025-03-25T10:25:36.964969", "lvl": "target", "msg": "mqueue:mq_open_tests"}
- {"dt": "2025-03-25T10:25:36.983815", "lvl": "target", "msg": "mqueue:mq_perf_tests"}
- {"dt": "2025-03-25T10:25:37.003779", "lvl": "target", "msg": "net:fib_nexthops.sh"}
- {"dt": "2025-03-25T10:25:37.023546", "lvl": "target", "msg": "net:msg_zerocopy.sh"}
- {"dt": "2025-03-25T10:25:37.042407", "lvl": "target", "msg": "net:rtnetlink.sh"}
- {"dt": "2025-03-25T10:25:37.061646", "lvl": "target", "msg": "net:run_afpackettests"}
- {"dt": "2025-03-25T10:25:37.080942", "lvl": "target", "msg": "net:tls"}
- {"dt": "2025-03-25T10:25:37.100258", "lvl": "target", "msg": "net:udpgro.sh"}
- {"dt": "2025-03-25T10:25:37.120160", "lvl": "target", "msg": "net:xfrm_policy.sh"}
- {"dt": "2025-03-25T10:25:37.140519", "lvl": "target", "msg": "netfilter:bridge_brouter.sh"}
- {"dt": "2025-03-25T10:25:37.159368", "lvl": "target", "msg": "netfilter:conntrack_icmp_related.sh"}
- {"dt": "2025-03-25T10:25:37.177793", "lvl": "target", "msg": "netfilter:nft_flowtable.sh"}
- {"dt": "2025-03-25T10:25:37.196451", "lvl": "target", "msg": "netfilter:nft_nat.sh"}
- {"dt": "2025-03-25T10:25:37.215156", "lvl": "target", "msg": "netfilter:nft_trans_stress.sh"}
- {"dt": "2025-03-25T10:25:37.233375", "lvl": "target", "msg": "pidfd:pidfd_wait"}
- {"dt": "2025-03-25T10:25:37.253910", "lvl": "target", "msg": "proc:proc-pid-vm"}
- {"dt": "2025-03-25T10:25:37.272585", "lvl": "target", "msg": "ptrace:vmaccess"}
- {"dt": "2025-03-25T10:25:37.291877", "lvl": "target", "msg": "rseq:run_param_test.sh"}
- {"dt": "2025-03-25T10:25:37.311467", "lvl": "target", "msg": "sync:sync_test"}
- {"dt": "2025-03-25T10:25:37.330986", "lvl": "target", "msg": "vm:run_vmtests"}
- {"dt": "2025-03-25T10:25:37.351390", "lvl": "target", "msg": "zram:zram.sh"}
- {"dt": "2025-03-25T10:25:37.371132", "lvl": "target", "msg": "========================================"}
- {"dt": "2025-03-25T10:25:37.408814", "lvl": "target", "msg": "clone3:clone3"}
- {"dt": "2025-03-25T10:25:37.409090", "lvl": "target", "msg": "clone3:clone3_clear_sighand"}
- {"dt": "2025-03-25T10:25:37.409174", "lvl": "target", "msg": "clone3:clone3_set_tid"}
- {"dt": "2025-03-25T10:25:37.409248", "lvl": "target", "msg": "clone3:clone3_cap_checkpoint_restore"}
- {"dt": "2025-03-25T10:25:37.419354", "lvl": "target", "msg": "============== Tests to run ==============="}
- {"dt": "2025-03-25T10:25:37.423507", "lvl": "target", "msg": "clone3:clone3"}
- {"dt": "2025-03-25T10:25:37.423587", "lvl": "target", "msg": "clone3:clone3_clear_sighand"}
- {"dt": "2025-03-25T10:25:37.423662", "lvl": "target", "msg": "clone3:clone3_set_tid"}
- {"dt": "2025-03-25T10:25:37.423747", "lvl": "target", "msg": "clone3:clone3_cap_checkpoint_restore"}
- {"dt": "2025-03-25T10:25:37.424816", "lvl": "target", "msg": "===========End Tests to run ==============="}
- {"dt": "2025-03-25T10:25:37.431993", "lvl": "target", "msg": "shardfile-clone3 pass"}
- {"dt": "2025-03-25T10:25:37.578434", "lvl": "target", "msg": "<12>[   22.329029] kselftest: Running tests in clone3"}
- {"dt": "2025-03-25T10:25:37.594340", "lvl": "target", "msg": "TAP version 13"}
- {"dt": "2025-03-25T10:25:37.607308", "lvl": "target", "msg": "1..4"}
- {"dt": "2025-03-25T10:25:37.637234", "lvl": "target", "msg": "# timeout set to 45"}
- {"dt": "2025-03-25T10:25:37.637314", "lvl": "target", "msg": "# selftests: clone3: clone3"}
- {"dt": "2025-03-25T10:25:37.857272", "lvl": "target", "msg": "# TAP version 13"}
- {"dt": "2025-03-25T10:25:37.857359", "lvl": "target", "msg": "# 1..19"}
- {"dt": "2025-03-25T10:25:37.857794", "lvl": "target", "msg": "# # clone3() syscall supported"}
- {"dt": "2025-03-25T10:25:37.858450", "lvl": "target", "msg": "# # Running test 'simple clone3()'"}
- {"dt": "2025-03-25T10:25:37.859526", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 0)"}
- {"dt": "2025-03-25T10:25:37.860449", "lvl": "target", "msg": "# # I am the parent (349). My child's pid is 350"}
- {"dt": "2025-03-25T10:25:37.861075", "lvl": "target", "msg": "# # I am the child, my PID is 350"}
- {"dt": "2025-03-25T10:25:37.862403", "lvl": "target", "msg": "# # [349] clone3() with flags says: 0 expected 0"}
- {"dt": "2025-03-25T10:25:37.862849", "lvl": "target", "msg": "# ok 1 simple clone3()"}
- {"dt": "2025-03-25T10:25:37.863758", "lvl": "target", "msg": "# # Running test 'clone3() in a new PID_NS'"}
- {"dt": "2025-03-25T10:25:37.864812", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0x20000000 (size 0)"}
- {"dt": "2025-03-25T10:25:37.865863", "lvl": "target", "msg": "# # I am the parent (349). My child's pid is 351"}
- {"dt": "2025-03-25T10:25:37.866659", "lvl": "target", "msg": "# # I am the child, my PID is 1"}
- {"dt": "2025-03-25T10:25:37.867587", "lvl": "target", "msg": "# # [349] clone3() with flags says: 0 expected 0"}
- {"dt": "2025-03-25T10:25:37.868308", "lvl": "target", "msg": "# ok 2 clone3() in a new PID_NS"}
- {"dt": "2025-03-25T10:25:37.869040", "lvl": "target", "msg": "# # Running test 'CLONE_ARGS_SIZE_VER0'"}
- {"dt": "2025-03-25T10:25:37.870290", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 64)"}
- {"dt": "2025-03-25T10:25:37.871193", "lvl": "target", "msg": "# # I am the parent (349). My child's pid is 352"}
- {"dt": "2025-03-25T10:25:37.871920", "lvl": "target", "msg": "# # I am the child, my PID is 352"}
- {"dt": "2025-03-25T10:25:37.872983", "lvl": "target", "msg": "# # [349] clone3() with flags says: 0 expected 0"}
- {"dt": "2025-03-25T10:25:37.873537", "lvl": "target", "msg": "# ok 3 CLONE_ARGS_SIZE_VER0"}
- {"dt": "2025-03-25T10:25:37.874518", "lvl": "target", "msg": "# # Running test 'CLONE_ARGS_SIZE_VER0 - 8'"}
- {"dt": "2025-03-25T10:25:37.875513", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 56)"}
- {"dt": "2025-03-25T10:25:37.876784", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.877872", "lvl": "target", "msg": "# # [349] clone3() with flags says: -22 expected -22"}
- {"dt": "2025-03-25T10:25:37.878614", "lvl": "target", "msg": "# ok 4 CLONE_ARGS_SIZE_VER0 - 8"}
- {"dt": "2025-03-25T10:25:37.879552", "lvl": "target", "msg": "# # Running test 'sizeof(struct clone_args) + 8'"}
- {"dt": "2025-03-25T10:25:37.880649", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 96)"}
- {"dt": "2025-03-25T10:25:37.881739", "lvl": "target", "msg": "# # I am the parent (349). My child's pid is 353"}
- {"dt": "2025-03-25T10:25:37.882496", "lvl": "target", "msg": "# # I am the child, my PID is 353"}
- {"dt": "2025-03-25T10:25:37.883425", "lvl": "target", "msg": "# # [349] clone3() with flags says: 0 expected 0"}
- {"dt": "2025-03-25T10:25:37.884189", "lvl": "target", "msg": "# ok 5 sizeof(struct clone_args) + 8"}
- {"dt": "2025-03-25T10:25:37.885622", "lvl": "target", "msg": "# # Running test 'exit_signal with highest 32 bits non-zero'"}
- {"dt": "2025-03-25T10:25:37.886567", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 0)"}
- {"dt": "2025-03-25T10:25:37.887856", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.888951", "lvl": "target", "msg": "# # [349] clone3() with flags says: -22 expected -22"}
- {"dt": "2025-03-25T10:25:37.890061", "lvl": "target", "msg": "# ok 6 exit_signal with highest 32 bits non-zero"}
- {"dt": "2025-03-25T10:25:37.890989", "lvl": "target", "msg": "# # Running test 'negative 32-bit exit_signal'"}
- {"dt": "2025-03-25T10:25:37.892106", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 0)"}
- {"dt": "2025-03-25T10:25:37.893217", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.894449", "lvl": "target", "msg": "# # [349] clone3() with flags says: -22 expected -22"}
- {"dt": "2025-03-25T10:25:37.895216", "lvl": "target", "msg": "# ok 7 negative 32-bit exit_signal"}
- {"dt": "2025-03-25T10:25:37.896471", "lvl": "target", "msg": "# # Running test 'exit_signal not fitting into CSIGNAL mask'"}
- {"dt": "2025-03-25T10:25:37.897549", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 0)"}
- {"dt": "2025-03-25T10:25:37.898669", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.899929", "lvl": "target", "msg": "# # [349] clone3() with flags says: -22 expected -22"}
- {"dt": "2025-03-25T10:25:37.900882", "lvl": "target", "msg": "# ok 8 exit_signal not fitting into CSIGNAL mask"}
- {"dt": "2025-03-25T10:25:37.901947", "lvl": "target", "msg": "# # Running test 'NSIG < exit_signal < CSIG'"}
- {"dt": "2025-03-25T10:25:37.903025", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 0)"}
- {"dt": "2025-03-25T10:25:37.904109", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.905191", "lvl": "target", "msg": "# # [349] clone3() with flags says: -22 expected -22"}
- {"dt": "2025-03-25T10:25:37.905944", "lvl": "target", "msg": "# ok 9 NSIG < exit_signal < CSIG"}
- {"dt": "2025-03-25T10:25:37.907215", "lvl": "target", "msg": "# # Running test 'Arguments sizeof(struct clone_args) + 8'"}
- {"dt": "2025-03-25T10:25:37.908305", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 96)"}
- {"dt": "2025-03-25T10:25:37.909401", "lvl": "target", "msg": "# # I am the parent (349). My child's pid is 354"}
- {"dt": "2025-03-25T10:25:37.910117", "lvl": "target", "msg": "# # I am the child, my PID is 354"}
- {"dt": "2025-03-25T10:25:37.911204", "lvl": "target", "msg": "# # [349] clone3() with flags says: 0 expected 0"}
- {"dt": "2025-03-25T10:25:37.912151", "lvl": "target", "msg": "# ok 10 Arguments sizeof(struct clone_args) + 8"}
- {"dt": "2025-03-25T10:25:37.913578", "lvl": "target", "msg": "# # Running test 'Arguments sizeof(struct clone_args) + 16'"}
- {"dt": "2025-03-25T10:25:37.914741", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 104)"}
- {"dt": "2025-03-25T10:25:37.915964", "lvl": "target", "msg": "# # Argument list too long - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.917050", "lvl": "target", "msg": "# # [349] clone3() with flags says: -7 expected -7"}
- {"dt": "2025-03-25T10:25:37.918189", "lvl": "target", "msg": "# ok 11 Arguments sizeof(struct clone_args) + 16"}
- {"dt": "2025-03-25T10:25:37.919308", "lvl": "target", "msg": "# # Running test 'Arguments sizeof(struct clone_arg) * 2'"}
- {"dt": "2025-03-25T10:25:37.920442", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 104)"}
- {"dt": "2025-03-25T10:25:37.921527", "lvl": "target", "msg": "# # Argument list too long - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.922804", "lvl": "target", "msg": "# # [349] clone3() with flags says: -7 expected -7"}
- {"dt": "2025-03-25T10:25:37.923720", "lvl": "target", "msg": "# ok 12 Arguments sizeof(struct clone_arg) * 2"}
- {"dt": "2025-03-25T10:25:37.924635", "lvl": "target", "msg": "# # Running test 'Arguments > page size'"}
- {"dt": "2025-03-25T10:25:37.925715", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0 (size 4104)"}
- {"dt": "2025-03-25T10:25:37.926967", "lvl": "target", "msg": "# # Argument list too long - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.928171", "lvl": "target", "msg": "# # [349] clone3() with flags says: -7 expected -7"}
- {"dt": "2025-03-25T10:25:37.928831", "lvl": "target", "msg": "# ok 13 Arguments > page size"}
- {"dt": "2025-03-25T10:25:37.930120", "lvl": "target", "msg": "# # Running test 'CLONE_ARGS_SIZE_VER0 in a new PID NS'"}
- {"dt": "2025-03-25T10:25:37.931390", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0x20000000 (size 64)"}
- {"dt": "2025-03-25T10:25:37.932323", "lvl": "target", "msg": "# # I am the parent (349). My child's pid is 355"}
- {"dt": "2025-03-25T10:25:37.933069", "lvl": "target", "msg": "# # I am the child, my PID is 1"}
- {"dt": "2025-03-25T10:25:37.934174", "lvl": "target", "msg": "# # [349] clone3() with flags says: 0 expected 0"}
- {"dt": "2025-03-25T10:25:37.935151", "lvl": "target", "msg": "# ok 14 CLONE_ARGS_SIZE_VER0 in a new PID NS"}
- {"dt": "2025-03-25T10:25:37.936420", "lvl": "target", "msg": "# # Running test 'CLONE_ARGS_SIZE_VER0 - 8 in a new PID NS'"}
- {"dt": "2025-03-25T10:25:37.937703", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0x20000000 (size 56)"}
- {"dt": "2025-03-25T10:25:37.938794", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.940044", "lvl": "target", "msg": "# # [349] clone3() with flags says: -22 expected -22"}
- {"dt": "2025-03-25T10:25:37.941114", "lvl": "target", "msg": "# ok 15 CLONE_ARGS_SIZE_VER0 - 8 in a new PID NS"}
- {"dt": "2025-03-25T10:25:37.942534", "lvl": "target", "msg": "# # Running test 'sizeof(struct clone_args) + 8 in a new PID NS'"}
- {"dt": "2025-03-25T10:25:37.943780", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0x20000000 (size 96)"}
- {"dt": "2025-03-25T10:25:37.944893", "lvl": "target", "msg": "# # I am the parent (349). My child's pid is 356"}
- {"dt": "2025-03-25T10:25:37.945470", "lvl": "target", "msg": "# # I am the child, my PID is 1"}
- {"dt": "2025-03-25T10:25:37.946604", "lvl": "target", "msg": "# # [349] clone3() with flags says: 0 expected 0"}
- {"dt": "2025-03-25T10:25:37.947712", "lvl": "target", "msg": "# ok 16 sizeof(struct clone_args) + 8 in a new PID NS"}
- {"dt": "2025-03-25T10:25:37.948989", "lvl": "target", "msg": "# # Running test 'Arguments > page size in a new PID NS'"}
- {"dt": "2025-03-25T10:25:37.950246", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0x20000000 (size 4104)"}
- {"dt": "2025-03-25T10:25:37.951486", "lvl": "target", "msg": "# # Argument list too long - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.952748", "lvl": "target", "msg": "# # [349] clone3() with flags says: -7 expected -7"}
- {"dt": "2025-03-25T10:25:37.953671", "lvl": "target", "msg": "# ok 17 Arguments > page size in a new PID NS"}
- {"dt": "2025-03-25T10:25:37.954427", "lvl": "target", "msg": "# # Running test 'New time NS'"}
- {"dt": "2025-03-25T10:25:37.955517", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0x80 (size 0)"}
- {"dt": "2025-03-25T10:25:37.956094", "lvl": "target", "msg": "# # I am the child, my PID is 357"}
- {"dt": "2025-03-25T10:25:37.957177", "lvl": "target", "msg": "# # I am the parent (349). My child's pid is 357"}
- {"dt": "2025-03-25T10:25:37.958452", "lvl": "target", "msg": "# # [349] clone3() with flags says: 0 expected 0"}
- {"dt": "2025-03-25T10:25:37.958863", "lvl": "target", "msg": "# ok 18 New time NS"}
- {"dt": "2025-03-25T10:25:37.959786", "lvl": "target", "msg": "# # Running test 'exit signal (SIGCHLD) in flags'"}
- {"dt": "2025-03-25T10:25:37.960876", "lvl": "target", "msg": "# # [349] Trying clone3() with flags 0x11 (size 0)"}
- {"dt": "2025-03-25T10:25:37.962118", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:37.963236", "lvl": "target", "msg": "# # [349] clone3() with flags says: -22 expected -22"}
- {"dt": "2025-03-25T10:25:37.964153", "lvl": "target", "msg": "# ok 19 exit signal (SIGCHLD) in flags"}
- {"dt": "2025-03-25T10:25:37.965406", "lvl": "target", "msg": "# # Totals: pass:19 fail:0 xfail:0 xpass:0 skip:0 error:0"}
- {"dt": "2025-03-25T10:25:37.972739", "lvl": "target", "msg": "ok 1 selftests: clone3: clone3"}
- {"dt": "2025-03-25T10:25:38.003815", "lvl": "target", "msg": "# timeout set to 45"}
- {"dt": "2025-03-25T10:25:38.003898", "lvl": "target", "msg": "# selftests: clone3: clone3_clear_sighand"}
- {"dt": "2025-03-25T10:25:38.135269", "lvl": "target", "msg": "# TAP version 13"}
- {"dt": "2025-03-25T10:25:38.135348", "lvl": "target", "msg": "# 1..1"}
- {"dt": "2025-03-25T10:25:38.135774", "lvl": "target", "msg": "# # clone3() syscall supported"}
- {"dt": "2025-03-25T10:25:38.136715", "lvl": "target", "msg": "# ok 1 Cleared signal handlers for child process"}
- {"dt": "2025-03-25T10:25:38.137777", "lvl": "target", "msg": "# # Totals: pass:1 fail:0 xfail:0 xpass:0 skip:0 error:0"}
- {"dt": "2025-03-25T10:25:38.145907", "lvl": "target", "msg": "ok 2 selftests: clone3: clone3_clear_sighand"}
- {"dt": "2025-03-25T10:25:38.178551", "lvl": "target", "msg": "# timeout set to 45"}
- {"dt": "2025-03-25T10:25:38.178629", "lvl": "target", "msg": "# selftests: clone3: clone3_set_tid"}
- {"dt": "2025-03-25T10:25:38.319203", "lvl": "target", "msg": "# TAP version 13"}
- {"dt": "2025-03-25T10:25:38.319468", "lvl": "target", "msg": "# 1..29"}
- {"dt": "2025-03-25T10:25:38.319895", "lvl": "target", "msg": "# # clone3() syscall supported"}
- {"dt": "2025-03-25T10:25:38.320457", "lvl": "target", "msg": "# # /proc/sys/kernel/pid_max 4194304"}
- {"dt": "2025-03-25T10:25:38.321706", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 0 and 0x0"}
- {"dt": "2025-03-25T10:25:38.322708", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.324150", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 0 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.325238", "lvl": "target", "msg": "# ok 1 invalid size, 0 TID with 33 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.326459", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 0 and 0x0"}
- {"dt": "2025-03-25T10:25:38.327577", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.328828", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 0 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.329893", "lvl": "target", "msg": "# ok 2 invalid size, 0 TID with 64 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.331308", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 0 and 0x0"}
- {"dt": "2025-03-25T10:25:38.332409", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.333711", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 0 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.334824", "lvl": "target", "msg": "# ok 3 invalid size, 0 TID with 65 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.335918", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 0 and 0x0"}
- {"dt": "2025-03-25T10:25:38.336987", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.338387", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 0 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.339673", "lvl": "target", "msg": "# ok 4 invalid size, 0 TID with 1344 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.340787", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 0 and 0x0"}
- {"dt": "2025-03-25T10:25:38.341717", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.343081", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 0 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.344223", "lvl": "target", "msg": "# ok 5 invalid size, 0 TID with 31 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.345307", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to -1 and 0x0"}
- {"dt": "2025-03-25T10:25:38.346548", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.347828", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID -1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.349080", "lvl": "target", "msg": "# ok 6 invalid size, TID all 1s with 33 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.350298", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to -1 and 0x0"}
- {"dt": "2025-03-25T10:25:38.351362", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.352783", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID -1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.353920", "lvl": "target", "msg": "# ok 7 invalid size, TID all 1s with 64 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.355167", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to -1 and 0x0"}
- {"dt": "2025-03-25T10:25:38.356247", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.357681", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID -1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.358911", "lvl": "target", "msg": "# ok 8 invalid size, TID all 1s with 65 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.360152", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to -1 and 0x0"}
- {"dt": "2025-03-25T10:25:38.361076", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.362557", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID -1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.363693", "lvl": "target", "msg": "# ok 9 invalid size, TID all 1s with 1344 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.364947", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to -1 and 0x0"}
- {"dt": "2025-03-25T10:25:38.366049", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.367308", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID -1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.368578", "lvl": "target", "msg": "# ok 10 invalid size, TID all 1s with 31 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.369838", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 0 and 0x0"}
- {"dt": "2025-03-25T10:25:38.370927", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.372180", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 0 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.373285", "lvl": "target", "msg": "# ok 11 valid size, 0 TID with 1 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.374566", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to -1 and 0x0"}
- {"dt": "2025-03-25T10:25:38.375661", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.376956", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID -1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.378234", "lvl": "target", "msg": "# ok 12 valid size, -1 TID with 1 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.379352", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to -1 and 0x0"}
- {"dt": "2025-03-25T10:25:38.380458", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.381749", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID -1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.382845", "lvl": "target", "msg": "# ok 13 2 TIDs, -1 and 0 with 2 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.384265", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to -1 and 0x20000000"}
- {"dt": "2025-03-25T10:25:38.385196", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.386624", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID -1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.387760", "lvl": "target", "msg": "# ok 14 valid size, -1 TID with 1 TIDs and flags 0x20000000"}
- {"dt": "2025-03-25T10:25:38.389049", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 1 and 0x0"}
- {"dt": "2025-03-25T10:25:38.389953", "lvl": "target", "msg": "# # File exists - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.391392", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 1 says: -17 - expected -17"}
- {"dt": "2025-03-25T10:25:38.392345", "lvl": "target", "msg": "# ok 15 duplicate PID 1 with 1 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.393615", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 1 and 0x20000000"}
- {"dt": "2025-03-25T10:25:38.394704", "lvl": "target", "msg": "# # I am the parent (394). My child's pid is 395"}
- {"dt": "2025-03-25T10:25:38.395643", "lvl": "target", "msg": "# # I am the child, my PID is 1 (expected 1)"}
- {"dt": "2025-03-25T10:25:38.396925", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 1 says: 0 - expected 0"}
- {"dt": "2025-03-25T10:25:38.398180", "lvl": "target", "msg": "# ok 16 duplicate PID 1 with 1 TIDs and flags 0x20000000"}
- {"dt": "2025-03-25T10:25:38.399456", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 4194304 and 0x0"}
- {"dt": "2025-03-25T10:25:38.400376", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.401947", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 4194304 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.403040", "lvl": "target", "msg": "# ok 17 set TID to maximum with 1 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.404475", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 4194304 and 0x20000000"}
- {"dt": "2025-03-25T10:25:38.405571", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.407090", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 4194304 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.408352", "lvl": "target", "msg": "# ok 18 set TID to maximum with 1 TIDs and flags 0x20000000"}
- {"dt": "2025-03-25T10:25:38.408752", "lvl": "target", "msg": "# # Child has PID 396"}
- {"dt": "2025-03-25T10:25:38.409829", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 396 and 0x0"}
- {"dt": "2025-03-25T10:25:38.411005", "lvl": "target", "msg": "# # I am the parent (394). My child's pid is 396"}
- {"dt": "2025-03-25T10:25:38.411937", "lvl": "target", "msg": "# # I am the child, my PID is 396 (expected 396)"}
- {"dt": "2025-03-25T10:25:38.413216", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 396 says: 0 - expected 0"}
- {"dt": "2025-03-25T10:25:38.414457", "lvl": "target", "msg": "# ok 19 reallocate child TID with 1 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.415722", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 396 and 0x20000000"}
- {"dt": "2025-03-25T10:25:38.416820", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.418118", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 396 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.419394", "lvl": "target", "msg": "# ok 20 duplicate child TID with 1 TIDs and flags 0x20000000"}
- {"dt": "2025-03-25T10:25:38.420674", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 1 and 0x20000000"}
- {"dt": "2025-03-25T10:25:38.421594", "lvl": "target", "msg": "# # I am the child, my PID is 1 (expected 1)"}
- {"dt": "2025-03-25T10:25:38.422650", "lvl": "target", "msg": "# # I am the parent (394). My child's pid is 396"}
- {"dt": "2025-03-25T10:25:38.423890", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 1 says: 0 - expected 0"}
- {"dt": "2025-03-25T10:25:38.425134", "lvl": "target", "msg": "# ok 21 create PID 1 in new NS with 2 TIDs and flags 0x20000000"}
- {"dt": "2025-03-25T10:25:38.425699", "lvl": "target", "msg": "# # unshare PID namespace"}
- {"dt": "2025-03-25T10:25:38.427099", "lvl": "target", "msg": "# # [394] Trying clone3() with CLONE_SET_TID to 396 and 0x0"}
- {"dt": "2025-03-25T10:25:38.428019", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.429437", "lvl": "target", "msg": "# # [394] clone3() with CLONE_SET_TID 396 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.430515", "lvl": "target", "msg": "# ok 22 duplicate PID 1 with 1 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.431761", "lvl": "target", "msg": "# # [1] Trying clone3() with CLONE_SET_TID to 43 and 0x0"}
- {"dt": "2025-03-25T10:25:38.432699", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.433962", "lvl": "target", "msg": "# # [1] clone3() with CLONE_SET_TID 43 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.435663", "lvl": "target", "msg": "# ok 23 check leak on invalid TID -1 with 2 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.436768", "lvl": "target", "msg": "# # [1] Trying clone3() with CLONE_SET_TID to 43 and 0x0"}
- {"dt": "2025-03-25T10:25:38.437680", "lvl": "target", "msg": "# # I am the parent (1). My child's pid is 43"}
- {"dt": "2025-03-25T10:25:38.438583", "lvl": "target", "msg": "# # I am the child, my PID is 43 (expected 43)"}
- {"dt": "2025-03-25T10:25:38.439833", "lvl": "target", "msg": "# # [1] clone3() with CLONE_SET_TID 43 says: 0 - expected 0"}
- {"dt": "2025-03-25T10:25:38.441242", "lvl": "target", "msg": "# ok 24 check leak on invalid specific TID with 2 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.442118", "lvl": "target", "msg": "# # Child in PID namespace has PID 1"}
- {"dt": "2025-03-25T10:25:38.443180", "lvl": "target", "msg": "# # [1] Trying clone3() with CLONE_SET_TID to 2 and 0x0"}
- {"dt": "2025-03-25T10:25:38.444076", "lvl": "target", "msg": "# # I am the parent (1). My child's pid is 2"}
- {"dt": "2025-03-25T10:25:38.444973", "lvl": "target", "msg": "# # I am the child, my PID is 2 (expected 2)"}
- {"dt": "2025-03-25T10:25:38.446213", "lvl": "target", "msg": "# # [1] clone3() with CLONE_SET_TID 2 says: 0 - expected 0"}
- {"dt": "2025-03-25T10:25:38.447444", "lvl": "target", "msg": "# ok 25 create PID 2 in child NS with 1 TIDs and flags 0x0"}
- {"dt": "2025-03-25T10:25:38.448701", "lvl": "target", "msg": "# # [1] Trying clone3() with CLONE_SET_TID to 1 and 0x20000000"}
- {"dt": "2025-03-25T10:25:38.449610", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.451057", "lvl": "target", "msg": "# # [1] clone3() with CLONE_SET_TID 1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.452668", "lvl": "target", "msg": "# ok 26 fail due to invalid TID at level 1 with 3 TIDs and flags 0x20000000"}
- {"dt": "2025-03-25T10:25:38.453801", "lvl": "target", "msg": "# # [1] Trying clone3() with CLONE_SET_TID to 1 and 0x20000000"}
- {"dt": "2025-03-25T10:25:38.455064", "lvl": "target", "msg": "# # Invalid argument - Failed to create new process"}
- {"dt": "2025-03-25T10:25:38.456296", "lvl": "target", "msg": "# # [1] clone3() with CLONE_SET_TID 1 says: -22 - expected -22"}
- {"dt": "2025-03-25T10:25:38.457698", "lvl": "target", "msg": "# ok 27 fail due to too few active PID NSs with 4 TIDs and flags 0x20000000"}
- {"dt": "2025-03-25T10:25:38.458969", "lvl": "target", "msg": "# # [1] Trying clone3() with CLONE_SET_TID to 1 and 0x20000000"}
- {"dt": "2025-03-25T10:25:38.460045", "lvl": "target", "msg": "# # I am the parent (1). My child's pid is 42"}
- {"dt": "2025-03-25T10:25:38.460952", "lvl": "target", "msg": "# # I am the child, my PID is 1 (expected 1)"}
- {"dt": "2025-03-25T10:25:38.461512", "lvl": "target", "msg": "# # [1] Child is ready and waiting"}
- {"dt": "2025-03-25T10:25:38.462410", "lvl": "target", "msg": "# # [394] Child is ready and waiting"}
- {"dt": "2025-03-25T10:25:38.463663", "lvl": "target", "msg": "# # [1] clone3() with CLONE_SET_TID 1 says: 0 - expected 0"}
- {"dt": "2025-03-25T10:25:38.464945", "lvl": "target", "msg": "# ok 28 verify that we have 3 PID NSs with 3 TIDs and flags 0x20000000"}
- {"dt": "2025-03-25T10:25:38.465514", "lvl": "target", "msg": "# # Expecting PIDs 396, 42, 1"}
- {"dt": "2025-03-25T10:25:38.466422", "lvl": "target", "msg": "# # Have PIDs in namespaces: 396, 42, 1"}
- {"dt": "2025-03-25T10:25:38.467320", "lvl": "target", "msg": "# ok 29 PIDs in all namespaces as expected"}
- {"dt": "2025-03-25T10:25:38.468383", "lvl": "target", "msg": "# # Totals: pass:29 fail:0 xfail:0 xpass:0 skip:0 error:0"}
- {"dt": "2025-03-25T10:25:38.475571", "lvl": "target", "msg": "ok 3 selftests: clone3: clone3_set_tid"}
- {"dt": "2025-03-25T10:25:38.507141", "lvl": "target", "msg": "# timeout set to 45"}
- {"dt": "2025-03-25T10:25:38.507219", "lvl": "target", "msg": "# selftests: clone3: clone3_cap_checkpoint_restore"}
- {"dt": "2025-03-25T10:25:38.649728", "lvl": "target", "msg": "# TAP version 13"}
- {"dt": "2025-03-25T10:25:38.649815", "lvl": "target", "msg": "# 1..1"}
- {"dt": "2025-03-25T10:25:38.650470", "lvl": "target", "msg": "# # Starting 1 tests from 1 test cases."}
- {"dt": "2025-03-25T10:25:38.651575", "lvl": "target", "msg": "# #  RUN           global.clone3_cap_checkpoint_restore ..."}
- {"dt": "2025-03-25T10:25:38.652315", "lvl": "target", "msg": "# # clone3() syscall supported"}
- {"dt": "2025-03-25T10:25:38.654347", "lvl": "target", "msg": "# # clone3_cap_checkpoint_restore.c:151:clone3_cap_checkpoint_restore:Child has PID 418"}
- {"dt": "2025-03-25T10:25:38.654773", "lvl": "target", "msg": "# cap_set_proc: Operation not permitted"}
- {"dt": "2025-03-25T10:25:38.657064", "lvl": "target", "msg": "# # clone3_cap_checkpoint_restore.c:160:clone3_cap_checkpoint_restore:Expected set_capability() (-1) == 0 (0)"}
- {"dt": "2025-03-25T10:25:38.659304", "lvl": "target", "msg": "# # clone3_cap_checkpoint_restore.c:161:clone3_cap_checkpoint_restore:Could not set CAP_CHECKPOINT_RESTORE"}
- {"dt": "2025-03-25T10:25:38.660594", "lvl": "target", "msg": "# # clone3_cap_checkpoint_restore: Test terminated by assertion"}
- {"dt": "2025-03-25T10:25:38.661674", "lvl": "target", "msg": "# #          FAIL  global.clone3_cap_checkpoint_restore"}
- {"dt": "2025-03-25T10:25:38.662741", "lvl": "target", "msg": "# not ok 1 global.clone3_cap_checkpoint_restore"}
- {"dt": "2025-03-25T10:25:38.663304", "lvl": "target", "msg": "# # FAILED: 0 / 1 tests passed."}
- {"dt": "2025-03-25T10:25:38.664386", "lvl": "target", "msg": "# # Totals: pass:0 fail:1 xfail:0 xpass:0 skip:0 error:0"}
- {"dt": "2025-03-25T10:25:38.673925", "lvl": "target", "msg": "not ok 4 selftests: clone3: clone3_cap_checkpoint_restore # exit=1"}
- {"dt": "2025-03-25T10:25:39.566695", "lvl": "target", "msg": ""}
- {"dt": "2025-03-25T10:25:39.567058", "lvl": "target", "msg": "WARNING: Optional imports not found, TAP 13 output will be"}
- {"dt": "2025-03-25T10:25:39.567130", "lvl": "target", "msg": "    ignored. To parse yaml, see requirements in docs:"}
- {"dt": "2025-03-25T10:25:39.567235", "lvl": "target", "msg": "    https://tappy.readthedocs.io/en/latest/consumers.html#tap-version-13"}
- {"dt": "2025-03-25T10:25:39.573731", "lvl": "target", "msg": "Traceback (most recent call last):"}
- {"dt": "2025-03-25T10:25:39.585307", "lvl": "target", "msg": "  File [35m\"/lava-1/0/tests/0_kselftest-clone3/automated/linux/kselftest/./parse-output.py\"[0m, line [35m93[0m, in [35m<module>[0m"}
- {"dt": "2025-03-25T10:25:39.585382", "lvl": "target", "msg": "    results = parse_nested_tap(sys.stdin.read())"}
- {"dt": "2025-03-25T10:25:39.585870", "lvl": "target", "msg": "  File [35m\"/lava-1/0/tests/0_kselftest-clone3/automated/linux/kselftest/./parse-output.py\"[0m, line [35m51[0m, in [35mparse_nested_tap[0m"}
- {"dt": "2025-03-25T10:25:39.585933", "lvl": "target", "msg": "    \"children\": [31mparse_nested_tap[0m[1;31m(output)[0m,"}
- {"dt": "2025-03-25T10:25:39.586187", "lvl": "target", "msg": "                [31m~~~~~~~~~~~~~~~~[0m[1;31m^^^^^^^^[0m"}
- {"dt": "2025-03-25T10:25:39.586801", "lvl": "target", "msg": "  File [35m\"/lava-1/0/tests/0_kselftest-clone3/automated/linux/kselftest/./parse-output.py\"[0m, line [35m59[0m, in [35mparse_nested_tap[0m"}
- {"dt": "2025-03-25T10:25:39.586871", "lvl": "target", "msg": "    [31mr[0m[1;31m[\"logs\"][0m += f\"{uncomment(l.text)}\\n\""}
- {"dt": "2025-03-25T10:25:39.586942", "lvl": "target", "msg": "    [31m~[0m[1;31m^^^^^^^^[0m"}
- {"dt": "2025-03-25T10:25:39.587199", "lvl": "target", "msg": "[1;35mKeyError[0m: [35m'logs'[0m"}
- {"dt": "2025-03-25T10:25:39.654201", "lvl": "target", "msg": "+ ../../utils/send-to-lava.sh ./output/result.txt"}
- {"dt": "2025-03-25T10:25:39.684626", "lvl": "target", "msg": "WARNING: no log file found for breakpoints:breakpoint_test_arm64 at ./output/breakpoints:breakpoint_test_arm64.log"}
- {"dt": "2025-03-25T10:25:39.699700", "lvl": "target", "msg": "<8>[   24.450435] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=breakpoints:breakpoint_test_arm64 RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.699984", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=breakpoints:breakpoint_test_arm64 RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.700095", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "breakpoints:breakpoint_test_arm64", "result": "skip", "starttc": ! "1104", "endtc": ! "1104"}}
- {"dt": "2025-03-25T10:25:39.712228", "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-25T10:25:39.726184", "lvl": "target", "msg": "<8>[   24.476638] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=breakpoints:step_after_suspend_test RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.726421", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=breakpoints:step_after_suspend_test RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.726535", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "breakpoints:step_after_suspend_test", "result": "skip", "starttc": ! "1108", "endtc": ! "1108"}}
- {"dt": "2025-03-25T10:25:39.737888", "lvl": "target", "msg": "WARNING: no log file found for kvm:get-reg-list at ./output/kvm:get-reg-list.log"}
- {"dt": "2025-03-25T10:25:39.751708", "lvl": "target", "msg": "<8>[   24.502462] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=kvm:get-reg-list RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.751966", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=kvm:get-reg-list RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.752088", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "kvm:get-reg-list", "result": "skip", "starttc": ! "1112", "endtc": ! "1112"}}
- {"dt": "2025-03-25T10:25:39.764145", "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-25T10:25:39.778313", "lvl": "target", "msg": "<8>[   24.528863] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=kvm:kvm_create_max_vcpus RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.778559", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=kvm:kvm_create_max_vcpus RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.778612", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "kvm:kvm_create_max_vcpus", "result": "skip", "starttc": ! "1116", "endtc": ! "1116"}}
- {"dt": "2025-03-25T10:25:39.789720", "lvl": "target", "msg": "WARNING: no log file found for mqueue:mq_open_tests at ./output/mqueue:mq_open_tests.log"}
- {"dt": "2025-03-25T10:25:39.803272", "lvl": "target", "msg": "<8>[   24.554060] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=mqueue:mq_open_tests RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.803529", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=mqueue:mq_open_tests RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.803608", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "mqueue:mq_open_tests", "result": "skip", "starttc": ! "1120", "endtc": ! "1120"}}
- {"dt": "2025-03-25T10:25:39.814850", "lvl": "target", "msg": "WARNING: no log file found for mqueue:mq_perf_tests at ./output/mqueue:mq_perf_tests.log"}
- {"dt": "2025-03-25T10:25:39.828164", "lvl": "target", "msg": "<8>[   24.579010] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=mqueue:mq_perf_tests RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.828422", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=mqueue:mq_perf_tests RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.828499", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "mqueue:mq_perf_tests", "result": "skip", "starttc": ! "1124", "endtc": ! "1124"}}
- {"dt": "2025-03-25T10:25:39.838957", "lvl": "target", "msg": "WARNING: no log file found for net:fib_nexthops.sh at ./output/net:fib_nexthops.sh.log"}
- {"dt": "2025-03-25T10:25:39.852563", "lvl": "target", "msg": "<8>[   24.603375] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:fib_nexthops.sh RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.852817", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:fib_nexthops.sh RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.852893", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "net:fib_nexthops.sh", "result": "skip", "starttc": ! "1128", "endtc": ! "1128"}}
- {"dt": "2025-03-25T10:25:39.863505", "lvl": "target", "msg": "WARNING: no log file found for net:msg_zerocopy.sh at ./output/net:msg_zerocopy.sh.log"}
- {"dt": "2025-03-25T10:25:39.877393", "lvl": "target", "msg": "<8>[   24.628173] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:msg_zerocopy.sh RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.877647", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:msg_zerocopy.sh RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.877739", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "net:msg_zerocopy.sh", "result": "skip", "starttc": ! "1132", "endtc": ! "1132"}}
- {"dt": "2025-03-25T10:25:39.888492", "lvl": "target", "msg": "WARNING: no log file found for net:rtnetlink.sh at ./output/net:rtnetlink.sh.log"}
- {"dt": "2025-03-25T10:25:39.902074", "lvl": "target", "msg": "<8>[   24.652676] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:rtnetlink.sh RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.902314", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:rtnetlink.sh RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.902391", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "net:rtnetlink.sh", "result": "skip", "starttc": ! "1136", "endtc": ! "1136"}}
- {"dt": "2025-03-25T10:25:39.913121", "lvl": "target", "msg": "WARNING: no log file found for net:run_afpackettests at ./output/net:run_afpackettests.log"}
- {"dt": "2025-03-25T10:25:39.926668", "lvl": "target", "msg": "<8>[   24.677468] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:run_afpackettests RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.926911", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:run_afpackettests RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.926984", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "net:run_afpackettests", "result": "skip", "starttc": ! "1140", "endtc": ! "1140"}}
- {"dt": "2025-03-25T10:25:39.937525", "lvl": "target", "msg": "WARNING: no log file found for net:tls at ./output/net:tls.log"}
- {"dt": "2025-03-25T10:25:39.951069", "lvl": "target", "msg": "<8>[   24.701909] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:tls RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.951315", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:tls RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.951387", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "net:tls", "result": "skip", "starttc": ! "1144", "endtc": ! "1144"}}
- {"dt": "2025-03-25T10:25:39.963506", "lvl": "target", "msg": "WARNING: no log file found for net:udpgro.sh at ./output/net:udpgro.sh.log"}
- {"dt": "2025-03-25T10:25:39.977601", "lvl": "target", "msg": "<8>[   24.728182] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:udpgro.sh RESULT=skip>"}
- {"dt": "2025-03-25T10:25:39.977842", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:udpgro.sh RESULT=skip"}
- {"dt": "2025-03-25T10:25:39.977911", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "net:udpgro.sh", "result": "skip", "starttc": ! "1148", "endtc": ! "1148"}}
- {"dt": "2025-03-25T10:25:39.988490", "lvl": "target", "msg": "WARNING: no log file found for net:xfrm_policy.sh at ./output/net:xfrm_policy.sh.log"}
- {"dt": "2025-03-25T10:25:40.003005", "lvl": "target", "msg": "<8>[   24.753789] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=net:xfrm_policy.sh RESULT=skip>"}
- {"dt": "2025-03-25T10:25:40.003226", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=net:xfrm_policy.sh RESULT=skip"}
- {"dt": "2025-03-25T10:25:40.003280", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "net:xfrm_policy.sh", "result": "skip", "starttc": ! "1152", "endtc": ! "1152"}}
- {"dt": "2025-03-25T10:25:40.014477", "lvl": "target", "msg": "WARNING: no log file found for pidfd:pidfd_wait at ./output/pidfd:pidfd_wait.log"}
- {"dt": "2025-03-25T10:25:40.028363", "lvl": "target", "msg": "<8>[   24.779155] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=pidfd:pidfd_wait RESULT=skip>"}
- {"dt": "2025-03-25T10:25:40.028597", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=pidfd:pidfd_wait RESULT=skip"}
- {"dt": "2025-03-25T10:25:40.028664", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "pidfd:pidfd_wait", "result": "skip", "starttc": ! "1156", "endtc": ! "1156"}}
- {"dt": "2025-03-25T10:25:40.039878", "lvl": "target", "msg": "WARNING: no log file found for proc:proc-pid-vm at ./output/proc:proc-pid-vm.log"}
- {"dt": "2025-03-25T10:25:40.053526", "lvl": "target", "msg": "<8>[   24.804325] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=proc:proc-pid-vm RESULT=skip>"}
- {"dt": "2025-03-25T10:25:40.053778", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=proc:proc-pid-vm RESULT=skip"}
- {"dt": "2025-03-25T10:25:40.053854", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "proc:proc-pid-vm", "result": "skip", "starttc": ! "1160", "endtc": ! "1160"}}
- {"dt": "2025-03-25T10:25:40.064203", "lvl": "target", "msg": "WARNING: no log file found for ptrace:vmaccess at ./output/ptrace:vmaccess.log"}
- {"dt": "2025-03-25T10:25:40.078391", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=ptrace:vmaccess RESULT=skip"}
- {"dt": "2025-03-25T10:25:40.078474", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "ptrace:vmaccess", "result": "skip", "starttc": ! "1163", "endtc": ! "1163"}}
- {"dt": "2025-03-25T10:25:40.078593", "lvl": "target", "msg": "<8>[   24.828917] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=ptrace:vmaccess RESULT=skip>"}
- {"dt": "2025-03-25T10:25:40.089453", "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-25T10:25:40.103238", "lvl": "target", "msg": "<8>[   24.853999] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=rseq:run_param_test.sh RESULT=skip>"}
- {"dt": "2025-03-25T10:25:40.103491", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=rseq:run_param_test.sh RESULT=skip"}
- {"dt": "2025-03-25T10:25:40.103561", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "rseq:run_param_test.sh", "result": "skip", "starttc": ! "1168", "endtc": ! "1168"}}
- {"dt": "2025-03-25T10:25:40.115942", "lvl": "target", "msg": "WARNING: no log file found for sync:sync_test at ./output/sync:sync_test.log"}
- {"dt": "2025-03-25T10:25:40.129884", "lvl": "target", "msg": "<8>[   24.880692] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=sync:sync_test RESULT=skip>"}
- {"dt": "2025-03-25T10:25:40.130137", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=sync:sync_test RESULT=skip"}
- {"dt": "2025-03-25T10:25:40.130210", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "sync:sync_test", "result": "skip", "starttc": ! "1172", "endtc": ! "1172"}}
- {"dt": "2025-03-25T10:25:40.142000", "lvl": "target", "msg": "WARNING: no log file found for zram:zram.sh at ./output/zram:zram.sh.log"}
- {"dt": "2025-03-25T10:25:40.156140", "lvl": "target", "msg": "<8>[   24.906954] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=zram:zram.sh RESULT=skip>"}
- {"dt": "2025-03-25T10:25:40.156402", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=zram:zram.sh RESULT=skip"}
- {"dt": "2025-03-25T10:25:40.156491", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "zram:zram.sh", "result": "skip", "starttc": ! "1176", "endtc": ! "1176"}}
- {"dt": "2025-03-25T10:25:40.167762", "lvl": "target", "msg": "WARNING: no log file found for shardfile-clone3 at ./output/shardfile-clone3.log"}
- {"dt": "2025-03-25T10:25:40.180841", "lvl": "target", "msg": "<8>[   24.931639] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=shardfile-clone3 RESULT=pass>"}
- {"dt": "2025-03-25T10:25:40.181095", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=shardfile-clone3 RESULT=pass"}
- {"dt": "2025-03-25T10:25:40.181175", "lvl": "results", "msg": {"definition": "0_kselftest-clone3", "case": "shardfile-clone3", "result": "pass", "starttc": ! "1180", "endtc": ! "1180"}}
- {"dt": "2025-03-25T10:25:40.298343", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2025-03-25T10:25:40.298844", "lvl": "target", "msg": "<8>[   25.049708] <LAVA_SIGNAL_ENDRUN 0_kselftest-clone3 1_1.1.3.1>"}
- {"dt": "2025-03-25T10:25:40.299091", "lvl": "debug", "msg": "Received signal: <ENDRUN> 0_kselftest-clone3 1_1.1.3.1"}
- {"dt": "2025-03-25T10:25:40.299185", "lvl": "info", "msg": "Ending use of test pattern."}
- {"dt": "2025-03-25T10:25:40.299250", "lvl": "info", "msg": "Ending test lava.0_kselftest-clone3 (1_1.1.3.1), duration 11.56"}
- {"dt": "2025-03-25T10:25:40.299332", "lvl": "results", "msg": {"definition": "lava", "case": "0_kselftest-clone3", "uuid": "1_1.1.3.1", "repository": "https://github.com/TheodoreRTG/test-definitions.git", "path": "automated/linux/kselftest/kselftest.yaml", "duration": "11.56", "result": "pass", "revision": "unspecified", "namespace": "common", "commit_id": "450111580e70664ab07b21744eff0a1147707c44"}}
- {"dt": "2025-03-25T10:25:40.301566", "lvl": "target", "msg": "<LAVA_TEST_RUNNER EXIT>"}
- {"dt": "2025-03-25T10:25:40.301791", "lvl": "info", "msg": "ok: lava_test_shell seems to have completed"}
- {"dt": "2025-03-25T10:25:40.301989", "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-clone3: pass\n"}
- {"dt": "2025-03-25T10:25:40.302090", "lvl": "debug", "msg": "end: 3.1 lava-test-shell (duration 00:00:12) [common]"}
- {"dt": "2025-03-25T10:25:40.302168", "lvl": "info", "msg": "end: 3 lava-test-retry (duration 00:00:12) [common]"}
- {"dt": "2025-03-25T10:25:40.302247", "lvl": "info", "msg": "start: 4 finalize (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T10:25:40.302330", "lvl": "debug", "msg": "start: 4.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2025-03-25T10:25:40.302405", "lvl": "debug", "msg": "end: 4.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2025-03-25T10:25:40.302472", "lvl": "debug", "msg": "start: 4.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2025-03-25T10:25:40.302577", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T10:25:40.303627", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T10:25:40.303967", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2025-03-25T10:25:41.303888", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2025-03-25T10:25:41.304060", "lvl": "debug", "msg": "Sending line: 'poweroff'"}
- {"dt": "2025-03-25T10:25:41.404695", "lvl": "input", "msg": "poweroff"}
- {"dt": "2025-03-25T10:25:41.405147", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2025-03-25T10:25:41.405237", "lvl": "target", "msg": "[?2004hroot@runner-ykxhnyexq-project-40964107-concurrent-0:~# poweroff"}
- {"dt": "2025-03-25T10:25:41.505904", "lvl": "debug", "msg": "end: 4.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2025-03-25T10:25:41.506042", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2025-03-25T10:25:41.506113", "lvl": "info", "msg": "end: 4 finalize (duration 00:00:01) [common]"}
- {"dt": "2025-03-25T10:25:41.506215", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2025-03-25T10:25:41.506352", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/kernel/Image"}
- {"dt": "2025-03-25T10:25:41.511892", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/rootfs/https___storage.tuxboot.com_debian_trixie_arm64_rootfs.ext4"}
- {"dt": "2025-03-25T10:25:41.639751", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/rootfs.kselftest/kselftest.tar"}
- {"dt": "2025-03-25T10:25:41.653983", "lvl": "debug", "msg": "Cleaning up downloaded image: /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1/deployimages-6jgp3s3m/rootfs.modules/modules.tar"}
- {"dt": "2025-03-25T10:25:41.664192", "lvl": "info", "msg": "Removing root tmp directory at /var/lib/lava/dispatcher/tmp/tuxrun-k4h5gx09-1"}
- {"dt": "2025-03-25T10:25:41.706847", "lvl": "info", "msg": "Job finished correctly"}
- {"dt": "2025-03-25T10:25:41.706915", "lvl": "results", "msg": {"definition": "lava", "case": "job", "result": "pass"}}
