- {"dt": "2024-02-07T13:33:22.860794", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2024.01"}
- {"dt": "2024-02-07T13:33:22.860904", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-02-07T13:33:22.860982", "lvl": "info", "msg": "Start time: 2024-02-07 13:33:22.860977+00:00 (UTC)"}
- {"dt": "2024-02-07T13:33:22.861807", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxmake/builds/398/Image.gz exists"}
- {"dt": "2024-02-07T13:33:22.861905", "lvl": "debug", "msg": "Validating that file:///home/anders/src/tmp/debian-xfstests3/bookworm/arm64/rootfs.ext4.xz exists"}
- {"dt": "2024-02-07T13:33:22.861988", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxmake/builds/398/modules.tar.xz exists"}
- {"dt": "2024-02-07T13:33:22.862062", "lvl": "debug", "msg": "Validating that file:///home/anders/src/tmp/debian/bookworm/arm64/xfstests/master/xfstests.tar.xz exists"}
- {"dt": "2024-02-07T13:33:22.862136", "lvl": "debug", "msg": "Validating that file:///home/anders/src/tmp/xfstests-artifacts/run-xfstests.sh exists"}
- {"dt": "2024-02-07T13:33:22.871188", "lvl": "info", "msg": "qemu-system-arm, installed at version: 1:8.2.0+ds-5, host architecture: amd64"}
- {"dt": "2024-02-07T13:33:22.871535", "lvl": "warning", "msg": "Missing image arg for rootfs.modules"}
- {"dt": "2024-02-07T13:33:22.871619", "lvl": "warning", "msg": "Missing image arg for rootfs.overlay-00"}
- {"dt": "2024-02-07T13:33:22.871688", "lvl": "warning", "msg": "Missing image arg for rootfs.overlay-01"}
- {"dt": "2024-02-07T13:33:22.871811", "lvl": "info", "msg": "validate duration: 0.01"}
- {"dt": "2024-02-07T13:33:22.871881", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2024-02-07T13:33:22.872007", "lvl": "info", "msg": "start: 1 deployimages (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.872083", "lvl": "debug", "msg": "start: 1.1 lava-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.872210", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze"}
- {"dt": "2024-02-07T13:33:22.872338", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin"}
- {"dt": "2024-02-07T13:33:22.872434", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/tests"}
- {"dt": "2024-02-07T13:33:22.872530", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/results"}
- {"dt": "2024-02-07T13:33:22.872602", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-add-keys"}
- {"dt": "2024-02-07T13:33:22.872730", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-add-sources"}
- {"dt": "2024-02-07T13:33:22.872857", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-background-process-start"}
- {"dt": "2024-02-07T13:33:22.872984", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-background-process-stop"}
- {"dt": "2024-02-07T13:33:22.873113", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-common-functions"}
- {"dt": "2024-02-07T13:33:22.873236", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-echo-ipv4"}
- {"dt": "2024-02-07T13:33:22.873358", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-install-packages"}
- {"dt": "2024-02-07T13:33:22.873479", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-installed-packages"}
- {"dt": "2024-02-07T13:33:22.873603", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-os-build"}
- {"dt": "2024-02-07T13:33:22.873725", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-probe-channel"}
- {"dt": "2024-02-07T13:33:22.873847", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-probe-ip"}
- {"dt": "2024-02-07T13:33:22.873967", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-target-ip"}
- {"dt": "2024-02-07T13:33:22.874087", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-target-mac"}
- {"dt": "2024-02-07T13:33:22.874208", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-target-storage"}
- {"dt": "2024-02-07T13:33:22.874332", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-test-case"}
- {"dt": "2024-02-07T13:33:22.874452", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-test-event"}
- {"dt": "2024-02-07T13:33:22.874571", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-test-feedback"}
- {"dt": "2024-02-07T13:33:22.874693", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-test-raise"}
- {"dt": "2024-02-07T13:33:22.874812", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-test-reference"}
- {"dt": "2024-02-07T13:33:22.874931", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-test-runner"}
- {"dt": "2024-02-07T13:33:22.875050", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-test-set"}
- {"dt": "2024-02-07T13:33:22.875169", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-test-shell"}
- {"dt": "2024-02-07T13:33:22.875304", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-install-packages (oe)"}
- {"dt": "2024-02-07T13:33:22.875459", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/bin/lava-installed-packages (oe)"}
- {"dt": "2024-02-07T13:33:22.875571", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/environment"}
- {"dt": "2024-02-07T13:33:22.875663", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2024-02-07T13:33:22.875713", "lvl": "debug", "msg": "- LAVA_JOB_ID=1"}
- {"dt": "2024-02-07T13:33:22.875758", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=10.0.2.100"}
- {"dt": "2024-02-07T13:33:22.875835", "lvl": "debug", "msg": "start: 1.1.1 lava-vland-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.875882", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2024-02-07T13:33:22.875937", "lvl": "debug", "msg": "end: 1.1.1 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.875996", "lvl": "debug", "msg": "start: 1.1.2 lava-multinode-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.876038", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2024-02-07T13:33:22.876090", "lvl": "debug", "msg": "end: 1.1.2 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.876145", "lvl": "debug", "msg": "start: 1.1.3 test-definition (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.876195", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2024-02-07T13:33:22.876255", "lvl": "debug", "msg": "start: 1.1.3.1 inline-repo-action (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.876302", "lvl": "debug", "msg": "Using /lava-1 at stage 0"}
- {"dt": "2024-02-07T13:33:22.876581", "lvl": "debug", "msg": "uuid=1_1.1.3.1 testdef=None"}
- {"dt": "2024-02-07T13:33:22.876648", "lvl": "debug", "msg": "end: 1.1.3.1 inline-repo-action (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.876706", "lvl": "debug", "msg": "start: 1.1.3.2 test-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.877069", "lvl": "debug", "msg": "end: 1.1.3.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.877123", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "inline", "name": "commands", "path": "command", "uuid": "1_1.1.3.1"}, "level": "1.1.3.2", "namespace": "common", "result": "pass"}}
- {"dt": "2024-02-07T13:33:22.877228", "lvl": "debug", "msg": "start: 1.1.3.3 test-install-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.877699", "lvl": "debug", "msg": "end: 1.1.3.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.877755", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "inline", "name": "commands", "path": "command", "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": "2024-02-07T13:33:22.877862", "lvl": "debug", "msg": "start: 1.1.3.4 test-runscript-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.878321", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/0/tests/0_commands test_uuid 1_1.1.3.1"}
- {"dt": "2024-02-07T13:33:22.878506", "lvl": "debug", "msg": "end: 1.1.3.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.878562", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.00", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/0/tests/0_commands/run.sh", "from": "inline", "name": "commands", "path": "command", "uuid": "1_1.1.3.1"}, "level": "1.1.3.4", "namespace": "common", "result": "pass"}}
- {"dt": "2024-02-07T13:33:22.878655", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2024-02-07T13:33:22.878697", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/lava-overlay-6aw0cnze/lava-1/0 for stage 0"}
- {"dt": "2024-02-07T13:33:22.878771", "lvl": "debug", "msg": "- 0_commands"}
- {"dt": "2024-02-07T13:33:22.878853", "lvl": "debug", "msg": "end: 1.1.3 test-definition (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.878915", "lvl": "debug", "msg": "start: 1.1.4 compress-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884180", "lvl": "debug", "msg": "end: 1.1.4 compress-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884257", "lvl": "debug", "msg": "start: 1.1.5 persistent-nfs-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884319", "lvl": "debug", "msg": "end: 1.1.5 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884377", "lvl": "debug", "msg": "end: 1.1 lava-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884434", "lvl": "debug", "msg": "start: 1.2 apply-overlay-guest (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884479", "lvl": "debug", "msg": "Overlay already applied"}
- {"dt": "2024-02-07T13:33:22.884532", "lvl": "debug", "msg": "end: 1.2 apply-overlay-guest (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884587", "lvl": "debug", "msg": "start: 1.3 deploy-device-env (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884639", "lvl": "debug", "msg": "end: 1.3 deploy-device-env (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884693", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884748", "lvl": "debug", "msg": "start: 1.4.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:22.884867", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxmake/builds/398/Image.gz"}
- {"dt": "2024-02-07T13:33:22.884922", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/kernel/Image"}
- {"dt": "2024-02-07T13:33:22.884966", "lvl": "debug", "msg": "total size: 14189518 (13\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.885010", "lvl": "info", "msg": "Using gunzip to decompress gz"}
- {"dt": "2024-02-07T13:33:22.885443", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.894050", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.904678", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.912362", "lvl": "debug", "msg": "progress  15\u202F% (2\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.922690", "lvl": "debug", "msg": "progress  20\u202F% (2\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.933216", "lvl": "debug", "msg": "progress  25\u202F% (3\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.941057", "lvl": "debug", "msg": "progress  30\u202F% (4\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.951516", "lvl": "debug", "msg": "progress  35\u202F% (4\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.961900", "lvl": "debug", "msg": "progress  40\u202F% (5\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.969438", "lvl": "debug", "msg": "progress  45\u202F% (6\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.979835", "lvl": "debug", "msg": "progress  50\u202F% (6\u202FMB)"}
- {"dt": "2024-02-07T13:33:22.990420", "lvl": "debug", "msg": "progress  55\u202F% (7\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.001101", "lvl": "debug", "msg": "progress  60\u202F% (8\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.009451", "lvl": "debug", "msg": "progress  65\u202F% (8\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.030726", "lvl": "debug", "msg": "progress  70\u202F% (9\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.045471", "lvl": "debug", "msg": "progress  75\u202F% (10\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.055100", "lvl": "debug", "msg": "progress  80\u202F% (10\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.067314", "lvl": "debug", "msg": "progress  85\u202F% (11\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.080394", "lvl": "debug", "msg": "progress  90\u202F% (12\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.099711", "lvl": "debug", "msg": "progress  95\u202F% (12\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.113275", "lvl": "debug", "msg": "progress 100\u202F% (13\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.132359", "lvl": "info", "msg": "13\u202FMB downloaded in 0.25\u202Fs (54.70\u202FMB/s)"}
- {"dt": "2024-02-07T13:33:23.132578", "lvl": "debug", "msg": "end: 1.4.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:23.132687", "lvl": "results", "msg": {"case": "file-download", "definition": "lava", "duration": "0.25", "extra": {"label": "kernel", "md5sum": "2c4be9ceec08ee6382da555506ff3f43", "sha256sum": "8b9ace7b678b7775c625af2e732058d3aa635233f3c1ee91fe93bba02279fe72", "sha512sum": "4b5bf5a80acda5210d1dfb121f8ec5d519c2bda4016e912d2bb94cc5e78ef769fcf88d48b0d3aed9e50b2e1cce8722e30d6a0e30801c9f655fc51305156d2841", "size": ! "14189518"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-02-07T13:33:23.132924", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:23.133046", "lvl": "debug", "msg": "start: 1.5 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:23.133163", "lvl": "debug", "msg": "start: 1.5.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:23.133420", "lvl": "info", "msg": "downloading file:///home/anders/src/tmp/debian-xfstests3/bookworm/arm64/rootfs.ext4.xz"}
- {"dt": "2024-02-07T13:33:23.133536", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs/rootfs.ext4"}
- {"dt": "2024-02-07T13:33:23.133631", "lvl": "debug", "msg": "total size: 120918524 (115\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.133724", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-02-07T13:33:23.134472", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.423416", "lvl": "debug", "msg": "progress   5\u202F% (5\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.686244", "lvl": "debug", "msg": "progress  10\u202F% (11\u202FMB)"}
- {"dt": "2024-02-07T13:33:23.936540", "lvl": "debug", "msg": "progress  15\u202F% (17\u202FMB)"}
- {"dt": "2024-02-07T13:33:24.192512", "lvl": "debug", "msg": "progress  20\u202F% (23\u202FMB)"}
- {"dt": "2024-02-07T13:33:24.436376", "lvl": "debug", "msg": "progress  25\u202F% (28\u202FMB)"}
- {"dt": "2024-02-07T13:33:24.686640", "lvl": "debug", "msg": "progress  30\u202F% (34\u202FMB)"}
- {"dt": "2024-02-07T13:33:24.950638", "lvl": "debug", "msg": "progress  35\u202F% (40\u202FMB)"}
- {"dt": "2024-02-07T13:33:25.199719", "lvl": "debug", "msg": "progress  40\u202F% (46\u202FMB)"}
- {"dt": "2024-02-07T13:33:25.444772", "lvl": "debug", "msg": "progress  45\u202F% (51\u202FMB)"}
- {"dt": "2024-02-07T13:33:25.706434", "lvl": "debug", "msg": "progress  50\u202F% (57\u202FMB)"}
- {"dt": "2024-02-07T13:33:25.959008", "lvl": "debug", "msg": "progress  55\u202F% (63\u202FMB)"}
- {"dt": "2024-02-07T13:33:26.216766", "lvl": "debug", "msg": "progress  60\u202F% (69\u202FMB)"}
- {"dt": "2024-02-07T13:33:26.491820", "lvl": "debug", "msg": "progress  65\u202F% (74\u202FMB)"}
- {"dt": "2024-02-07T13:33:26.734637", "lvl": "debug", "msg": "progress  70\u202F% (80\u202FMB)"}
- {"dt": "2024-02-07T13:33:26.987938", "lvl": "debug", "msg": "progress  75\u202F% (86\u202FMB)"}
- {"dt": "2024-02-07T13:33:27.228218", "lvl": "debug", "msg": "progress  80\u202F% (92\u202FMB)"}
- {"dt": "2024-02-07T13:33:27.482296", "lvl": "debug", "msg": "progress  85\u202F% (98\u202FMB)"}
- {"dt": "2024-02-07T13:33:27.717749", "lvl": "debug", "msg": "progress  90\u202F% (103\u202FMB)"}
- {"dt": "2024-02-07T13:33:27.943924", "lvl": "debug", "msg": "progress  95\u202F% (109\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.030185", "lvl": "debug", "msg": "progress 100\u202F% (115\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.787535", "lvl": "info", "msg": "115\u202FMB downloaded in 27.65\u202Fs (4.17\u202FMB/s)"}
- {"dt": "2024-02-07T13:33:50.787791", "lvl": "debug", "msg": "end: 1.5.1 file-download (duration 00:00:28) [common]"}
- {"dt": "2024-02-07T13:33:50.787913", "lvl": "results", "msg": {"case": "file-download", "definition": "lava", "duration": "27.65", "extra": {"label": "rootfs", "md5sum": "feb26957093acf80d02bef400f98e6ea", "sha256sum": "bc464a1f762fafa73eaf3272fc5ddfbc9f2bf959d782e30ea6115d465d760069", "sha512sum": "e1479cb0ffde14cb9f61ac7b096c39bb343c8cd1992cd527f9deba6c1aceedb4818b66ead783f71c157af58e74cb050e9896f7927a2d8517804f172de6f18a25", "size": ! "120918524"}, "level": "1.5.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-02-07T13:33:50.788168", "lvl": "debug", "msg": "start: 1.5.2 download-retry (timeout 00:04:32) [common]"}
- {"dt": "2024-02-07T13:33:50.788316", "lvl": "debug", "msg": "start: 1.5.2.1 file-download (timeout 00:04:32) [common]"}
- {"dt": "2024-02-07T13:33:50.788584", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxmake/builds/398/modules.tar.xz"}
- {"dt": "2024-02-07T13:33:50.788699", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs.modules/modules.tar"}
- {"dt": "2024-02-07T13:33:50.788797", "lvl": "debug", "msg": "total size: 10539932 (10\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.788903", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-02-07T13:33:50.789637", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.813094", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.836073", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.859239", "lvl": "debug", "msg": "progress  15\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.888005", "lvl": "debug", "msg": "progress  20\u202F% (2\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.915079", "lvl": "debug", "msg": "progress  25\u202F% (2\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.938245", "lvl": "debug", "msg": "progress  30\u202F% (3\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.960913", "lvl": "debug", "msg": "progress  35\u202F% (3\u202FMB)"}
- {"dt": "2024-02-07T13:33:50.984584", "lvl": "debug", "msg": "progress  40\u202F% (4\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.006808", "lvl": "debug", "msg": "progress  45\u202F% (4\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.028954", "lvl": "debug", "msg": "progress  50\u202F% (5\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.051227", "lvl": "debug", "msg": "progress  55\u202F% (5\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.073444", "lvl": "debug", "msg": "progress  60\u202F% (6\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.098483", "lvl": "debug", "msg": "progress  65\u202F% (6\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.121381", "lvl": "debug", "msg": "progress  70\u202F% (7\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.142994", "lvl": "debug", "msg": "progress  75\u202F% (7\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.164738", "lvl": "debug", "msg": "progress  80\u202F% (8\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.186415", "lvl": "debug", "msg": "progress  85\u202F% (8\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.209349", "lvl": "debug", "msg": "progress  90\u202F% (9\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.235682", "lvl": "debug", "msg": "progress  95\u202F% (9\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.262340", "lvl": "debug", "msg": "progress 100\u202F% (10\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.266417", "lvl": "info", "msg": "10\u202FMB downloaded in 0.48\u202Fs (21.05\u202FMB/s)"}
- {"dt": "2024-02-07T13:33:51.266647", "lvl": "debug", "msg": "end: 1.5.2.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:51.266760", "lvl": "results", "msg": {"case": "file-download", "definition": "lava", "duration": "0.48", "extra": {"label": "rootfs.modules", "md5sum": "cf4198f96896d692f061a24bd6a17bee", "sha256sum": "c9f8d18a4bbfa21d7f872d211da26b0629f748168f13fc253f3293d4d54dba84", "sha512sum": "22f808093cf8814f87f16cf9a47d3a0aef211a30edb528c0942d6dabe074449a083458b446f7c9b469c10a8750725149d6905ea1044b01dbcfde7026c719802c", "size": ! "10539932"}, "level": "1.5.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-02-07T13:33:51.267001", "lvl": "debug", "msg": "end: 1.5.2 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:51.267136", "lvl": "debug", "msg": "start: 1.5.3 download-retry (timeout 00:04:32) [common]"}
- {"dt": "2024-02-07T13:33:51.267268", "lvl": "debug", "msg": "start: 1.5.3.1 file-download (timeout 00:04:32) [common]"}
- {"dt": "2024-02-07T13:33:51.267565", "lvl": "info", "msg": "downloading file:///home/anders/src/tmp/debian/bookworm/arm64/xfstests/master/xfstests.tar.xz"}
- {"dt": "2024-02-07T13:33:51.267680", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs.overlay-00/xfstests.tar"}
- {"dt": "2024-02-07T13:33:51.267776", "lvl": "debug", "msg": "total size: 2163052 (2\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.267876", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-02-07T13:33:51.268615", "lvl": "debug", "msg": "progress   1\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.272281", "lvl": "debug", "msg": "progress   6\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.279024", "lvl": "debug", "msg": "progress  12\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.285661", "lvl": "debug", "msg": "progress  18\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.292041", "lvl": "debug", "msg": "progress  24\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.298763", "lvl": "debug", "msg": "progress  30\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.304733", "lvl": "debug", "msg": "progress  36\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.310570", "lvl": "debug", "msg": "progress  42\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.316613", "lvl": "debug", "msg": "progress  48\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.321098", "lvl": "debug", "msg": "progress  53\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.327481", "lvl": "debug", "msg": "progress  59\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.333303", "lvl": "debug", "msg": "progress  65\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.339095", "lvl": "debug", "msg": "progress  71\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.345017", "lvl": "debug", "msg": "progress  77\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.350622", "lvl": "debug", "msg": "progress  83\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.356355", "lvl": "debug", "msg": "progress  89\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.361840", "lvl": "debug", "msg": "progress  95\u202F% (1\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.367060", "lvl": "debug", "msg": "progress 100\u202F% (2\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.370069", "lvl": "info", "msg": "2\u202FMB downloaded in 0.10\u202Fs (20.17\u202FMB/s)"}
- {"dt": "2024-02-07T13:33:51.370272", "lvl": "debug", "msg": "end: 1.5.3.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:51.370390", "lvl": "results", "msg": {"case": "file-download", "definition": "lava", "duration": "0.10", "extra": {"label": "rootfs.overlay-00", "md5sum": "76fda03fd5ee55764a49c39e74b0166c", "sha256sum": "3d3b8b15eb0c3834732476892b7594908353f31ce453bf2b2817a10a00c7ea62", "sha512sum": "6fe3ac0149377e6f4f2f05c41f2b126a140838c77b66e4f01aa6377da96f9acccee05d0b5feff7fcdfb447c600a9afb3092540669ea980d6ae9bdd026bed4e03", "size": ! "2163052"}, "level": "1.5.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-02-07T13:33:51.370636", "lvl": "debug", "msg": "end: 1.5.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:51.370770", "lvl": "debug", "msg": "start: 1.5.4 download-retry (timeout 00:04:32) [common]"}
- {"dt": "2024-02-07T13:33:51.370896", "lvl": "debug", "msg": "start: 1.5.4.1 file-download (timeout 00:04:32) [common]"}
- {"dt": "2024-02-07T13:33:51.371131", "lvl": "info", "msg": "downloading file:///home/anders/src/tmp/xfstests-artifacts/run-xfstests.sh"}
- {"dt": "2024-02-07T13:33:51.371241", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs.overlay-01/run-xfstests.sh"}
- {"dt": "2024-02-07T13:33:51.371363", "lvl": "debug", "msg": "total size: 563 (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.371455", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-02-07T13:33:51.371645", "lvl": "debug", "msg": "progress 100\u202F% (0\u202FMB)"}
- {"dt": "2024-02-07T13:33:51.371795", "lvl": "info", "msg": "0\u202FMB downloaded in 0.00\u202Fs (1.26\u202FMB/s)"}
- {"dt": "2024-02-07T13:33:51.371981", "lvl": "debug", "msg": "end: 1.5.4.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:51.372081", "lvl": "results", "msg": {"case": "file-download", "definition": "lava", "duration": "0.00", "extra": {"label": "rootfs.overlay-01", "md5sum": "e5f967548c00b13748bd236fb8bb374f", "sha256sum": "9273f7933ff64417f5cf547496b0f459c17d7c9b83e6cfbc69ca7e0c2ea8ce83", "sha512sum": "65b2e989ebd01d7eab8eccb2d267b6c047db8f7310f5a3fee401906c5bfcb480787212e0dfc45c2512c9feb8f4c93745248629954796a123b89b306132e83077", "size": ! "563"}, "level": "1.5.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-02-07T13:33:51.372309", "lvl": "debug", "msg": "end: 1.5.4 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:51.372432", "lvl": "debug", "msg": "start: 1.5.5 append-overlays (timeout 00:04:31) [common]"}
- {"dt": "2024-02-07T13:33:51.372532", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs/rootfs.ext4'"}
- {"dt": "2024-02-07T13:33:53.707047", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2024-02-07T13:33:53.708240", "lvl": "debug", "msg": "- rootfs.lava: '/var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/compress-overlay-ce8ggtwp/overlay-1.1.4.tar.gz' to '/'"}
- {"dt": "2024-02-07T13:33:53.712978", "lvl": "debug", "msg": "- rootfs.modules: '/var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs.modules/modules.tar' to '/'"}
- {"dt": "2024-02-07T13:33:53.899770", "lvl": "debug", "msg": "- rootfs.overlay-00: '/var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs.overlay-00/xfstests.tar' to '/opt/'"}
- {"dt": "2024-02-07T13:33:54.061237", "lvl": "debug", "msg": "- rootfs.overlay-01: '/var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs.overlay-01/run-xfstests.sh' to '/tmp/'"}
- {"dt": "2024-02-07T13:33:54.093988", "lvl": "exception", "msg": "upload: /tmp/: Is a directory"}
- {"dt": "2024-02-07T13:33:54.094245", "lvl": "exception", "msg": "Unable to update image rootfs: 'upload: /tmp/: Is a directory'"}
- {"dt": "2024-02-07T13:33:54.094429", "lvl": "debug", "msg": "end: 1.5.5 append-overlays (duration 00:00:03) [common]"}
- {"dt": "2024-02-07T13:33:54.094578", "lvl": "results", "msg": {"case": "append-overlays", "definition": "lava", "duration": "2.72", "extra": {"fail": "Unable to update image rootfs: 'upload: /tmp/: Is a directory'"}, "level": "1.5.5", "namespace": "common", "result": "fail"}}
- {"dt": "2024-02-07T13:33:54.094788", "lvl": "error", "msg": "download-retry failed: 1 of 1 attempts. 'Unable to update image rootfs: 'upload: /tmp/: Is a directory''"}
- {"dt": "2024-02-07T13:33:54.094929", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs"}
- {"dt": "2024-02-07T13:33:54.095259", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs.modules"}
- {"dt": "2024-02-07T13:33:54.112814", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs.overlay-00"}
- {"dt": "2024-02-07T13:33:54.118722", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/rootfs.overlay-01"}
- {"dt": "2024-02-07T13:33:54.118994", "lvl": "exception", "msg": "Unable to update image rootfs: 'upload: /tmp/: Is a directory'"}
- {"dt": "2024-02-07T13:33:54.119103", "lvl": "debug", "msg": "end: 1.5 download-retry (duration 00:00:31) [common]"}
- {"dt": "2024-02-07T13:33:54.119218", "lvl": "results", "msg": {"case": "download-retry", "definition": "lava", "duration": "30.99", "extra": {"fail": "Unable to update image rootfs: 'upload: /tmp/: Is a directory'"}, "level": "1.5", "namespace": "common", "result": "fail"}}
- {"dt": "2024-02-07T13:33:54.119425", "lvl": "exception", "msg": "Unable to update image rootfs: 'upload: /tmp/: Is a directory'"}
- {"dt": "2024-02-07T13:33:54.119536", "lvl": "info", "msg": "end: 1 deployimages (duration 00:00:31) [common]"}
- {"dt": "2024-02-07T13:33:54.119696", "lvl": "results", "msg": {"case": "deployimages", "definition": "lava", "duration": "31.25", "extra": {"fail": "Unable to update image rootfs: 'upload: /tmp/: Is a directory'"}, "level": "1", "namespace": "common", "result": "fail"}}
- {"dt": "2024-02-07T13:33:54.120065", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-02-07T13:33:54.120188", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1/deployimages-hlcp7z8j/kernel"}
- {"dt": "2024-02-07T13:33:54.130088", "lvl": "debug", "msg": "start: 4.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2024-02-07T13:33:54.130241", "lvl": "debug", "msg": "end: 4.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:54.130361", "lvl": "debug", "msg": "start: 4.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2024-02-07T13:33:54.130469", "lvl": "debug", "msg": "No connection for namespace common"}
- {"dt": "2024-02-07T13:33:54.130581", "lvl": "debug", "msg": "end: 4.2 read-feedback (duration 00:00:00) [common]"}
- {"dt": "2024-02-07T13:33:54.130698", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/tuxrun-thy2r_f_-1"}
- {"dt": "2024-02-07T13:33:54.132575", "lvl": "error", "msg": "JobError: Your job cannot terminate cleanly."}
- {"dt": "2024-02-07T13:33:54.132680", "lvl": "results", "msg": {"case": "job", "definition": "lava", "error_msg": "Unable to update image rootfs: 'upload: /tmp/: Is a directory'", "error_type": "Job", "result": "fail"}}
