- {"dt": "2024-11-14T12:32:27.488239", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2024.05.dev0067"}
- {"dt": "2024-11-14T12:32:27.488327", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-11-14T12:32:27.488402", "lvl": "info", "msg": "Start time: 2024-11-14 12:32:27.488395+00:00 (UTC)"}
- {"dt": "2024-11-14T12:32:27.489143", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxsuite/plan/144/build_1/vmlinux.xz exists"}
- {"dt": "2024-11-14T12:32:27.489264", "lvl": "debug", "msg": "Validating that file:///home/anders/src/tuxtest-buildroot/builds/sparc64/images/rootfs.ext2.zst exists"}
- {"dt": "2024-11-14T12:32:27.501378", "lvl": "info", "msg": "qemu, installed at version: 8.2.4, host architecture: x86_64"}
- {"dt": "2024-11-14T12:32:27.501717", "lvl": "info", "msg": "validate duration: 0.01"}
- {"dt": "2024-11-14T12:32:27.501822", "lvl": "results", "msg": {"definition": "lava", "case": "validate", "result": "pass"}}
- {"dt": "2024-11-14T12:32:27.501987", "lvl": "info", "msg": "start: 1 deployimages (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.502078", "lvl": "debug", "msg": "start: 1.1 lava-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.502349", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w"}
- {"dt": "2024-11-14T12:32:27.502557", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin"}
- {"dt": "2024-11-14T12:32:27.502670", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/tests"}
- {"dt": "2024-11-14T12:32:27.502785", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/results"}
- {"dt": "2024-11-14T12:32:27.502861", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-add-keys"}
- {"dt": "2024-11-14T12:32:27.502996", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-add-sources"}
- {"dt": "2024-11-14T12:32:27.503116", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-background-process-start"}
- {"dt": "2024-11-14T12:32:27.503237", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-background-process-stop"}
- {"dt": "2024-11-14T12:32:27.503359", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-common-functions"}
- {"dt": "2024-11-14T12:32:27.503529", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-echo-ipv4"}
- {"dt": "2024-11-14T12:32:27.503721", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-install-packages"}
- {"dt": "2024-11-14T12:32:27.503913", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-installed-packages"}
- {"dt": "2024-11-14T12:32:27.504056", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-os-build"}
- {"dt": "2024-11-14T12:32:27.504190", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-probe-channel"}
- {"dt": "2024-11-14T12:32:27.504313", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-probe-ip"}
- {"dt": "2024-11-14T12:32:27.504433", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-target-ip"}
- {"dt": "2024-11-14T12:32:27.504554", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-target-mac"}
- {"dt": "2024-11-14T12:32:27.504672", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-target-storage"}
- {"dt": "2024-11-14T12:32:27.504793", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-test-case"}
- {"dt": "2024-11-14T12:32:27.504913", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-test-event"}
- {"dt": "2024-11-14T12:32:27.505033", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-test-feedback"}
- {"dt": "2024-11-14T12:32:27.505150", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-test-raise"}
- {"dt": "2024-11-14T12:32:27.505279", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-test-reference"}
- {"dt": "2024-11-14T12:32:27.505399", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-test-runner"}
- {"dt": "2024-11-14T12:32:27.505517", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-test-set"}
- {"dt": "2024-11-14T12:32:27.505636", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-test-shell"}
- {"dt": "2024-11-14T12:32:27.505756", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-install-packages (oe)"}
- {"dt": "2024-11-14T12:32:27.505903", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/bin/lava-installed-packages (oe)"}
- {"dt": "2024-11-14T12:32:27.506012", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/environment"}
- {"dt": "2024-11-14T12:32:27.506098", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2024-11-14T12:32:27.506149", "lvl": "debug", "msg": "- LAVA_JOB_ID=1"}
- {"dt": "2024-11-14T12:32:27.506194", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.32.138"}
- {"dt": "2024-11-14T12:32:27.506271", "lvl": "debug", "msg": "start: 1.1.1 lava-vland-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.506318", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2024-11-14T12:32:27.506371", "lvl": "debug", "msg": "end: 1.1.1 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.506428", "lvl": "debug", "msg": "start: 1.1.2 lava-multinode-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.506470", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2024-11-14T12:32:27.506519", "lvl": "debug", "msg": "end: 1.1.2 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.506572", "lvl": "debug", "msg": "start: 1.1.3 test-definition (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.506621", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2024-11-14T12:32:27.506680", "lvl": "debug", "msg": "start: 1.1.3.1 inline-repo-action (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.506726", "lvl": "debug", "msg": "Using /lava-1 at stage 0"}
- {"dt": "2024-11-14T12:32:27.507059", "lvl": "debug", "msg": "uuid=1_1.1.3.1 testdef=None"}
- {"dt": "2024-11-14T12:32:27.507127", "lvl": "debug", "msg": "end: 1.1.3.1 inline-repo-action (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.507183", "lvl": "debug", "msg": "start: 1.1.3.2 test-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.507558", "lvl": "debug", "msg": "end: 1.1.3.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.507609", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "test-overlay", "level": "1.1.3.2", "duration": "0.00", "result": "pass", "extra": {"uuid": "1_1.1.3.1", "name": "commands", "path": "command", "from": "inline"}}}
- {"dt": "2024-11-14T12:32:27.507720", "lvl": "debug", "msg": "start: 1.1.3.3 test-install-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.508216", "lvl": "debug", "msg": "end: 1.1.3.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.508270", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "test-install-overlay", "level": "1.1.3.3", "duration": "0.00", "result": "pass", "extra": {"uuid": "1_1.1.3.1", "name": "commands", "path": "command", "from": "inline", "skipped test-install-overlay": "1_1.1.3.1"}}}
- {"dt": "2024-11-14T12:32:27.508378", "lvl": "debug", "msg": "start: 1.1.3.4 test-runscript-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.514263", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/0/tests/0_commands test_uuid 1_1.1.3.1"}
- {"dt": "2024-11-14T12:32:27.514482", "lvl": "debug", "msg": "end: 1.1.3.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.514538", "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": "commands", "path": "command", "from": "inline", "filename": "/var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/0/tests/0_commands/run.sh"}}}
- {"dt": "2024-11-14T12:32:27.514630", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2024-11-14T12:32:27.514677", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/lava-overlay-w8szdx6w/lava-1/0 for stage 0"}
- {"dt": "2024-11-14T12:32:27.514755", "lvl": "debug", "msg": "- 0_commands"}
- {"dt": "2024-11-14T12:32:27.514833", "lvl": "debug", "msg": "end: 1.1.3 test-definition (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.514892", "lvl": "debug", "msg": "start: 1.1.4 compress-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520340", "lvl": "debug", "msg": "end: 1.1.4 compress-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520435", "lvl": "debug", "msg": "start: 1.1.5 persistent-nfs-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520502", "lvl": "debug", "msg": "end: 1.1.5 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520561", "lvl": "debug", "msg": "end: 1.1 lava-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520622", "lvl": "debug", "msg": "start: 1.2 apply-overlay-guest (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520679", "lvl": "debug", "msg": "Overlay already applied"}
- {"dt": "2024-11-14T12:32:27.520732", "lvl": "debug", "msg": "end: 1.2 apply-overlay-guest (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520784", "lvl": "debug", "msg": "start: 1.3 deploy-device-env (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520834", "lvl": "debug", "msg": "end: 1.3 deploy-device-env (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520886", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.520940", "lvl": "debug", "msg": "start: 1.4.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.521079", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxsuite/plan/144/build_1/vmlinux.xz"}
- {"dt": "2024-11-14T12:32:27.521133", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/deployimages-2ujzuvv6/kernel/vmlinux"}
- {"dt": "2024-11-14T12:32:27.521175", "lvl": "debug", "msg": "total size: 4269492 (4\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.521228", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-11-14T12:32:27.521592", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.522968", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.523785", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.524514", "lvl": "debug", "msg": "progress  15\u202F% (0\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.525319", "lvl": "debug", "msg": "progress  20\u202F% (0\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.526005", "lvl": "debug", "msg": "progress  25\u202F% (1\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.526796", "lvl": "debug", "msg": "progress  30\u202F% (1\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.527484", "lvl": "debug", "msg": "progress  35\u202F% (1\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.528322", "lvl": "debug", "msg": "progress  40\u202F% (1\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.529036", "lvl": "debug", "msg": "progress  45\u202F% (1\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.530052", "lvl": "debug", "msg": "progress  50\u202F% (2\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.530943", "lvl": "debug", "msg": "progress  55\u202F% (2\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.531972", "lvl": "debug", "msg": "progress  60\u202F% (2\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.532917", "lvl": "debug", "msg": "progress  65\u202F% (2\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.533926", "lvl": "debug", "msg": "progress  70\u202F% (2\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.534689", "lvl": "debug", "msg": "progress  75\u202F% (3\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.535643", "lvl": "debug", "msg": "progress  80\u202F% (3\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.536617", "lvl": "debug", "msg": "progress  85\u202F% (3\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.537469", "lvl": "debug", "msg": "progress  90\u202F% (3\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.538183", "lvl": "debug", "msg": "progress  95\u202F% (3\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.538984", "lvl": "debug", "msg": "progress 100\u202F% (4\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.648305", "lvl": "info", "msg": "4\u202FMB downloaded in 0.13\u202Fs (32.03\u202FMB/s)"}
- {"dt": "2024-11-14T12:32:27.648535", "lvl": "debug", "msg": "end: 1.4.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.648601", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.4.1", "duration": "0.13", "result": "pass", "extra": {"label": "kernel", "size": ! "4269492", "md5sum": "f28244c5e345c74aaa962e0b10e4525d", "sha256sum": "a6875e270198864320b054f3b3b9a94d5ca324663d5c13e11ef669a7d4361052", "sha512sum": "2db1d507222331d9eaa9bf90dd91f20d1ffb4e924a1d5547641caf7ce65894ba330b42d6f2619ed000061987be31bbe1e585cf4d1006f09ff7b4fe180ed4a094"}}}
- {"dt": "2024-11-14T12:32:27.648726", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:27.648802", "lvl": "debug", "msg": "start: 1.5 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.648870", "lvl": "debug", "msg": "start: 1.5.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:27.649113", "lvl": "info", "msg": "downloading file:///home/anders/src/tuxtest-buildroot/builds/sparc64/images/rootfs.ext2.zst"}
- {"dt": "2024-11-14T12:32:27.649171", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/deployimages-2ujzuvv6/rootfs/rootfs.ext2"}
- {"dt": "2024-11-14T12:32:27.649239", "lvl": "debug", "msg": "total size: 68772662 (65\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.649292", "lvl": "info", "msg": "Using unzstd to decompress zstd"}
- {"dt": "2024-11-14T12:32:27.649732", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.666681", "lvl": "debug", "msg": "progress   5\u202F% (3\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.678699", "lvl": "debug", "msg": "progress  10\u202F% (6\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.697576", "lvl": "debug", "msg": "progress  15\u202F% (9\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.720184", "lvl": "debug", "msg": "progress  20\u202F% (13\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.738606", "lvl": "debug", "msg": "progress  25\u202F% (16\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.757926", "lvl": "debug", "msg": "progress  30\u202F% (19\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.776176", "lvl": "debug", "msg": "progress  35\u202F% (22\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.796324", "lvl": "debug", "msg": "progress  40\u202F% (26\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.819076", "lvl": "debug", "msg": "progress  45\u202F% (29\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.839966", "lvl": "debug", "msg": "progress  50\u202F% (32\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.856728", "lvl": "debug", "msg": "progress  55\u202F% (36\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.875339", "lvl": "debug", "msg": "progress  60\u202F% (39\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.899854", "lvl": "debug", "msg": "progress  65\u202F% (42\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.912033", "lvl": "debug", "msg": "progress  70\u202F% (45\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.926229", "lvl": "debug", "msg": "progress  75\u202F% (49\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.938813", "lvl": "debug", "msg": "progress  80\u202F% (52\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.950430", "lvl": "debug", "msg": "progress  85\u202F% (55\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.976684", "lvl": "debug", "msg": "progress  90\u202F% (59\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.988322", "lvl": "debug", "msg": "progress  95\u202F% (62\u202FMB)"}
- {"dt": "2024-11-14T12:32:27.999621", "lvl": "debug", "msg": "progress 100\u202F% (65\u202FMB)"}
- {"dt": "2024-11-14T12:32:28.222573", "lvl": "info", "msg": "65\u202FMB downloaded in 0.57\u202Fs (114.40\u202FMB/s)"}
- {"dt": "2024-11-14T12:32:28.222791", "lvl": "debug", "msg": "end: 1.5.1 file-download (duration 00:00:01) [common]"}
- {"dt": "2024-11-14T12:32:28.222871", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.5.1", "duration": "0.57", "result": "pass", "extra": {"label": "rootfs", "size": ! "68772662", "md5sum": "983e7e4a16b3396d6159785634e6d1c7", "sha256sum": "d23821fb969c484cc7cdaa0989df6d379d992007117c78857775ba50edc0bfd5", "sha512sum": "63e3fbf998a7a0951d40bacc288f9cfe81fc29e0b6c6391de7bd8dd1e7b9732ad3bcc3850342362335bd30fd97f93c06d2a8c8cfc6260e8bbaacdc8b47696fdf"}}}
- {"dt": "2024-11-14T12:32:28.223023", "lvl": "debug", "msg": "start: 1.5.2 append-overlays (timeout 00:04:59) [common]"}
- {"dt": "2024-11-14T12:32:28.223085", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/deployimages-2ujzuvv6/rootfs/rootfs.ext2'"}
- {"dt": "2024-11-14T12:32:29.962803", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2024-11-14T12:32:29.963501", "lvl": "debug", "msg": "- rootfs.lava: '/var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/compress-overlay-_2gk5ejp/overlay-1.1.4.tar.gz' to '/'"}
- {"dt": "2024-11-14T12:32:30.169025", "lvl": "debug", "msg": "end: 1.5.2 append-overlays (duration 00:00:02) [common]"}
- {"dt": "2024-11-14T12:32:30.169461", "lvl": "debug", "msg": "end: 1.5 download-retry (duration 00:00:03) [common]"}
- {"dt": "2024-11-14T12:32:30.169580", "lvl": "info", "msg": "end: 1 deployimages (duration 00:00:03) [common]"}
- {"dt": "2024-11-14T12:32:30.169699", "lvl": "info", "msg": "start: 2 boot-image-retry (timeout 00:15:00) [common]"}
- {"dt": "2024-11-14T12:32:30.169794", "lvl": "debug", "msg": "start: 2.1 boot-qemu-image (timeout 00:15:00) [common]"}
- {"dt": "2024-11-14T12:32:30.169858", "lvl": "debug", "msg": "start: 2.1.1 execute-qemu (timeout 00:15:00) [common]"}
- {"dt": "2024-11-14T12:32:30.170106", "lvl": "info", "msg": "Boot command: /usr/bin/qemu-system-sparc64 -machine sun4u -nographic -nic none -m 4G -monitor none -no-reboot  -kernel /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/deployimages-2ujzuvv6/kernel/vmlinux -append \"console=ttyS0,115200 rootwait root=/dev/sda debug verbose console_msg_format=syslog systemd.log_level=warning rootdelay=10 earlycon\" -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/deployimages-2ujzuvv6/rootfs/rootfs.ext2,if=ide,format=raw"}
- {"dt": "2024-11-14T12:32:30.173489", "lvl": "debug", "msg": "started a shell command"}
- {"dt": "2024-11-14T12:32:30.173885", "lvl": "debug", "msg": "end: 2.1.1 execute-qemu (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:30.174063", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "execute-qemu", "level": "2.1.1", "duration": "0.00", "result": "pass", "extra": {"qemu_version": "8.2.4", "host_arch": "x86_64", "job_arch": "sparc64"}}}
- {"dt": "2024-11-14T12:32:30.174285", "lvl": "debug", "msg": "end: 2.1 boot-qemu-image (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:30.174394", "lvl": "debug", "msg": "start: 2.2 auto-login-action (timeout 00:15:00) [common]"}
- {"dt": "2024-11-14T12:32:30.174494", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2024-11-14T12:32:30.174561", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:15:00)"}
- {"dt": "2024-11-14T12:32:30.201949", "lvl": "target", "msg": "OpenBIOS for Sparc64"}
- {"dt": "2024-11-14T12:32:31.133107", "lvl": "target", "msg": "Configuration device id QEMU version 1 machine id 0"}
- {"dt": "2024-11-14T12:32:31.133526", "lvl": "target", "msg": "kernel phys 404000 virt 40004000 size 0x13d3a88"}
- {"dt": "2024-11-14T12:32:31.134164", "lvl": "target", "msg": "kernel cmdline console=ttyS0,115200 rootwait root=/dev/sda debug verbose console_msg_format=syslog systemd.log_level=warning rootdelay=10 earlycon"}
- {"dt": "2024-11-14T12:32:31.151870", "lvl": "target", "msg": "CPUs: 1 x SUNW,UltraSPARC-IIi"}
- {"dt": "2024-11-14T12:32:31.151969", "lvl": "target", "msg": "UUID: 00000000-0000-0000-0000-000000000000"}
- {"dt": "2024-11-14T12:32:31.271402", "lvl": "target", "msg": "Welcome to OpenBIOS v1.1 built on May 20 2024 13:14"}
- {"dt": "2024-11-14T12:32:31.273547", "lvl": "target", "msg": "  Type 'help' for detailed information"}
- {"dt": "2024-11-14T12:32:31.278398", "lvl": "target", "msg": "[sparc64] Kernel already loaded"}
- {"dt": "2024-11-14T12:32:31.288851", "lvl": "target", "msg": "\r"}
- {"dt": "2024-11-14T12:32:31.335549", "lvl": "target", "msg": "[    0.000499] PROMLIB: Sun IEEE Boot Prom 'OBP 3.10.24 1999/01/01 01:01'\r"}
- {"dt": "2024-11-14T12:32:31.336036", "lvl": "target", "msg": "[    0.001374] PROMLIB: Root node compatible: sun4u\r"}
- {"dt": "2024-11-14T12:32:31.336604", "lvl": "target", "msg": "[    0.002340] Linux version 6.12.0-rc7 (tuxmake@tuxmake) (sparc64-linux-gnu-gcc (Debian 13.3.0-5) 13.3.0, GNU ld (GNU Binutils for Debian) 2.43.1) #1 SMP @1731277175\r"}
- {"dt": "2024-11-14T12:32:31.336903", "lvl": "debug", "msg": "start: 2.2.1 login-action (timeout 00:14:59) [common]"}
- {"dt": "2024-11-14T12:32:31.336980", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2024-11-14T12:32:31.337058", "lvl": "debug", "msg": "Setting prompt string to ['-\\\\[ cut here \\\\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing']"}
- {"dt": "2024-11-14T12:32:31.337130", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2024-11-14T12:32:31.337182", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2024-11-14T12:32:31.337250", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2024-11-14T12:32:31.337301", "lvl": "debug", "msg": ["-\\[ cut here \\]", "Unhandled fault", "BUG: KCSAN:", "BUG: KASAN:", "BUG: KFENCE:", "Oops(?: -|:)", "WARNING:", "(kernel BUG at|BUG:)", "invalid opcode:", "Kernel panic - not syncing", "root@(.*):[/~]#", "login:", "Login incorrect"]}
- {"dt": "2024-11-14T12:32:31.337389", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:14:59)"}
- {"dt": "2024-11-14T12:32:31.337451", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:07:29)"}
- {"dt": "2024-11-14T12:32:31.337847", "lvl": "target", "msg": "[    0.005237] printk: legacy bootconsole [earlyprom0] enabled\r"}
- {"dt": "2024-11-14T12:32:31.337907", "lvl": "target", "msg": "[    0.008351] ARCH: SUN4U\r"}
- {"dt": "2024-11-14T12:32:31.339236", "lvl": "target", "msg": "[    0.009800] Ethernet address: 52:54:00:12:34:56\r"}
- {"dt": "2024-11-14T12:32:31.341593", "lvl": "target", "msg": "[    0.012201] MM: PAGE_OFFSET is 0xfffff80000000000 (max_phys_bits == 40)\r"}
- {"dt": "2024-11-14T12:32:31.342027", "lvl": "target", "msg": "[    0.012821] MM: VMALLOC [0x0000000100000000 --> 0x0000060000000000]\r"}
- {"dt": "2024-11-14T12:32:31.342465", "lvl": "target", "msg": "[    0.013271] MM: VMEMMAP [0x0000060000000000 --> 0x00000c0000000000]\r"}
- {"dt": "2024-11-14T12:32:31.351369", "lvl": "target", "msg": "[    0.022114] Kernel: Using 5 locked TLB entries for main kernel image.\r"}
- {"dt": "2024-11-14T12:32:31.355941", "lvl": "target", "msg": "[    0.022609] Remapping the kernel... \r"}
- {"dt": "2024-11-14T12:32:31.356213", "lvl": "target", "msg": "[    0.026722] done.\r"}
- {"dt": "2024-11-14T12:32:31.841601", "lvl": "target", "msg": "[    0.512274] OF stdout device is: /pci@1fe,0/pci@1,1/ebus@1/su\r"}
- {"dt": "2024-11-14T12:32:31.841944", "lvl": "target", "msg": "[    0.512761] PROM: Built device tree with 58260 bytes of memory.\r"}
- {"dt": "2024-11-14T12:32:31.843275", "lvl": "target", "msg": "[    0.514052] Top of RAM: 0xffe80000, Total RAM: 0xffe80000\r"}
- {"dt": "2024-11-14T12:32:31.843571", "lvl": "target", "msg": "[    0.514473] Memory hole size: 0MB\r"}
- {"dt": "2024-11-14T12:32:31.844330", "lvl": "target", "msg": "[    0.515036] NODE_DATA(0) allocated [mem 0xffe62640-0xffe63c3f]\r"}
- {"dt": "2024-11-14T12:32:31.847879", "lvl": "target", "msg": "[    0.518665] Allocated 16384 bytes for kernel page tables.\r"}
- {"dt": "2024-11-14T12:32:31.848784", "lvl": "target", "msg": "[    0.519569] Zone ranges:\r"}
- {"dt": "2024-11-14T12:32:31.849570", "lvl": "target", "msg": "[    0.519934]   Normal   [mem 0x0000000000000000-0x00000000ffe7ffff]\r"}
- {"dt": "2024-11-14T12:32:31.849943", "lvl": "target", "msg": "[    0.520798] Movable zone start for each node\r"}
- {"dt": "2024-11-14T12:32:31.850300", "lvl": "target", "msg": "[    0.521198] Early memory node ranges\r"}
- {"dt": "2024-11-14T12:32:31.850769", "lvl": "target", "msg": "[    0.521545]   node   0: [mem 0x0000000000000000-0x00000000ffe7ffff]\r"}
- {"dt": "2024-11-14T12:32:31.851519", "lvl": "target", "msg": "[    0.522283] Initmem setup node 0 [mem 0x0000000000000000-0x00000000ffe7ffff]\r"}
- {"dt": "2024-11-14T12:32:31.852503", "lvl": "target", "msg": "[    0.523301] Initmem setup node 1 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.853019", "lvl": "target", "msg": "[    0.523807] Initmem setup node 2 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.853466", "lvl": "target", "msg": "[    0.524261] Initmem setup node 3 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.853917", "lvl": "target", "msg": "[    0.524720] Initmem setup node 4 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.854371", "lvl": "target", "msg": "[    0.525170] Initmem setup node 5 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.854820", "lvl": "target", "msg": "[    0.525625] Initmem setup node 6 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.855264", "lvl": "target", "msg": "[    0.526071] Initmem setup node 7 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.855711", "lvl": "target", "msg": "[    0.526512] Initmem setup node 8 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.856140", "lvl": "target", "msg": "[    0.526947] Initmem setup node 9 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.856603", "lvl": "target", "msg": "[    0.527390] Initmem setup node 10 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.856958", "lvl": "target", "msg": "[    0.527842] Initmem setup node 11 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.857495", "lvl": "target", "msg": "[    0.528290] Initmem setup node 12 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.857933", "lvl": "target", "msg": "[    0.528743] Initmem setup node 13 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.858384", "lvl": "target", "msg": "[    0.529190] Initmem setup node 14 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.858858", "lvl": "target", "msg": "[    0.529636] Initmem setup node 15 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.859201", "lvl": "target", "msg": "[    0.530083] Initmem setup node 16 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.859777", "lvl": "target", "msg": "[    0.530532] Initmem setup node 17 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.860100", "lvl": "target", "msg": "[    0.530985] Initmem setup node 18 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.860667", "lvl": "target", "msg": "[    0.531429] Initmem setup node 19 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.861008", "lvl": "target", "msg": "[    0.531877] Initmem setup node 20 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.861550", "lvl": "target", "msg": "[    0.532328] Initmem setup node 21 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.861892", "lvl": "target", "msg": "[    0.532780] Initmem setup node 22 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.862419", "lvl": "target", "msg": "[    0.533227] Initmem setup node 23 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.862866", "lvl": "target", "msg": "[    0.533674] Initmem setup node 24 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.863313", "lvl": "target", "msg": "[    0.534121] Initmem setup node 25 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.863762", "lvl": "target", "msg": "[    0.534569] Initmem setup node 26 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.864212", "lvl": "target", "msg": "[    0.535016] Initmem setup node 27 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.864677", "lvl": "target", "msg": "[    0.535472] Initmem setup node 28 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.865140", "lvl": "target", "msg": "[    0.535929] Initmem setup node 29 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.865595", "lvl": "target", "msg": "[    0.536385] Initmem setup node 30 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.866048", "lvl": "target", "msg": "[    0.536845] Initmem setup node 31 as memoryless\r"}
- {"dt": "2024-11-14T12:32:31.880834", "lvl": "target", "msg": "[    0.551444] On node 0, zone Normal: 192 pages in unavailable ranges\r"}
- {"dt": "2024-11-14T12:32:31.881058", "lvl": "target", "msg": "[    0.551973] Booting Linux...\r"}
- {"dt": "2024-11-14T12:32:31.881827", "lvl": "target", "msg": "[    0.552394] CPU CAPS: [flush,stbar,swap,muldiv,v9,mul32,div32,v8plus]\r"}
- {"dt": "2024-11-14T12:32:31.882106", "lvl": "target", "msg": "[    0.553000] CPU CAPS: [vis]\r"}
- {"dt": "2024-11-14T12:32:31.885265", "lvl": "target", "msg": "[    0.556001] percpu: Embedded 18 pages/cpu s106584 r8192 d32680 u4194304\r"}
- {"dt": "2024-11-14T12:32:31.886462", "lvl": "target", "msg": "[    0.557185] pcpu-alloc: s106584 r8192 d32680 u4194304 alloc=1*4194304\r"}
- {"dt": "2024-11-14T12:32:31.887062", "lvl": "target", "msg": "[    0.557670] pcpu-alloc: [0] 0 \r"}
- {"dt": "2024-11-14T12:32:31.889878", "lvl": "target", "msg": "[    0.560440] Kernel command line: console=ttyS0,115200 rootwait root=/dev/sda debug verbose console_msg_format=syslog systemd.log_level=warning rootdelay=10 earlycon\r"}
- {"dt": "2024-11-14T12:32:31.891371", "lvl": "target", "msg": "<5>[    0.562107] Unknown kernel command line parameters \"verbose earlycon\", will be passed to user space.\r"}
- {"dt": "2024-11-14T12:32:31.893726", "lvl": "target", "msg": "<6>[    0.564456] Dentry cache hash table entries: 524288 (order: 9, 4194304 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:31.894799", "lvl": "target", "msg": "<6>[    0.565553] Inode-cache hash table entries: 262144 (order: 8, 2097152 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:31.895169", "lvl": "target", "msg": "<5>[    0.566060] Sorting __ex_table...\r"}
- {"dt": "2024-11-14T12:32:31.897358", "lvl": "target", "msg": "<6>[    0.567419] Fallback order for Node 0: 0 \r"}
- {"dt": "2024-11-14T12:32:31.897636", "lvl": "target", "msg": "<6>[    0.567674] Fallback order for Node 1: 0 \r"}
- {"dt": "2024-11-14T12:32:31.897930", "lvl": "target", "msg": "<6>[    0.567686] Fallback order for Node 2: 0 \r"}
- {"dt": "2024-11-14T12:32:31.898263", "lvl": "target", "msg": "<6>[    0.567695] Fallback order for Node 3: 0 \r"}
- {"dt": "2024-11-14T12:32:31.898594", "lvl": "target", "msg": "<6>[    0.567704] Fallback order for Node 4: 0 \r"}
- {"dt": "2024-11-14T12:32:31.898925", "lvl": "target", "msg": "<6>[    0.567713] Fallback order for Node 5: 0 \r"}
- {"dt": "2024-11-14T12:32:31.899258", "lvl": "target", "msg": "<6>[    0.567721] Fallback order for Node 6: 0 \r"}
- {"dt": "2024-11-14T12:32:31.899594", "lvl": "target", "msg": "<6>[    0.567730] Fallback order for Node 7: 0 \r"}
- {"dt": "2024-11-14T12:32:31.899928", "lvl": "target", "msg": "<6>[    0.567738] Fallback order for Node 8: 0 \r"}
- {"dt": "2024-11-14T12:32:31.900251", "lvl": "target", "msg": "<6>[    0.567747] Fallback order for Node 9: 0 \r"}
- {"dt": "2024-11-14T12:32:31.900583", "lvl": "target", "msg": "<6>[    0.567755] Fallback order for Node 10: 0 \r"}
- {"dt": "2024-11-14T12:32:31.900919", "lvl": "target", "msg": "<6>[    0.567765] Fallback order for Node 11: 0 \r"}
- {"dt": "2024-11-14T12:32:31.901256", "lvl": "target", "msg": "<6>[    0.567775] Fallback order for Node 12: 0 \r"}
- {"dt": "2024-11-14T12:32:31.901722", "lvl": "target", "msg": "<6>[    0.567784] Fallback order for Node 13: 0 \r"}
- {"dt": "2024-11-14T12:32:31.901982", "lvl": "target", "msg": "<6>[    0.567792] Fallback order for Node 14: 0 \r"}
- {"dt": "2024-11-14T12:32:31.902290", "lvl": "target", "msg": "<6>[    0.567801] Fallback order for Node 15: 0 \r"}
- {"dt": "2024-11-14T12:32:31.902645", "lvl": "target", "msg": "<6>[    0.567811] Fallback order for Node 16: 0 \r"}
- {"dt": "2024-11-14T12:32:31.902978", "lvl": "target", "msg": "<6>[    0.567820] Fallback order for Node 17: 0 \r"}
- {"dt": "2024-11-14T12:32:31.903312", "lvl": "target", "msg": "<6>[    0.567829] Fallback order for Node 18: 0 \r"}
- {"dt": "2024-11-14T12:32:31.903641", "lvl": "target", "msg": "<6>[    0.567838] Fallback order for Node 19: 0 \r"}
- {"dt": "2024-11-14T12:32:31.903971", "lvl": "target", "msg": "<6>[    0.567847] Fallback order for Node 20: 0 \r"}
- {"dt": "2024-11-14T12:32:31.904301", "lvl": "target", "msg": "<6>[    0.567855] Fallback order for Node 21: 0 \r"}
- {"dt": "2024-11-14T12:32:31.904628", "lvl": "target", "msg": "<6>[    0.567864] Fallback order for Node 22: 0 \r"}
- {"dt": "2024-11-14T12:32:31.904960", "lvl": "target", "msg": "<6>[    0.567873] Fallback order for Node 23: 0 \r"}
- {"dt": "2024-11-14T12:32:31.905296", "lvl": "target", "msg": "<6>[    0.567882] Fallback order for Node 24: 0 \r"}
- {"dt": "2024-11-14T12:32:31.905631", "lvl": "target", "msg": "<6>[    0.567891] Fallback order for Node 25: 0 \r"}
- {"dt": "2024-11-14T12:32:31.905960", "lvl": "target", "msg": "<6>[    0.567900] Fallback order for Node 26: 0 \r"}
- {"dt": "2024-11-14T12:32:31.906291", "lvl": "target", "msg": "<6>[    0.567909] Fallback order for Node 27: 0 \r"}
- {"dt": "2024-11-14T12:32:31.906622", "lvl": "target", "msg": "<6>[    0.567918] Fallback order for Node 28: 0 \r"}
- {"dt": "2024-11-14T12:32:31.906952", "lvl": "target", "msg": "<6>[    0.567926] Fallback order for Node 29: 0 \r"}
- {"dt": "2024-11-14T12:32:31.907280", "lvl": "target", "msg": "<6>[    0.567936] Fallback order for Node 30: 0 \r"}
- {"dt": "2024-11-14T12:32:31.907612", "lvl": "target", "msg": "<6>[    0.567945] Fallback order for Node 31: 0 \r"}
- {"dt": "2024-11-14T12:32:31.908128", "lvl": "target", "msg": "<6>[    0.568128] Built 1 zonelists, mobility grouping on.  Total pages: 524096\r"}
- {"dt": "2024-11-14T12:32:31.908392", "lvl": "target", "msg": "<6>[    0.579260] Policy zone: Normal\r"}
- {"dt": "2024-11-14T12:32:31.909023", "lvl": "target", "msg": "<6>[    0.579791] mem auto-init: stack:all(zero), heap alloc:off, heap free:off\r"}
- {"dt": "2024-11-14T12:32:31.920310", "lvl": "target", "msg": "<6>[    0.590999] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=32\r"}
- {"dt": "2024-11-14T12:32:31.923891", "lvl": "target", "msg": "<6>[    0.594614] trace event string verifier disabled\r"}
- {"dt": "2024-11-14T12:32:31.929659", "lvl": "target", "msg": "<6>[    0.600386] rcu: Hierarchical RCU implementation.\r"}
- {"dt": "2024-11-14T12:32:31.929967", "lvl": "target", "msg": "<6>[    0.600797] rcu: \tRCU event tracing is enabled.\r"}
- {"dt": "2024-11-14T12:32:31.930432", "lvl": "target", "msg": "<6>[    0.601209] rcu: \tRCU restricting CPUs from NR_CPUS=4096 to nr_cpu_ids=1.\r"}
- {"dt": "2024-11-14T12:32:31.931127", "lvl": "target", "msg": "<6>[    0.601900] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.\r"}
- {"dt": "2024-11-14T12:32:31.931579", "lvl": "target", "msg": "<6>[    0.602367] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1\r"}
- {"dt": "2024-11-14T12:32:31.937458", "lvl": "target", "msg": "<6>[    0.608192] NR_IRQS: 2048, nr_irqs: 2048, preallocated irqs: 1\r"}
- {"dt": "2024-11-14T12:32:31.938743", "lvl": "target", "msg": "<6>[    0.609520] rcu: srcu_init: Setting srcu_struct sizes based on contention.\r"}
- {"dt": "2024-11-14T12:32:31.940141", "lvl": "target", "msg": "<6>[    0.610788] clocksource: tick: mask: 0xffffffffffffffff max_cycles: 0x171024e7e0, max_idle_ns: 440795205315 ns\r"}
- {"dt": "2024-11-14T12:32:31.940684", "lvl": "target", "msg": "<4>[    0.611468] clocksource: mult[a000000] shift[24]\r"}
- {"dt": "2024-11-14T12:32:31.941155", "lvl": "target", "msg": "<4>[    0.611943] clockevent: mult[1999999a] shift[32]\r"}
- {"dt": "2024-11-14T12:32:31.944706", "lvl": "target", "msg": "<6>[    0.615367] Console: colour dummy device 80x25\r"}
- {"dt": "2024-11-14T12:32:32.094393", "lvl": "target", "msg": "<6>[    0.764952] Calibrating delay using timer specific routine.. 201.11 BogoMIPS (lpj=1005577)\r"}
- {"dt": "2024-11-14T12:32:32.094789", "lvl": "target", "msg": "<6>[    0.765611] pid_max: default: 32768 minimum: 301\r"}
- {"dt": "2024-11-14T12:32:32.097275", "lvl": "target", "msg": "<6>[    0.767987] Mount-cache hash table entries: 8192 (order: 3, 65536 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.097979", "lvl": "target", "msg": "<6>[    0.768459] Mountpoint-cache hash table entries: 8192 (order: 3, 65536 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.139901", "lvl": "target", "msg": "<6>[    0.807984] rcu: Hierarchical SRCU implementation.\r"}
- {"dt": "2024-11-14T12:32:32.140870", "lvl": "target", "msg": "<6>[    0.811629] rcu: \tMax phase no-delay instances is 1000.\r"}
- {"dt": "2024-11-14T12:32:32.144561", "lvl": "target", "msg": "<6>[    0.815302] smp: Bringing up secondary CPUs ...\r"}
- {"dt": "2024-11-14T12:32:32.145449", "lvl": "target", "msg": "<6>[    0.816211] smp: Brought up 1 node, 1 CPU\r"}
- {"dt": "2024-11-14T12:32:32.153039", "lvl": "target", "msg": "<6>[    0.823569] Memory: 4130280K/4192768K available (7752K kernel code, 7964K rwdata, 2064K rodata, 464K init, 2006K bss, 59864K reserved, 0K cma-reserved)\r"}
- {"dt": "2024-11-14T12:32:32.164612", "lvl": "target", "msg": "<6>[    0.835329] devtmpfs: initialized\r"}
- {"dt": "2024-11-14T12:32:32.173586", "lvl": "target", "msg": "<6>[    0.843911] Performance events: No support for PMU type 'ultra12'\r"}
- {"dt": "2024-11-14T12:32:32.175205", "lvl": "target", "msg": "<6>[    0.845815] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns\r"}
- {"dt": "2024-11-14T12:32:32.175974", "lvl": "target", "msg": "<6>[    0.846722] futex hash table entries: 256 (order: 1, 16384 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.182966", "lvl": "target", "msg": "<6>[    0.853696] NET: Registered PF_NETLINK/PF_ROUTE protocol family\r"}
- {"dt": "2024-11-14T12:32:32.200070", "lvl": "target", "msg": "<4>[    0.870546] pci@1f,0: PCI IO [io  0x1fe02000000-0x1fe02ffffff] offset 1fe02000000\r"}
- {"dt": "2024-11-14T12:32:32.200548", "lvl": "target", "msg": "<4>[    0.871257] pci@1f,0: PCI MEM [mem 0x1ff00000000-0x1ffefffffff] offset 1ff00000000\r"}
- {"dt": "2024-11-14T12:32:32.201298", "lvl": "target", "msg": "<6>[    0.872049] pci@1f,0: SABRE PCI Bus Module ver[0:0]\r"}
- {"dt": "2024-11-14T12:32:32.201670", "lvl": "target", "msg": "<4>[    0.872496] PCI: Scanning PBM /pci@1f,0\r"}
- {"dt": "2024-11-14T12:32:32.204942", "lvl": "target", "msg": "<6>[    0.875624] sabre ffe2e480: PCI host bridge to bus 0000:00\r"}
- {"dt": "2024-11-14T12:32:32.205419", "lvl": "target", "msg": "<4>[    0.876200] pci_bus 0000:00: Unknown NUMA node; performance will be reduced\r"}
- {"dt": "2024-11-14T12:32:32.206152", "lvl": "target", "msg": "<6>[    0.876871] pci_bus 0000:00: root bus resource [io  0x1fe02000000-0x1fe02ffffff] (bus address [0x0000-0xffffff])\r"}
- {"dt": "2024-11-14T12:32:32.206692", "lvl": "target", "msg": "<6>[    0.877413] pci_bus 0000:00: root bus resource [mem 0x1ff00000000-0x1ffefffffff] (bus address [0x00000000-0xefffffff])\r"}
- {"dt": "2024-11-14T12:32:32.207329", "lvl": "target", "msg": "<6>[    0.878043] pci_bus 0000:00: root bus resource [bus 00-02]\r"}
- {"dt": "2024-11-14T12:32:32.208602", "lvl": "target", "msg": "<6>[    0.879356] pci 0000:00:01.1: [108e:5000] type 01 class 0x060400\r"}
- {"dt": "2024-11-14T12:32:32.211182", "lvl": "target", "msg": "<6>[    0.881936] pci_bus 0000:01: extended config space not accessible\r"}
- {"dt": "2024-11-14T12:32:32.212291", "lvl": "target", "msg": "<6>[    0.883054] pci 0000:01:01.0: [108e:1000] type 00 class 0x068000\r"}
- {"dt": "2024-11-14T12:32:32.212791", "lvl": "target", "msg": "<6>[    0.883562] pci 0000:01:01.0: reg 0x10: [mem 0x1ff20000000-0x1ff20ffffff]\r"}
- {"dt": "2024-11-14T12:32:32.213263", "lvl": "target", "msg": "<6>[    0.884046] pci 0000:01:01.0: reg 0x14: [io  0x1fe02000000-0x1fe02007fff]\r"}
- {"dt": "2024-11-14T12:32:32.214129", "lvl": "target", "msg": "<6>[    0.884903] pci 0000:01:02.0: [1234:1111] type 00 class 0x030000\r"}
- {"dt": "2024-11-14T12:32:32.214612", "lvl": "target", "msg": "<6>[    0.885318] pci 0000:01:02.0: reg 0x10: [mem 0x1ff21000000-0x1ff21ffffff pref]\r"}
- {"dt": "2024-11-14T12:32:32.214991", "lvl": "target", "msg": "<6>[    0.885801] pci 0000:01:02.0: reg 0x18: [mem 0x1ff22000000-0x1ff22000fff]\r"}
- {"dt": "2024-11-14T12:32:32.215895", "lvl": "target", "msg": "<6>[    0.886624] pci 0000:01:03.0: [1095:0646] type 00 class 0x01018f\r"}
- {"dt": "2024-11-14T12:32:32.216258", "lvl": "target", "msg": "<6>[    0.887052] pci 0000:01:03.0: reg 0x10: [io  0x1fe02008000-0x1fe02008007]\r"}
- {"dt": "2024-11-14T12:32:32.216686", "lvl": "target", "msg": "<6>[    0.887486] pci 0000:01:03.0: reg 0x14: [io  0x1fe02008080-0x1fe02008083]\r"}
- {"dt": "2024-11-14T12:32:32.217087", "lvl": "target", "msg": "<6>[    0.887902] pci 0000:01:03.0: reg 0x18: [io  0x1fe02008100-0x1fe02008107]\r"}
- {"dt": "2024-11-14T12:32:32.217622", "lvl": "target", "msg": "<6>[    0.888306] pci 0000:01:03.0: reg 0x1c: [io  0x1fe02008180-0x1fe02008183]\r"}
- {"dt": "2024-11-14T12:32:32.218224", "lvl": "target", "msg": "<6>[    0.888989] pci 0000:01:03.0: reg 0x20: [io  0x1fe02008200-0x1fe0200820f]\r"}
- {"dt": "2024-11-14T12:32:32.218925", "lvl": "target", "msg": "<6>[    0.889684] pci 0000:00:01.0: [108e:5000] type 01 class 0x060400\r"}
- {"dt": "2024-11-14T12:32:32.219682", "lvl": "target", "msg": "<6>[    0.890436] pci_bus 0000:02: extended config space not accessible\r"}
- {"dt": "2024-11-14T12:32:32.220816", "lvl": "target", "msg": "<6>[    0.891484] pci 0000:01:02.0: can't claim VGA legacy [mem 0x1ff000a0000-0x1ff000bffff]: no compatible bridge window\r"}
- {"dt": "2024-11-14T12:32:32.221523", "lvl": "target", "msg": "<3>[    0.892246] pci 0000:00:01.1: failed to populate child OF nodes (-19)\r"}
- {"dt": "2024-11-14T12:32:32.221912", "lvl": "target", "msg": "<3>[    0.892727] pci 0000:00:01.0: failed to populate child OF nodes (-19)\r"}
- {"dt": "2024-11-14T12:32:32.232563", "lvl": "target", "msg": "<6>[    0.903261] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages\r"}
- {"dt": "2024-11-14T12:32:32.232911", "lvl": "target", "msg": "<6>[    0.903728] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page\r"}
- {"dt": "2024-11-14T12:32:32.233345", "lvl": "target", "msg": "<6>[    0.904161] HugeTLB: registered 8.00 MiB page size, pre-allocated 0 pages\r"}
- {"dt": "2024-11-14T12:32:32.233748", "lvl": "target", "msg": "<6>[    0.904571] HugeTLB: 0 KiB vmemmap can be freed for a 8.00 MiB page\r"}
- {"dt": "2024-11-14T12:32:32.234200", "lvl": "target", "msg": "<6>[    0.904979] HugeTLB: registered 256 MiB page size, pre-allocated 0 pages\r"}
- {"dt": "2024-11-14T12:32:32.234576", "lvl": "target", "msg": "<6>[    0.905411] HugeTLB: 0 KiB vmemmap can be freed for a 256 MiB page\r"}
- {"dt": "2024-11-14T12:32:32.234994", "lvl": "target", "msg": "<6>[    0.905798] HugeTLB: registered 2.00 GiB page size, pre-allocated 0 pages\r"}
- {"dt": "2024-11-14T12:32:32.235380", "lvl": "target", "msg": "<6>[    0.906218] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 GiB page\r"}
- {"dt": "2024-11-14T12:32:32.250791", "lvl": "target", "msg": "<5>[    0.921449] SCSI subsystem initialized\r"}
- {"dt": "2024-11-14T12:32:32.252261", "lvl": "target", "msg": "<7>[    0.922580] libata version 3.00 loaded.\r"}
- {"dt": "2024-11-14T12:32:32.252659", "lvl": "target", "msg": "<6>[    0.923409] usbcore: registered new interface driver usbfs\r"}
- {"dt": "2024-11-14T12:32:32.253229", "lvl": "target", "msg": "<6>[    0.924003] usbcore: registered new interface driver hub\r"}
- {"dt": "2024-11-14T12:32:32.253755", "lvl": "target", "msg": "<6>[    0.924512] usbcore: registered new device driver usb\r"}
- {"dt": "2024-11-14T12:32:32.254658", "lvl": "target", "msg": "<6>[    0.925193] pps_core: LinuxPPS API ver. 1 registered\r"}
- {"dt": "2024-11-14T12:32:32.254887", "lvl": "target", "msg": "<6>[    0.925600] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>\r"}
- {"dt": "2024-11-14T12:32:32.255340", "lvl": "target", "msg": "<6>[    0.926186] PTP clock support registered\r"}
- {"dt": "2024-11-14T12:32:32.280253", "lvl": "target", "msg": "<6>[    0.950951] pci 0000:01:02.0: vgaarb: setting as boot VGA device\r"}
- {"dt": "2024-11-14T12:32:32.280643", "lvl": "target", "msg": "<6>[    0.951431] pci 0000:01:02.0: vgaarb: bridge control possible\r"}
- {"dt": "2024-11-14T12:32:32.281091", "lvl": "target", "msg": "<6>[    0.951859] pci 0000:01:02.0: vgaarb: VGA device added: decodes=io+mem,owns=none,locks=none\r"}
- {"dt": "2024-11-14T12:32:32.281578", "lvl": "target", "msg": "<6>[    0.952347] vgaarb: loaded\r"}
- {"dt": "2024-11-14T12:32:32.282199", "lvl": "target", "msg": "<6>[    0.952941] /pci@1f,0/pci@1,1/ebus@1/eeprom@14,2000: Mostek regs at 0x1fe02002000\r"}
- {"dt": "2024-11-14T12:32:32.290466", "lvl": "target", "msg": "<6>[    0.961167] clocksource: Switched to clocksource tick\r"}
- {"dt": "2024-11-14T12:32:32.316649", "lvl": "target", "msg": "<6>[    0.987377] NET: Registered PF_INET protocol family\r"}
- {"dt": "2024-11-14T12:32:32.318078", "lvl": "target", "msg": "<6>[    0.988824] IP idents hash table entries: 65536 (order: 6, 524288 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.325022", "lvl": "target", "msg": "<6>[    0.995702] tcp_listen_portaddr_hash hash table entries: 2048 (order: 2, 32768 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.325874", "lvl": "target", "msg": "<6>[    0.996325] Table-perturb hash table entries: 65536 (order: 5, 262144 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.326435", "lvl": "target", "msg": "<6>[    0.997017] TCP established hash table entries: 32768 (order: 5, 262144 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.327040", "lvl": "target", "msg": "<6>[    0.997765] TCP bind hash table entries: 32768 (order: 7, 1048576 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.328131", "lvl": "target", "msg": "<6>[    0.998873] TCP: Hash tables configured (established 32768 bind 32768)\r"}
- {"dt": "2024-11-14T12:32:32.329191", "lvl": "target", "msg": "<6>[    0.999928] UDP hash table entries: 2048 (order: 3, 65536 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.329812", "lvl": "target", "msg": "<6>[    1.000573] UDP-Lite hash table entries: 2048 (order: 3, 65536 bytes, linear)\r"}
- {"dt": "2024-11-14T12:32:32.333263", "lvl": "target", "msg": "<6>[    1.002248] NET: Registered PF_UNIX/PF_LOCAL protocol family\r"}
- {"dt": "2024-11-14T12:32:32.333345", "lvl": "target", "msg": "<6>[    1.003001] PCI: CLS 0 bytes, default 64\r"}
- {"dt": "2024-11-14T12:32:32.335925", "lvl": "target", "msg": "<6>[    1.006646] power: Control reg at 1fe02007240\r"}
- {"dt": "2024-11-14T12:32:32.340374", "lvl": "target", "msg": "<6>[    1.011111] workingset: timestamp_bits=57 max_order=19 bucket_order=0\r"}
- {"dt": "2024-11-14T12:32:32.416514", "lvl": "target", "msg": "<6>[    1.087158] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)\r"}
- {"dt": "2024-11-14T12:32:32.416919", "lvl": "target", "msg": "<6>[    1.087768] io scheduler mq-deadline registered\r"}
- {"dt": "2024-11-14T12:32:32.417311", "lvl": "target", "msg": "<6>[    1.088186] io scheduler kyber registered\r"}
- {"dt": "2024-11-14T12:32:32.421762", "lvl": "target", "msg": "<6>[    1.092487] ffe30b48: ttyS0 at MMIO 0x1fe020003f8 (irq = 5, base_baud = 115387) is a 16550A\r"}
- {"dt": "2024-11-14T12:32:32.423203", "lvl": "target", "msg": "<4>[    1.093327] Console: ttyS0 (SU)\r"}
- {"dt": "2024-11-14T12:32:32.423892", "lvl": "target", "msg": "<6>[    1.094662] printk: legacy console [ttyS0] enabled"}
- {"dt": "2024-11-14T12:32:32.424275", "lvl": "target", "msg": "<6>[    1.094662] printk: legacy console [ttyS0] enabled\r"}
- {"dt": "2024-11-14T12:32:32.424609", "lvl": "target", "msg": "<6>[    1.095595] printk: legacy bootconsole [earlyprom0] disabled"}
- {"dt": "2024-11-14T12:32:32.424982", "lvl": "target", "msg": "<6>[    1.095595] printk: legacy bootconsole [earlyprom0] disabled\r"}
- {"dt": "2024-11-14T12:32:32.434045", "lvl": "target", "msg": "<6>[    1.105023] scsi host0: pata_cmd64x"}
- {"dt": "2024-11-14T12:32:32.436274", "lvl": "target", "msg": "<6>[    1.107235] scsi host1: pata_cmd64x"}
- {"dt": "2024-11-14T12:32:32.436852", "lvl": "target", "msg": "<6>[    1.107664] ata1: PATA max UDMA/33 cmd 0x1fe02008000 ctl 0x1fe02008080 bmdma 0x1fe02008200 irq 7 lpm-pol 0"}
- {"dt": "2024-11-14T12:32:32.437292", "lvl": "target", "msg": "<6>[    1.108125] ata2: PATA max UDMA/33 cmd 0x1fe02008100 ctl 0x1fe02008180 bmdma 0x1fe02008208 irq 7 lpm-pol 0"}
- {"dt": "2024-11-14T12:32:32.445930", "lvl": "target", "msg": "<6>[    1.116885] rtc-m48t59 rtc-m48t59.0: registered as rtc0"}
- {"dt": "2024-11-14T12:32:32.447220", "lvl": "target", "msg": "<6>[    1.117714] rtc-m48t59 rtc-m48t59.0: setting system clock to 2024-11-14T12:32:32 UTC (1731587552)"}
- {"dt": "2024-11-14T12:32:32.448816", "lvl": "target", "msg": "<6>[    1.119808] usbcore: registered new interface driver usbhid"}
- {"dt": "2024-11-14T12:32:32.449001", "lvl": "target", "msg": "<6>[    1.120057] usbhid: USB HID core driver"}
- {"dt": "2024-11-14T12:32:32.450567", "lvl": "target", "msg": "<6>[    1.121555] NET: Registered PF_INET6 protocol family"}
- {"dt": "2024-11-14T12:32:32.455717", "lvl": "target", "msg": "<6>[    1.126681] Segment Routing with IPv6"}
- {"dt": "2024-11-14T12:32:32.456007", "lvl": "target", "msg": "<6>[    1.127014] In-situ OAM (IOAM) with IPv6"}
- {"dt": "2024-11-14T12:32:32.456721", "lvl": "target", "msg": "<6>[    1.127681] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver"}
- {"dt": "2024-11-14T12:32:32.459186", "lvl": "target", "msg": "<6>[    1.130151] NET: Registered PF_PACKET protocol family"}
- {"dt": "2024-11-14T12:32:32.474637", "lvl": "target", "msg": "<6>[    1.145612] Demotion targets for Node 0: null"}
- {"dt": "2024-11-14T12:32:32.482688", "lvl": "target", "msg": "<6>[    1.153648] Waiting 10 sec before mounting root device..."}
- {"dt": "2024-11-14T12:32:32.601016", "lvl": "target", "msg": "<6>[    1.271896] ata1: found unknown device (class 0)"}
- {"dt": "2024-11-14T12:32:32.604993", "lvl": "target", "msg": "<6>[    1.275945] ata1.00: ATA-7: QEMU HARDDISK, 2.5+, max UDMA/100"}
- {"dt": "2024-11-14T12:32:32.605296", "lvl": "target", "msg": "<6>[    1.276282] ata1.00: 2097152 sectors, multi 16: LBA48 "}
- {"dt": "2024-11-14T12:32:32.615915", "lvl": "target", "msg": "<5>[    1.286777] scsi 0:0:0:0: Direct-Access     ATA      QEMU HARDDISK    2.5+ PQ: 0 ANSI: 5"}
- {"dt": "2024-11-14T12:32:32.621041", "lvl": "target", "msg": "<5>[    1.291935] sd 0:0:0:0: [sda] 2097152 512-byte logical blocks: (1.07 GB/1.00 GiB)"}
- {"dt": "2024-11-14T12:32:32.621781", "lvl": "target", "msg": "<5>[    1.292748] sd 0:0:0:0: [sda] Write Protect is off"}
- {"dt": "2024-11-14T12:32:32.622003", "lvl": "target", "msg": "<7>[    1.293005] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00"}
- {"dt": "2024-11-14T12:32:32.622699", "lvl": "target", "msg": "<5>[    1.293560] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA"}
- {"dt": "2024-11-14T12:32:32.623928", "lvl": "target", "msg": "<6>[    1.294888] sd 0:0:0:0: [sda] Preferred minimum I/O size 512 bytes"}
- {"dt": "2024-11-14T12:32:32.668937", "lvl": "target", "msg": "<5>[    1.339877] sd 0:0:0:0: [sda] Attached SCSI disk"}
- {"dt": "2024-11-14T12:32:32.779983", "lvl": "target", "msg": "<6>[    1.450832] ata2: found unknown device (class 0)"}
- {"dt": "2024-11-14T12:32:32.780861", "lvl": "target", "msg": "<6>[    1.451836] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100"}
- {"dt": "2024-11-14T12:32:32.784150", "lvl": "target", "msg": "<5>[    1.455002] scsi 1:0:0:0: CD-ROM            QEMU     QEMU DVD-ROM     2.5+ PQ: 0 ANSI: 5"}
- {"dt": "2024-11-14T12:32:42.705965", "lvl": "target", "msg": "<6>[   11.376804] EXT4-fs (sda): orphan cleanup on readonly fs"}
- {"dt": "2024-11-14T12:32:42.707313", "lvl": "target", "msg": "<6>[   11.377919] EXT4-fs (sda): mounted filesystem 3eed6636-a12a-426c-a6eb-6ac31be70b1f ro with ordered data mode. Quota mode: disabled."}
- {"dt": "2024-11-14T12:32:42.707773", "lvl": "target", "msg": "<6>[   11.378702] VFS: Mounted root (ext4 filesystem) readonly on device 8:0."}
- {"dt": "2024-11-14T12:32:42.746957", "lvl": "target", "msg": "<4>[   11.417880] This architecture does not have kernel memory protection."}
- {"dt": "2024-11-14T12:32:42.747528", "lvl": "target", "msg": "<6>[   11.418490] Run /sbin/init as init process"}
- {"dt": "2024-11-14T12:32:42.747599", "lvl": "target", "msg": "<7>[   11.418688]   with arguments:"}
- {"dt": "2024-11-14T12:32:42.747746", "lvl": "target", "msg": "<7>[   11.418837]     /sbin/init"}
- {"dt": "2024-11-14T12:32:42.747881", "lvl": "target", "msg": "<7>[   11.418982]     verbose"}
- {"dt": "2024-11-14T12:32:42.747998", "lvl": "target", "msg": "<7>[   11.419099]     earlycon"}
- {"dt": "2024-11-14T12:32:42.748140", "lvl": "target", "msg": "<7>[   11.419223]   with environment:"}
- {"dt": "2024-11-14T12:32:42.748414", "lvl": "target", "msg": "<7>[   11.419379]     HOME=/"}
- {"dt": "2024-11-14T12:32:42.748459", "lvl": "target", "msg": "<7>[   11.419504]     TERM=linux"}
- {"dt": "2024-11-14T12:32:43.012651", "lvl": "target", "msg": "<6>[   11.683437] EXT4-fs (sda): re-mounted 3eed6636-a12a-426c-a6eb-6ac31be70b1f r/w. Quota mode: disabled."}
- {"dt": "2024-11-14T12:32:43.119348", "lvl": "target", "msg": "\rcan't open /dev/null: No such file or directory"}
- {"dt": "2024-11-14T12:32:43.121478", "lvl": "target", "msg": "\rcan't open /dev/null: No such file or directory"}
- {"dt": "2024-11-14T12:32:43.122573", "lvl": "target", "msg": "\rcan't open /dev/null: No such file or directory"}
- {"dt": "2024-11-14T12:32:43.123512", "lvl": "target", "msg": "\rcan't open /dev/null: No such file or directory"}
- {"dt": "2024-11-14T12:32:43.298584", "lvl": "target", "msg": "Saving 256 bits of non-creditable seed for next boot"}
- {"dt": "2024-11-14T12:32:43.375624", "lvl": "target", "msg": "Starting syslogd: OK"}
- {"dt": "2024-11-14T12:32:43.454296", "lvl": "target", "msg": "Starting klogd: OK"}
- {"dt": "2024-11-14T12:32:43.666713", "lvl": "target", "msg": "Running sysctl: OK"}
- {"dt": "2024-11-14T12:32:43.713463", "lvl": "target", "msg": "Starting mdev... OK"}
- {"dt": "2024-11-14T12:32:45.019154", "lvl": "target", "msg": "Starting network: OK"}
- {"dt": "2024-11-14T12:32:45.149428", "lvl": "target", "msg": "\r"}
- {"dt": "2024-11-14T12:32:45.151238", "lvl": "target", "msg": "Welcome to TuxTest"}
- {"dt": "2024-11-14T12:32:45.152315", "lvl": "debug", "msg": "Matched prompt #11: login:"}
- {"dt": "2024-11-14T12:32:45.152409", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "kernel-messages", "level": "2.2.1", "duration": "13.82", "result": "pass", "extra": {"extra": []}}}
- {"dt": "2024-11-14T12:32:45.152531", "lvl": "debug", "msg": "Sending username root"}
- {"dt": "2024-11-14T12:32:45.152583", "lvl": "debug", "msg": "Sending line: 'root'"}
- {"dt": "2024-11-14T12:32:45.252879", "lvl": "input", "msg": "root"}
- {"dt": "2024-11-14T12:32:45.253086", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2024-11-14T12:32:45.253171", "lvl": "debug", "msg": "login-action: Wait for prompt ['root@(.*):[/~]#', 'Login incorrect', 'Login timed out'] (timeout 00:14:45)"}
- {"dt": "2024-11-14T12:32:45.253254", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:07:22)"}
- {"dt": "2024-11-14T12:32:45.258182", "lvl": "target", "msg": "\rtuxtest login: root"}
- {"dt": "2024-11-14T12:32:45.367263", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2024-11-14T12:32:45.367442", "lvl": "debug", "msg": "end: 2.2.1 login-action (duration 00:00:14) [common]"}
- {"dt": "2024-11-14T12:32:45.367523", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "login-action", "level": "2.2.1", "duration": "14.03", "result": "pass", "extra": {"success": "No kernel warnings or errors detected."}}}
- {"dt": "2024-11-14T12:32:45.367665", "lvl": "debug", "msg": "end: 2.2 auto-login-action (duration 00:00:15) [common]"}
- {"dt": "2024-11-14T12:32:45.367757", "lvl": "debug", "msg": "start: 2.3 expect-shell-connection (timeout 00:14:45) [common]"}
- {"dt": "2024-11-14T12:32:45.367830", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2024-11-14T12:32:45.367892", "lvl": "debug", "msg": "Forcing a shell prompt, looking for ['root@(.*):[/~]#']"}
- {"dt": "2024-11-14T12:32:45.368002", "lvl": "debug", "msg": "Sending line: ''"}
- {"dt": "2024-11-14T12:32:45.418158", "lvl": "input", "msg": ""}
- {"dt": "2024-11-14T12:32:45.418322", "lvl": "debug", "msg": "expect-shell-connection: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:15:00)"}
- {"dt": "2024-11-14T12:32:45.418399", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:07:30)"}
- {"dt": "2024-11-14T12:32:45.424088", "lvl": "target", "msg": "root@tuxtest:~# "}
- {"dt": "2024-11-14T12:32:45.426860", "lvl": "debug", "msg": "end: 2.3 expect-shell-connection (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:45.426964", "lvl": "debug", "msg": "start: 2.4 export-device-env (timeout 00:14:45) [common]"}
- {"dt": "2024-11-14T12:32:45.427065", "lvl": "debug", "msg": "end: 2.4 export-device-env (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:45.427157", "lvl": "info", "msg": "end: 2 boot-image-retry (duration 00:00:15) [common]"}
- {"dt": "2024-11-14T12:32:45.427246", "lvl": "info", "msg": "start: 3 lava-test-retry (timeout 00:02:00) [common]"}
- {"dt": "2024-11-14T12:32:45.427325", "lvl": "debug", "msg": "start: 3.1 lava-test-shell (timeout 00:02:00) [common]"}
- {"dt": "2024-11-14T12:32:45.427396", "lvl": "debug", "msg": "Using namespace: common"}
- {"dt": "2024-11-14T12:32:45.427463", "lvl": "debug", "msg": "Sending line: '#'"}
- {"dt": "2024-11-14T12:32:45.527697", "lvl": "input", "msg": "#"}
- {"dt": "2024-11-14T12:32:45.527943", "lvl": "debug", "msg": "lava-test-shell: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:02:00)"}
- {"dt": "2024-11-14T12:32:45.532802", "lvl": "target", "msg": "root@tuxtest:~# #"}
- {"dt": "2024-11-14T12:32:45.535157", "lvl": "debug", "msg": "Using /lava-1"}
- {"dt": "2024-11-14T12:32:45.535241", "lvl": "debug", "msg": "Sending line: 'export SHELL=/bin/sh'"}
- {"dt": "2024-11-14T12:32:45.635496", "lvl": "input", "msg": "export SHELL=/bin/sh"}
- {"dt": "2024-11-14T12:32:45.641608", "lvl": "target", "msg": "root@tuxtest:~# export SHELL=/bin/sh"}
- {"dt": "2024-11-14T12:32:45.643493", "lvl": "debug", "msg": "Sending line: '. /lava-1/environment'"}
- {"dt": "2024-11-14T12:32:45.743737", "lvl": "input", "msg": ". /lava-1/environment"}
- {"dt": "2024-11-14T12:32:45.748493", "lvl": "target", "msg": "root@tuxtest:~# . /lava-1/environment"}
- {"dt": "2024-11-14T12:32:45.751543", "lvl": "debug", "msg": "Sending line: '/lava-1/bin/lava-test-runner /lava-1/0'"}
- {"dt": "2024-11-14T12:32:45.851828", "lvl": "input", "msg": "/lava-1/bin/lava-test-runner /lava-1/0"}
- {"dt": "2024-11-14T12:32:45.852055", "lvl": "info", "msg": "Test shell timeout: 10s (minimum of the action and connection timeout)"}
- {"dt": "2024-11-14T12:32:45.856754", "lvl": "target", "msg": "root@tuxtest:~# /lava-1/bin/lava-test-runner /lava-1/0"}
- {"dt": "2024-11-14T12:32:46.058997", "lvl": "target", "msg": "+ export TESTRUN_ID=0_commands"}
- {"dt": "2024-11-14T12:32:46.059773", "lvl": "target", "msg": "+ TESTRUN_ID=0_commands"}
- {"dt": "2024-11-14T12:32:46.060443", "lvl": "target", "msg": "+ cd /lava-1/0/tests/0_commands"}
- {"dt": "2024-11-14T12:32:46.065876", "lvl": "target", "msg": "++ cat uuid"}
- {"dt": "2024-11-14T12:32:46.080113", "lvl": "target", "msg": "+ UUID=1_1.1.3.1"}
- {"dt": "2024-11-14T12:32:46.080612", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2024-11-14T12:32:46.081503", "lvl": "target", "msg": "<LAVA_SIGNAL_STARTRUN 0_commands 1_1.1.3.1>"}
- {"dt": "2024-11-14T12:32:46.081731", "lvl": "debug", "msg": "Received signal: <STARTRUN> 0_commands 1_1.1.3.1"}
- {"dt": "2024-11-14T12:32:46.081788", "lvl": "info", "msg": "Starting test lava.0_commands (1_1.1.3.1)"}
- {"dt": "2024-11-14T12:32:46.081861", "lvl": "info", "msg": "Skipping test definition patterns."}
- {"dt": "2024-11-14T12:32:46.082396", "lvl": "target", "msg": "+ lava-test-case command --shell 'ls -l /dev/null && stat /dev/null'"}
- {"dt": "2024-11-14T12:32:46.107007", "lvl": "target", "msg": "<LAVA_SIGNAL_STARTTC command>"}
- {"dt": "2024-11-14T12:32:46.107308", "lvl": "debug", "msg": "Received signal: <STARTTC> command"}
- {"dt": "2024-11-14T12:32:46.135209", "lvl": "target", "msg": "-rw-rw---- 1 root root 12 Nov 14 12:32 /dev/null"}
- {"dt": "2024-11-14T12:32:46.150859", "lvl": "target", "msg": "  File: /dev/null"}
- {"dt": "2024-11-14T12:32:46.152653", "lvl": "target", "msg": "  Size: 12        \tBlocks: 8          IO Block: 4096   regular file"}
- {"dt": "2024-11-14T12:32:46.153072", "lvl": "target", "msg": "Device: 8,0\tInode: 9109        Links: 1"}
- {"dt": "2024-11-14T12:32:46.155720", "lvl": "target", "msg": "Access: (0660/-rw-rw----)  Uid: (    0/    root)   Gid: (    0/    root)"}
- {"dt": "2024-11-14T12:32:46.156790", "lvl": "target", "msg": "Access: 2024-11-14 12:32:43.600000000 +0000"}
- {"dt": "2024-11-14T12:32:46.157219", "lvl": "target", "msg": "Modify: 2024-11-14 12:32:44.240000000 +0000"}
- {"dt": "2024-11-14T12:32:46.157599", "lvl": "target", "msg": "Change: 2024-11-14 12:32:44.240000000 +0000"}
- {"dt": "2024-11-14T12:32:46.157976", "lvl": "target", "msg": " Birth: 2024-11-14 12:32:43.600000000 +0000"}
- {"dt": "2024-11-14T12:32:46.162431", "lvl": "target", "msg": "<LAVA_SIGNAL_ENDTC command>"}
- {"dt": "2024-11-14T12:32:46.162690", "lvl": "debug", "msg": "Received signal: <ENDTC> command"}
- {"dt": "2024-11-14T12:32:46.179267", "lvl": "target", "msg": "<LAVA_SIGNAL_TESTCASE TEST_CASE_ID=command RESULT=pass>"}
- {"dt": "2024-11-14T12:32:46.179548", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=command RESULT=pass"}
- {"dt": "2024-11-14T12:32:46.179662", "lvl": "results", "msg": {"definition": "0_commands", "case": "command", "result": "pass", "starttc": ! "485", "endtc": ! "496"}}
- {"dt": "2024-11-14T12:32:46.184326", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2024-11-14T12:32:46.184848", "lvl": "target", "msg": "<LAVA_SIGNAL_ENDRUN 0_commands 1_1.1.3.1>"}
- {"dt": "2024-11-14T12:32:46.185107", "lvl": "debug", "msg": "Received signal: <ENDRUN> 0_commands 1_1.1.3.1"}
- {"dt": "2024-11-14T12:32:46.185170", "lvl": "info", "msg": "Ending use of test pattern."}
- {"dt": "2024-11-14T12:32:46.185225", "lvl": "info", "msg": "Ending test lava.0_commands (1_1.1.3.1), duration 0.10"}
- {"dt": "2024-11-14T12:32:46.185294", "lvl": "results", "msg": {"definition": "lava", "case": "0_commands", "uuid": "1_1.1.3.1", "repository": {"metadata": {"format": "lava-test test definition 1.0", "name": "commands", "description": "Run commands"}, "run": {"steps": ["lava-test-case command --shell 'ls -l /dev/null && stat /dev/null'"]}}, "path": "command", "duration": "0.10", "result": "pass", "revision": "unspecified", "namespace": "common"}}
- {"dt": "2024-11-14T12:32:46.195297", "lvl": "target", "msg": "<LAVA_TEST_RUNNER EXIT>"}
- {"dt": "2024-11-14T12:32:46.195528", "lvl": "info", "msg": "ok: lava_test_shell seems to have completed"}
- {"dt": "2024-11-14T12:32:46.195599", "lvl": "debug", "msg": "command: pass\n"}
- {"dt": "2024-11-14T12:32:46.195668", "lvl": "debug", "msg": "end: 3.1 lava-test-shell (duration 00:00:01) [common]"}
- {"dt": "2024-11-14T12:32:46.195729", "lvl": "info", "msg": "end: 3 lava-test-retry (duration 00:00:01) [common]"}
- {"dt": "2024-11-14T12:32:46.195793", "lvl": "info", "msg": "start: 4 finalize (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:46.195856", "lvl": "debug", "msg": "start: 4.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2024-11-14T12:32:46.195914", "lvl": "debug", "msg": "end: 4.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2024-11-14T12:32:46.195966", "lvl": "debug", "msg": "start: 4.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2024-11-14T12:32:46.196070", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2024-11-14T12:32:46.201179", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2024-11-14T12:32:47.197127", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2024-11-14T12:32:47.197342", "lvl": "debug", "msg": "Sending line: 'poweroff'"}
- {"dt": "2024-11-14T12:32:47.297582", "lvl": "input", "msg": "poweroff"}
- {"dt": "2024-11-14T12:32:47.298022", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2024-11-14T12:32:47.298082", "lvl": "target", "msg": "root@tuxtest:~# poweroff"}
- {"dt": "2024-11-14T12:32:47.398300", "lvl": "debug", "msg": "end: 4.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2024-11-14T12:32:47.398405", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2024-11-14T12:32:47.398490", "lvl": "info", "msg": "end: 4 finalize (duration 00:00:01) [common]"}
- {"dt": "2024-11-14T12:32:47.398586", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-11-14T12:32:47.398699", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/deployimages-2ujzuvv6/kernel"}
- {"dt": "2024-11-14T12:32:47.401775", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1/deployimages-2ujzuvv6/rootfs"}
- {"dt": "2024-11-14T12:32:47.573088", "lvl": "info", "msg": "Removing root tmp directory at /var/lib/lava/dispatcher/tmp/tuxrun-x3wzmrai-1"}
- {"dt": "2024-11-14T12:32:47.574204", "lvl": "info", "msg": "Job finished correctly"}
- {"dt": "2024-11-14T12:32:47.574277", "lvl": "results", "msg": {"definition": "lava", "case": "job", "result": "pass"}}
