- {"dt": "2024-12-12T10:22:39.315557", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.10"}
- {"dt": "2024-12-12T10:22:39.315826", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-12-12T10:22:39.315984", "lvl": "info", "msg": "Start time: 2024-12-12 10:22:39.315975+00:00 (UTC)"}
- {"dt": "2024-12-12T10:22:39.316168", "lvl": "debug", "msg": "Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/images/rootfs/buildroot/buildroot-baseline/20230623.0/riscv/rootfs.cpio.gz?raw=true exists"}
- {"dt": "2024-12-12T10:22:44.099201", "lvl": "debug", "msg": "Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/kernel/Image?raw=true exists"}
- {"dt": "2024-12-12T10:22:49.940904", "lvl": "debug", "msg": "Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/dtbs/sifive/hifive-unmatched-a00.dtb?raw=true exists"}
- {"dt": "2024-12-12T10:22:54.524434", "lvl": "debug", "msg": "Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/modules.tar.xz?raw=true exists"}
- {"dt": "2024-12-12T10:22:55.670916", "lvl": "info", "msg": "validate duration: 16.35"}
- {"dt": "2024-12-12T10:22:55.671100", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2024-12-12T10:22:55.671274", "lvl": "info", "msg": "start: 1 tftp-deploy (timeout 00:10:00) [common]"}
- {"dt": "2024-12-12T10:22:55.671386", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 00:10:00) [common]"}
- {"dt": "2024-12-12T10:22:55.671487", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 00:10:00) [common]"}
- {"dt": "2024-12-12T10:22:55.671661", "lvl": "debug", "msg": "Not decompressing ramdisk as can be used compressed."}
- {"dt": "2024-12-12T10:22:55.671766", "lvl": "info", "msg": "downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/images/rootfs/buildroot/buildroot-baseline/20230623.0/riscv/rootfs.cpio.gz?raw=true"}
- {"dt": "2024-12-12T10:22:55.671841", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/ramdisk/rootfs.cpio.gz"}
- {"dt": "2024-12-12T10:22:55.671915", "lvl": "debug", "msg": "total size: 7844224 (7\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.103324", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.148944", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.164097", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.174770", "lvl": "debug", "msg": "progress  15\u202F% (1\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.180422", "lvl": "debug", "msg": "progress  20\u202F% (1\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.200060", "lvl": "debug", "msg": "progress  25\u202F% (1\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.205497", "lvl": "debug", "msg": "progress  30\u202F% (2\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.210595", "lvl": "debug", "msg": "progress  35\u202F% (2\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.216154", "lvl": "debug", "msg": "progress  40\u202F% (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.221611", "lvl": "debug", "msg": "progress  45\u202F% (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.243372", "lvl": "debug", "msg": "progress  50\u202F% (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.250109", "lvl": "debug", "msg": "progress  55\u202F% (4\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.255657", "lvl": "debug", "msg": "progress  60\u202F% (4\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.261296", "lvl": "debug", "msg": "progress  65\u202F% (4\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.266899", "lvl": "debug", "msg": "progress  70\u202F% (5\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.287054", "lvl": "debug", "msg": "progress  75\u202F% (5\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.294238", "lvl": "debug", "msg": "progress  80\u202F% (6\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.304314", "lvl": "debug", "msg": "progress  85\u202F% (6\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.309839", "lvl": "debug", "msg": "progress  90\u202F% (6\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.315475", "lvl": "debug", "msg": "progress  95\u202F% (7\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.320914", "lvl": "debug", "msg": "progress 100\u202F% (7\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.321118", "lvl": "info", "msg": "7\u202FMB downloaded in 0.65\u202Fs (11.52\u202FMB/s)"}
- {"dt": "2024-12-12T10:22:56.321303", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2024-12-12T10:22:56.321387", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.65", "extra": {"label": "ramdisk", "md5sum": "4bbb32813cb05021df34cefcbb385507", "sha256sum": "5a9577755f4c03de73672a1f7d73d1fefcc1af9c766e4815d716d23495f74ed8", "sha512sum": "b435cc3fbbdc57e455d0c13d9dcec3969dcf4e26cee57fa102df8b82e1a4e9b739f026cc19905db282fd50a3187a6e143709e111a847d8c8ff9d38fba0434aa8", "size": ! "7844224"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:56.321569", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:01) [common]"}
- {"dt": "2024-12-12T10:22:56.321659", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 00:09:59) [common]"}
- {"dt": "2024-12-12T10:22:56.321746", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 00:09:59) [common]"}
- {"dt": "2024-12-12T10:22:56.321947", "lvl": "info", "msg": "downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/kernel/Image?raw=true"}
- {"dt": "2024-12-12T10:22:56.322022", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/kernel/Image"}
- {"dt": "2024-12-12T10:22:56.322086", "lvl": "debug", "msg": "total size: 19845120 (18\u202FMB)"}
- {"dt": "2024-12-12T10:22:56.322150", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-12-12T10:22:57.094474", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.109171", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.126151", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.140176", "lvl": "debug", "msg": "progress  15\u202F% (2\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.173362", "lvl": "debug", "msg": "progress  20\u202F% (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.190512", "lvl": "debug", "msg": "progress  25\u202F% (4\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.204599", "lvl": "debug", "msg": "progress  30\u202F% (5\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.234863", "lvl": "debug", "msg": "progress  35\u202F% (6\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.256952", "lvl": "debug", "msg": "progress  40\u202F% (7\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.271209", "lvl": "debug", "msg": "progress  45\u202F% (8\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.303486", "lvl": "debug", "msg": "progress  50\u202F% (9\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.322446", "lvl": "debug", "msg": "progress  55\u202F% (10\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.336591", "lvl": "debug", "msg": "progress  60\u202F% (11\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.350638", "lvl": "debug", "msg": "progress  65\u202F% (12\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.384471", "lvl": "debug", "msg": "progress  70\u202F% (13\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.399059", "lvl": "debug", "msg": "progress  75\u202F% (14\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.434279", "lvl": "debug", "msg": "progress  80\u202F% (15\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.447513", "lvl": "debug", "msg": "progress  85\u202F% (16\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.472540", "lvl": "debug", "msg": "progress  90\u202F% (17\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.486741", "lvl": "debug", "msg": "progress  95\u202F% (18\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.500707", "lvl": "debug", "msg": "progress 100\u202F% (18\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.500976", "lvl": "info", "msg": "18\u202FMB downloaded in 1.18\u202Fs (16.05\u202FMB/s)"}
- {"dt": "2024-12-12T10:22:57.501186", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2024-12-12T10:22:57.501266", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "1.18", "extra": {"label": "kernel", "md5sum": "bc353ea01eab589bb4cd6918b0d126de", "sha256sum": "8a98e42d83b971b3f17b23f2fded633f8d3c97ef956efe6ee5d6edd727f87ee1", "sha512sum": "4cad13e71faae976b6b963587c809e948943cb1a76d6655667aac8f154e7068fccb3b3a1191ff00b29dd63f0e46a7b939ed0c46d4edda16d7e9efa5acf87b65b", "size": ! "19845120"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:57.501472", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:01) [common]"}
- {"dt": "2024-12-12T10:22:57.501592", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 00:09:58) [common]"}
- {"dt": "2024-12-12T10:22:57.501704", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 00:09:58) [common]"}
- {"dt": "2024-12-12T10:22:57.501945", "lvl": "info", "msg": "downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/dtbs/sifive/hifive-unmatched-a00.dtb?raw=true"}
- {"dt": "2024-12-12T10:22:57.502020", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/dtb/hifive-unmatched-a00.dtb"}
- {"dt": "2024-12-12T10:22:57.502101", "lvl": "debug", "msg": "total size: 10707 (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.502183", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-12-12T10:22:57.786149", "lvl": "debug", "msg": "progress 100\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.787020", "lvl": "info", "msg": "0\u202FMB downloaded in 0.28\u202Fs (0.04\u202FMB/s)"}
- {"dt": "2024-12-12T10:22:57.787696", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:57.788037", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.29", "extra": {"label": "dtb", "md5sum": "6e4ede97cac7e574ba154868ae6bd490", "sha256sum": "bfd83286eab97548a6663437655c0c6805a361a06c726c439b8d9655be38d15b", "sha512sum": "429c70a390d17dc993647232bfa0333fdf25e66e87f05676252174f698e925e876ddf6b1e722bfdedaf8fd299f71a19b2c8c383eade9bf4df01262d0773fd702", "size": ! "10707"}, "level": "1.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:57.788803", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:57.789182", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:09:58) [common]"}
- {"dt": "2024-12-12T10:22:57.789544", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:09:58) [common]"}
- {"dt": "2024-12-12T10:22:57.789947", "lvl": "info", "msg": "downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-6.1.y/v6.1.54/riscv/defconfig/gcc-10/modules.tar.xz?raw=true"}
- {"dt": "2024-12-12T10:22:57.790021", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/modules/modules.tar"}
- {"dt": "2024-12-12T10:22:57.790083", "lvl": "debug", "msg": "total size: 3892756 (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:57.790147", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-12-12T10:22:58.155003", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.166097", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.180561", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.195447", "lvl": "debug", "msg": "progress  15\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.207776", "lvl": "debug", "msg": "progress  20\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.223451", "lvl": "debug", "msg": "progress  25\u202F% (0\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.240175", "lvl": "debug", "msg": "progress  30\u202F% (1\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.253667", "lvl": "debug", "msg": "progress  35\u202F% (1\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.267108", "lvl": "debug", "msg": "progress  40\u202F% (1\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.278515", "lvl": "debug", "msg": "progress  45\u202F% (1\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.290675", "lvl": "debug", "msg": "progress  50\u202F% (1\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.304947", "lvl": "debug", "msg": "progress  55\u202F% (2\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.321576", "lvl": "debug", "msg": "progress  60\u202F% (2\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.334496", "lvl": "debug", "msg": "progress  65\u202F% (2\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.347727", "lvl": "debug", "msg": "progress  70\u202F% (2\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.359351", "lvl": "debug", "msg": "progress  75\u202F% (2\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.373154", "lvl": "debug", "msg": "progress  80\u202F% (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.386300", "lvl": "debug", "msg": "progress  85\u202F% (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.401549", "lvl": "debug", "msg": "progress  90\u202F% (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.415014", "lvl": "debug", "msg": "progress  95\u202F% (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.428018", "lvl": "debug", "msg": "progress 100\u202F% (3\u202FMB)"}
- {"dt": "2024-12-12T10:22:58.435357", "lvl": "info", "msg": "3\u202FMB downloaded in 0.65\u202Fs (5.75\u202FMB/s)"}
- {"dt": "2024-12-12T10:22:58.435568", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2024-12-12T10:22:58.435646", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.65", "extra": {"label": "modules", "md5sum": "bd526ab1d1394350f02fce39169fd3ed", "sha256sum": "3adbbae160cc6e797e09f2ec6df9c6c848d48f6451e75131e278b4f8dc96bb3b", "sha512sum": "94ab1014e55f1dc62ed235004bd221efcacdbad3af4ff6cb191ec3007be7588b46db84f73d3a3f0da7d101fa96ae93c4dc51fe8a49d2b43b50fcf42e95b38c7f", "size": ! "3892756"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:58.435819", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:01) [common]"}
- {"dt": "2024-12-12T10:22:58.435908", "lvl": "debug", "msg": "start: 1.5 prepare-tftp-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.435995", "lvl": "debug", "msg": "start: 1.5.1 extract-nfsrootfs (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.436076", "lvl": "debug", "msg": "end: 1.5.1 extract-nfsrootfs (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.436157", "lvl": "debug", "msg": "start: 1.5.2 lava-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.436399", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr"}
- {"dt": "2024-12-12T10:22:58.436571", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin"}
- {"dt": "2024-12-12T10:22:58.436690", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/tests"}
- {"dt": "2024-12-12T10:22:58.436832", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/results"}
- {"dt": "2024-12-12T10:22:58.436946", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-add-keys"}
- {"dt": "2024-12-12T10:22:58.437125", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-add-sources"}
- {"dt": "2024-12-12T10:22:58.437290", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-background-process-start"}
- {"dt": "2024-12-12T10:22:58.437452", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-background-process-stop"}
- {"dt": "2024-12-12T10:22:58.437628", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-common-functions"}
- {"dt": "2024-12-12T10:22:58.437785", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-echo-ipv4"}
- {"dt": "2024-12-12T10:22:58.437943", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-install-packages"}
- {"dt": "2024-12-12T10:22:58.438094", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-installed-packages"}
- {"dt": "2024-12-12T10:22:58.438244", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-os-build"}
- {"dt": "2024-12-12T10:22:58.438397", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-probe-channel"}
- {"dt": "2024-12-12T10:22:58.438547", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-probe-ip"}
- {"dt": "2024-12-12T10:22:58.438697", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-target-ip"}
- {"dt": "2024-12-12T10:22:58.438843", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-target-mac"}
- {"dt": "2024-12-12T10:22:58.438990", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-target-storage"}
- {"dt": "2024-12-12T10:22:58.439142", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-test-case"}
- {"dt": "2024-12-12T10:22:58.439290", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-test-event"}
- {"dt": "2024-12-12T10:22:58.439434", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-test-feedback"}
- {"dt": "2024-12-12T10:22:58.439581", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-test-raise"}
- {"dt": "2024-12-12T10:22:58.439727", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-test-reference"}
- {"dt": "2024-12-12T10:22:58.439872", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-test-runner"}
- {"dt": "2024-12-12T10:22:58.440017", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-test-set"}
- {"dt": "2024-12-12T10:22:58.440161", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-test-shell"}
- {"dt": "2024-12-12T10:22:58.440308", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-install-packages (oe)"}
- {"dt": "2024-12-12T10:22:58.440499", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/bin/lava-installed-packages (oe)"}
- {"dt": "2024-12-12T10:22:58.440646", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/environment"}
- {"dt": "2024-12-12T10:22:58.440786", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2024-12-12T10:22:58.440874", "lvl": "debug", "msg": "- LAVA_JOB_ID=38322"}
- {"dt": "2024-12-12T10:22:58.440939", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.66.1"}
- {"dt": "2024-12-12T10:22:58.441054", "lvl": "debug", "msg": "start: 1.5.2.1 ssh-authorize (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.441378", "lvl": "debug", "msg": "end: 1.5.2.1 ssh-authorize (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.441477", "lvl": "debug", "msg": "start: 1.5.2.2 lava-vland-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.441542", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2024-12-12T10:22:58.441619", "lvl": "debug", "msg": "end: 1.5.2.2 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.441698", "lvl": "debug", "msg": "start: 1.5.2.3 lava-multinode-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.441759", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2024-12-12T10:22:58.441830", "lvl": "debug", "msg": "end: 1.5.2.3 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.441907", "lvl": "debug", "msg": "start: 1.5.2.4 test-definition (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.441979", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2024-12-12T10:22:58.442065", "lvl": "debug", "msg": "start: 1.5.2.4.1 inline-repo-action (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.442132", "lvl": "debug", "msg": "Using /lava-38322 at stage 0"}
- {"dt": "2024-12-12T10:22:58.442527", "lvl": "debug", "msg": "uuid=38322_1.5.2.4.1 testdef=None"}
- {"dt": "2024-12-12T10:22:58.442621", "lvl": "debug", "msg": "end: 1.5.2.4.1 inline-repo-action (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.442721", "lvl": "debug", "msg": "start: 1.5.2.4.2 test-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.443355", "lvl": "debug", "msg": "end: 1.5.2.4.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.443432", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "inline", "name": "dmesg", "path": "inline/dmesg.yaml", "uuid": "38322_1.5.2.4.1"}, "level": "1.5.2.4.2", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:58.443629", "lvl": "debug", "msg": "start: 1.5.2.4.3 test-install-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.444516", "lvl": "debug", "msg": "end: 1.5.2.4.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.444618", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "inline", "name": "dmesg", "path": "inline/dmesg.yaml", "skipped test-install-overlay": "38322_1.5.2.4.1", "uuid": "38322_1.5.2.4.1"}, "level": "1.5.2.4.3", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:58.444843", "lvl": "debug", "msg": "start: 1.5.2.4.4 test-runscript-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.445750", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/0/tests/0_dmesg test_uuid 38322_1.5.2.4.1"}
- {"dt": "2024-12-12T10:22:58.445988", "lvl": "debug", "msg": "end: 1.5.2.4.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.446089", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.00", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/0/tests/0_dmesg/run.sh", "from": "inline", "name": "dmesg", "path": "inline/dmesg.yaml", "uuid": "38322_1.5.2.4.1"}, "level": "1.5.2.4.4", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:58.446298", "lvl": "debug", "msg": "start: 1.5.2.4.5 inline-repo-action (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.446384", "lvl": "debug", "msg": "Using /lava-38322 at stage 1"}
- {"dt": "2024-12-12T10:22:58.446855", "lvl": "debug", "msg": "uuid=38322_1.5.2.4.5 testdef=None"}
- {"dt": "2024-12-12T10:22:58.446974", "lvl": "debug", "msg": "end: 1.5.2.4.5 inline-repo-action (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.447077", "lvl": "debug", "msg": "start: 1.5.2.4.6 test-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.447775", "lvl": "debug", "msg": "end: 1.5.2.4.6 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.447869", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "inline", "name": "bootrr", "path": "inline/bootrr.yaml", "uuid": "38322_1.5.2.4.5"}, "level": "1.5.2.4.6", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:58.448062", "lvl": "debug", "msg": "start: 1.5.2.4.7 test-install-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.448998", "lvl": "debug", "msg": "end: 1.5.2.4.7 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.449101", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "inline", "name": "bootrr", "path": "inline/bootrr.yaml", "skipped test-install-overlay": "38322_1.5.2.4.5", "uuid": "38322_1.5.2.4.5"}, "level": "1.5.2.4.7", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:58.449308", "lvl": "debug", "msg": "start: 1.5.2.4.8 test-runscript-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.450198", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/1/tests/1_bootrr test_uuid 38322_1.5.2.4.5"}
- {"dt": "2024-12-12T10:22:58.450433", "lvl": "debug", "msg": "end: 1.5.2.4.8 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.450531", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.00", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/1/tests/1_bootrr/run.sh", "from": "inline", "name": "bootrr", "path": "inline/bootrr.yaml", "uuid": "38322_1.5.2.4.5"}, "level": "1.5.2.4.8", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:22:58.450712", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2024-12-12T10:22:58.450790", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/0 for stage 0"}
- {"dt": "2024-12-12T10:22:58.450918", "lvl": "debug", "msg": "- 0_dmesg"}
- {"dt": "2024-12-12T10:22:58.451032", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/38322/lava-overlay-kscfv7nr/lava-38322/1 for stage 1"}
- {"dt": "2024-12-12T10:22:58.451162", "lvl": "debug", "msg": "- 1_bootrr"}
- {"dt": "2024-12-12T10:22:58.451294", "lvl": "debug", "msg": "end: 1.5.2.4 test-definition (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.451402", "lvl": "debug", "msg": "start: 1.5.2.5 compress-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.461744", "lvl": "debug", "msg": "end: 1.5.2.5 compress-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.461894", "lvl": "debug", "msg": "start: 1.5.2.6 persistent-nfs-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.461993", "lvl": "debug", "msg": "end: 1.5.2.6 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.462091", "lvl": "debug", "msg": "end: 1.5.2 lava-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.462185", "lvl": "debug", "msg": "start: 1.5.3 extract-overlay-ramdisk (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.720532", "lvl": "debug", "msg": "end: 1.5.3 extract-overlay-ramdisk (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.720731", "lvl": "debug", "msg": "start: 1.5.4 extract-modules (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.720866", "lvl": "info", "msg": "extracting modules file /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/modules/modules.tar to /var/lib/lava/dispatcher/tmp/38322/extract-overlay-ramdisk-d3rcnuj5/ramdisk"}
- {"dt": "2024-12-12T10:22:58.776539", "lvl": "debug", "msg": "end: 1.5.4 extract-modules (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.776727", "lvl": "debug", "msg": "start: 1.5.5 apply-overlay-tftp (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.776865", "lvl": "info", "msg": "[common] Applying overlay /var/lib/lava/dispatcher/tmp/38322/compress-overlay-b51u8nlm/overlay-1.5.2.5.tar.gz to ramdisk"}
- {"dt": "2024-12-12T10:22:58.776942", "lvl": "debug", "msg": "[common] Applying overlay /var/lib/lava/dispatcher/tmp/38322/compress-overlay-b51u8nlm/overlay-1.5.2.5.tar.gz to directory /var/lib/lava/dispatcher/tmp/38322/extract-overlay-ramdisk-d3rcnuj5/ramdisk"}
- {"dt": "2024-12-12T10:22:58.788426", "lvl": "debug", "msg": "end: 1.5.5 apply-overlay-tftp (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.788565", "lvl": "debug", "msg": "start: 1.5.6 prepare-kernel (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.788668", "lvl": "debug", "msg": "start: 1.5.6.1 uboot-prepare-kernel (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.788869", "lvl": "debug", "msg": "end: 1.5.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.788965", "lvl": "debug", "msg": "end: 1.5.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.789058", "lvl": "debug", "msg": "start: 1.5.7 configure-preseed-file (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.789154", "lvl": "debug", "msg": "end: 1.5.7 configure-preseed-file (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:22:58.789244", "lvl": "debug", "msg": "start: 1.5.8 compress-ramdisk (timeout 00:09:57) [common]"}
- {"dt": "2024-12-12T10:22:58.789333", "lvl": "info", "msg": "Building ramdisk /var/lib/lava/dispatcher/tmp/38322/extract-overlay-ramdisk-d3rcnuj5/ramdisk.cpio containing /var/lib/lava/dispatcher/tmp/38322/extract-overlay-ramdisk-d3rcnuj5/ramdisk"}
- {"dt": "2024-12-12T10:22:59.086464", "lvl": "debug", "msg": ">> 86851 blocks\n"}
- {"dt": "2024-12-12T10:23:00.958719", "lvl": "debug", "msg": "Adding RAMdisk u-boot header."}
- {"dt": "2024-12-12T10:23:00.958899", "lvl": "debug", "msg": "mkimage -A riscv -T ramdisk -C none -d /var/lib/lava/dispatcher/tmp/38322/extract-overlay-ramdisk-d3rcnuj5/ramdisk.cpio.gz /var/lib/lava/dispatcher/tmp/38322/extract-overlay-ramdisk-d3rcnuj5/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-12T10:23:01.067070", "lvl": "debug", "msg": "output: Image Name:   "}
- {"dt": "2024-12-12T10:23:01.067242", "lvl": "debug", "msg": "output: Created:      Thu Dec 12 10:23:00 2024"}
- {"dt": "2024-12-12T10:23:01.067313", "lvl": "debug", "msg": "output: Image Type:   RISC-V Linux RAMDisk Image (uncompressed)"}
- {"dt": "2024-12-12T10:23:01.067375", "lvl": "debug", "msg": "output: Data Size:    13631417 Bytes = 13311.93 KiB = 13.00 MiB"}
- {"dt": "2024-12-12T10:23:01.067440", "lvl": "debug", "msg": "output: Load Address: 00000000"}
- {"dt": "2024-12-12T10:23:01.067496", "lvl": "debug", "msg": "output: Entry Point:  00000000"}
- {"dt": "2024-12-12T10:23:01.067551", "lvl": "debug", "msg": "output: "}
- {"dt": "2024-12-12T10:23:01.067689", "lvl": "debug", "msg": "rename /var/lib/lava/dispatcher/tmp/38322/extract-overlay-ramdisk-d3rcnuj5/ramdisk.cpio.gz.uboot to /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-12T10:23:01.067816", "lvl": "debug", "msg": "end: 1.5.8 compress-ramdisk (duration 00:00:02) [common]"}
- {"dt": "2024-12-12T10:23:01.067906", "lvl": "debug", "msg": "end: 1.5 prepare-tftp-overlay (duration 00:00:03) [common]"}
- {"dt": "2024-12-12T10:23:01.067991", "lvl": "debug", "msg": "start: 1.6 lxc-create-udev-rule-action (timeout 00:09:55) [common]"}
- {"dt": "2024-12-12T10:23:01.068063", "lvl": "debug", "msg": "No LXC device requested"}
- {"dt": "2024-12-12T10:23:01.068138", "lvl": "debug", "msg": "end: 1.6 lxc-create-udev-rule-action (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:23:01.068215", "lvl": "debug", "msg": "start: 1.7 deploy-device-env (timeout 00:09:55) [common]"}
- {"dt": "2024-12-12T10:23:01.068288", "lvl": "debug", "msg": "end: 1.7 deploy-device-env (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:23:01.068347", "lvl": "debug", "msg": "Checking files for TFTP limit of 4294967296 bytes."}
- {"dt": "2024-12-12T10:23:01.068862", "lvl": "info", "msg": "end: 1 tftp-deploy (duration 00:00:05) [common]"}
- {"dt": "2024-12-12T10:23:01.068960", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:05:00) [common]"}
- {"dt": "2024-12-12T10:23:01.069043", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:05:00) [common]"}
- {"dt": "2024-12-12T10:23:01.069117", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:23:01.069192", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-12-12T10:23:01.069318", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2024-12-12T10:23:01.069384", "lvl": "debug", "msg": "- {BOOTX}: booti 0x80200000 0x83500000 0x83000000"}
- {"dt": "2024-12-12T10:23:01.069445", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x83000000"}
- {"dt": "2024-12-12T10:23:01.069504", "lvl": "debug", "msg": "- {DTB}: 38322/tftp-deploy-96ookhif/dtb/hifive-unmatched-a00.dtb"}
- {"dt": "2024-12-12T10:23:01.069560", "lvl": "debug", "msg": "- {INITRD}: 38322/tftp-deploy-96ookhif/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-12T10:23:01.069617", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x80200000"}
- {"dt": "2024-12-12T10:23:01.069673", "lvl": "debug", "msg": "- {KERNEL}: 38322/tftp-deploy-96ookhif/kernel/Image"}
- {"dt": "2024-12-12T10:23:01.069728", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2024-12-12T10:23:01.069794", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2024-12-12T10:23:01.069852", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2024-12-12T10:23:01.069907", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x83500000"}
- {"dt": "2024-12-12T10:23:01.069963", "lvl": "debug", "msg": "- {RAMDISK}: 38322/tftp-deploy-96ookhif/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-12T10:23:01.070019", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2024-12-12T10:23:01.070075", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2024-12-12T10:23:01.070132", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2024-12-12T10:23:01.070190", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2024-12-12T10:23:01.070246", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2024-12-12T10:23:01.070302", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2024-12-12T10:23:01.070355", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2024-12-12T10:23:01.070410", "lvl": "info", "msg": "- setenv initrd_high 0xffffffffffffffff"}
- {"dt": "2024-12-12T10:23:01.070466", "lvl": "info", "msg": "- setenv fdt_high 0xffffffffffffffff"}
- {"dt": "2024-12-12T10:23:01.070521", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2024-12-12T10:23:01.070575", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2024-12-12T10:23:01.070630", "lvl": "info", "msg": "- tftp 0x80200000 38322/tftp-deploy-96ookhif/kernel/Image"}
- {"dt": "2024-12-12T10:23:01.070685", "lvl": "info", "msg": "- tftp 0x83500000 38322/tftp-deploy-96ookhif/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-12T10:23:01.070740", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2024-12-12T10:23:01.070795", "lvl": "info", "msg": "- tftp 0x83000000 38322/tftp-deploy-96ookhif/dtb/hifive-unmatched-a00.dtb"}
- {"dt": "2024-12-12T10:23:01.070851", "lvl": "info", "msg": "- setenv bootargs '115200 root=/dev/ram0 console_msg_format=syslog earlycon deferred_probe_timeout=60 ip=dhcp'"}
- {"dt": "2024-12-12T10:23:01.070906", "lvl": "info", "msg": "- booti 0x80200000 0x83500000 0x83000000"}
- {"dt": "2024-12-12T10:23:01.070978", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:23:01.071041", "lvl": "results", "msg": {"case": "bootloader-overlay", "definition": "lava", "duration": "0.00", "extra": {"dtb_addr": "0x83000000", "kernel_addr": "0x80200000", "ramdisk_addr": "0x83500000", "tee_addr": "0x83000000"}, "level": "2.2", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:23:01.071195", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:05:00) [common]"}
- {"dt": "2024-12-12T10:23:01.071257", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63006'"}
- {"dt": "2024-12-12T10:23:01.074610", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2024-12-12T10:23:01.074985", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:00) [common]"}
- {"dt": "2024-12-12T10:23:01.075117", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:05:00) [common]"}
- {"dt": "2024-12-12T10:23:01.075214", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:05:00) [common]"}
- {"dt": "2024-12-12T10:23:01.075302", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:05:00) [common]"}
- {"dt": "2024-12-12T10:23:01.075519", "lvl": "debug", "msg": "Calling: 'upower.sh' '--atx' 'reset' '1'"}
- {"dt": "2024-12-12T10:23:02.105324", "lvl": "debug", "msg": ">> No GEMBIRD SiS-PM found. Check USB connections, please!\r"}
- {"dt": "2024-12-12T10:23:06.141197", "lvl": "debug", "msg": ">> No GEMBIRD SiS-PM found. Check USB connections, please!\r"}
- {"dt": "2024-12-12T10:23:08.184924", "lvl": "debug", "msg": ">> FTDI RELAY: power on\r"}
- {"dt": "2024-12-12T10:23:10.185433", "lvl": "debug", "msg": ">> FTDI RELAY: power off\r"}
- {"dt": "2024-12-12T10:23:10.213096", "lvl": "debug", "msg": "Returned 0 in 9 seconds"}
- {"dt": "2024-12-12T10:23:10.314371", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:09) [common]"}
- {"dt": "2024-12-12T10:23:10.314984", "lvl": "results", "msg": {"case": "pdu-reboot", "definition": "lava", "duration": "9.24", "extra": {"status": "success"}, "level": "2.4.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:23:10.315672", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:09) [common]"}
- {"dt": "2024-12-12T10:23:10.316074", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:04:51) [common]"}
- {"dt": "2024-12-12T10:23:10.316426", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2024-12-12T10:23:10.316721", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:05:00)"}
- {"dt": "2024-12-12T10:23:10.317688", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2024-12-12T10:23:10.317986", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2024-12-12T10:23:10.318238", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2024-12-12T10:28:01.316585", "lvl": "exception", "msg": "bootloader-interrupt timed out after 291 seconds"}
- {"dt": "2024-12-12T10:28:01.317245", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:04:51) [common]"}
- {"dt": "2024-12-12T10:28:01.317600", "lvl": "results", "msg": {"case": "bootloader-interrupt", "definition": "lava", "duration": "291.00", "extra": {"fail": "bootloader-interrupt timed out after 291 seconds"}, "level": "2.4.2", "namespace": "common", "result": "fail"}}
- {"dt": "2024-12-12T10:28:01.318217", "lvl": "exception", "msg": "bootloader-interrupt timed out after 291 seconds"}
- {"dt": "2024-12-12T10:28:01.318552", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:05:00) [common]"}
- {"dt": "2024-12-12T10:28:01.318918", "lvl": "results", "msg": {"case": "uboot-commands", "definition": "lava", "duration": "300.24", "extra": {"fail": "bootloader-interrupt timed out after 291 seconds"}, "level": "2.4", "namespace": "common", "result": "fail"}}
- {"dt": "2024-12-12T10:28:01.319444", "lvl": "error", "msg": "uboot-action failed: 1 of 1 attempts. 'bootloader-interrupt timed out after 291 seconds'"}
- {"dt": "2024-12-12T10:28:01.319855", "lvl": "exception", "msg": "bootloader-interrupt timed out after 291 seconds"}
- {"dt": "2024-12-12T10:28:01.320155", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:05:00) [common]"}
- {"dt": "2024-12-12T10:28:01.320475", "lvl": "results", "msg": {"case": "uboot-action", "definition": "lava", "duration": "300.25", "extra": {"fail": "bootloader-interrupt timed out after 291 seconds"}, "level": "2", "namespace": "common", "result": "fail"}}
- {"dt": "2024-12-12T10:28:01.321021", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-12-12T10:28:01.321161", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/ramdisk"}
- {"dt": "2024-12-12T10:28:01.322942", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/kernel"}
- {"dt": "2024-12-12T10:28:01.325159", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/dtb"}
- {"dt": "2024-12-12T10:28:01.325362", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38322/tftp-deploy-96ookhif/modules"}
- {"dt": "2024-12-12T10:28:01.327845", "lvl": "debug", "msg": "start: 5.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2024-12-12T10:28:01.328016", "lvl": "debug", "msg": "Calling: 'upower.sh' '--atx' 'off' '1'"}
- {"dt": "2024-12-12T10:28:02.357297", "lvl": "debug", "msg": ">> No GEMBIRD SiS-PM found. Check USB connections, please!\r"}
- {"dt": "2024-12-12T10:28:02.358990", "lvl": "debug", "msg": "Returned 0 in 1 seconds"}
- {"dt": "2024-12-12T10:28:02.459807", "lvl": "debug", "msg": "end: 5.1 power-off (duration 00:00:01) [common]"}
- {"dt": "2024-12-12T10:28:02.460381", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "1.13", "extra": {"status": "success"}, "level": "5.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-12T10:28:02.461162", "lvl": "debug", "msg": "start: 5.2 read-feedback (timeout 00:09:59) [common]"}
- {"dt": "2024-12-12T10:28:02.462113", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2024-12-12T10:28:03.463078", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2024-12-12T10:28:03.463723", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2024-12-12T10:28:03.564817", "lvl": "debug", "msg": "end: 5.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2024-12-12T10:28:03.565400", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/38322"}
- {"dt": "2024-12-12T10:28:03.592154", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/38322"}
- {"dt": "2024-12-12T10:28:03.592393", "lvl": "error", "msg": "InfrastructureError: The Infrastructure is not working correctly. Please report this error to LAVA admins."}
- {"dt": "2024-12-12T10:28:03.592479", "lvl": "results", "msg": {"case": "job", "definition": "lava", "error_msg": "bootloader-interrupt timed out after 291 seconds", "error_type": "Infrastructure", "result": "fail"}}
