- {"dt": "2023-02-02T12:35:13.302600", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2022.11.1"}
- {"dt": "2023-02-02T12:35:13.302730", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2023-02-02T12:35:13.302822", "lvl": "info", "msg": "Start time: 2023-02-02 12:35:13.302816+00:00 (UTC)"}
- {"dt": "2023-02-02T12:35:13.303824", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2023.01.tar.zst exists"}
- {"dt": "2023-02-02T12:35:13.304143", "lvl": "debug", "msg": "Validating that https://storage.tuxboot.com/riscv64/Image exists"}
- {"dt": "2023-02-02T12:35:13.694364", "lvl": "debug", "msg": "Validating that https://storage.tuxboot.com/riscv64/fw_jump.elf exists"}
- {"dt": "2023-02-02T12:35:14.072612", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_riscv64_rootfs.ext4.zst exists"}
- {"dt": "2023-02-02T12:35:14.073190", "lvl": "debug", "msg": "cmd: ['docker', 'pull', 'docker.io/linaro/tuxrun-qemu:master']"}
- {"dt": "2023-02-02T12:35:14.073332", "lvl": "debug", "msg": "Calling: 'nice' 'docker' 'pull' 'docker.io/linaro/tuxrun-qemu:master'"}
- {"dt": "2023-02-02T12:35:14.169688", "lvl": "debug", "msg": ">> SRC: '/usr/local/bin/docker pull docker.io/linaro/tuxrun-qemu:master'\r"}
- {"dt": "2023-02-02T12:35:14.170066", "lvl": "debug", "msg": ">> DST: '/usr/bin/podman --remote --url unix://run/podman/podman.sock pull docker.io/linaro/tuxrun-qemu:master'\r"}
- {"dt": "2023-02-02T12:35:14.208445", "lvl": "debug", "msg": ">> Trying to pull docker.io/linaro/tuxrun-qemu:master...\r"}
- {"dt": "2023-02-02T12:35:15.825161", "lvl": "debug", "msg": ">> Getting image source signatures\r"}
- {"dt": "2023-02-02T12:35:15.825681", "lvl": "debug", "msg": ">> Copying blob sha256:3313a463c20d9308e68334a22c52f11f0565fbc9021735c8b2541748ddfbb027\r"}
- {"dt": "2023-02-02T12:35:15.825867", "lvl": "debug", "msg": ">> Copying blob sha256:e0f2b672ff4188a5c5fb9133b4908ae53d235597a4fa16972839237e25769987\r"}
- {"dt": "2023-02-02T12:35:15.826024", "lvl": "debug", "msg": ">> Copying blob sha256:994260ae333aa8d74e5433ac19a3c3eb57d6bebdabc032187235057d40db0b1c\r"}
- {"dt": "2023-02-02T12:35:15.826163", "lvl": "debug", "msg": ">> Copying blob sha256:bbeef03cda1f5d6c9e20c310c1c91382a6b0a1a2501c3436b28152f13896f082\r"}
- {"dt": "2023-02-02T12:35:15.827211", "lvl": "debug", "msg": ">> Copying config sha256:1be8120b2fad8f5126cd3ec9180bd806ba7570f86b32047044293648b52e93ff\r"}
- {"dt": "2023-02-02T12:35:15.854319", "lvl": "debug", "msg": ">> Writing manifest to image destination\r"}
- {"dt": "2023-02-02T12:35:15.854472", "lvl": "debug", "msg": ">> Storing signatures\r"}
- {"dt": "2023-02-02T12:35:15.919082", "lvl": "debug", "msg": ">> 1be8120b2fad8f5126cd3ec9180bd806ba7570f86b32047044293648b52e93ff\r"}
- {"dt": "2023-02-02T12:35:15.922440", "lvl": "debug", "msg": "Returned 0 in 1 seconds"}
- {"dt": "2023-02-02T12:35:16.063491", "lvl": "debug", "msg": "cmd: ['docker', 'run', '--rm', '--init', 'docker.io/linaro/tuxrun-qemu:master', 'qemu-system-riscv64', '--version']"}
- {"dt": "2023-02-02T12:35:16.063825", "lvl": "debug", "msg": "Calling: 'nice' 'docker' 'run' '--rm' '--init' 'docker.io/linaro/tuxrun-qemu:master' 'qemu-system-riscv64' '--version'"}
- {"dt": "2023-02-02T12:35:16.156732", "lvl": "debug", "msg": ">> SRC: '/usr/local/bin/docker run --rm --init docker.io/linaro/tuxrun-qemu:master qemu-system-riscv64 --version'\r"}
- {"dt": "2023-02-02T12:35:16.157101", "lvl": "debug", "msg": ">> DST: '/usr/bin/podman --remote --url unix://run/podman/podman.sock run --rm --init docker.io/linaro/tuxrun-qemu:master qemu-system-riscv64 --version'\r"}
- {"dt": "2023-02-02T12:35:16.409005", "lvl": "debug", "msg": ">> QEMU emulator version 7.2.50\r"}
- {"dt": "2023-02-02T12:35:16.409272", "lvl": "debug", "msg": ">> Copyright (c) 2003-2022 Fabrice Bellard and the QEMU Project developers\r"}
- {"dt": "2023-02-02T12:35:16.685424", "lvl": "debug", "msg": "Returned 0 in 0 seconds"}
- {"dt": "2023-02-02T12:35:16.785956", "lvl": "warning", "msg": "Missing image arg for url_repo"}
- {"dt": "2023-02-02T12:35:16.786573", "lvl": "info", "msg": "validate duration: 3.48"}
- {"dt": "2023-02-02T12:35:16.786727", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2023-02-02T12:35:16.787131", "lvl": "info", "msg": "start: 1 deployimages (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:16.787387", "lvl": "debug", "msg": "start: 1.1 lava-overlay (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:16.787897", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq"}
- {"dt": "2023-02-02T12:35:16.788185", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin"}
- {"dt": "2023-02-02T12:35:16.788450", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/tests"}
- {"dt": "2023-02-02T12:35:16.788728", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/results"}
- {"dt": "2023-02-02T12:35:16.789067", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-add-keys"}
- {"dt": "2023-02-02T12:35:16.789474", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-add-sources"}
- {"dt": "2023-02-02T12:35:16.789831", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-background-process-start"}
- {"dt": "2023-02-02T12:35:16.790193", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-background-process-stop"}
- {"dt": "2023-02-02T12:35:16.790534", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-common-functions"}
- {"dt": "2023-02-02T12:35:16.790721", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-echo-ipv4"}
- {"dt": "2023-02-02T12:35:16.790911", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-install-packages"}
- {"dt": "2023-02-02T12:35:16.791090", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-installed-packages"}
- {"dt": "2023-02-02T12:35:16.791270", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-os-build"}
- {"dt": "2023-02-02T12:35:16.791492", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-probe-channel"}
- {"dt": "2023-02-02T12:35:16.791673", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-probe-ip"}
- {"dt": "2023-02-02T12:35:16.791854", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-target-ip"}
- {"dt": "2023-02-02T12:35:16.792065", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-target-mac"}
- {"dt": "2023-02-02T12:35:16.792252", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-target-storage"}
- {"dt": "2023-02-02T12:35:16.792439", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-test-case"}
- {"dt": "2023-02-02T12:35:16.792617", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-test-event"}
- {"dt": "2023-02-02T12:35:16.792798", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-test-feedback"}
- {"dt": "2023-02-02T12:35:16.793000", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-test-raise"}
- {"dt": "2023-02-02T12:35:16.793181", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-test-reference"}
- {"dt": "2023-02-02T12:35:16.793400", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-test-runner"}
- {"dt": "2023-02-02T12:35:16.793614", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-test-set"}
- {"dt": "2023-02-02T12:35:16.793801", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-test-shell"}
- {"dt": "2023-02-02T12:35:16.793988", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-install-packages (oe)"}
- {"dt": "2023-02-02T12:35:16.794200", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/bin/lava-installed-packages (oe)"}
- {"dt": "2023-02-02T12:35:16.794334", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/environment"}
- {"dt": "2023-02-02T12:35:16.794446", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2023-02-02T12:35:16.794540", "lvl": "debug", "msg": "- LAVA_JOB_ID=1"}
- {"dt": "2023-02-02T12:35:16.794640", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=10.0.2.100"}
- {"dt": "2023-02-02T12:35:16.794781", "lvl": "debug", "msg": "start: 1.1.1 lava-vland-overlay (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:16.794888", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2023-02-02T12:35:16.794957", "lvl": "debug", "msg": "end: 1.1.1 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:16.795077", "lvl": "debug", "msg": "start: 1.1.2 lava-multinode-overlay (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:16.795165", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2023-02-02T12:35:16.795275", "lvl": "debug", "msg": "end: 1.1.2 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:16.795384", "lvl": "debug", "msg": "start: 1.1.3 test-definition (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:16.795523", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2023-02-02T12:35:16.795642", "lvl": "debug", "msg": "start: 1.1.3.1 url-repo-action (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:16.795750", "lvl": "debug", "msg": "start: 1.1.3.1.1 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:16.795863", "lvl": "debug", "msg": "start: 1.1.3.1.1.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:16.796037", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2023.01.tar.zst"}
- {"dt": "2023-02-02T12:35:16.796109", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/url-repo-action-0by013x4/url_repo/https___storage.tuxboot.com_test-definitions_2023.01.tar"}
- {"dt": "2023-02-02T12:35:16.796185", "lvl": "debug", "msg": "total size: 13688498 (13MB)"}
- {"dt": "2023-02-02T12:35:16.796273", "lvl": "info", "msg": "Using unzstd to decompress zstd"}
- {"dt": "2023-02-02T12:35:16.798749", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-02-02T12:35:16.802548", "lvl": "debug", "msg": "progress   5% (0MB)"}
- {"dt": "2023-02-02T12:35:16.805157", "lvl": "debug", "msg": "progress  10% (1MB)"}
- {"dt": "2023-02-02T12:35:16.807148", "lvl": "debug", "msg": "progress  15% (1MB)"}
- {"dt": "2023-02-02T12:35:16.809550", "lvl": "debug", "msg": "progress  20% (2MB)"}
- {"dt": "2023-02-02T12:35:16.811562", "lvl": "debug", "msg": "progress  25% (3MB)"}
- {"dt": "2023-02-02T12:35:16.813650", "lvl": "debug", "msg": "progress  30% (3MB)"}
- {"dt": "2023-02-02T12:35:16.816532", "lvl": "debug", "msg": "progress  35% (4MB)"}
- {"dt": "2023-02-02T12:35:16.818927", "lvl": "debug", "msg": "progress  40% (5MB)"}
- {"dt": "2023-02-02T12:35:16.821560", "lvl": "debug", "msg": "progress  45% (5MB)"}
- {"dt": "2023-02-02T12:35:16.824801", "lvl": "debug", "msg": "progress  50% (6MB)"}
- {"dt": "2023-02-02T12:35:16.828108", "lvl": "debug", "msg": "progress  55% (7MB)"}
- {"dt": "2023-02-02T12:35:16.832892", "lvl": "debug", "msg": "progress  60% (7MB)"}
- {"dt": "2023-02-02T12:35:16.836968", "lvl": "debug", "msg": "progress  65% (8MB)"}
- {"dt": "2023-02-02T12:35:16.840201", "lvl": "debug", "msg": "progress  70% (9MB)"}
- {"dt": "2023-02-02T12:35:16.845395", "lvl": "debug", "msg": "progress  75% (9MB)"}
- {"dt": "2023-02-02T12:35:16.848961", "lvl": "debug", "msg": "progress  80% (10MB)"}
- {"dt": "2023-02-02T12:35:16.855311", "lvl": "debug", "msg": "progress  85% (11MB)"}
- {"dt": "2023-02-02T12:35:16.862184", "lvl": "debug", "msg": "progress  90% (11MB)"}
- {"dt": "2023-02-02T12:35:16.868641", "lvl": "debug", "msg": "progress  95% (12MB)"}
- {"dt": "2023-02-02T12:35:16.873884", "lvl": "debug", "msg": "progress 100% (13MB)"}
- {"dt": "2023-02-02T12:35:16.874898", "lvl": "info", "msg": "13MB downloaded in 0.08s (165.86MB/s)"}
- {"dt": "2023-02-02T12:35:16.875148", "lvl": "debug", "msg": "end: 1.1.3.1.1.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:16.875228", "lvl": "results", "msg": {"case": "file-download", "definition": "lava", "duration": "0.08", "extra": {"label": "url_repo", "md5sum": "261ec8c673852c799b239e8d6b3ecc5e", "sha256sum": "410fbd88bdbf7c098f0ab04d08d94914dabb7537fd1d8641f1f77fbdcc37bb5f", "sha512sum": "ebd15962216f72c47d15e71574eaa6cf5ba359eb19dbf8d516287a7b3b9cb437d016b3b8859650824407fcce000339c87e2660158e6802b125e12b3c825107e7", "size": ! "13688498"}, "level": "1.1.3.1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-02-02T12:35:16.875438", "lvl": "debug", "msg": "end: 1.1.3.1.1 download-retry (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:16.875534", "lvl": "debug", "msg": "Using /lava-1 at stage 0"}
- {"dt": "2023-02-02T12:35:16.875679", "lvl": "debug", "msg": "Runner path : /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/0/tests/0_ltp-fcntl-locktests"}
- {"dt": "2023-02-02T12:35:16.875788", "lvl": "info", "msg": "Untar tests from file /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/url-repo-action-0by013x4/url_repo/https___storage.tuxboot.com_test-definitions_2023.01.tar to directory /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/0/tests/0_ltp-fcntl-locktests"}
- {"dt": "2023-02-02T12:35:17.025999", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/ltp.yaml"}
- {"dt": "2023-02-02T12:35:17.026473", "lvl": "debug", "msg": "uuid=1_1.1.3.1 testdef=None"}
- {"dt": "2023-02-02T12:35:17.026635", "lvl": "debug", "msg": "end: 1.1.3.1 url-repo-action (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:17.026743", "lvl": "debug", "msg": "start: 1.1.3.2 test-overlay (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:17.027427", "lvl": "debug", "msg": "end: 1.1.3.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:17.027493", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "url", "name": "ltp-fcntl-locktests", "path": "automated/linux/ltp/ltp.yaml", "repository": "file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2023.01.tar.zst", "uuid": "1_1.1.3.1"}, "level": "1.1.3.2", "namespace": "common", "result": "pass"}}
- {"dt": "2023-02-02T12:35:17.027623", "lvl": "debug", "msg": "start: 1.1.3.3 test-install-overlay (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:17.028508", "lvl": "debug", "msg": "end: 1.1.3.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:17.028576", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "url", "name": "ltp-fcntl-locktests", "path": "automated/linux/ltp/ltp.yaml", "repository": "file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2023.01.tar.zst", "skipped test-install-overlay": "1_1.1.3.1", "uuid": "1_1.1.3.1"}, "level": "1.1.3.3", "namespace": "common", "result": "pass"}}
- {"dt": "2023-02-02T12:35:17.028711", "lvl": "debug", "msg": "start: 1.1.3.4 test-runscript-overlay (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:17.037000", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/0/tests/0_ltp-fcntl-locktests test_uuid 1_1.1.3.1"}
- {"dt": "2023-02-02T12:35:17.037072", "lvl": "debug", "msg": "SKIP_INSTALL='true'"}
- {"dt": "2023-02-02T12:35:17.037123", "lvl": "debug", "msg": "TST_CMDFILES='fcntl-locktests'"}
- {"dt": "2023-02-02T12:35:17.037169", "lvl": "debug", "msg": "SKIPFILE='skipfile-lkft.yaml'"}
- {"dt": "2023-02-02T12:35:17.037212", "lvl": "debug", "msg": "ENVIRONMENT='production'"}
- {"dt": "2023-02-02T12:35:17.037256", "lvl": "debug", "msg": "TIMEOUT_MULTIPLIER='5'"}
- {"dt": "2023-02-02T12:35:17.037300", "lvl": "debug", "msg": "LTP_TMPDIR='/scratch'"}
- {"dt": "2023-02-02T12:35:17.037342", "lvl": "debug", "msg": "LTP_INSTALL_PATH='/opt/ltp/'"}
- {"dt": "2023-02-02T12:35:17.037384", "lvl": "debug", "msg": "SHARD_NUMBER='1'"}
- {"dt": "2023-02-02T12:35:17.037427", "lvl": "debug", "msg": "SHARD_INDEX='1'"}
- {"dt": "2023-02-02T12:35:17.037542", "lvl": "debug", "msg": "end: 1.1.3.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:17.037604", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/0/tests/0_ltp-fcntl-locktests/run.sh", "from": "url", "name": "ltp-fcntl-locktests", "path": "automated/linux/ltp/ltp.yaml", "repository": "file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2023.01.tar.zst", "uuid": "1_1.1.3.1"}, "level": "1.1.3.4", "namespace": "common", "result": "pass"}}
- {"dt": "2023-02-02T12:35:17.037722", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2023-02-02T12:35:17.037771", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/lava-overlay-0j0kv0vq/lava-1/0 for stage 0"}
- {"dt": "2023-02-02T12:35:17.037842", "lvl": "debug", "msg": "- 0_ltp-fcntl-locktests"}
- {"dt": "2023-02-02T12:35:17.037927", "lvl": "debug", "msg": "end: 1.1.3 test-definition (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:17.037999", "lvl": "debug", "msg": "start: 1.1.4 compress-overlay (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:23.390033", "lvl": "debug", "msg": "end: 1.1.4 compress-overlay (duration 00:00:06) [common]"}
- {"dt": "2023-02-02T12:35:23.390199", "lvl": "debug", "msg": "start: 1.1.5 persistent-nfs-overlay (timeout 00:04:53) [common]"}
- {"dt": "2023-02-02T12:35:23.390282", "lvl": "debug", "msg": "end: 1.1.5 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:23.390364", "lvl": "debug", "msg": "end: 1.1 lava-overlay (duration 00:00:07) [common]"}
- {"dt": "2023-02-02T12:35:23.390441", "lvl": "debug", "msg": "start: 1.2 apply-overlay-guest (timeout 00:04:53) [common]"}
- {"dt": "2023-02-02T12:35:23.390504", "lvl": "debug", "msg": "Overlay already applied"}
- {"dt": "2023-02-02T12:35:23.390603", "lvl": "debug", "msg": "end: 1.2 apply-overlay-guest (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:23.390678", "lvl": "debug", "msg": "start: 1.3 deploy-device-env (timeout 00:04:53) [common]"}
- {"dt": "2023-02-02T12:35:23.390741", "lvl": "debug", "msg": "end: 1.3 deploy-device-env (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:23.390810", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:04:53) [common]"}
- {"dt": "2023-02-02T12:35:23.390897", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:04:53) [common]"}
- {"dt": "2023-02-02T12:35:23.391049", "lvl": "info", "msg": "downloading https://storage.tuxboot.com/riscv64/Image"}
- {"dt": "2023-02-02T12:35:23.391115", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/kernel/Image"}
- {"dt": "2023-02-02T12:35:23.391175", "lvl": "debug", "msg": "total size: 19825664 (18MB)"}
- {"dt": "2023-02-02T12:35:23.391234", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-02-02T12:35:24.211252", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-02-02T12:35:24.627282", "lvl": "debug", "msg": "progress   5% (0MB)"}
- {"dt": "2023-02-02T12:35:24.773977", "lvl": "debug", "msg": "progress  10% (1MB)"}
- {"dt": "2023-02-02T12:35:24.880447", "lvl": "debug", "msg": "progress  15% (2MB)"}
- {"dt": "2023-02-02T12:35:24.987952", "lvl": "debug", "msg": "progress  20% (3MB)"}
- {"dt": "2023-02-02T12:35:25.088991", "lvl": "debug", "msg": "progress  25% (4MB)"}
- {"dt": "2023-02-02T12:35:25.188704", "lvl": "debug", "msg": "progress  30% (5MB)"}
- {"dt": "2023-02-02T12:35:25.507363", "lvl": "debug", "msg": "progress  35% (6MB)"}
- {"dt": "2023-02-02T12:35:25.515490", "lvl": "debug", "msg": "progress  40% (7MB)"}
- {"dt": "2023-02-02T12:35:25.523208", "lvl": "debug", "msg": "progress  45% (8MB)"}
- {"dt": "2023-02-02T12:35:25.641035", "lvl": "debug", "msg": "progress  50% (9MB)"}
- {"dt": "2023-02-02T12:35:25.856056", "lvl": "debug", "msg": "progress  55% (10MB)"}
- {"dt": "2023-02-02T12:35:25.926935", "lvl": "debug", "msg": "progress  60% (11MB)"}
- {"dt": "2023-02-02T12:35:25.973360", "lvl": "debug", "msg": "progress  65% (12MB)"}
- {"dt": "2023-02-02T12:35:26.086738", "lvl": "debug", "msg": "progress  70% (13MB)"}
- {"dt": "2023-02-02T12:35:26.185461", "lvl": "debug", "msg": "progress  75% (14MB)"}
- {"dt": "2023-02-02T12:35:26.288480", "lvl": "debug", "msg": "progress  80% (15MB)"}
- {"dt": "2023-02-02T12:35:26.390707", "lvl": "debug", "msg": "progress  85% (16MB)"}
- {"dt": "2023-02-02T12:35:26.489827", "lvl": "debug", "msg": "progress  90% (17MB)"}
- {"dt": "2023-02-02T12:35:26.592420", "lvl": "debug", "msg": "progress  95% (17MB)"}
- {"dt": "2023-02-02T12:35:26.694013", "lvl": "debug", "msg": "progress 100% (18MB)"}
- {"dt": "2023-02-02T12:35:26.695936", "lvl": "info", "msg": "18MB downloaded in 3.30s (5.72MB/s)"}
- {"dt": "2023-02-02T12:35:26.696412", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:03) [common]"}
- {"dt": "2023-02-02T12:35:26.696550", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "3.31", "extra": {"label": "kernel", "md5sum": "96847b960e7cc3dc5959a1f563f3b0ea", "sha256sum": "3f1bdafa0506a0eb34d0109d83b8d96e636a6981a99e0c0f7949c93241f201d2", "sha512sum": "fa795b23e7fedbb308ad42c313f5e269e1f3151d5488f14fedb8482e762b12e50b4f6dc0aa46e5131068846c086d689a85a8758f3c6fe3484be0dbc824e7e7c0", "size": ! "19825664"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-02-02T12:35:26.696824", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:03) [common]"}
- {"dt": "2023-02-02T12:35:26.696962", "lvl": "debug", "msg": "start: 1.5 download-retry (timeout 00:04:50) [common]"}
- {"dt": "2023-02-02T12:35:26.697095", "lvl": "debug", "msg": "start: 1.5.1 http-download (timeout 00:04:50) [common]"}
- {"dt": "2023-02-02T12:35:26.697313", "lvl": "info", "msg": "downloading https://storage.tuxboot.com/riscv64/fw_jump.elf"}
- {"dt": "2023-02-02T12:35:26.697429", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/bios/fw_jump.elf"}
- {"dt": "2023-02-02T12:35:26.697524", "lvl": "debug", "msg": "total size: 766616 (0MB)"}
- {"dt": "2023-02-02T12:35:26.697614", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-02-02T12:35:27.414633", "lvl": "debug", "msg": "progress   4% (0MB)"}
- {"dt": "2023-02-02T12:35:27.513620", "lvl": "debug", "msg": "progress  12% (0MB)"}
- {"dt": "2023-02-02T12:35:27.598196", "lvl": "debug", "msg": "progress  17% (0MB)"}
- {"dt": "2023-02-02T12:35:27.612615", "lvl": "debug", "msg": "progress  25% (0MB)"}
- {"dt": "2023-02-02T12:35:27.638336", "lvl": "debug", "msg": "progress  34% (0MB)"}
- {"dt": "2023-02-02T12:35:27.698141", "lvl": "debug", "msg": "progress  42% (0MB)"}
- {"dt": "2023-02-02T12:35:27.701153", "lvl": "debug", "msg": "progress  47% (0MB)"}
- {"dt": "2023-02-02T12:35:27.711159", "lvl": "debug", "msg": "progress  55% (0MB)"}
- {"dt": "2023-02-02T12:35:27.721727", "lvl": "debug", "msg": "progress  64% (0MB)"}
- {"dt": "2023-02-02T12:35:27.732170", "lvl": "debug", "msg": "progress  72% (0MB)"}
- {"dt": "2023-02-02T12:35:27.789595", "lvl": "debug", "msg": "progress  81% (0MB)"}
- {"dt": "2023-02-02T12:35:27.797437", "lvl": "debug", "msg": "progress  89% (0MB)"}
- {"dt": "2023-02-02T12:35:27.802173", "lvl": "debug", "msg": "progress  94% (0MB)"}
- {"dt": "2023-02-02T12:35:27.805602", "lvl": "debug", "msg": "progress 100% (0MB)"}
- {"dt": "2023-02-02T12:35:27.807260", "lvl": "info", "msg": "0MB downloaded in 1.11s (0.66MB/s)"}
- {"dt": "2023-02-02T12:35:27.807949", "lvl": "debug", "msg": "end: 1.5.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2023-02-02T12:35:27.808083", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "1.11", "extra": {"label": "bios", "md5sum": "f86e9605b093cc938e7e4dfb44118bd2", "sha256sum": "f0880f5a8ea20327b7935c81e690944d2eb7e04b65940d0a5df3835db27f94e5", "sha512sum": "32d5c018c8b4cd2a60a752fcede5538206b0ffede4aa954a12a48e5009351d60e77a6585e05885b08e422505ea8d6321b662ca41a5248568849beaaeb5891b8f", "size": ! "766616"}, "level": "1.5.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-02-02T12:35:27.808356", "lvl": "debug", "msg": "end: 1.5 download-retry (duration 00:00:01) [common]"}
- {"dt": "2023-02-02T12:35:27.808497", "lvl": "debug", "msg": "start: 1.6 download-retry (timeout 00:04:49) [common]"}
- {"dt": "2023-02-02T12:35:27.808636", "lvl": "debug", "msg": "start: 1.6.1 file-download (timeout 00:04:49) [common]"}
- {"dt": "2023-02-02T12:35:27.808862", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_riscv64_rootfs.ext4.zst"}
- {"dt": "2023-02-02T12:35:27.808981", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/rootfs/https___storage.tuxboot.com_riscv64_rootfs.ext4"}
- {"dt": "2023-02-02T12:35:27.809079", "lvl": "debug", "msg": "total size: 58102171 (55MB)"}
- {"dt": "2023-02-02T12:35:27.809173", "lvl": "info", "msg": "Using unzstd to decompress zstd"}
- {"dt": "2023-02-02T12:35:27.812483", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-02-02T12:35:27.838228", "lvl": "debug", "msg": "progress   5% (2MB)"}
- {"dt": "2023-02-02T12:35:27.863704", "lvl": "debug", "msg": "progress  10% (5MB)"}
- {"dt": "2023-02-02T12:35:27.892113", "lvl": "debug", "msg": "progress  15% (8MB)"}
- {"dt": "2023-02-02T12:35:27.924066", "lvl": "debug", "msg": "progress  20% (11MB)"}
- {"dt": "2023-02-02T12:35:27.951250", "lvl": "debug", "msg": "progress  25% (13MB)"}
- {"dt": "2023-02-02T12:35:27.977764", "lvl": "debug", "msg": "progress  30% (16MB)"}
- {"dt": "2023-02-02T12:35:28.005351", "lvl": "debug", "msg": "progress  35% (19MB)"}
- {"dt": "2023-02-02T12:35:28.032327", "lvl": "debug", "msg": "progress  40% (22MB)"}
- {"dt": "2023-02-02T12:35:28.059485", "lvl": "debug", "msg": "progress  45% (24MB)"}
- {"dt": "2023-02-02T12:35:28.087293", "lvl": "debug", "msg": "progress  50% (27MB)"}
- {"dt": "2023-02-02T12:35:28.115094", "lvl": "debug", "msg": "progress  55% (30MB)"}
- {"dt": "2023-02-02T12:35:28.141462", "lvl": "debug", "msg": "progress  60% (33MB)"}
- {"dt": "2023-02-02T12:35:28.168295", "lvl": "debug", "msg": "progress  65% (36MB)"}
- {"dt": "2023-02-02T12:35:28.182899", "lvl": "debug", "msg": "progress  70% (38MB)"}
- {"dt": "2023-02-02T12:35:28.196309", "lvl": "debug", "msg": "progress  75% (41MB)"}
- {"dt": "2023-02-02T12:35:28.211212", "lvl": "debug", "msg": "progress  80% (44MB)"}
- {"dt": "2023-02-02T12:35:28.226656", "lvl": "debug", "msg": "progress  85% (47MB)"}
- {"dt": "2023-02-02T12:35:28.242267", "lvl": "debug", "msg": "progress  90% (49MB)"}
- {"dt": "2023-02-02T12:35:28.250146", "lvl": "debug", "msg": "progress  95% (52MB)"}
- {"dt": "2023-02-02T12:35:28.266354", "lvl": "debug", "msg": "progress 100% (55MB)"}
- {"dt": "2023-02-02T12:35:28.555117", "lvl": "info", "msg": "55MB downloaded in 0.75s (74.28MB/s)"}
- {"dt": "2023-02-02T12:35:28.555543", "lvl": "debug", "msg": "end: 1.6.1 file-download (duration 00:00:01) [common]"}
- {"dt": "2023-02-02T12:35:28.555683", "lvl": "results", "msg": {"case": "file-download", "definition": "lava", "duration": "0.75", "extra": {"label": "rootfs", "md5sum": "504d0f027be300e9c988a0df9600d9c3", "sha256sum": "a66a48cb5df32a41ec6cc750f8c554af7b912c9e5d11eada5bfc2e2c86200bc0", "sha512sum": "d0d12a99bc52e5c50e95e5f3de24d9ec729002d2c9bc0236fc726a779f12254ae836467b6930304c2737cf54afd5b6af33df3ff3235ec21a9de85dabcc0e7044", "size": ! "58102171"}, "level": "1.6.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-02-02T12:35:28.555887", "lvl": "debug", "msg": "start: 1.6.2 append-overlays (timeout 00:04:48) [common]"}
- {"dt": "2023-02-02T12:35:28.555965", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/rootfs/https___storage.tuxboot.com_riscv64_rootfs.ext4'"}
- {"dt": "2023-02-02T12:35:31.446023", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2023-02-02T12:35:31.446894", "lvl": "debug", "msg": "- rootfs.lava: '/var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/compress-overlay-x6xq8du_/overlay-1.1.4.tar.gz' to '/'"}
- {"dt": "2023-02-02T12:35:32.145232", "lvl": "debug", "msg": "end: 1.6.2 append-overlays (duration 00:00:04) [common]"}
- {"dt": "2023-02-02T12:35:32.145670", "lvl": "debug", "msg": "end: 1.6 download-retry (duration 00:00:04) [common]"}
- {"dt": "2023-02-02T12:35:32.145840", "lvl": "info", "msg": "end: 1 deployimages (duration 00:00:15) [common]"}
- {"dt": "2023-02-02T12:35:32.146005", "lvl": "info", "msg": "start: 2 boot-image-retry (timeout 00:15:00) [common]"}
- {"dt": "2023-02-02T12:35:32.146160", "lvl": "debug", "msg": "start: 2.1 boot-qemu-image (timeout 00:15:00) [common]"}
- {"dt": "2023-02-02T12:35:32.146299", "lvl": "debug", "msg": "start: 2.1.1 execute-qemu (timeout 00:15:00) [common]"}
- {"dt": "2023-02-02T12:35:32.147013", "lvl": "info", "msg": "Pulling docker image"}
- {"dt": "2023-02-02T12:35:32.147178", "lvl": "debug", "msg": "cmd: ['docker', 'pull', 'docker.io/linaro/tuxrun-qemu:master']"}
- {"dt": "2023-02-02T12:35:32.147305", "lvl": "debug", "msg": "Calling: 'nice' 'docker' 'pull' 'docker.io/linaro/tuxrun-qemu:master'"}
- {"dt": "2023-02-02T12:35:32.241015", "lvl": "debug", "msg": ">> SRC: '/usr/local/bin/docker pull docker.io/linaro/tuxrun-qemu:master'\r"}
- {"dt": "2023-02-02T12:35:32.241396", "lvl": "debug", "msg": ">> DST: '/usr/bin/podman --remote --url unix://run/podman/podman.sock pull docker.io/linaro/tuxrun-qemu:master'\r"}
- {"dt": "2023-02-02T12:35:32.260077", "lvl": "debug", "msg": ">> Trying to pull docker.io/linaro/tuxrun-qemu:master...\r"}
- {"dt": "2023-02-02T12:35:33.840133", "lvl": "debug", "msg": ">> Getting image source signatures\r"}
- {"dt": "2023-02-02T12:35:33.840539", "lvl": "debug", "msg": ">> Copying blob sha256:3313a463c20d9308e68334a22c52f11f0565fbc9021735c8b2541748ddfbb027\r"}
- {"dt": "2023-02-02T12:35:33.840660", "lvl": "debug", "msg": ">> Copying blob sha256:bbeef03cda1f5d6c9e20c310c1c91382a6b0a1a2501c3436b28152f13896f082\r"}
- {"dt": "2023-02-02T12:35:33.840739", "lvl": "debug", "msg": ">> Copying blob sha256:994260ae333aa8d74e5433ac19a3c3eb57d6bebdabc032187235057d40db0b1c\r"}
- {"dt": "2023-02-02T12:35:33.840803", "lvl": "debug", "msg": ">> Copying blob sha256:e0f2b672ff4188a5c5fb9133b4908ae53d235597a4fa16972839237e25769987\r"}
- {"dt": "2023-02-02T12:35:33.841989", "lvl": "debug", "msg": ">> Copying config sha256:1be8120b2fad8f5126cd3ec9180bd806ba7570f86b32047044293648b52e93ff\r"}
- {"dt": "2023-02-02T12:35:33.860800", "lvl": "debug", "msg": ">> Writing manifest to image destination\r"}
- {"dt": "2023-02-02T12:35:33.860894", "lvl": "debug", "msg": ">> Storing signatures\r"}
- {"dt": "2023-02-02T12:35:33.924027", "lvl": "debug", "msg": ">> 1be8120b2fad8f5126cd3ec9180bd806ba7570f86b32047044293648b52e93ff\r"}
- {"dt": "2023-02-02T12:35:33.926892", "lvl": "debug", "msg": "Returned 0 in 1 seconds"}
- {"dt": "2023-02-02T12:35:34.065510", "lvl": "info", "msg": "Boot command: docker run --network=host --cap-add=NET_ADMIN --interactive --tty --rm --init --name=lava-docker-qemu-1-2.1.1-561l3jb3jh --device=/dev/kvm --mount=type=bind,source=/var/lib/lava/dispatcher/tmp,destination=/var/lib/lava/dispatcher/tmp docker.io/linaro/tuxrun-qemu:master qemu-system-riscv64 -cpu rv64 -machine virt -nographic -nic none -m 4G -monitor none -no-reboot -smp 2 -kernel /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/kernel/Image -append \"console=ttyS0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog earlycon\" -bios /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/bios/fw_jump.elf -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/rootfs/https___storage.tuxboot.com_riscv64_rootfs.ext4,format=raw,id=hd0 -device virtio-blk-device,drive=hd0"}
- {"dt": "2023-02-02T12:35:34.150354", "lvl": "debug", "msg": "started a shell command"}
- {"dt": "2023-02-02T12:35:34.150762", "lvl": "debug", "msg": "end: 2.1.1 execute-qemu (duration 00:00:02) [common]"}
- {"dt": "2023-02-02T12:35:34.150903", "lvl": "debug", "msg": "end: 2.1 boot-qemu-image (duration 00:00:02) [common]"}
- {"dt": "2023-02-02T12:35:34.151020", "lvl": "debug", "msg": "start: 2.2 auto-login-action (timeout 00:14:58) [common]"}
- {"dt": "2023-02-02T12:35:34.151129", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2023-02-02T12:35:34.151214", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:15:00)"}
- {"dt": "2023-02-02T12:35:34.161637", "lvl": "target", "msg": "SRC: '/usr/local/bin/docker run --network=host --cap-add=NET_ADMIN --interactive --tty --rm --init --name=lava-docker-qemu-1-2.1.1-561l3jb3jh --device=/dev/kvm --mount=type=bind,source=/var/lib/lava/dispatcher/tmp,destination=/var/lib/lava/dispatcher/tmp docker.io/linaro/tuxrun-qemu:master qemu-system-riscv64 -cpu rv64 -machine virt -nographic -nic none -m 4G -monitor none -no-reboot -smp 2 -kernel /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/kernel/Image -append console=ttyS0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog earlycon -bios /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/bios/fw_jump.elf -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/rootfs/https___storage.tuxboot.com_riscv64_rootfs.ext4,format=raw,id=hd0 -device virtio-blk-device,drive=hd0'"}
- {"dt": "2023-02-02T12:35:34.161757", "lvl": "target", "msg": "DST: '/usr/bin/podman --remote --url unix://run/podman/podman.sock run --network=host --cap-add=NET_ADMIN --interactive --tty --rm --init --name=lava-docker-qemu-1-2.1.1-561l3jb3jh --device=/dev/kvm --mount=type=bind,source=/tmp/tuxrun-o_ykcwqx/dispatcher/tmp,destination=/var/lib/lava/dispatcher/tmp docker.io/linaro/tuxrun-qemu:master qemu-system-riscv64 -cpu rv64 -machine virt -nographic -nic none -m 4G -monitor none -no-reboot -smp 2 -kernel /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/kernel/Image -append console=ttyS0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog earlycon -bios /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/bios/fw_jump.elf -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/rootfs/https___storage.tuxboot.com_riscv64_rootfs.ext4,format=raw,id=hd0 -device virtio-blk-device,drive=hd0'"}
- {"dt": "2023-02-02T12:35:34.407147", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:34.407606", "lvl": "target", "msg": "OpenSBI v0.9"}
- {"dt": "2023-02-02T12:35:34.407754", "lvl": "target", "msg": "   ____                    _____ ____ _____"}
- {"dt": "2023-02-02T12:35:34.407862", "lvl": "target", "msg": "  / __ \\                  / ____|  _ \\_   _|"}
- {"dt": "2023-02-02T12:35:34.407976", "lvl": "target", "msg": " | |  | |_ __   ___ _ __ | (___ | |_) || |"}
- {"dt": "2023-02-02T12:35:34.408076", "lvl": "target", "msg": " | |  | | '_ \\ / _ \\ '_ \\ \\___ \\|  _ < | |"}
- {"dt": "2023-02-02T12:35:34.408189", "lvl": "target", "msg": " | |__| | |_) |  __/ | | |____) | |_) || |_"}
- {"dt": "2023-02-02T12:35:34.408303", "lvl": "target", "msg": "  \\____/| .__/ \\___|_| |_|_____/|____/_____|"}
- {"dt": "2023-02-02T12:35:34.408416", "lvl": "target", "msg": "        | |"}
- {"dt": "2023-02-02T12:35:34.408511", "lvl": "target", "msg": "        |_|"}
- {"dt": "2023-02-02T12:35:34.408599", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:34.412521", "lvl": "target", "msg": "Platform Name             : riscv-virtio,qemu"}
- {"dt": "2023-02-02T12:35:34.412854", "lvl": "target", "msg": "Platform Features         : timer,mfdeleg"}
- {"dt": "2023-02-02T12:35:34.412977", "lvl": "target", "msg": "Platform HART Count       : 2"}
- {"dt": "2023-02-02T12:35:34.413269", "lvl": "target", "msg": "Firmware Base             : 0x80000000"}
- {"dt": "2023-02-02T12:35:34.413388", "lvl": "target", "msg": "Firmware Size             : 132 KB"}
- {"dt": "2023-02-02T12:35:34.413497", "lvl": "target", "msg": "Runtime SBI Version       : 0.2"}
- {"dt": "2023-02-02T12:35:34.413601", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:34.414113", "lvl": "target", "msg": "Domain0 Name              : root"}
- {"dt": "2023-02-02T12:35:34.414216", "lvl": "target", "msg": "Domain0 Boot HART         : 0"}
- {"dt": "2023-02-02T12:35:34.414321", "lvl": "target", "msg": "Domain0 HARTs             : 0*,1*"}
- {"dt": "2023-02-02T12:35:34.414602", "lvl": "target", "msg": "Domain0 Region00          : 0x0000000080000000-0x000000008003ffff ()"}
- {"dt": "2023-02-02T12:35:34.414933", "lvl": "target", "msg": "Domain0 Region01          : 0x0000000000000000-0xffffffffffffffff (R,W,X)"}
- {"dt": "2023-02-02T12:35:34.415048", "lvl": "target", "msg": "Domain0 Next Address      : 0x0000000080200000"}
- {"dt": "2023-02-02T12:35:34.415353", "lvl": "target", "msg": "Domain0 Next Arg1         : 0x0000000082200000"}
- {"dt": "2023-02-02T12:35:34.415469", "lvl": "target", "msg": "Domain0 Next Mode         : S-mode"}
- {"dt": "2023-02-02T12:35:34.415575", "lvl": "target", "msg": "Domain0 SysReset          : yes"}
- {"dt": "2023-02-02T12:35:34.415665", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:34.417589", "lvl": "target", "msg": "Boot HART ID              : 0"}
- {"dt": "2023-02-02T12:35:34.417711", "lvl": "target", "msg": "Boot HART Domain          : root"}
- {"dt": "2023-02-02T12:35:34.417824", "lvl": "target", "msg": "Boot HART ISA             : rv64imafdcsuh"}
- {"dt": "2023-02-02T12:35:34.417966", "lvl": "target", "msg": "Boot HART Features        : scounteren,mcounteren,time"}
- {"dt": "2023-02-02T12:35:34.418080", "lvl": "target", "msg": "Boot HART PMP Count       : 16"}
- {"dt": "2023-02-02T12:35:34.418186", "lvl": "target", "msg": "Boot HART PMP Granularity : 4"}
- {"dt": "2023-02-02T12:35:34.418290", "lvl": "target", "msg": "Boot HART PMP Address Bits: 54"}
- {"dt": "2023-02-02T12:35:34.418601", "lvl": "target", "msg": "Boot HART MHPM Count      : 0"}
- {"dt": "2023-02-02T12:35:34.418706", "lvl": "target", "msg": "Boot HART MHPM Count      : 0"}
- {"dt": "2023-02-02T12:35:34.418812", "lvl": "target", "msg": "Boot HART MIDELEG         : 0x0000000000001666"}
- {"dt": "2023-02-02T12:35:34.418904", "lvl": "target", "msg": "Boot HART MEDELEG         : 0x0000000000f0b509"}
- {"dt": "2023-02-02T12:35:34.425988", "lvl": "debug", "msg": "start: 2.2.1 login-action (timeout 00:14:58) [common]"}
- {"dt": "2023-02-02T12:35:34.426152", "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": "2023-02-02T12:35:34.426287", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2023-02-02T12:35:34.426391", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2023-02-02T12:35:34.426490", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2023-02-02T12:35:34.426590", "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": "2023-02-02T12:35:34.426775", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:14:58)"}
- {"dt": "2023-02-02T12:35:34.427811", "lvl": "target", "msg": "[    0.000000] Linux version 5.15.18 (root@runner-sezqzeu7-project-23449704-concurrent-2) (riscv64-linux-gcc.br_real (Buildroot 2021.11-4428-g6b6741b) 11.3.0, GNU ld (GNU Binutils) 2.38) #1 SMP Thu Jan 5 12:10:09 UTC 2023"}
- {"dt": "2023-02-02T12:35:34.427943", "lvl": "target", "msg": "[    0.000000] OF: fdt: Ignoring memory range 0x80000000 - 0x80200000"}
- {"dt": "2023-02-02T12:35:34.428044", "lvl": "target", "msg": "[    0.000000] Machine model: riscv-virtio,qemu"}
- {"dt": "2023-02-02T12:35:34.428134", "lvl": "target", "msg": "[    0.000000] earlycon: ns16550a0 at MMIO 0x0000000010000000 (options '')"}
- {"dt": "2023-02-02T12:35:34.428225", "lvl": "target", "msg": "[    0.000000] printk: bootconsole [ns16550a0] enabled"}
- {"dt": "2023-02-02T12:35:34.428313", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2023-02-02T12:35:34.440074", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2023-02-02T12:35:34.440611", "lvl": "target", "msg": "[    0.000000]   DMA32    [mem 0x0000000080200000-0x00000000ffffffff]"}
- {"dt": "2023-02-02T12:35:34.440940", "lvl": "target", "msg": "[    0.000000]   Normal   [mem 0x0000000100000000-0x000000017fffffff]"}
- {"dt": "2023-02-02T12:35:34.441058", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2023-02-02T12:35:34.441167", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2023-02-02T12:35:34.441499", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000080200000-0x000000017fffffff]"}
- {"dt": "2023-02-02T12:35:34.441618", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000080200000-0x000000017fffffff]"}
- {"dt": "2023-02-02T12:35:34.473395", "lvl": "target", "msg": "[    0.000000] SBI specification v0.2 detected"}
- {"dt": "2023-02-02T12:35:34.473773", "lvl": "target", "msg": "[    0.000000] SBI implementation ID=0x1 Version=0x9"}
- {"dt": "2023-02-02T12:35:34.473877", "lvl": "target", "msg": "[    0.000000] SBI TIME extension detected"}
- {"dt": "2023-02-02T12:35:34.473985", "lvl": "target", "msg": "[    0.000000] SBI IPI extension detected"}
- {"dt": "2023-02-02T12:35:34.474076", "lvl": "target", "msg": "[    0.000000] SBI RFENCE extension detected"}
- {"dt": "2023-02-02T12:35:34.474179", "lvl": "target", "msg": "[    0.000000] SBI v0.2 HSM extension detected"}
- {"dt": "2023-02-02T12:35:34.475038", "lvl": "target", "msg": "[    0.000000] riscv: ISA extensions abcdefhimnprstuw"}
- {"dt": "2023-02-02T12:35:34.475158", "lvl": "target", "msg": "[    0.000000] riscv: ELF capabilities acdfim"}
- {"dt": "2023-02-02T12:35:34.477265", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 17 pages/cpu s32168 r8192 d29272 u69632"}
- {"dt": "2023-02-02T12:35:34.477947", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: s32168 r8192 d29272 u69632 alloc=17*4096"}
- {"dt": "2023-02-02T12:35:34.478277", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: [0] 0 [0] 1 "}
- {"dt": "2023-02-02T12:35:34.480793", "lvl": "target", "msg": "[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1033735"}
- {"dt": "2023-02-02T12:35:34.481349", "lvl": "target", "msg": "[    0.000000] Kernel command line: console=ttyS0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog earlycon"}
- {"dt": "2023-02-02T12:35:34.482451", "lvl": "target", "msg": "<5>[    0.000000] Unknown kernel command line parameters \\\"verbose\\\", will be passed to user space."}
- {"dt": "2023-02-02T12:35:34.484260", "lvl": "target", "msg": "<6>[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.485315", "lvl": "target", "msg": "<6>[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.485780", "lvl": "target", "msg": "<6>[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off"}
- {"dt": "2023-02-02T12:35:34.516117", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: mapped [mem 0x00000000fbfff000-0x00000000fffff000] (64MB)"}
- {"dt": "2023-02-02T12:35:34.530925", "lvl": "target", "msg": "<5>[    0.000000] Virtual kernel memory layout:"}
- {"dt": "2023-02-02T12:35:34.531193", "lvl": "target", "msg": "<5>[    0.000000]       fixmap : 0xffffffcefee00000 - 0xffffffceff000000   (2048 kB)"}
- {"dt": "2023-02-02T12:35:34.531337", "lvl": "target", "msg": "<5>[    0.000000]       pci io : 0xffffffceff000000 - 0xffffffcf00000000   (  16 MB)"}
- {"dt": "2023-02-02T12:35:34.531701", "lvl": "target", "msg": "<5>[    0.000000]      vmemmap : 0xffffffcf00000000 - 0xffffffcfffffffff   (4095 MB)"}
- {"dt": "2023-02-02T12:35:34.531821", "lvl": "target", "msg": "<5>[    0.000000]      vmalloc : 0xffffffd000000000 - 0xffffffdfffffffff   (65535 MB)"}
- {"dt": "2023-02-02T12:35:34.532151", "lvl": "target", "msg": "<5>[    0.000000]       lowmem : 0xffffffe000000000 - 0xffffffe0ffe00000   (4094 MB)"}
- {"dt": "2023-02-02T12:35:34.532490", "lvl": "target", "msg": "<5>[    0.000000]       kernel : 0xffffffff80000000 - 0xffffffffffffffff   (2047 MB)"}
- {"dt": "2023-02-02T12:35:34.533120", "lvl": "target", "msg": "<6>[    0.000000] Memory: 4041788K/4192256K available (7347K kernel code, 4925K rwdata, 4096K rodata, 2147K init, 301K bss, 150468K reserved, 0K cma-reserved)"}
- {"dt": "2023-02-02T12:35:34.536103", "lvl": "target", "msg": "<6>[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1"}
- {"dt": "2023-02-02T12:35:34.540666", "lvl": "target", "msg": "<6>[    0.000000] rcu: Hierarchical RCU implementation."}
- {"dt": "2023-02-02T12:35:34.540791", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=2."}
- {"dt": "2023-02-02T12:35:34.541130", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU debug extended QS entry/exit."}
- {"dt": "2023-02-02T12:35:34.541231", "lvl": "target", "msg": "<6>[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2023-02-02T12:35:34.541570", "lvl": "target", "msg": "<6>[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2023-02-02T12:35:34.541912", "lvl": "target", "msg": "<6>[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2"}
- {"dt": "2023-02-02T12:35:34.542513", "lvl": "target", "msg": "<6>[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2023-02-02T12:35:34.543848", "lvl": "target", "msg": "<6>[    0.000000] riscv-intc: 64 local interrupts mapped"}
- {"dt": "2023-02-02T12:35:34.547512", "lvl": "target", "msg": "<6>[    0.000000] plic: plic@c000000: mapped 95 interrupts with 2 handlers for 4 contexts."}
- {"dt": "2023-02-02T12:35:34.550234", "lvl": "target", "msg": "<5>[    0.000000] random: get_random_bytes called from start_kernel+0x4c0/0x6da with crng_init=0"}
- {"dt": "2023-02-02T12:35:34.550668", "lvl": "target", "msg": "<6>[    0.000000] riscv_timer_init_dt: Registering clocksource cpuid [0] hartid [0]"}
- {"dt": "2023-02-02T12:35:34.551196", "lvl": "target", "msg": "<6>[    0.000000] clocksource: riscv_clocksource: mask: 0xffffffffffffffff max_cycles: 0x24e6a1710, max_idle_ns: 440795202120 ns"}
- {"dt": "2023-02-02T12:35:34.551607", "lvl": "target", "msg": "<6>[    0.000053] sched_clock: 64 bits at 10MHz, resolution 100ns, wraps every 4398046511100ns"}
- {"dt": "2023-02-02T12:35:34.554486", "lvl": "target", "msg": "<6>[    0.003036] Console: colour dummy device 80x25"}
- {"dt": "2023-02-02T12:35:34.555790", "lvl": "target", "msg": "<6>[    0.004183] Calibrating delay loop (skipped), value calculated using timer frequency.. 20.00 BogoMIPS (lpj=40000)"}
- {"dt": "2023-02-02T12:35:34.556056", "lvl": "target", "msg": "<6>[    0.004676] pid_max: default: 32768 minimum: 301"}
- {"dt": "2023-02-02T12:35:34.558850", "lvl": "target", "msg": "<6>[    0.007217] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.558960", "lvl": "target", "msg": "<6>[    0.007514] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.576413", "lvl": "target", "msg": "<6>[    0.024962] ASID allocator using 16 bits (65536 entries)"}
- {"dt": "2023-02-02T12:35:34.577219", "lvl": "target", "msg": "<6>[    0.025814] rcu: Hierarchical SRCU implementation."}
- {"dt": "2023-02-02T12:35:34.578458", "lvl": "target", "msg": "<6>[    0.027073] EFI services will not be available."}
- {"dt": "2023-02-02T12:35:34.580412", "lvl": "target", "msg": "<6>[    0.029003] smp: Bringing up secondary CPUs ..."}
- {"dt": "2023-02-02T12:35:34.586318", "lvl": "target", "msg": "<6>[    0.034872] smp: Brought up 1 node, 2 CPUs"}
- {"dt": "2023-02-02T12:35:34.598548", "lvl": "target", "msg": "<6>[    0.047034] devtmpfs: initialized"}
- {"dt": "2023-02-02T12:35:34.604617", "lvl": "target", "msg": "<6>[    0.053151] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2023-02-02T12:35:34.605059", "lvl": "target", "msg": "<6>[    0.053491] futex hash table entries: 512 (order: 3, 32768 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.607946", "lvl": "target", "msg": "<6>[    0.056494] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2023-02-02T12:35:34.636100", "lvl": "target", "msg": "<6>[    0.084585] vgaarb: loaded"}
- {"dt": "2023-02-02T12:35:34.637035", "lvl": "target", "msg": "<5>[    0.085586] SCSI subsystem initialized"}
- {"dt": "2023-02-02T12:35:34.637756", "lvl": "target", "msg": "<7>[    0.086306] libata version 3.00 loaded."}
- {"dt": "2023-02-02T12:35:34.638487", "lvl": "target", "msg": "<6>[    0.087023] usbcore: registered new interface driver usbfs"}
- {"dt": "2023-02-02T12:35:34.638657", "lvl": "target", "msg": "<6>[    0.087324] usbcore: registered new interface driver hub"}
- {"dt": "2023-02-02T12:35:34.639052", "lvl": "target", "msg": "<6>[    0.087535] usbcore: registered new device driver usb"}
- {"dt": "2023-02-02T12:35:34.645175", "lvl": "target", "msg": "<6>[    0.093703] clocksource: Switched to clocksource riscv_clocksource"}
- {"dt": "2023-02-02T12:35:34.667040", "lvl": "target", "msg": "<6>[    0.115536] NET: Registered PF_INET protocol family"}
- {"dt": "2023-02-02T12:35:34.667964", "lvl": "target", "msg": "<6>[    0.116503] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.671456", "lvl": "target", "msg": "<6>[    0.120002] tcp_listen_portaddr_hash hash table entries: 2048 (order: 4, 81920 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.671594", "lvl": "target", "msg": "<6>[    0.120274] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.672216", "lvl": "target", "msg": "<6>[    0.120708] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.673473", "lvl": "target", "msg": "<6>[    0.122035] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2023-02-02T12:35:34.674257", "lvl": "target", "msg": "<6>[    0.122823] UDP hash table entries: 2048 (order: 5, 196608 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.674630", "lvl": "target", "msg": "<6>[    0.123239] UDP-Lite hash table entries: 2048 (order: 5, 196608 bytes, linear)"}
- {"dt": "2023-02-02T12:35:34.675691", "lvl": "target", "msg": "<6>[    0.124245] NET: Registered PF_UNIX/PF_LOCAL protocol family"}
- {"dt": "2023-02-02T12:35:34.677863", "lvl": "target", "msg": "<6>[    0.126404] RPC: Registered named UNIX socket transport module."}
- {"dt": "2023-02-02T12:35:34.677979", "lvl": "target", "msg": "<6>[    0.126556] RPC: Registered udp transport module."}
- {"dt": "2023-02-02T12:35:34.678096", "lvl": "target", "msg": "<6>[    0.126663] RPC: Registered tcp transport module."}
- {"dt": "2023-02-02T12:35:34.678192", "lvl": "target", "msg": "<6>[    0.126774] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2023-02-02T12:35:34.678317", "lvl": "target", "msg": "<6>[    0.126998] PCI: CLS 0 bytes, default 64"}
- {"dt": "2023-02-02T12:35:34.682292", "lvl": "target", "msg": "<6>[    0.130825] workingset: timestamp_bits=62 max_order=20 bucket_order=0"}
- {"dt": "2023-02-02T12:35:34.691236", "lvl": "target", "msg": "<5>[    0.139743] NFS: Registering the id_resolver key type"}
- {"dt": "2023-02-02T12:35:34.691641", "lvl": "target", "msg": "<5>[    0.140361] Key type id_resolver registered"}
- {"dt": "2023-02-02T12:35:34.691791", "lvl": "target", "msg": "<5>[    0.140471] Key type id_legacy registered"}
- {"dt": "2023-02-02T12:35:34.692179", "lvl": "target", "msg": "<6>[    0.140765] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2023-02-02T12:35:34.692316", "lvl": "target", "msg": "<6>[    0.140945] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering..."}
- {"dt": "2023-02-02T12:35:34.693311", "lvl": "target", "msg": "<6>[    0.141849] 9p: Installing v9fs 9p2000 file system support"}
- {"dt": "2023-02-02T12:35:34.694636", "lvl": "target", "msg": "<6>[    0.143176] NET: Registered PF_ALG protocol family"}
- {"dt": "2023-02-02T12:35:34.695111", "lvl": "target", "msg": "<6>[    0.143733] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)"}
- {"dt": "2023-02-02T12:35:34.695271", "lvl": "target", "msg": "<6>[    0.144002] io scheduler mq-deadline registered"}
- {"dt": "2023-02-02T12:35:34.695426", "lvl": "target", "msg": "<6>[    0.144136] io scheduler kyber registered"}
- {"dt": "2023-02-02T12:35:34.696477", "lvl": "target", "msg": "<7>[    0.145021] start plist test"}
- {"dt": "2023-02-02T12:35:34.700396", "lvl": "target", "msg": "<7>[    0.148931] end plist test"}
- {"dt": "2023-02-02T12:35:34.702406", "lvl": "target", "msg": "<6>[    0.150847] pci-host-generic 30000000.pci: host bridge /soc/pci@30000000 ranges:"}
- {"dt": "2023-02-02T12:35:34.702900", "lvl": "target", "msg": "<6>[    0.151520] pci-host-generic 30000000.pci:       IO 0x0003000000..0x000300ffff -> 0x0000000000"}
- {"dt": "2023-02-02T12:35:34.703409", "lvl": "target", "msg": "<6>[    0.151962] pci-host-generic 30000000.pci:      MEM 0x0040000000..0x007fffffff -> 0x0040000000"}
- {"dt": "2023-02-02T12:35:34.703625", "lvl": "target", "msg": "<6>[    0.152168] pci-host-generic 30000000.pci:      MEM 0x0400000000..0x07ffffffff -> 0x0400000000"}
- {"dt": "2023-02-02T12:35:34.703927", "lvl": "target", "msg": "<4>[    0.152596] pci-host-generic 30000000.pci: Memory resource size exceeds max for 32 bits"}
- {"dt": "2023-02-02T12:35:34.705101", "lvl": "target", "msg": "<6>[    0.153381] pci-host-generic 30000000.pci: ECAM at [mem 0x30000000-0x3fffffff] for [bus 00-ff]"}
- {"dt": "2023-02-02T12:35:34.705573", "lvl": "target", "msg": "<6>[    0.154256] pci-host-generic 30000000.pci: PCI host bridge to bus 0000:00"}
- {"dt": "2023-02-02T12:35:34.706034", "lvl": "target", "msg": "<6>[    0.154489] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2023-02-02T12:35:34.706159", "lvl": "target", "msg": "<6>[    0.154643] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]"}
- {"dt": "2023-02-02T12:35:34.706318", "lvl": "target", "msg": "<6>[    0.154804] pci_bus 0000:00: root bus resource [mem 0x40000000-0x7fffffff]"}
- {"dt": "2023-02-02T12:35:34.706425", "lvl": "target", "msg": "<6>[    0.154939] pci_bus 0000:00: root bus resource [mem 0x400000000-0x7ffffffff]"}
- {"dt": "2023-02-02T12:35:34.707213", "lvl": "target", "msg": "<6>[    0.155757] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000"}
- {"dt": "2023-02-02T12:35:34.814415", "lvl": "target", "msg": "<6>[    0.262791] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled"}
- {"dt": "2023-02-02T12:35:34.819998", "lvl": "target", "msg": "<6>[    0.268490] printk: console [ttyS0] disabled"}
- {"dt": "2023-02-02T12:35:34.821196", "lvl": "target", "msg": "<6>[    0.269706] 10000000.serial: ttyS0 at MMIO 0x10000000 (irq = 2, base_baud = 230400) is a 16550A"}
- {"dt": "2023-02-02T12:35:34.822276", "lvl": "target", "msg": "<6>[    0.270721] printk: console [ttyS0] enabled"}
- {"dt": "2023-02-02T12:35:34.822398", "lvl": "target", "msg": "<6>[    0.270721] printk: console [ttyS0] enabled"}
- {"dt": "2023-02-02T12:35:34.822518", "lvl": "target", "msg": "<6>[    0.271015] printk: bootconsole [ns16550a0] disabled"}
- {"dt": "2023-02-02T12:35:34.822629", "lvl": "target", "msg": "<6>[    0.271015] printk: bootconsole [ns16550a0] disabled"}
- {"dt": "2023-02-02T12:35:34.823929", "lvl": "target", "msg": "<6>[    0.272447] [drm] radeon kernel modesetting enabled."}
- {"dt": "2023-02-02T12:35:34.834147", "lvl": "target", "msg": "<6>[    0.282869] loop: module loaded"}
- {"dt": "2023-02-02T12:35:34.839144", "lvl": "target", "msg": "<5>[    0.287658] virtio_blk virtio0: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)"}
- {"dt": "2023-02-02T12:35:34.853635", "lvl": "target", "msg": "<6>[    0.302146] e1000e: Intel(R) PRO/1000 Network Driver"}
- {"dt": "2023-02-02T12:35:34.853764", "lvl": "target", "msg": "<6>[    0.302256] e1000e: Copyright(c) 1999 - 2015 Intel Corporation."}
- {"dt": "2023-02-02T12:35:34.853884", "lvl": "target", "msg": "<6>[    0.302539] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"}
- {"dt": "2023-02-02T12:35:34.854001", "lvl": "target", "msg": "<6>[    0.302715] ehci-pci: EHCI PCI platform driver"}
- {"dt": "2023-02-02T12:35:34.854350", "lvl": "target", "msg": "<6>[    0.302929] ehci-platform: EHCI generic platform driver"}
- {"dt": "2023-02-02T12:35:34.854468", "lvl": "target", "msg": "<6>[    0.303141] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"}
- {"dt": "2023-02-02T12:35:34.854590", "lvl": "target", "msg": "<6>[    0.303299] ohci-pci: OHCI PCI platform driver"}
- {"dt": "2023-02-02T12:35:34.854777", "lvl": "target", "msg": "<6>[    0.303492] ohci-platform: OHCI generic platform driver"}
- {"dt": "2023-02-02T12:35:34.855785", "lvl": "target", "msg": "<6>[    0.304329] usbcore: registered new interface driver uas"}
- {"dt": "2023-02-02T12:35:34.855914", "lvl": "target", "msg": "<6>[    0.304580] usbcore: registered new interface driver usb-storage"}
- {"dt": "2023-02-02T12:35:34.856928", "lvl": "target", "msg": "<6>[    0.305480] mousedev: PS/2 mouse device common for all mice"}
- {"dt": "2023-02-02T12:35:34.858543", "lvl": "target", "msg": "<6>[    0.307094] goldfish_rtc 101000.rtc: registered as rtc0"}
- {"dt": "2023-02-02T12:35:34.859163", "lvl": "target", "msg": "<6>[    0.307513] goldfish_rtc 101000.rtc: setting system clock to 2023-02-02T12:35:34 UTC (1675341334)"}
- {"dt": "2023-02-02T12:35:34.860628", "lvl": "target", "msg": "<3>[    0.309138] syscon-poweroff poweroff: pm_power_off already claimed for sbi_shutdown"}
- {"dt": "2023-02-02T12:35:34.860773", "lvl": "target", "msg": "<4>[    0.309341] syscon-poweroff: probe of poweroff failed with error -16"}
- {"dt": "2023-02-02T12:35:34.861378", "lvl": "target", "msg": "<6>[    0.309844] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2023-02-02T12:35:34.861485", "lvl": "target", "msg": "<6>[    0.310022] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2023-02-02T12:35:34.861595", "lvl": "target", "msg": "<6>[    0.310211] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2023-02-02T12:35:34.862269", "lvl": "target", "msg": "<6>[    0.310833] usbcore: registered new interface driver usbhid"}
- {"dt": "2023-02-02T12:35:34.862376", "lvl": "target", "msg": "<6>[    0.310959] usbhid: USB HID core driver"}
- {"dt": "2023-02-02T12:35:34.863536", "lvl": "target", "msg": "<6>[    0.312054] NET: Registered PF_INET6 protocol family"}
- {"dt": "2023-02-02T12:35:34.867675", "lvl": "target", "msg": "<6>[    0.316179] Segment Routing with IPv6"}
- {"dt": "2023-02-02T12:35:34.867821", "lvl": "target", "msg": "<6>[    0.316368] In-situ OAM (IOAM) with IPv6"}
- {"dt": "2023-02-02T12:35:34.868221", "lvl": "target", "msg": "<6>[    0.316685] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver"}
- {"dt": "2023-02-02T12:35:34.869998", "lvl": "target", "msg": "<6>[    0.318526] NET: Registered PF_PACKET protocol family"}
- {"dt": "2023-02-02T12:35:34.870828", "lvl": "target", "msg": "<6>[    0.319378] 9pnet: Installing 9P2000 support"}
- {"dt": "2023-02-02T12:35:34.870961", "lvl": "target", "msg": "<5>[    0.319668] Key type dns_resolver registered"}
- {"dt": "2023-02-02T12:35:34.873704", "lvl": "target", "msg": "<6>[    0.322254] debug_vm_pgtable: [debug_vm_pgtable         ]: Validating architecture page table helpers"}
- {"dt": "2023-02-02T12:35:34.894111", "lvl": "target", "msg": "<6>[    0.342540] EXT4-fs (vda): mounted filesystem with ordered data mode. Opts: (null). Quota mode: disabled."}
- {"dt": "2023-02-02T12:35:34.894276", "lvl": "target", "msg": "<6>[    0.342908] VFS: Mounted root (ext4 filesystem) readonly on device 254:0."}
- {"dt": "2023-02-02T12:35:34.895708", "lvl": "target", "msg": "<6>[    0.344179] devtmpfs: mounted"}
- {"dt": "2023-02-02T12:35:34.913798", "lvl": "target", "msg": "<6>[    0.362291] Freeing unused kernel image (initmem) memory: 2144K"}
- {"dt": "2023-02-02T12:35:34.921712", "lvl": "target", "msg": "<6>[    0.370229] Run /sbin/init as init process"}
- {"dt": "2023-02-02T12:35:34.921835", "lvl": "target", "msg": "<7>[    0.370383]   with arguments:"}
- {"dt": "2023-02-02T12:35:34.921956", "lvl": "target", "msg": "<7>[    0.370500]     /sbin/init"}
- {"dt": "2023-02-02T12:35:34.922055", "lvl": "target", "msg": "<7>[    0.370605]     verbose"}
- {"dt": "2023-02-02T12:35:34.922164", "lvl": "target", "msg": "<7>[    0.370697]   with environment:"}
- {"dt": "2023-02-02T12:35:34.922262", "lvl": "target", "msg": "<7>[    0.370792]     HOME=/"}
- {"dt": "2023-02-02T12:35:34.922352", "lvl": "target", "msg": "<7>[    0.370894]     TERM=linux"}
- {"dt": "2023-02-02T12:35:35.074210", "lvl": "target", "msg": "<6>[    0.522538] EXT4-fs (vda): re-mounted. Opts: (null). Quota mode: disabled."}
- {"dt": "2023-02-02T12:35:35.551806", "lvl": "target", "msg": "Starting syslogd: OK"}
- {"dt": "2023-02-02T12:35:35.708982", "lvl": "target", "msg": "Starting klogd: OK"}
- {"dt": "2023-02-02T12:35:35.881902", "lvl": "target", "msg": "Running sysctl: OK"}
- {"dt": "2023-02-02T12:35:36.021098", "lvl": "target", "msg": "Starting mdev... OK"}
- {"dt": "2023-02-02T12:35:37.781231", "lvl": "target", "msg": "Saving random seed: <5>[    3.229508] random: dd: uninitialized urandom read (512 bytes read)"}
- {"dt": "2023-02-02T12:35:37.896180", "lvl": "target", "msg": "OK"}
- {"dt": "2023-02-02T12:35:38.670240", "lvl": "target", "msg": "Starting network: OK"}
- {"dt": "2023-02-02T12:35:38.801112", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:38.803527", "lvl": "target", "msg": "Welcome to TuxTest"}
- {"dt": "2023-02-02T12:35:38.805565", "lvl": "debug", "msg": "Matched prompt #11: login:"}
- {"dt": "2023-02-02T12:35:38.805708", "lvl": "results", "msg": {"case": "kernel-messages", "definition": "lava", "duration": "4.38", "extra": {"extra": []}, "level": "2.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-02-02T12:35:38.805922", "lvl": "debug", "msg": "Sending username root"}
- {"dt": "2023-02-02T12:35:38.806031", "lvl": "input", "msg": "root\n"}
- {"dt": "2023-02-02T12:35:38.906312", "lvl": "target", "msg": "tuxtest login: root"}
- {"dt": "2023-02-02T12:35:38.906555", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2023-02-02T12:35:38.906716", "lvl": "debug", "msg": "login-action: Wait for prompt ['root@(.*):[/~]#', 'Login incorrect', 'Login timed out'] (timeout 00:14:53)"}
- {"dt": "2023-02-02T12:35:38.907842", "lvl": "target", "msg": "root"}
- {"dt": "2023-02-02T12:35:39.092071", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2023-02-02T12:35:39.092310", "lvl": "debug", "msg": "end: 2.2.1 login-action (duration 00:00:05) [common]"}
- {"dt": "2023-02-02T12:35:39.092444", "lvl": "results", "msg": {"case": "login-action", "definition": "lava", "duration": "4.67", "extra": {"success": "No kernel warnings or errors detected."}, "level": "2.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-02-02T12:35:39.092686", "lvl": "debug", "msg": "end: 2.2 auto-login-action (duration 00:00:05) [common]"}
- {"dt": "2023-02-02T12:35:39.092858", "lvl": "debug", "msg": "start: 2.3 expect-shell-connection (timeout 00:14:53) [common]"}
- {"dt": "2023-02-02T12:35:39.092980", "lvl": "debug", "msg": "Setting prompt string to ['root@(.*):[/~]#']"}
- {"dt": "2023-02-02T12:35:39.093077", "lvl": "debug", "msg": "Forcing a shell prompt, looking for ['root@(.*):[/~]#']"}
- {"dt": "2023-02-02T12:35:39.093174", "lvl": "input", "msg": "\n"}
- {"dt": "2023-02-02T12:35:39.143347", "lvl": "target", "msg": "root@tuxtest:~# "}
- {"dt": "2023-02-02T12:35:39.143530", "lvl": "debug", "msg": "expect-shell-connection: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:15:00)"}
- {"dt": "2023-02-02T12:35:39.143692", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:07:30)"}
- {"dt": "2023-02-02T12:35:39.145387", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:39.146988", "lvl": "debug", "msg": "end: 2.3 expect-shell-connection (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:39.147155", "lvl": "debug", "msg": "start: 2.4 export-device-env (timeout 00:14:53) [common]"}
- {"dt": "2023-02-02T12:35:39.147311", "lvl": "debug", "msg": "end: 2.4 export-device-env (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:39.147448", "lvl": "info", "msg": "end: 2 boot-image-retry (duration 00:00:07) [common]"}
- {"dt": "2023-02-02T12:35:39.147589", "lvl": "info", "msg": "start: 3 lava-test-retry (timeout 00:02:00) [common]"}
- {"dt": "2023-02-02T12:35:39.147726", "lvl": "debug", "msg": "start: 3.1 lava-test-shell (timeout 00:02:00) [common]"}
- {"dt": "2023-02-02T12:35:39.147836", "lvl": "debug", "msg": "Using namespace: common"}
- {"dt": "2023-02-02T12:35:39.147949", "lvl": "input", "msg": "#\n"}
- {"dt": "2023-02-02T12:35:39.248219", "lvl": "target", "msg": "root@tuxtest:~# #"}
- {"dt": "2023-02-02T12:35:39.248411", "lvl": "debug", "msg": "lava-test-shell: Wait for prompt ['root@(.*):[/~]#'] (timeout 00:02:00)"}
- {"dt": "2023-02-02T12:35:39.249344", "lvl": "target", "msg": "#"}
- {"dt": "2023-02-02T12:35:39.252181", "lvl": "debug", "msg": "Using /lava-1"}
- {"dt": "2023-02-02T12:35:39.252351", "lvl": "input", "msg": "export SHELL=/bin/sh\n"}
- {"dt": "2023-02-02T12:35:39.352721", "lvl": "target", "msg": "root@tuxtest:~# export SHELL=/bin/sh"}
- {"dt": "2023-02-02T12:35:39.353993", "lvl": "target", "msg": "export SHELL=/bin/sh"}
- {"dt": "2023-02-02T12:35:39.356645", "lvl": "input", "msg": ". /lava-1/environment\n"}
- {"dt": "2023-02-02T12:35:39.456999", "lvl": "target", "msg": "root@tuxtest:~# . /lava-1/environment"}
- {"dt": "2023-02-02T12:35:39.458290", "lvl": "target", "msg": ". /lava-1/environment"}
- {"dt": "2023-02-02T12:35:39.463106", "lvl": "input", "msg": "/lava-1/bin/lava-test-runner /lava-1/0\n"}
- {"dt": "2023-02-02T12:35:39.563441", "lvl": "target", "msg": "root@tuxtest:~# /lava-1/bin/lava-test-runner /lava-1/0"}
- {"dt": "2023-02-02T12:35:39.563669", "lvl": "info", "msg": "Test shell timeout: 10s (minimum of the action and connection timeout)"}
- {"dt": "2023-02-02T12:35:39.564696", "lvl": "target", "msg": "/lava-1/bin/lava-test-runner /lava-1/0"}
- {"dt": "2023-02-02T12:35:40.028365", "lvl": "target", "msg": "+ export TESTRUN_ID=0_ltp-fcntl-locktests"}
- {"dt": "2023-02-02T12:35:40.028792", "lvl": "target", "msg": "+ TESTRUN_ID=0_ltp-fcntl-locktests"}
- {"dt": "2023-02-02T12:35:40.029089", "lvl": "target", "msg": "+ cd /lava-1/0/tests/0_ltp-fcntl-locktests"}
- {"dt": "2023-02-02T12:35:40.039426", "lvl": "target", "msg": "++ cat uuid"}
- {"dt": "2023-02-02T12:35:40.076084", "lvl": "target", "msg": "+ UUID=1_1.1.3.1"}
- {"dt": "2023-02-02T12:35:40.076666", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2023-02-02T12:35:40.081886", "lvl": "target", "msg": "<8>[    5.530353] <LAVA_SIGNAL_STARTRUN 0_ltp-fcntl-locktests 1_1.1.3.1>"}
- {"dt": "2023-02-02T12:35:40.082236", "lvl": "debug", "msg": "Received signal: <STARTRUN> 0_ltp-fcntl-locktests 1_1.1.3.1"}
- {"dt": "2023-02-02T12:35:40.082366", "lvl": "info", "msg": "Starting test lava.0_ltp-fcntl-locktests (1_1.1.3.1)"}
- {"dt": "2023-02-02T12:35:40.082506", "lvl": "info", "msg": "Skipping test definition patterns."}
- {"dt": "2023-02-02T12:35:40.083175", "lvl": "target", "msg": "+ cd ./automated/linux/ltp/"}
- {"dt": "2023-02-02T12:35:40.090735", "lvl": "target", "msg": "+ ./ltp.sh -T fcntl-locktests -s true -v '' -M 5 -R root -b '' -d /scratch -g '' -e production -i /opt/ltp/ -S skipfile-lkft.yaml -p '' -u '' -t false -n 1 -c 1"}
- {"dt": "2023-02-02T12:35:40.142058", "lvl": "target", "msg": "+ . ../../lib/sh-test-lib"}
- {"dt": "2023-02-02T12:35:40.144641", "lvl": "target", "msg": "++ LANG=C"}
- {"dt": "2023-02-02T12:35:40.145263", "lvl": "target", "msg": "++ export LANG"}
- {"dt": "2023-02-02T12:35:40.161322", "lvl": "target", "msg": "++ export PATH=/lava-1/0/../bin:/bin:/sbin:/usr/bin:/usr/sbin:/sbin:/usr/sbin:/usr/local/sbin"}
- {"dt": "2023-02-02T12:35:40.161502", "lvl": "target", "msg": "++ PATH=/lava-1/0/../bin:/bin:/sbin:/usr/bin:/usr/sbin:/sbin:/usr/sbin:/usr/local/sbin"}
- {"dt": "2023-02-02T12:35:40.167296", "lvl": "target", "msg": "++ kernel_config="}
- {"dt": "2023-02-02T12:35:40.178081", "lvl": "target", "msg": "++ pwd"}
- {"dt": "2023-02-02T12:35:40.184770", "lvl": "target", "msg": "+ OUTPUT=/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output"}
- {"dt": "2023-02-02T12:35:40.185914", "lvl": "target", "msg": "+ RESULT_FILE=/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/result.txt"}
- {"dt": "2023-02-02T12:35:40.193961", "lvl": "target", "msg": "++ readlink -f ./ltp.sh"}
- {"dt": "2023-02-02T12:35:40.231099", "lvl": "target", "msg": "+ SCRIPT=/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/ltp.sh"}
- {"dt": "2023-02-02T12:35:40.238449", "lvl": "target", "msg": "++ dirname /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/ltp.sh"}
- {"dt": "2023-02-02T12:35:40.260580", "lvl": "target", "msg": "+ SCRIPTPATH=/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp"}
- {"dt": "2023-02-02T12:35:40.262181", "lvl": "target", "msg": "+ echo 'Script path is: /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp'"}
- {"dt": "2023-02-02T12:35:40.263399", "lvl": "target", "msg": "Script path is: /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp"}
- {"dt": "2023-02-02T12:35:40.263903", "lvl": "target", "msg": "+ TST_CMDFILES="}
- {"dt": "2023-02-02T12:35:40.264230", "lvl": "target", "msg": "+ SKIPFILE="}
- {"dt": "2023-02-02T12:35:40.264748", "lvl": "target", "msg": "+ SKIPFILE_YAML="}
- {"dt": "2023-02-02T12:35:40.265259", "lvl": "target", "msg": "+ BOARD="}
- {"dt": "2023-02-02T12:35:40.265606", "lvl": "target", "msg": "+ BRANCH="}
- {"dt": "2023-02-02T12:35:40.265966", "lvl": "target", "msg": "+ ENVIRONMENT="}
- {"dt": "2023-02-02T12:35:40.266253", "lvl": "target", "msg": "+ LTP_VERSION=20180926"}
- {"dt": "2023-02-02T12:35:40.266883", "lvl": "target", "msg": "+ TEST_PROGRAM=ltp"}
- {"dt": "2023-02-02T12:35:40.267123", "lvl": "target", "msg": "+ TEST_GIT_URL="}
- {"dt": "2023-02-02T12:35:40.271469", "lvl": "target", "msg": "++ pwd"}
- {"dt": "2023-02-02T12:35:40.274343", "lvl": "target", "msg": "+ TEST_DIR=/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/ltp"}
- {"dt": "2023-02-02T12:35:40.275161", "lvl": "target", "msg": "+ BUILD_FROM_TAR=false"}
- {"dt": "2023-02-02T12:35:40.275579", "lvl": "target", "msg": "+ SHARD_NUMBER=1"}
- {"dt": "2023-02-02T12:35:40.275821", "lvl": "target", "msg": "+ SHARD_INDEX=1"}
- {"dt": "2023-02-02T12:35:40.276283", "lvl": "target", "msg": "+ LTP_TMPDIR=/ltp-tmp"}
- {"dt": "2023-02-02T12:35:40.276690", "lvl": "target", "msg": "+ LTP_INSTALL_PATH=/opt/ltp"}
- {"dt": "2023-02-02T12:35:40.281846", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.284354", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.285961", "lvl": "target", "msg": "+ TST_CMDFILES=fcntl-locktests"}
- {"dt": "2023-02-02T12:35:40.294314", "lvl": "target", "msg": "++ sed 's,\\/,_,'"}
- {"dt": "2023-02-02T12:35:40.296177", "lvl": "target", "msg": "++ echo fcntl-locktests"}
- {"dt": "2023-02-02T12:35:40.317737", "lvl": "target", "msg": "+ LOG_FILE=fcntl-locktests"}
- {"dt": "2023-02-02T12:35:40.318508", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.319011", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.319706", "lvl": "target", "msg": "+ SKIP_INSTALL=true"}
- {"dt": "2023-02-02T12:35:40.320130", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.320574", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.321551", "lvl": "target", "msg": "+ LTP_VERSION="}
- {"dt": "2023-02-02T12:35:40.322051", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.322387", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.322623", "lvl": "target", "msg": "<5>[    5.771244] random: fast init done"}
- {"dt": "2023-02-02T12:35:40.323306", "lvl": "target", "msg": "+ export LTP_TIMEOUT_MUL=5"}
- {"dt": "2023-02-02T12:35:40.323642", "lvl": "target", "msg": "+ LTP_TIMEOUT_MUL=5"}
- {"dt": "2023-02-02T12:35:40.324154", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.324464", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.325832", "lvl": "target", "msg": "+ export PASSWD=root"}
- {"dt": "2023-02-02T12:35:40.326152", "lvl": "target", "msg": "+ PASSWD=root"}
- {"dt": "2023-02-02T12:35:40.326668", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.326990", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.327545", "lvl": "target", "msg": "+ export BOARD="}
- {"dt": "2023-02-02T12:35:40.327678", "lvl": "target", "msg": "+ BOARD="}
- {"dt": "2023-02-02T12:35:40.328207", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.328531", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.329270", "lvl": "target", "msg": "+ export LTP_TMPDIR=/scratch"}
- {"dt": "2023-02-02T12:35:40.329640", "lvl": "target", "msg": "+ LTP_TMPDIR=/scratch"}
- {"dt": "2023-02-02T12:35:40.330290", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.330613", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.331103", "lvl": "target", "msg": "+ export BRANCH="}
- {"dt": "2023-02-02T12:35:40.331356", "lvl": "target", "msg": "+ BRANCH="}
- {"dt": "2023-02-02T12:35:40.331826", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.332283", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.332932", "lvl": "target", "msg": "+ export ENVIRONMENT=production"}
- {"dt": "2023-02-02T12:35:40.333551", "lvl": "target", "msg": "+ ENVIRONMENT=production"}
- {"dt": "2023-02-02T12:35:40.334121", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.334559", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.335118", "lvl": "target", "msg": "+ export LTP_INSTALL_PATH=/opt/ltp/"}
- {"dt": "2023-02-02T12:35:40.335554", "lvl": "target", "msg": "+ LTP_INSTALL_PATH=/opt/ltp/"}
- {"dt": "2023-02-02T12:35:40.335972", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.336395", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.338762", "lvl": "target", "msg": "+ '[' -z skipfile-lkft.yaml ']'"}
- {"dt": "2023-02-02T12:35:40.354309", "lvl": "target", "msg": "+ '[' yaml = yaml ']'"}
- {"dt": "2023-02-02T12:35:40.357423", "lvl": "target", "msg": "+ SKIPFILE_YAML=/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/skipfile-lkft.yaml"}
- {"dt": "2023-02-02T12:35:40.358402", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.360060", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.361047", "lvl": "target", "msg": "+ [[ '' != '' ]]"}
- {"dt": "2023-02-02T12:35:40.361201", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.361538", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.361686", "lvl": "target", "msg": "+ [[ '' != '' ]]"}
- {"dt": "2023-02-02T12:35:40.361829", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.361966", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.362270", "lvl": "target", "msg": "+ BUILD_FROM_TAR=false"}
- {"dt": "2023-02-02T12:35:40.362605", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.362734", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.362864", "lvl": "target", "msg": "+ SHARD_NUMBER=1"}
- {"dt": "2023-02-02T12:35:40.363191", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.363315", "lvl": "target", "msg": "+ case \\\"$arg\\\" in"}
- {"dt": "2023-02-02T12:35:40.363443", "lvl": "target", "msg": "+ SHARD_INDEX=1"}
- {"dt": "2023-02-02T12:35:40.363744", "lvl": "target", "msg": "+ getopts M:T:S:b:d:g:e:i:s:v:R:u:p:t:c:n: arg"}
- {"dt": "2023-02-02T12:35:40.366318", "lvl": "target", "msg": "+ TEST_TARFILE=https://github.com/linux-test-project/ltp/releases/download//ltp-full-.tar.xz"}
- {"dt": "2023-02-02T12:35:40.367297", "lvl": "target", "msg": "+ '[' -n /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/skipfile-lkft.yaml ']'"}
- {"dt": "2023-02-02T12:35:40.367955", "lvl": "target", "msg": "+ export SKIPFILE_PATH=/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/generated_skipfile"}
- {"dt": "2023-02-02T12:35:40.368420", "lvl": "target", "msg": "+ SKIPFILE_PATH=/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/generated_skipfile"}
- {"dt": "2023-02-02T12:35:40.368586", "lvl": "target", "msg": "+ generate_skipfile"}
- {"dt": "2023-02-02T12:35:40.370021", "lvl": "target", "msg": "+ info_msg 'Generating a skipfile based on /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/skipfile-lkft.yaml'"}
- {"dt": "2023-02-02T12:35:40.370918", "lvl": "target", "msg": "+ local 'msg=Generating a skipfile based on /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/skipfile-lkft.yaml'"}
- {"dt": "2023-02-02T12:35:40.372507", "lvl": "target", "msg": "+ '[' -z 'Generating a skipfile based on /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/skipfile-lkft.yaml' ']'"}
- {"dt": "2023-02-02T12:35:40.373521", "lvl": "target", "msg": "+ printf 'INFO: %s\\n' 'Generating a skipfile based on /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/skipfile-lkft.yaml'"}
- {"dt": "2023-02-02T12:35:40.374182", "lvl": "target", "msg": "INFO: Generating a skipfile based on /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/skipfile-lkft.yaml"}
- {"dt": "2023-02-02T12:35:40.375357", "lvl": "target", "msg": "+ detect_abi"}
- {"dt": "2023-02-02T12:35:40.384986", "lvl": "target", "msg": "++ uname -m"}
- {"dt": "2023-02-02T12:35:40.413588", "lvl": "target", "msg": "+ abi=riscv64"}
- {"dt": "2023-02-02T12:35:40.414011", "lvl": "target", "msg": "+ case \\\"${abi}\\\" in"}
- {"dt": "2023-02-02T12:35:40.414335", "lvl": "target", "msg": "+ abi=riscv64"}
- {"dt": "2023-02-02T12:35:40.414954", "lvl": "target", "msg": "+ local SKIPGEN_ARGS="}
- {"dt": "2023-02-02T12:35:40.415723", "lvl": "target", "msg": "+ test -n ''"}
- {"dt": "2023-02-02T12:35:40.415967", "lvl": "target", "msg": "+ test -n ''"}
- {"dt": "2023-02-02T12:35:40.416379", "lvl": "target", "msg": "+ test -n production"}
- {"dt": "2023-02-02T12:35:40.416637", "lvl": "target", "msg": "+ SKIPGEN_ARGS=' --environment production'"}
- {"dt": "2023-02-02T12:35:40.417448", "lvl": "target", "msg": "+ ../../bin/riscv64/skipgen --environment production /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/skipfile-lkft.yaml"}
- {"dt": "2023-02-02T12:35:40.510625", "lvl": "target", "msg": "+ test 0 -eq 0"}
- {"dt": "2023-02-02T12:35:40.511854", "lvl": "target", "msg": "+ info_msg 'Using the following generated skipfile contents (until EOF):'"}
- {"dt": "2023-02-02T12:35:40.512998", "lvl": "target", "msg": "+ local 'msg=Using the following generated skipfile contents (until EOF):'"}
- {"dt": "2023-02-02T12:35:40.513987", "lvl": "target", "msg": "+ '[' -z 'Using the following generated skipfile contents (until EOF):' ']'"}
- {"dt": "2023-02-02T12:35:40.514597", "lvl": "target", "msg": "+ printf 'INFO: %s\\n' 'Using the following generated skipfile contents (until EOF):'"}
- {"dt": "2023-02-02T12:35:40.515212", "lvl": "target", "msg": "INFO: Using the following generated skipfile contents (until EOF):"}
- {"dt": "2023-02-02T12:35:40.516137", "lvl": "target", "msg": "+ cat /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/generated_skipfile"}
- {"dt": "2023-02-02T12:35:40.534636", "lvl": "target", "msg": "bind06"}
- {"dt": "2023-02-02T12:35:40.534781", "lvl": "target", "msg": "cve-2018-18559"}
- {"dt": "2023-02-02T12:35:40.534888", "lvl": "target", "msg": "dio10"}
- {"dt": "2023-02-02T12:35:40.534993", "lvl": "target", "msg": "dio12"}
- {"dt": "2023-02-02T12:35:40.535330", "lvl": "target", "msg": "dio13"}
- {"dt": "2023-02-02T12:35:40.535456", "lvl": "target", "msg": "dio14"}
- {"dt": "2023-02-02T12:35:40.535554", "lvl": "target", "msg": "dio15"}
- {"dt": "2023-02-02T12:35:40.535653", "lvl": "target", "msg": "dio16"}
- {"dt": "2023-02-02T12:35:40.535780", "lvl": "target", "msg": "dio17"}
- {"dt": "2023-02-02T12:35:40.535919", "lvl": "target", "msg": "dio18"}
- {"dt": "2023-02-02T12:35:40.536060", "lvl": "target", "msg": "dio19"}
- {"dt": "2023-02-02T12:35:40.536192", "lvl": "target", "msg": "dio20"}
- {"dt": "2023-02-02T12:35:40.536318", "lvl": "target", "msg": "dio21"}
- {"dt": "2023-02-02T12:35:40.536430", "lvl": "target", "msg": "dio22"}
- {"dt": "2023-02-02T12:35:40.536554", "lvl": "target", "msg": "dio23"}
- {"dt": "2023-02-02T12:35:40.536682", "lvl": "target", "msg": "dio24"}
- {"dt": "2023-02-02T12:35:40.536779", "lvl": "target", "msg": "dio25"}
- {"dt": "2023-02-02T12:35:40.536888", "lvl": "target", "msg": "dio26"}
- {"dt": "2023-02-02T12:35:40.537001", "lvl": "target", "msg": "dio27"}
- {"dt": "2023-02-02T12:35:40.537142", "lvl": "target", "msg": "dio28"}
- {"dt": "2023-02-02T12:35:40.537290", "lvl": "target", "msg": "dio29"}
- {"dt": "2023-02-02T12:35:40.537425", "lvl": "target", "msg": "dio30"}
- {"dt": "2023-02-02T12:35:40.537563", "lvl": "target", "msg": "fanotify07"}
- {"dt": "2023-02-02T12:35:40.537672", "lvl": "target", "msg": "fanotify08"}
- {"dt": "2023-02-02T12:35:40.537777", "lvl": "target", "msg": "fanotify09"}
- {"dt": "2023-02-02T12:35:40.537919", "lvl": "target", "msg": "fork13"}
- {"dt": "2023-02-02T12:35:40.538025", "lvl": "target", "msg": "ftrace_stress_test.sh"}
- {"dt": "2023-02-02T12:35:40.538118", "lvl": "target", "msg": "futex_wake04"}
- {"dt": "2023-02-02T12:35:40.538209", "lvl": "target", "msg": "gf01"}
- {"dt": "2023-02-02T12:35:40.538298", "lvl": "target", "msg": "gf14"}
- {"dt": "2023-02-02T12:35:40.538385", "lvl": "target", "msg": "gf15"}
- {"dt": "2023-02-02T12:35:40.538469", "lvl": "target", "msg": "gf18"}
- {"dt": "2023-02-02T12:35:40.538554", "lvl": "target", "msg": "hackbench01"}
- {"dt": "2023-02-02T12:35:40.538661", "lvl": "target", "msg": "hackbench02"}
- {"dt": "2023-02-02T12:35:40.538748", "lvl": "target", "msg": "hugemmap06"}
- {"dt": "2023-02-02T12:35:40.538833", "lvl": "target", "msg": "inotify07"}
- {"dt": "2023-02-02T12:35:40.538917", "lvl": "target", "msg": "inotify08"}
- {"dt": "2023-02-02T12:35:40.539001", "lvl": "target", "msg": "ksm01"}
- {"dt": "2023-02-02T12:35:40.539086", "lvl": "target", "msg": "memcg_stress"}
- {"dt": "2023-02-02T12:35:40.539171", "lvl": "target", "msg": "msgctl10"}
- {"dt": "2023-02-02T12:35:40.539255", "lvl": "target", "msg": "msgctl11"}
- {"dt": "2023-02-02T12:35:40.539339", "lvl": "target", "msg": "msgstress03"}
- {"dt": "2023-02-02T12:35:40.539424", "lvl": "target", "msg": "msgstress04"}
- {"dt": "2023-02-02T12:35:40.539512", "lvl": "target", "msg": "mtest06"}
- {"dt": "2023-02-02T12:35:40.539597", "lvl": "target", "msg": "perf_event_open02"}
- {"dt": "2023-02-02T12:35:40.539682", "lvl": "target", "msg": "ping01"}
- {"dt": "2023-02-02T12:35:40.539765", "lvl": "target", "msg": "ping602"}
- {"dt": "2023-02-02T12:35:40.539850", "lvl": "target", "msg": "pth_str01"}
- {"dt": "2023-02-02T12:35:40.539935", "lvl": "target", "msg": "pth_str02"}
- {"dt": "2023-02-02T12:35:40.540019", "lvl": "target", "msg": "pth_str03"}
- {"dt": "2023-02-02T12:35:40.540104", "lvl": "target", "msg": "sendfile09"}
- {"dt": "2023-02-02T12:35:40.540189", "lvl": "target", "msg": "sendfile09_64"}
- {"dt": "2023-02-02T12:35:40.540273", "lvl": "target", "msg": "setsockopt06"}
- {"dt": "2023-02-02T12:35:40.540357", "lvl": "target", "msg": "time-schedule01"}
- {"dt": "2023-02-02T12:35:40.542002", "lvl": "target", "msg": "+ info_msg EOF"}
- {"dt": "2023-02-02T12:35:40.543854", "lvl": "target", "msg": "+ local msg=EOF"}
- {"dt": "2023-02-02T12:35:40.544529", "lvl": "target", "msg": "+ '[' -z EOF ']'"}
- {"dt": "2023-02-02T12:35:40.545244", "lvl": "target", "msg": "+ printf 'INFO: %s\\n' EOF"}
- {"dt": "2023-02-02T12:35:40.545385", "lvl": "target", "msg": "INFO: EOF"}
- {"dt": "2023-02-02T12:35:40.546791", "lvl": "target", "msg": "+ '[' '!' -f /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/generated_skipfile ']'"}
- {"dt": "2023-02-02T12:35:40.547952", "lvl": "target", "msg": "+ SKIPFILE='-S /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/generated_skipfile'"}
- {"dt": "2023-02-02T12:35:40.560073", "lvl": "target", "msg": "+ check_root"}
- {"dt": "2023-02-02T12:35:40.564703", "lvl": "target", "msg": "++ id -ru"}
- {"dt": "2023-02-02T12:35:40.582842", "lvl": "target", "msg": "+ '[' 0 -eq 0 ']'"}
- {"dt": "2023-02-02T12:35:40.583505", "lvl": "target", "msg": "+ return 0"}
- {"dt": "2023-02-02T12:35:40.585254", "lvl": "target", "msg": "+ create_out_dir /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output"}
- {"dt": "2023-02-02T12:35:40.586248", "lvl": "target", "msg": "+ '[' -z /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output ']'"}
- {"dt": "2023-02-02T12:35:40.586966", "lvl": "target", "msg": "+ local OUTPUT=/lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output"}
- {"dt": "2023-02-02T12:35:40.587897", "lvl": "target", "msg": "+ '[' -d /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output ']'"}
- {"dt": "2023-02-02T12:35:40.588877", "lvl": "target", "msg": "+ mkdir -p /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output"}
- {"dt": "2023-02-02T12:35:40.610469", "lvl": "target", "msg": "+ '[' -d /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output ']'"}
- {"dt": "2023-02-02T12:35:40.612020", "lvl": "target", "msg": "+ info_msg 'About to run ltp test...'"}
- {"dt": "2023-02-02T12:35:40.612722", "lvl": "target", "msg": "+ local 'msg=About to run ltp test...'"}
- {"dt": "2023-02-02T12:35:40.613474", "lvl": "target", "msg": "+ '[' -z 'About to run ltp test...' ']'"}
- {"dt": "2023-02-02T12:35:40.614083", "lvl": "target", "msg": "+ printf 'INFO: %s\\n' 'About to run ltp test...'"}
- {"dt": "2023-02-02T12:35:40.614399", "lvl": "target", "msg": "INFO: About to run ltp test..."}
- {"dt": "2023-02-02T12:35:40.615506", "lvl": "target", "msg": "+ info_msg 'Output directory: /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output'"}
- {"dt": "2023-02-02T12:35:40.616250", "lvl": "target", "msg": "+ local 'msg=Output directory: /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output'"}
- {"dt": "2023-02-02T12:35:40.617239", "lvl": "target", "msg": "+ '[' -z 'Output directory: /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output' ']'"}
- {"dt": "2023-02-02T12:35:40.618099", "lvl": "target", "msg": "+ printf 'INFO: %s\\n' 'Output directory: /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output'"}
- {"dt": "2023-02-02T12:35:40.618691", "lvl": "target", "msg": "INFO: Output directory: /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output"}
- {"dt": "2023-02-02T12:35:40.619554", "lvl": "target", "msg": "+ '[' true = true ']'"}
- {"dt": "2023-02-02T12:35:40.620071", "lvl": "target", "msg": "+ info_msg 'ltp installation skipped altogether'"}
- {"dt": "2023-02-02T12:35:40.620721", "lvl": "target", "msg": "+ local 'msg=ltp installation skipped altogether'"}
- {"dt": "2023-02-02T12:35:40.621484", "lvl": "target", "msg": "+ '[' -z 'ltp installation skipped altogether' ']'"}
- {"dt": "2023-02-02T12:35:40.622122", "lvl": "target", "msg": "+ printf 'INFO: %s\\n' 'ltp installation skipped altogether'"}
- {"dt": "2023-02-02T12:35:40.622603", "lvl": "target", "msg": "INFO: ltp installation skipped altogether"}
- {"dt": "2023-02-02T12:35:40.623903", "lvl": "target", "msg": "+ '[' '!' -d /opt/ltp/ ']'"}
- {"dt": "2023-02-02T12:35:40.625416", "lvl": "target", "msg": "+ info_msg 'Running prep_system'"}
- {"dt": "2023-02-02T12:35:40.625978", "lvl": "target", "msg": "+ local 'msg=Running prep_system'"}
- {"dt": "2023-02-02T12:35:40.626607", "lvl": "target", "msg": "+ '[' -z 'Running prep_system' ']'"}
- {"dt": "2023-02-02T12:35:40.627222", "lvl": "target", "msg": "+ printf 'INFO: %s\\n' 'Running prep_system'"}
- {"dt": "2023-02-02T12:35:40.627591", "lvl": "target", "msg": "INFO: Running prep_system"}
- {"dt": "2023-02-02T12:35:40.628211", "lvl": "target", "msg": "+ prep_system"}
- {"dt": "2023-02-02T12:35:40.628722", "lvl": "target", "msg": "+ systemctl is-active systemd-timesyncd"}
- {"dt": "2023-02-02T12:35:40.635726", "lvl": "target", "msg": "+ '[' -f /proc/sys/kernel/unprivileged_userns_clone ']'"}
- {"dt": "2023-02-02T12:35:40.636633", "lvl": "target", "msg": "+ info_msg 'Kernel has no support of unprivileged_userns_clone'"}
- {"dt": "2023-02-02T12:35:40.637778", "lvl": "target", "msg": "+ local 'msg=Kernel has no support of unprivileged_userns_clone'"}
- {"dt": "2023-02-02T12:35:40.638734", "lvl": "target", "msg": "+ '[' -z 'Kernel has no support of unprivileged_userns_clone' ']'"}
- {"dt": "2023-02-02T12:35:40.639397", "lvl": "target", "msg": "+ printf 'INFO: %s\\n' 'Kernel has no support of unprivileged_userns_clone'"}
- {"dt": "2023-02-02T12:35:40.639740", "lvl": "target", "msg": "INFO: Kernel has no support of unprivileged_userns_clone"}
- {"dt": "2023-02-02T12:35:40.640743", "lvl": "target", "msg": "+ info_msg 'Running run_ltp'"}
- {"dt": "2023-02-02T12:35:40.641420", "lvl": "target", "msg": "+ local 'msg=Running run_ltp'"}
- {"dt": "2023-02-02T12:35:40.642027", "lvl": "target", "msg": "+ '[' -z 'Running run_ltp' ']'"}
- {"dt": "2023-02-02T12:35:40.642614", "lvl": "target", "msg": "+ printf 'INFO: %s\\n' 'Running run_ltp'"}
- {"dt": "2023-02-02T12:35:40.642948", "lvl": "target", "msg": "INFO: Running run_ltp"}
- {"dt": "2023-02-02T12:35:40.643571", "lvl": "target", "msg": "+ run_ltp"}
- {"dt": "2023-02-02T12:35:40.644332", "lvl": "target", "msg": "+ cd /opt/ltp/"}
- {"dt": "2023-02-02T12:35:40.646456", "lvl": "target", "msg": "+ mkdir -m 777 -p /scratch"}
- {"dt": "2023-02-02T12:35:40.672821", "lvl": "target", "msg": "+ for file in ${TST_CMDFILES//,/ }"}
- {"dt": "2023-02-02T12:35:40.673767", "lvl": "target", "msg": "+ cat runtest/fcntl-locktests"}
- {"dt": "2023-02-02T12:35:40.694735", "lvl": "target", "msg": "+ sed -i 's/#.*$//;/^$/d' alltests"}
- {"dt": "2023-02-02T12:35:40.724581", "lvl": "target", "msg": "+ split --verbose --numeric-suffixes=1 -n l/1/1 alltests"}
- {"dt": "2023-02-02T12:35:40.747667", "lvl": "target", "msg": "+ echo '============== Tests to run ==============='"}
- {"dt": "2023-02-02T12:35:40.748214", "lvl": "target", "msg": "============== Tests to run ==============="}
- {"dt": "2023-02-02T12:35:40.748563", "lvl": "target", "msg": "+ cat runtest/shardfile"}
- {"dt": "2023-02-02T12:35:40.764834", "lvl": "target", "msg": "FCNTL_LOCKTESTS locktests -n 100 -f /tmp/fcntl_locktest_testfile"}
- {"dt": "2023-02-02T12:35:40.768018", "lvl": "target", "msg": "+ echo '===========End Tests to run ==============='"}
- {"dt": "2023-02-02T12:35:40.768485", "lvl": "target", "msg": "===========End Tests to run ==============="}
- {"dt": "2023-02-02T12:35:40.771466", "lvl": "target", "msg": "+ pipe0_status './runltp -p -q -f shardfile                                  -l /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.log                                  -C /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.failed                                  -d /scratch                                     -S /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/generated_skipfile' 'tee /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.out'"}
- {"dt": "2023-02-02T12:35:40.772371", "lvl": "target", "msg": "+ '[' 2 -ne 2 ']'"}
- {"dt": "2023-02-02T12:35:40.774582", "lvl": "target", "msg": "+ local 'cmd1=./runltp -p -q -f shardfile                                  -l /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.log                                  -C /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.failed                                  -d /scratch                                     -S /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/generated_skipfile'"}
- {"dt": "2023-02-02T12:35:40.775350", "lvl": "target", "msg": "+ local 'cmd2=tee /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.out'"}
- {"dt": "2023-02-02T12:35:40.775817", "lvl": "target", "msg": "+ exec"}
- {"dt": "2023-02-02T12:35:40.776747", "lvl": "target", "msg": "+ local ret_val"}
- {"dt": "2023-02-02T12:35:40.785977", "lvl": "target", "msg": "++ eval 'tee /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.out'"}
- {"dt": "2023-02-02T12:35:40.787187", "lvl": "target", "msg": "+++ tee /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.out"}
- {"dt": "2023-02-02T12:35:40.791497", "lvl": "target", "msg": "++ eval './runltp -p -q -f shardfile                                  -l /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.log                                  -C /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.failed                                  -d /scratch                                     -S /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/generated_skipfile'"}
- {"dt": "2023-02-02T12:35:40.794592", "lvl": "target", "msg": "+++ ./runltp -p -q -f shardfile -l /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.log -C /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.failed -d /scratch -S /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/generated_skipfile"}
- {"dt": "2023-02-02T12:35:41.044620", "lvl": "target", "msg": "INFO: creating /opt/ltp/output directory"}
- {"dt": "2023-02-02T12:35:42.739765", "lvl": "target", "msg": "Checking for required user/group ids"}
- {"dt": "2023-02-02T12:35:42.740715", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:43.050115", "lvl": "target", "msg": "'nobody' user id and group found."}
- {"dt": "2023-02-02T12:35:43.051754", "lvl": "target", "msg": "'bin' user id and group found."}
- {"dt": "2023-02-02T12:35:43.052430", "lvl": "target", "msg": "'daemon' user id and group found."}
- {"dt": "2023-02-02T12:35:43.053168", "lvl": "target", "msg": "Users group found."}
- {"dt": "2023-02-02T12:35:43.053497", "lvl": "target", "msg": "Sys group found."}
- {"dt": "2023-02-02T12:35:43.287371", "lvl": "target", "msg": "Required users/groups exist."}
- {"dt": "2023-02-02T12:35:43.294037", "lvl": "target", "msg": "no big block device was specified on commandline."}
- {"dt": "2023-02-02T12:35:43.294297", "lvl": "target", "msg": "Tests which require a big block device are disabled."}
- {"dt": "2023-02-02T12:35:43.294464", "lvl": "target", "msg": "You can specify it with option -z"}
- {"dt": "2023-02-02T12:35:43.342815", "lvl": "target", "msg": "INFO: Test start time: Thu Feb  2 12:35:42 UTC 2023"}
- {"dt": "2023-02-02T12:35:43.344630", "lvl": "target", "msg": "COMMAND:    /opt/ltp/bin/ltp-pan -q  -e -S   -a 153     -n 153 -p -f /scratch/ltp-oW1ZF0gCoS/alltests -l /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.log  -C /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.failed -T /opt/ltp/output/LTP_RUN_ON-LTP_fcntl-locktests.log.tconf"}
- {"dt": "2023-02-02T12:35:43.382228", "lvl": "target", "msg": "LOG File: /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.log"}
- {"dt": "2023-02-02T12:35:43.413422", "lvl": "target", "msg": "FAILED COMMAND File: /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.failed"}
- {"dt": "2023-02-02T12:35:43.460533", "lvl": "target", "msg": "TCONF COMMAND File: /opt/ltp/output/LTP_RUN_ON-LTP_fcntl-locktests.log.tconf"}
- {"dt": "2023-02-02T12:35:43.465310", "lvl": "target", "msg": "Running tests......."}
- {"dt": "2023-02-02T12:35:44.018076", "lvl": "target", "msg": "........................................................................................................................................................................................................TEST : TRY TO WRITE ON A READ  LOCK:====================================================================================================TEST : TRY TO WRITE ON A WRITE LOCK:====================================================================================================TEST : TRY TO READ  ON A READ  LOCK:====================================================================================================TEST : TRY TO READ  ON A WRITE LOCK:====================================================================================================TEST : TRY TO SET A READ  LOCK ON A READ  LOCK:====================================================================================================TEST : TRY TO SET A WRITE LOCK ON A WRITE LOCK:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxTEST : TRY TO SET A WRITE LOCK ON A READ  LOCK:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxTEST : TRY TO SET A READ  LOCK ON A WRITE LOCK:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxTEST : TRY TO READ LOCK THE WHOLE FILE BYTE BY BYTE:====================================================================================================TEST : TRY TO WRITE LOCK THE WHOLE FILE BYTE BY BYTE:====================================================================================================Init"}
- {"dt": "2023-02-02T12:35:44.018340", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.019118", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.019464", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.020255", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.020371", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.021240", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.021357", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.022128", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.022243", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.023046", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.023164", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.023258", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.023346", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.024238", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.024354", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.024448", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.024539", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.024856", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.025185", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.026259", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.026372", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.026463", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.026559", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.027466", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.027591", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.027720", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.027813", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.027921", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.028016", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.028697", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.028808", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.030105", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.030235", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.030340", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.030471", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.042009", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.042354", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.042481", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.042592", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.042719", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.042846", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.042959", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.043076", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.043190", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.043340", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.043464", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.043564", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.043688", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.043790", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.043915", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.044026", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.044142", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.044258", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.044373", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.044490", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.044597", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.044733", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.044853", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.044967", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.045087", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.045199", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.045317", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.045463", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.045587", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.045702", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.045824", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.045935", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.046054", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.046166", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.046292", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.046390", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.046481", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.046580", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.046673", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.046761", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.046847", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.046934", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.047019", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.047104", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.047191", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.047278", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.047362", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.047449", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.047536", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.047623", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.047711", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.047799", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.047886", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.047975", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.048060", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.048147", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.063754", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.064074", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.064200", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.064293", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.064415", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.064554", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.064674", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.064792", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.064965", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.065125", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.065279", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.065436", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.065588", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.065741", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.065890", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.066039", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.066187", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.066334", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.066484", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.066641", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.066793", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.066942", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.067093", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.067242", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.067395", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.067563", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.067690", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.067808", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.067925", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.068041", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.068156", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.068276", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.068390", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.068508", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.068622", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.068741", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.068861", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.068974", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.069087", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.069191", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.069300", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.069406", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.069517", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.069630", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.069740", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.069851", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.069970", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.070080", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.070195", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.070309", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.070418", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.070530", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.070665", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.070777", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.070891", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.071011", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.071121", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.071239", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.071350", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.071460", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.071571", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.071682", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.071798", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.071917", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.072029", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.072148", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.072260", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.072368", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.072486", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.072597", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.072706", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.072820", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.072935", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.073052", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.073167", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.073264", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.073375", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.073493", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.073605", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.073719", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.073833", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.073941", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.074057", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.074206", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.074313", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.074422", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.074531", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.074651", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.074762", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.074870", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.074976", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.075082", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.075186", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.075291", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.075395", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.075500", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.075605", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.075712", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.075815", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.075918", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.076022", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.076125", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.076228", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.076330", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.076434", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.076538", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:44.076642", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:44.076744", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:46.073637", "lvl": "target", "msg": "Init"}
- {"dt": "2023-02-02T12:35:46.073924", "lvl": "target", "msg": "process initialization"}
- {"dt": "2023-02-02T12:35:46.074078", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.074221", "lvl": "target", "msg": "--------------------------------------"}
- {"dt": "2023-02-02T12:35:46.074570", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.074707", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.074826", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.074944", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.075056", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.075175", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.075278", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.075381", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.075491", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.075596", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.075705", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.075808", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:46.075919", "lvl": "target", "msg": "process number : 100 - Remote clients: 0 local client 1 - Total client 1 - Total concurent tests: 100"}
- {"dt": "2023-02-02T12:35:46.076026", "lvl": "target", "msg": "process number running test successfully :"}
- {"dt": "2023-02-02T12:35:46.076137", "lvl": "target", "msg": "100 process of 100 successfully ran test : WRITE ON A READ  LOCK"}
- {"dt": "2023-02-02T12:35:46.076266", "lvl": "target", "msg": "100 process of 100 successfully ran test : WRITE ON A WRITE LOCK"}
- {"dt": "2023-02-02T12:35:46.076424", "lvl": "target", "msg": "100 process of 100 successfully ran test : READ  ON A READ  LOCK"}
- {"dt": "2023-02-02T12:35:46.076538", "lvl": "target", "msg": "100 process of 100 successfully ran test : READ  ON A WRITE LOCK"}
- {"dt": "2023-02-02T12:35:46.076647", "lvl": "target", "msg": "100 process of 100 successfully ran test : SET A READ  LOCK ON A READ  LOCK"}
- {"dt": "2023-02-02T12:35:46.076755", "lvl": "target", "msg": "100 process of 100 successfully ran test : SET A WRITE LOCK ON A WRITE LOCK"}
- {"dt": "2023-02-02T12:35:46.076861", "lvl": "target", "msg": "100 process of 100 successfully ran test : SET A WRITE LOCK ON A READ  LOCK"}
- {"dt": "2023-02-02T12:35:46.076965", "lvl": "target", "msg": "100 process of 100 successfully ran test : SET A READ  LOCK ON A WRITE LOCK"}
- {"dt": "2023-02-02T12:35:46.077072", "lvl": "target", "msg": "100 process of 100 successfully ran test : READ LOCK THE WHOLE FILE BYTE BY BYTE"}
- {"dt": "2023-02-02T12:35:46.077175", "lvl": "target", "msg": "100 process of 100 successfully ran test : WRITE LOCK THE WHOLE FILE BYTE BY BYTE"}
- {"dt": "2023-02-02T12:35:51.090135", "lvl": "target", "msg": "INFO: ltp-pan reported all tests PASS"}
- {"dt": "2023-02-02T12:35:51.092464", "lvl": "target", "msg": "LTP Version: 20220930"}
- {"dt": "2023-02-02T12:35:51.144647", "lvl": "target", "msg": "INFO: Test end time: Thu Feb  2 12:35:50 UTC 2023"}
- {"dt": "2023-02-02T12:35:51.174208", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:51.174559", "lvl": "target", "msg": "       ###############################################################"}
- {"dt": "2023-02-02T12:35:51.174693", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:51.174821", "lvl": "target", "msg": "            Done executing testcases."}
- {"dt": "2023-02-02T12:35:51.174962", "lvl": "target", "msg": "            LTP Version:  20220930"}
- {"dt": "2023-02-02T12:35:51.175097", "lvl": "target", "msg": "       ###############################################################"}
- {"dt": "2023-02-02T12:35:51.175211", "lvl": "target", "msg": ""}
- {"dt": "2023-02-02T12:35:51.211139", "lvl": "target", "msg": "++ echo 0"}
- {"dt": "2023-02-02T12:35:51.222025", "lvl": "target", "msg": "+ ret_val=0"}
- {"dt": "2023-02-02T12:35:51.222785", "lvl": "target", "msg": "+ exec"}
- {"dt": "2023-02-02T12:35:51.223536", "lvl": "target", "msg": "+ return 0"}
- {"dt": "2023-02-02T12:35:51.225509", "lvl": "target", "msg": "+ parse_ltp_output /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.log"}
- {"dt": "2023-02-02T12:35:51.229584", "lvl": "target", "msg": "+ grep -E 'PASS|FAIL|CONF' /lava-1/0/tests/0_ltp-fcntl-locktests/automated/linux/ltp/output/LTP_fcntl-locktests.log"}
- {"dt": "2023-02-02T12:35:51.236281", "lvl": "target", "msg": "+ awk '{print $1\\\" \\\"$2}'"}
- {"dt": "2023-02-02T12:35:51.246091", "lvl": "target", "msg": "+ sed 's/PASS/pass/; s/FAIL/fail/; s/CONF/skip/'"}
- {"dt": "2023-02-02T12:35:51.293079", "lvl": "target", "msg": "+ rm -rf /scratch"}
- {"dt": "2023-02-02T12:35:51.316121", "lvl": "target", "msg": "+ rm -rf alltests"}
- {"dt": "2023-02-02T12:35:51.340981", "lvl": "target", "msg": "+ ../../utils/send-to-lava.sh ./output/result.txt"}
- {"dt": "2023-02-02T12:35:51.559425", "lvl": "target", "msg": "<8>[   17.007967] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=FCNTL_LOCKTESTS RESULT=pass>"}
- {"dt": "2023-02-02T12:35:51.559956", "lvl": "debug", "msg": "Received signal: <TESTCASE> TEST_CASE_ID=FCNTL_LOCKTESTS RESULT=pass"}
- {"dt": "2023-02-02T12:35:51.560117", "lvl": "results", "msg": {"case": "FCNTL_LOCKTESTS", "definition": "0_ltp-fcntl-locktests", "endtc": ! "1055", "result": "pass", "starttc": ! "1055"}}
- {"dt": "2023-02-02T12:35:51.566572", "lvl": "target", "msg": "+ set +x"}
- {"dt": "2023-02-02T12:35:51.567570", "lvl": "target", "msg": "<8>[   17.016159] <LAVA_SIGNAL_ENDRUN 0_ltp-fcntl-locktests 1_1.1.3.1>"}
- {"dt": "2023-02-02T12:35:51.567874", "lvl": "debug", "msg": "Received signal: <ENDRUN> 0_ltp-fcntl-locktests 1_1.1.3.1"}
- {"dt": "2023-02-02T12:35:51.568002", "lvl": "info", "msg": "Ending use of test pattern."}
- {"dt": "2023-02-02T12:35:51.568106", "lvl": "info", "msg": "Ending test lava.0_ltp-fcntl-locktests (1_1.1.3.1), duration 11.49"}
- {"dt": "2023-02-02T12:35:51.568302", "lvl": "results", "msg": {"case": "0_ltp-fcntl-locktests", "definition": "lava", "duration": "11.49", "namespace": "common", "path": "automated/linux/ltp/ltp.yaml", "repository": "file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_test-definitions_2023.01.tar.zst", "result": "pass", "revision": "unspecified", "uuid": "1_1.1.3.1"}}
- {"dt": "2023-02-02T12:35:51.584342", "lvl": "info", "msg": "ok: lava_test_shell seems to have completed"}
- {"dt": "2023-02-02T12:35:51.584559", "lvl": "debug", "msg": "FCNTL_LOCKTESTS: pass\n"}
- {"dt": "2023-02-02T12:35:51.584803", "lvl": "debug", "msg": "end: 3.1 lava-test-shell (duration 00:00:12) [common]"}
- {"dt": "2023-02-02T12:35:51.585025", "lvl": "info", "msg": "end: 3 lava-test-retry (duration 00:00:12) [common]"}
- {"dt": "2023-02-02T12:35:51.585256", "lvl": "info", "msg": "start: 4 finalize (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:51.585492", "lvl": "debug", "msg": "start: 4.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2023-02-02T12:35:51.585718", "lvl": "debug", "msg": "end: 4.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2023-02-02T12:35:51.585939", "lvl": "debug", "msg": "start: 4.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2023-02-02T12:35:51.586341", "lvl": "feedback", "msg": "<LAVA_TEST_RUNNER EXIT>", "ns": "common"}
- {"dt": "2023-02-02T12:35:51.586685", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2023-02-02T12:35:51.588519", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2023-02-02T12:35:52.586659", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2023-02-02T12:35:52.586905", "lvl": "input", "msg": "poweroff\n"}
- {"dt": "2023-02-02T12:35:52.687247", "lvl": "target", "msg": "root@tuxtest:~# poweroff"}
- {"dt": "2023-02-02T12:35:52.687746", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2023-02-02T12:35:52.687890", "lvl": "target", "msg": "poweroff"}
- {"dt": "2023-02-02T12:35:52.788287", "lvl": "debug", "msg": "end: 4.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2023-02-02T12:35:52.788503", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2023-02-02T12:35:52.788631", "lvl": "info", "msg": "end: 4 finalize (duration 00:00:01) [common]"}
- {"dt": "2023-02-02T12:35:52.788753", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2023-02-02T12:35:52.788843", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/url-repo-action-0by013x4/url_repo"}
- {"dt": "2023-02-02T12:35:52.794605", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/kernel"}
- {"dt": "2023-02-02T12:35:52.797057", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/bios"}
- {"dt": "2023-02-02T12:35:52.797164", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1/deployimages-0eozbca9/rootfs"}
- {"dt": "2023-02-02T12:35:52.797260", "lvl": "info", "msg": "Stopping the qemu container lava-docker-qemu-1-2.1.1-561l3jb3jh"}
- {"dt": "2023-02-02T12:35:53.078066", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/tuxrun-o_ykcwqx-1"}
- {"dt": "2023-02-02T12:35:53.099469", "lvl": "info", "msg": "Job finished correctly"}
- {"dt": "2023-02-02T12:35:53.099604", "lvl": "results", "msg": {"case": "job", "definition": "lava", "result": "pass"}}
