- {"dt": "2024-12-06T09:53:19.462021", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.10"}
- {"dt": "2024-12-06T09:53:19.462311", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-12-06T09:53:19.462463", "lvl": "info", "msg": "Start time: 2024-12-06 09:53:19.462453+00:00 (UTC)"}
- {"dt": "2024-12-06T09:53:19.462649", "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-06T09:53:20.772569", "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-06T09:53:22.714258", "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-06T09:53:23.426171", "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-06T09:53:24.642656", "lvl": "info", "msg": "validate duration: 5.18"}
- {"dt": "2024-12-06T09:53:24.643325", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2024-12-06T09:53:24.644096", "lvl": "info", "msg": "start: 1 tftp-deploy (timeout 00:10:00) [common]"}
- {"dt": "2024-12-06T09:53:24.644641", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 00:10:00) [common]"}
- {"dt": "2024-12-06T09:53:24.645177", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 00:10:00) [common]"}
- {"dt": "2024-12-06T09:53:24.645894", "lvl": "debug", "msg": "Not decompressing ramdisk as can be used compressed."}
- {"dt": "2024-12-06T09:53:24.646409", "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-06T09:53:24.646745", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/ramdisk/rootfs.cpio.gz"}
- {"dt": "2024-12-06T09:53:24.647058", "lvl": "debug", "msg": "total size: 7844224 (7\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.063155", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.108679", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.123363", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.132538", "lvl": "debug", "msg": "progress  15\u202F% (1\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.142162", "lvl": "debug", "msg": "progress  20\u202F% (1\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.153604", "lvl": "debug", "msg": "progress  25\u202F% (1\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.159239", "lvl": "debug", "msg": "progress  30\u202F% (2\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.164993", "lvl": "debug", "msg": "progress  35\u202F% (2\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.170665", "lvl": "debug", "msg": "progress  40\u202F% (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.176441", "lvl": "debug", "msg": "progress  45\u202F% (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.197763", "lvl": "debug", "msg": "progress  50\u202F% (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.205085", "lvl": "debug", "msg": "progress  55\u202F% (4\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.212382", "lvl": "debug", "msg": "progress  60\u202F% (4\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.218079", "lvl": "debug", "msg": "progress  65\u202F% (4\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.223762", "lvl": "debug", "msg": "progress  70\u202F% (5\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.229335", "lvl": "debug", "msg": "progress  75\u202F% (5\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.235032", "lvl": "debug", "msg": "progress  80\u202F% (6\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.256563", "lvl": "debug", "msg": "progress  85\u202F% (6\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.262682", "lvl": "debug", "msg": "progress  90\u202F% (6\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.270251", "lvl": "debug", "msg": "progress  95\u202F% (7\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.281563", "lvl": "debug", "msg": "progress 100\u202F% (7\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.281966", "lvl": "info", "msg": "7\u202FMB downloaded in 0.63\u202Fs (11.78\u202FMB/s)"}
- {"dt": "2024-12-06T09:53:25.282246", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2024-12-06T09:53:25.282360", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.64", "extra": {"label": "ramdisk", "md5sum": "4bbb32813cb05021df34cefcbb385507", "sha256sum": "5a9577755f4c03de73672a1f7d73d1fefcc1af9c766e4815d716d23495f74ed8", "sha512sum": "b435cc3fbbdc57e455d0c13d9dcec3969dcf4e26cee57fa102df8b82e1a4e9b739f026cc19905db282fd50a3187a6e143709e111a847d8c8ff9d38fba0434aa8", "size": ! "7844224"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:25.282606", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:01) [common]"}
- {"dt": "2024-12-06T09:53:25.282729", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 00:09:59) [common]"}
- {"dt": "2024-12-06T09:53:25.282835", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 00:09:59) [common]"}
- {"dt": "2024-12-06T09:53:25.283058", "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-06T09:53:25.283154", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/kernel/Image"}
- {"dt": "2024-12-06T09:53:25.283236", "lvl": "debug", "msg": "total size: 19845120 (18\u202FMB)"}
- {"dt": "2024-12-06T09:53:25.283319", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-12-06T09:53:26.396186", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.416135", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.432423", "lvl": "debug", "msg": "progress  10\u202F% (1\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.469587", "lvl": "debug", "msg": "progress  15\u202F% (2\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.485561", "lvl": "debug", "msg": "progress  20\u202F% (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.501611", "lvl": "debug", "msg": "progress  25\u202F% (4\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.544232", "lvl": "debug", "msg": "progress  30\u202F% (5\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.571687", "lvl": "debug", "msg": "progress  35\u202F% (6\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.590509", "lvl": "debug", "msg": "progress  40\u202F% (7\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.606765", "lvl": "debug", "msg": "progress  45\u202F% (8\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.644047", "lvl": "debug", "msg": "progress  50\u202F% (9\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.674498", "lvl": "debug", "msg": "progress  55\u202F% (10\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.693836", "lvl": "debug", "msg": "progress  60\u202F% (11\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.711000", "lvl": "debug", "msg": "progress  65\u202F% (12\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.754051", "lvl": "debug", "msg": "progress  70\u202F% (13\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.781520", "lvl": "debug", "msg": "progress  75\u202F% (14\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.802685", "lvl": "debug", "msg": "progress  80\u202F% (15\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.819069", "lvl": "debug", "msg": "progress  85\u202F% (16\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.835932", "lvl": "debug", "msg": "progress  90\u202F% (17\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.878529", "lvl": "debug", "msg": "progress  95\u202F% (18\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.899284", "lvl": "debug", "msg": "progress 100\u202F% (18\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.899610", "lvl": "info", "msg": "18\u202FMB downloaded in 1.62\u202Fs (11.71\u202FMB/s)"}
- {"dt": "2024-12-06T09:53:26.899834", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2024-12-06T09:53:26.899947", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "1.62", "extra": {"label": "kernel", "md5sum": "bc353ea01eab589bb4cd6918b0d126de", "sha256sum": "8a98e42d83b971b3f17b23f2fded633f8d3c97ef956efe6ee5d6edd727f87ee1", "sha512sum": "4cad13e71faae976b6b963587c809e948943cb1a76d6655667aac8f154e7068fccb3b3a1191ff00b29dd63f0e46a7b939ed0c46d4edda16d7e9efa5acf87b65b", "size": ! "19845120"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:26.900366", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:02) [common]"}
- {"dt": "2024-12-06T09:53:26.900491", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 00:09:58) [common]"}
- {"dt": "2024-12-06T09:53:26.900607", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 00:09:58) [common]"}
- {"dt": "2024-12-06T09:53:26.900859", "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-06T09:53:26.900963", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/dtb/hifive-unmatched-a00.dtb"}
- {"dt": "2024-12-06T09:53:26.901046", "lvl": "debug", "msg": "total size: 10707 (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:26.901129", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-12-06T09:53:27.112555", "lvl": "debug", "msg": "progress 100\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.112856", "lvl": "info", "msg": "0\u202FMB downloaded in 0.21\u202Fs (0.05\u202FMB/s)"}
- {"dt": "2024-12-06T09:53:27.113090", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.113203", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.21", "extra": {"label": "dtb", "md5sum": "6e4ede97cac7e574ba154868ae6bd490", "sha256sum": "bfd83286eab97548a6663437655c0c6805a361a06c726c439b8d9655be38d15b", "sha512sum": "429c70a390d17dc993647232bfa0333fdf25e66e87f05676252174f698e925e876ddf6b1e722bfdedaf8fd299f71a19b2c8c383eade9bf4df01262d0773fd702", "size": ! "10707"}, "level": "1.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:27.113441", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.113581", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:09:58) [common]"}
- {"dt": "2024-12-06T09:53:27.113710", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:09:58) [common]"}
- {"dt": "2024-12-06T09:53:27.113952", "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-06T09:53:27.114057", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/modules/modules.tar"}
- {"dt": "2024-12-06T09:53:27.114148", "lvl": "debug", "msg": "total size: 3892756 (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.114240", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-12-06T09:53:27.342416", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.350635", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.367348", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.384575", "lvl": "debug", "msg": "progress  15\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.399526", "lvl": "debug", "msg": "progress  20\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.416602", "lvl": "debug", "msg": "progress  25\u202F% (0\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.436744", "lvl": "debug", "msg": "progress  30\u202F% (1\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.453176", "lvl": "debug", "msg": "progress  35\u202F% (1\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.469324", "lvl": "debug", "msg": "progress  40\u202F% (1\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.485396", "lvl": "debug", "msg": "progress  45\u202F% (1\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.503252", "lvl": "debug", "msg": "progress  50\u202F% (1\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.520985", "lvl": "debug", "msg": "progress  55\u202F% (2\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.542814", "lvl": "debug", "msg": "progress  60\u202F% (2\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.559359", "lvl": "debug", "msg": "progress  65\u202F% (2\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.576456", "lvl": "debug", "msg": "progress  70\u202F% (2\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.590728", "lvl": "debug", "msg": "progress  75\u202F% (2\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.608411", "lvl": "debug", "msg": "progress  80\u202F% (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.625396", "lvl": "debug", "msg": "progress  85\u202F% (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.645182", "lvl": "debug", "msg": "progress  90\u202F% (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.662727", "lvl": "debug", "msg": "progress  95\u202F% (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.680450", "lvl": "debug", "msg": "progress 100\u202F% (3\u202FMB)"}
- {"dt": "2024-12-06T09:53:27.690201", "lvl": "info", "msg": "3\u202FMB downloaded in 0.58\u202Fs (6.44\u202FMB/s)"}
- {"dt": "2024-12-06T09:53:27.690828", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2024-12-06T09:53:27.691106", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.58", "extra": {"label": "modules", "md5sum": "bd526ab1d1394350f02fce39169fd3ed", "sha256sum": "3adbbae160cc6e797e09f2ec6df9c6c848d48f6451e75131e278b4f8dc96bb3b", "sha512sum": "94ab1014e55f1dc62ed235004bd221efcacdbad3af4ff6cb191ec3007be7588b46db84f73d3a3f0da7d101fa96ae93c4dc51fe8a49d2b43b50fcf42e95b38c7f", "size": ! "3892756"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:27.691778", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:01) [common]"}
- {"dt": "2024-12-06T09:53:27.692089", "lvl": "debug", "msg": "start: 1.5 prepare-tftp-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.692381", "lvl": "debug", "msg": "start: 1.5.1 extract-nfsrootfs (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.692711", "lvl": "debug", "msg": "end: 1.5.1 extract-nfsrootfs (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.693048", "lvl": "debug", "msg": "start: 1.5.2 lava-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.693848", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj"}
- {"dt": "2024-12-06T09:53:27.694321", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin"}
- {"dt": "2024-12-06T09:53:27.694705", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/tests"}
- {"dt": "2024-12-06T09:53:27.695180", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/results"}
- {"dt": "2024-12-06T09:53:27.695476", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-add-keys"}
- {"dt": "2024-12-06T09:53:27.696043", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-add-sources"}
- {"dt": "2024-12-06T09:53:27.696785", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-background-process-start"}
- {"dt": "2024-12-06T09:53:27.697234", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-background-process-stop"}
- {"dt": "2024-12-06T09:53:27.697902", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-common-functions"}
- {"dt": "2024-12-06T09:53:27.698501", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-echo-ipv4"}
- {"dt": "2024-12-06T09:53:27.699131", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-install-packages"}
- {"dt": "2024-12-06T09:53:27.699525", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-installed-packages"}
- {"dt": "2024-12-06T09:53:27.700391", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-os-build"}
- {"dt": "2024-12-06T09:53:27.700615", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-probe-channel"}
- {"dt": "2024-12-06T09:53:27.700850", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-probe-ip"}
- {"dt": "2024-12-06T09:53:27.701063", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-target-ip"}
- {"dt": "2024-12-06T09:53:27.701269", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-target-mac"}
- {"dt": "2024-12-06T09:53:27.701476", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-target-storage"}
- {"dt": "2024-12-06T09:53:27.701697", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-case"}
- {"dt": "2024-12-06T09:53:27.701902", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-event"}
- {"dt": "2024-12-06T09:53:27.702103", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-feedback"}
- {"dt": "2024-12-06T09:53:27.702306", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-raise"}
- {"dt": "2024-12-06T09:53:27.702508", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-reference"}
- {"dt": "2024-12-06T09:53:27.702711", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-runner"}
- {"dt": "2024-12-06T09:53:27.702911", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-set"}
- {"dt": "2024-12-06T09:53:27.703110", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-test-shell"}
- {"dt": "2024-12-06T09:53:27.703316", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-install-packages (oe)"}
- {"dt": "2024-12-06T09:53:27.703567", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/bin/lava-installed-packages (oe)"}
- {"dt": "2024-12-06T09:53:27.703765", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/environment"}
- {"dt": "2024-12-06T09:53:27.703930", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2024-12-06T09:53:27.704031", "lvl": "debug", "msg": "- LAVA_JOB_ID=38167"}
- {"dt": "2024-12-06T09:53:27.704119", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.66.1"}
- {"dt": "2024-12-06T09:53:27.704282", "lvl": "debug", "msg": "start: 1.5.2.1 ssh-authorize (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.704708", "lvl": "debug", "msg": "end: 1.5.2.1 ssh-authorize (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.704851", "lvl": "debug", "msg": "start: 1.5.2.2 lava-vland-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.704938", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2024-12-06T09:53:27.705038", "lvl": "debug", "msg": "end: 1.5.2.2 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.705143", "lvl": "debug", "msg": "start: 1.5.2.3 lava-multinode-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.705224", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2024-12-06T09:53:27.705319", "lvl": "debug", "msg": "end: 1.5.2.3 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.705421", "lvl": "debug", "msg": "start: 1.5.2.4 test-definition (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.705517", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2024-12-06T09:53:27.705630", "lvl": "debug", "msg": "start: 1.5.2.4.1 inline-repo-action (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.705719", "lvl": "debug", "msg": "Using /lava-38167 at stage 0"}
- {"dt": "2024-12-06T09:53:27.706264", "lvl": "debug", "msg": "uuid=38167_1.5.2.4.1 testdef=None"}
- {"dt": "2024-12-06T09:53:27.706392", "lvl": "debug", "msg": "end: 1.5.2.4.1 inline-repo-action (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.706502", "lvl": "debug", "msg": "start: 1.5.2.4.2 test-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.707273", "lvl": "debug", "msg": "end: 1.5.2.4.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.707386", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "inline", "name": "dmesg", "path": "inline/dmesg.yaml", "uuid": "38167_1.5.2.4.1"}, "level": "1.5.2.4.2", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:27.707602", "lvl": "debug", "msg": "start: 1.5.2.4.3 test-install-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.708618", "lvl": "debug", "msg": "end: 1.5.2.4.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.708725", "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": "38167_1.5.2.4.1", "uuid": "38167_1.5.2.4.1"}, "level": "1.5.2.4.3", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:27.708963", "lvl": "debug", "msg": "start: 1.5.2.4.4 test-runscript-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.709988", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/0/tests/0_dmesg test_uuid 38167_1.5.2.4.1"}
- {"dt": "2024-12-06T09:53:27.710263", "lvl": "debug", "msg": "end: 1.5.2.4.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.710376", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.00", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/0/tests/0_dmesg/run.sh", "from": "inline", "name": "dmesg", "path": "inline/dmesg.yaml", "uuid": "38167_1.5.2.4.1"}, "level": "1.5.2.4.4", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:27.710596", "lvl": "debug", "msg": "start: 1.5.2.4.5 inline-repo-action (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.710690", "lvl": "debug", "msg": "Using /lava-38167 at stage 1"}
- {"dt": "2024-12-06T09:53:27.711213", "lvl": "debug", "msg": "uuid=38167_1.5.2.4.5 testdef=None"}
- {"dt": "2024-12-06T09:53:27.711349", "lvl": "debug", "msg": "end: 1.5.2.4.5 inline-repo-action (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.711464", "lvl": "debug", "msg": "start: 1.5.2.4.6 test-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.712210", "lvl": "debug", "msg": "end: 1.5.2.4.6 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.712311", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "inline", "name": "bootrr", "path": "inline/bootrr.yaml", "uuid": "38167_1.5.2.4.5"}, "level": "1.5.2.4.6", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:27.712517", "lvl": "debug", "msg": "start: 1.5.2.4.7 test-install-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.713532", "lvl": "debug", "msg": "end: 1.5.2.4.7 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.713634", "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": "38167_1.5.2.4.5", "uuid": "38167_1.5.2.4.5"}, "level": "1.5.2.4.7", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:27.713849", "lvl": "debug", "msg": "start: 1.5.2.4.8 test-runscript-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.714805", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/1/tests/1_bootrr test_uuid 38167_1.5.2.4.5"}
- {"dt": "2024-12-06T09:53:27.715377", "lvl": "debug", "msg": "end: 1.5.2.4.8 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.715815", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.00", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/1/tests/1_bootrr/run.sh", "from": "inline", "name": "bootrr", "path": "inline/bootrr.yaml", "uuid": "38167_1.5.2.4.5"}, "level": "1.5.2.4.8", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:27.716267", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2024-12-06T09:53:27.716361", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/0 for stage 0"}
- {"dt": "2024-12-06T09:53:27.716513", "lvl": "debug", "msg": "- 0_dmesg"}
- {"dt": "2024-12-06T09:53:27.717072", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/38167/lava-overlay-vsvvwbnj/lava-38167/1 for stage 1"}
- {"dt": "2024-12-06T09:53:27.717694", "lvl": "debug", "msg": "- 1_bootrr"}
- {"dt": "2024-12-06T09:53:27.718081", "lvl": "debug", "msg": "end: 1.5.2.4 test-definition (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.718215", "lvl": "debug", "msg": "start: 1.5.2.5 compress-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.738938", "lvl": "debug", "msg": "end: 1.5.2.5 compress-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.739154", "lvl": "debug", "msg": "start: 1.5.2.6 persistent-nfs-overlay (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:27.739549", "lvl": "debug", "msg": "end: 1.5.2.6 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.739698", "lvl": "debug", "msg": "end: 1.5.2 lava-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:27.740055", "lvl": "debug", "msg": "start: 1.5.3 extract-overlay-ramdisk (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:28.066879", "lvl": "debug", "msg": "end: 1.5.3 extract-overlay-ramdisk (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:28.067103", "lvl": "debug", "msg": "start: 1.5.4 extract-modules (timeout 00:09:57) [common]"}
- {"dt": "2024-12-06T09:53:28.067236", "lvl": "info", "msg": "extracting modules file /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/modules/modules.tar to /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk"}
- {"dt": "2024-12-06T09:53:28.188385", "lvl": "debug", "msg": "end: 1.5.4 extract-modules (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:28.188611", "lvl": "debug", "msg": "start: 1.5.5 apply-overlay-tftp (timeout 00:09:56) [common]"}
- {"dt": "2024-12-06T09:53:28.188793", "lvl": "info", "msg": "[common] Applying overlay /var/lib/lava/dispatcher/tmp/38167/compress-overlay-d6oze46s/overlay-1.5.2.5.tar.gz to ramdisk"}
- {"dt": "2024-12-06T09:53:28.188900", "lvl": "debug", "msg": "[common] Applying overlay /var/lib/lava/dispatcher/tmp/38167/compress-overlay-d6oze46s/overlay-1.5.2.5.tar.gz to directory /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk"}
- {"dt": "2024-12-06T09:53:28.204659", "lvl": "debug", "msg": "end: 1.5.5 apply-overlay-tftp (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:28.204958", "lvl": "debug", "msg": "start: 1.5.6 prepare-kernel (timeout 00:09:56) [common]"}
- {"dt": "2024-12-06T09:53:28.205431", "lvl": "debug", "msg": "start: 1.5.6.1 uboot-prepare-kernel (timeout 00:09:56) [common]"}
- {"dt": "2024-12-06T09:53:28.205585", "lvl": "debug", "msg": "end: 1.5.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:28.205707", "lvl": "debug", "msg": "end: 1.5.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:28.205827", "lvl": "debug", "msg": "start: 1.5.7 configure-preseed-file (timeout 00:09:56) [common]"}
- {"dt": "2024-12-06T09:53:28.206281", "lvl": "debug", "msg": "end: 1.5.7 configure-preseed-file (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:28.206424", "lvl": "debug", "msg": "start: 1.5.8 compress-ramdisk (timeout 00:09:56) [common]"}
- {"dt": "2024-12-06T09:53:28.206535", "lvl": "info", "msg": "Building ramdisk /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk.cpio containing /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk"}
- {"dt": "2024-12-06T09:53:28.506143", "lvl": "debug", "msg": ">> 86851 blocks\n"}
- {"dt": "2024-12-06T09:53:30.715259", "lvl": "debug", "msg": "Adding RAMdisk u-boot header."}
- {"dt": "2024-12-06T09:53:30.715453", "lvl": "debug", "msg": "mkimage -A riscv -T ramdisk -C none -d /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk.cpio.gz /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-06T09:53:30.813909", "lvl": "debug", "msg": "output: Image Name:   "}
- {"dt": "2024-12-06T09:53:30.814090", "lvl": "debug", "msg": "output: Created:      Fri Dec  6 09:53:30 2024"}
- {"dt": "2024-12-06T09:53:30.814163", "lvl": "debug", "msg": "output: Image Type:   RISC-V Linux RAMDisk Image (uncompressed)"}
- {"dt": "2024-12-06T09:53:30.814227", "lvl": "debug", "msg": "output: Data Size:    13631840 Bytes = 13312.34 KiB = 13.00 MiB"}
- {"dt": "2024-12-06T09:53:30.814287", "lvl": "debug", "msg": "output: Load Address: 00000000"}
- {"dt": "2024-12-06T09:53:30.814345", "lvl": "debug", "msg": "output: Entry Point:  00000000"}
- {"dt": "2024-12-06T09:53:30.814401", "lvl": "debug", "msg": "output: "}
- {"dt": "2024-12-06T09:53:30.814544", "lvl": "debug", "msg": "rename /var/lib/lava/dispatcher/tmp/38167/extract-overlay-ramdisk-pelnbvv9/ramdisk.cpio.gz.uboot to /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-06T09:53:30.814677", "lvl": "debug", "msg": "end: 1.5.8 compress-ramdisk (duration 00:00:03) [common]"}
- {"dt": "2024-12-06T09:53:30.814770", "lvl": "debug", "msg": "end: 1.5 prepare-tftp-overlay (duration 00:00:03) [common]"}
- {"dt": "2024-12-06T09:53:30.814858", "lvl": "debug", "msg": "start: 1.6 lxc-create-udev-rule-action (timeout 00:09:54) [common]"}
- {"dt": "2024-12-06T09:53:30.814932", "lvl": "debug", "msg": "No LXC device requested"}
- {"dt": "2024-12-06T09:53:30.815019", "lvl": "debug", "msg": "end: 1.6 lxc-create-udev-rule-action (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:30.815114", "lvl": "debug", "msg": "start: 1.7 deploy-device-env (timeout 00:09:54) [common]"}
- {"dt": "2024-12-06T09:53:30.815190", "lvl": "debug", "msg": "end: 1.7 deploy-device-env (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:30.815252", "lvl": "debug", "msg": "Checking files for TFTP limit of 4294967296 bytes."}
- {"dt": "2024-12-06T09:53:30.815762", "lvl": "info", "msg": "end: 1 tftp-deploy (duration 00:00:06) [common]"}
- {"dt": "2024-12-06T09:53:30.815881", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:05:00) [common]"}
- {"dt": "2024-12-06T09:53:30.815966", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:05:00) [common]"}
- {"dt": "2024-12-06T09:53:30.816042", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:30.816119", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:05:00) [common]"}
- {"dt": "2024-12-06T09:53:30.816250", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2024-12-06T09:53:30.816318", "lvl": "debug", "msg": "- {BOOTX}: booti 0x80200000 0x83500000 0x83000000"}
- {"dt": "2024-12-06T09:53:30.816380", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x83000000"}
- {"dt": "2024-12-06T09:53:30.816439", "lvl": "debug", "msg": "- {DTB}: 38167/tftp-deploy-jdlmucrc/dtb/hifive-unmatched-a00.dtb"}
- {"dt": "2024-12-06T09:53:30.816497", "lvl": "debug", "msg": "- {INITRD}: 38167/tftp-deploy-jdlmucrc/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-06T09:53:30.816555", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x80200000"}
- {"dt": "2024-12-06T09:53:30.816613", "lvl": "debug", "msg": "- {KERNEL}: 38167/tftp-deploy-jdlmucrc/kernel/Image"}
- {"dt": "2024-12-06T09:53:30.816669", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2024-12-06T09:53:30.816743", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2024-12-06T09:53:30.816819", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2024-12-06T09:53:30.816879", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x83500000"}
- {"dt": "2024-12-06T09:53:30.816936", "lvl": "debug", "msg": "- {RAMDISK}: 38167/tftp-deploy-jdlmucrc/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-06T09:53:30.816993", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2024-12-06T09:53:30.817051", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2024-12-06T09:53:30.817110", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2024-12-06T09:53:30.817170", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2024-12-06T09:53:30.817227", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2024-12-06T09:53:30.817285", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2024-12-06T09:53:30.817339", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2024-12-06T09:53:30.817397", "lvl": "info", "msg": "- setenv initrd_high 0xffffffffffffffff"}
- {"dt": "2024-12-06T09:53:30.817458", "lvl": "info", "msg": "- setenv fdt_high 0xffffffffffffffff"}
- {"dt": "2024-12-06T09:53:30.817531", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2024-12-06T09:53:30.817604", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2024-12-06T09:53:30.817667", "lvl": "info", "msg": "- tftp 0x80200000 38167/tftp-deploy-jdlmucrc/kernel/Image"}
- {"dt": "2024-12-06T09:53:30.817723", "lvl": "info", "msg": "- tftp 0x83500000 38167/tftp-deploy-jdlmucrc/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2024-12-06T09:53:30.817780", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2024-12-06T09:53:30.817836", "lvl": "info", "msg": "- tftp 0x83000000 38167/tftp-deploy-jdlmucrc/dtb/hifive-unmatched-a00.dtb"}
- {"dt": "2024-12-06T09:53:30.817892", "lvl": "info", "msg": "- setenv bootargs '115200 root=/dev/ram0 console_msg_format=syslog earlycon deferred_probe_timeout=60 ip=dhcp'"}
- {"dt": "2024-12-06T09:53:30.817950", "lvl": "info", "msg": "- booti 0x80200000 0x83500000 0x83000000"}
- {"dt": "2024-12-06T09:53:30.818028", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:30.818093", "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-06T09:53:30.818255", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:05:00) [common]"}
- {"dt": "2024-12-06T09:53:30.818321", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63006'"}
- {"dt": "2024-12-06T09:53:30.821894", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2024-12-06T09:53:30.822342", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:00) [common]"}
- {"dt": "2024-12-06T09:53:30.822505", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:05:00) [common]"}
- {"dt": "2024-12-06T09:53:30.822631", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:05:00) [common]"}
- {"dt": "2024-12-06T09:53:30.822741", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:05:00) [common]"}
- {"dt": "2024-12-06T09:53:30.822960", "lvl": "debug", "msg": "Calling: 'upower.sh' '--atx' 'reset' '1'"}
- {"dt": "2024-12-06T09:53:31.749260", "lvl": "debug", "msg": ">> No GEMBIRD SiS-PM found. Check USB connections, please!\r"}
- {"dt": "2024-12-06T09:53:35.791934", "lvl": "debug", "msg": ">> No GEMBIRD SiS-PM found. Check USB connections, please!\r"}
- {"dt": "2024-12-06T09:53:37.839762", "lvl": "debug", "msg": ">> FTDI RELAY: power on\r"}
- {"dt": "2024-12-06T09:53:39.840295", "lvl": "debug", "msg": ">> FTDI RELAY: power off\r"}
- {"dt": "2024-12-06T09:53:39.858243", "lvl": "debug", "msg": "Returned 0 in 9 seconds"}
- {"dt": "2024-12-06T09:53:39.959160", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:09) [common]"}
- {"dt": "2024-12-06T09:53:39.959720", "lvl": "results", "msg": {"case": "pdu-reboot", "definition": "lava", "duration": "9.14", "extra": {"status": "success"}, "level": "2.4.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:53:39.960405", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:09) [common]"}
- {"dt": "2024-12-06T09:53:39.960840", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:04:51) [common]"}
- {"dt": "2024-12-06T09:53:39.961204", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2024-12-06T09:53:39.961504", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:05:00)"}
- {"dt": "2024-12-06T09:53:39.962466", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2024-12-06T09:53:39.962770", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2024-12-06T09:53:39.963044", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2024-12-06T09:58:30.961383", "lvl": "exception", "msg": "bootloader-interrupt timed out after 291 seconds"}
- {"dt": "2024-12-06T09:58:30.962014", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:04:51) [common]"}
- {"dt": "2024-12-06T09:58:30.962376", "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-06T09:58:30.962995", "lvl": "exception", "msg": "bootloader-interrupt timed out after 291 seconds"}
- {"dt": "2024-12-06T09:58:30.963323", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:05:00) [common]"}
- {"dt": "2024-12-06T09:58:30.963686", "lvl": "results", "msg": {"case": "uboot-commands", "definition": "lava", "duration": "300.14", "extra": {"fail": "bootloader-interrupt timed out after 291 seconds"}, "level": "2.4", "namespace": "common", "result": "fail"}}
- {"dt": "2024-12-06T09:58:30.964209", "lvl": "error", "msg": "uboot-action failed: 1 of 1 attempts. 'bootloader-interrupt timed out after 291 seconds'"}
- {"dt": "2024-12-06T09:58:30.964648", "lvl": "exception", "msg": "bootloader-interrupt timed out after 291 seconds"}
- {"dt": "2024-12-06T09:58:30.965035", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:05:00) [common]"}
- {"dt": "2024-12-06T09:58:30.965377", "lvl": "results", "msg": {"case": "uboot-action", "definition": "lava", "duration": "300.15", "extra": {"fail": "bootloader-interrupt timed out after 291 seconds"}, "level": "2", "namespace": "common", "result": "fail"}}
- {"dt": "2024-12-06T09:58:30.965877", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-12-06T09:58:30.966040", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/ramdisk"}
- {"dt": "2024-12-06T09:58:30.967672", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/kernel"}
- {"dt": "2024-12-06T09:58:30.969693", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/dtb"}
- {"dt": "2024-12-06T09:58:30.969892", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/38167/tftp-deploy-jdlmucrc/modules"}
- {"dt": "2024-12-06T09:58:30.971987", "lvl": "debug", "msg": "start: 5.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2024-12-06T09:58:30.972142", "lvl": "debug", "msg": "Calling: 'upower.sh' '--atx' 'off' '1'"}
- {"dt": "2024-12-06T09:58:32.005296", "lvl": "debug", "msg": ">> No GEMBIRD SiS-PM found. Check USB connections, please!\r"}
- {"dt": "2024-12-06T09:58:32.007194", "lvl": "debug", "msg": "Returned 0 in 1 seconds"}
- {"dt": "2024-12-06T09:58:32.108005", "lvl": "debug", "msg": "end: 5.1 power-off (duration 00:00:01) [common]"}
- {"dt": "2024-12-06T09:58:32.108582", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "1.14", "extra": {"status": "success"}, "level": "5.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-12-06T09:58:32.109341", "lvl": "debug", "msg": "start: 5.2 read-feedback (timeout 00:09:59) [common]"}
- {"dt": "2024-12-06T09:58:32.110305", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2024-12-06T09:58:33.111280", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2024-12-06T09:58:33.111925", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2024-12-06T09:58:33.213030", "lvl": "debug", "msg": "end: 5.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2024-12-06T09:58:33.213609", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/38167"}
- {"dt": "2024-12-06T09:58:33.239174", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/38167"}
- {"dt": "2024-12-06T09:58:33.239414", "lvl": "error", "msg": "InfrastructureError: The Infrastructure is not working correctly. Please report this error to LAVA admins."}
- {"dt": "2024-12-06T09:58:33.239499", "lvl": "results", "msg": {"case": "job", "definition": "lava", "error_msg": "bootloader-interrupt timed out after 291 seconds", "error_type": "Infrastructure", "result": "fail"}}
