- {"dt": "2023-03-02T07:33:14.958484", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.01"}
- {"dt": "2023-03-02T07:33:14.959974", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2023-03-02T07:33:14.960980", "lvl": "info", "msg": "Start time: 2023-03-02 07:33:14.960940+00:00 (UTC)"}
- {"dt": "2023-03-02T07:33:14.962107", "lvl": "debug", "msg": "Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/images/rootfs/buildroot/kci-2019.02-11-g17e793fa4728/arm64/base/rootfs.cpio.gz?raw=true exists"}
- {"dt": "2023-03-02T07:33:16.071293", "lvl": "debug", "msg": "Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/Image?raw=true exists"}
- {"dt": "2023-03-02T07:33:16.663938", "lvl": "debug", "msg": "Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/dtbs/broadcom/bcm2711-rpi-4-b.dtb?raw=true exists"}
- {"dt": "2023-03-02T07:33:17.274748", "lvl": "debug", "msg": "Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/modules.tar.xz?raw=true exists"}
- {"dt": "2023-03-02T07:33:17.989957", "lvl": "info", "msg": "validate duration: 3.03"}
- {"dt": "2023-03-02T07:33:17.990761", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2023-03-02T07:33:17.991965", "lvl": "info", "msg": "start: 1 tftp-deploy (timeout 00:10:00) [common]"}
- {"dt": "2023-03-02T07:33:17.992901", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 00:10:00) [common]"}
- {"dt": "2023-03-02T07:33:17.993764", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 00:10:00) [common]"}
- {"dt": "2023-03-02T07:33:17.994831", "lvl": "debug", "msg": "Not decompressing ramdisk as can be used compressed."}
- {"dt": "2023-03-02T07:33:17.995797", "lvl": "info", "msg": "downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/images/rootfs/buildroot/kci-2019.02-11-g17e793fa4728/arm64/base/rootfs.cpio.gz?raw=true"}
- {"dt": "2023-03-02T07:33:17.996466", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/ramdisk/rootfs.cpio.gz"}
- {"dt": "2023-03-02T07:33:17.997027", "lvl": "debug", "msg": "total size: 4192947 (3MB)"}
- {"dt": "2023-03-02T07:33:18.885517", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-03-02T07:33:18.909942", "lvl": "debug", "msg": "progress   5% (0MB)"}
- {"dt": "2023-03-02T07:33:18.923415", "lvl": "debug", "msg": "progress  10% (0MB)"}
- {"dt": "2023-03-02T07:33:18.936503", "lvl": "debug", "msg": "progress  15% (0MB)"}
- {"dt": "2023-03-02T07:33:18.947689", "lvl": "debug", "msg": "progress  20% (0MB)"}
- {"dt": "2023-03-02T07:33:18.958146", "lvl": "debug", "msg": "progress  25% (1MB)"}
- {"dt": "2023-03-02T07:33:18.981598", "lvl": "debug", "msg": "progress  30% (1MB)"}
- {"dt": "2023-03-02T07:33:18.992958", "lvl": "debug", "msg": "progress  35% (1MB)"}
- {"dt": "2023-03-02T07:33:19.005940", "lvl": "debug", "msg": "progress  40% (1MB)"}
- {"dt": "2023-03-02T07:33:19.018094", "lvl": "debug", "msg": "progress  45% (1MB)"}
- {"dt": "2023-03-02T07:33:19.029912", "lvl": "debug", "msg": "progress  50% (2MB)"}
- {"dt": "2023-03-02T07:33:19.042936", "lvl": "debug", "msg": "progress  55% (2MB)"}
- {"dt": "2023-03-02T07:33:19.053800", "lvl": "debug", "msg": "progress  60% (2MB)"}
- {"dt": "2023-03-02T07:33:19.066850", "lvl": "debug", "msg": "progress  65% (2MB)"}
- {"dt": "2023-03-02T07:33:19.077403", "lvl": "debug", "msg": "progress  70% (2MB)"}
- {"dt": "2023-03-02T07:33:19.088017", "lvl": "debug", "msg": "progress  75% (3MB)"}
- {"dt": "2023-03-02T07:33:19.100014", "lvl": "debug", "msg": "progress  80% (3MB)"}
- {"dt": "2023-03-02T07:33:19.110119", "lvl": "debug", "msg": "progress  85% (3MB)"}
- {"dt": "2023-03-02T07:33:19.121988", "lvl": "debug", "msg": "progress  90% (3MB)"}
- {"dt": "2023-03-02T07:33:19.131995", "lvl": "debug", "msg": "progress  95% (3MB)"}
- {"dt": "2023-03-02T07:33:19.143063", "lvl": "debug", "msg": "progress 100% (3MB)"}
- {"dt": "2023-03-02T07:33:19.145107", "lvl": "info", "msg": "3MB downloaded in 1.15s (3.48MB/s)"}
- {"dt": "2023-03-02T07:33:19.146425", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2023-03-02T07:33:19.147353", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "1.15", "extra": {"label": "ramdisk", "md5sum": "dc99d8359b36a4a5fd569a984bb84bdf", "sha256sum": "cc73f153f47870c8ec995a00a0ad2aec3f05b6d22fc90b37a61f5066faa1b684", "sha512sum": "8fc07bd282f59a659b6417e8faca6c464be64927ab091cb2a9908805d12a680377bb58c5e52a1ed4d877b6f68783c02335e94ecf2764f5198816d2afd293923a", "size": ! "4192947"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-02T07:33:19.149127", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:01) [common]"}
- {"dt": "2023-03-02T07:33:19.149994", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 00:09:59) [common]"}
- {"dt": "2023-03-02T07:33:19.150820", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 00:09:59) [common]"}
- {"dt": "2023-03-02T07:33:19.152027", "lvl": "info", "msg": "downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/Image?raw=true"}
- {"dt": "2023-03-02T07:33:19.152776", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/kernel/Image"}
- {"dt": "2023-03-02T07:33:19.153378", "lvl": "debug", "msg": "total size: 27247104 (25MB)"}
- {"dt": "2023-03-02T07:33:19.154068", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-03-02T07:33:19.345515", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-03-02T07:33:19.452734", "lvl": "debug", "msg": "progress   5% (1MB)"}
- {"dt": "2023-03-02T07:33:19.555282", "lvl": "debug", "msg": "progress  10% (2MB)"}
- {"dt": "2023-03-02T07:33:19.655712", "lvl": "debug", "msg": "progress  15% (3MB)"}
- {"dt": "2023-03-02T07:33:19.759170", "lvl": "debug", "msg": "progress  20% (5MB)"}
- {"dt": "2023-03-02T07:33:19.858168", "lvl": "debug", "msg": "progress  25% (6MB)"}
- {"dt": "2023-03-02T07:33:19.955143", "lvl": "debug", "msg": "progress  30% (7MB)"}
- {"dt": "2023-03-02T07:33:20.037884", "lvl": "debug", "msg": "progress  35% (9MB)"}
- {"dt": "2023-03-02T07:33:20.113875", "lvl": "debug", "msg": "progress  40% (10MB)"}
- {"dt": "2023-03-02T07:33:20.189243", "lvl": "debug", "msg": "progress  45% (11MB)"}
- {"dt": "2023-03-02T07:33:20.266152", "lvl": "debug", "msg": "progress  50% (13MB)"}
- {"dt": "2023-03-02T07:33:20.343682", "lvl": "debug", "msg": "progress  55% (14MB)"}
- {"dt": "2023-03-02T07:33:20.420165", "lvl": "debug", "msg": "progress  60% (15MB)"}
- {"dt": "2023-03-02T07:33:20.497323", "lvl": "debug", "msg": "progress  65% (16MB)"}
- {"dt": "2023-03-02T07:33:20.581067", "lvl": "debug", "msg": "progress  70% (18MB)"}
- {"dt": "2023-03-02T07:33:20.655989", "lvl": "debug", "msg": "progress  75% (19MB)"}
- {"dt": "2023-03-02T07:33:20.733276", "lvl": "debug", "msg": "progress  80% (20MB)"}
- {"dt": "2023-03-02T07:33:20.815301", "lvl": "debug", "msg": "progress  85% (22MB)"}
- {"dt": "2023-03-02T07:33:20.905845", "lvl": "debug", "msg": "progress  90% (23MB)"}
- {"dt": "2023-03-02T07:33:20.986778", "lvl": "debug", "msg": "progress  95% (24MB)"}
- {"dt": "2023-03-02T07:33:21.048502", "lvl": "debug", "msg": "progress 100% (25MB)"}
- {"dt": "2023-03-02T07:33:21.050063", "lvl": "info", "msg": "25MB downloaded in 1.90s (13.70MB/s)"}
- {"dt": "2023-03-02T07:33:21.051335", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2023-03-02T07:33:21.052065", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "1.90", "extra": {"label": "kernel", "md5sum": "72d29fea218746b728a438f8a5b06fcd", "sha256sum": "038284bca9e8e0d7a7f18c35684550365ede71fa430f977f893544ddbbc358c3", "sha512sum": "1677e3adf0de7906c97fbce4dcdde51fcf68b4fd7131c17fdbbd7e9d573686d2adb5fe65a35184ecbffd2bde054d852ec80dafe5699e26491c46bcf588e8208e", "size": ! "27247104"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-02T07:33:21.054471", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:02) [common]"}
- {"dt": "2023-03-02T07:33:21.055461", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 00:09:57) [common]"}
- {"dt": "2023-03-02T07:33:21.056292", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 00:09:57) [common]"}
- {"dt": "2023-03-02T07:33:21.057408", "lvl": "info", "msg": "downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/dtbs/broadcom/bcm2711-rpi-4-b.dtb?raw=true"}
- {"dt": "2023-03-02T07:33:21.058124", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-02T07:33:21.058701", "lvl": "debug", "msg": "total size: 22210 (0MB)"}
- {"dt": "2023-03-02T07:33:21.059364", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-03-02T07:33:21.246377", "lvl": "debug", "msg": "progress 100% (0MB)"}
- {"dt": "2023-03-02T07:33:21.248254", "lvl": "info", "msg": "0MB downloaded in 0.19s (0.11MB/s)"}
- {"dt": "2023-03-02T07:33:21.249471", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:21.250169", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.19", "extra": {"label": "dtb", "md5sum": "35e07c8c1178357e2ca07c7c96d27eb2", "sha256sum": "afaf477d22603c52e823a22f64edf96f8a5ff2899f37159fe03a087a8cef7afd", "sha512sum": "f8b5cd80677a91eabd047d7d044b1e1880560f578b31b1beec8d700e455804d74ed10ece7f61b8870189da08c83d121b0f140ae6b7d1752cbdaba48b0dea3cab", "size": ! "22210"}, "level": "1.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-02T07:33:21.251765", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:21.252531", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:09:57) [common]"}
- {"dt": "2023-03-02T07:33:21.253282", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:09:57) [common]"}
- {"dt": "2023-03-02T07:33:21.254377", "lvl": "info", "msg": "downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.6.y/v5.6.12/arm64/defconfig/gcc-8/modules.tar.xz?raw=true"}
- {"dt": "2023-03-02T07:33:21.255158", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/modules/modules.tar"}
- {"dt": "2023-03-02T07:33:21.255755", "lvl": "debug", "msg": "total size: 6392588 (6MB)"}
- {"dt": "2023-03-02T07:33:21.256313", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2023-03-02T07:33:21.818479", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-03-02T07:33:21.876482", "lvl": "debug", "msg": "progress   5% (0MB)"}
- {"dt": "2023-03-02T07:33:21.950271", "lvl": "debug", "msg": "progress  10% (0MB)"}
- {"dt": "2023-03-02T07:33:22.019552", "lvl": "debug", "msg": "progress  15% (0MB)"}
- {"dt": "2023-03-02T07:33:22.113984", "lvl": "debug", "msg": "progress  20% (1MB)"}
- {"dt": "2023-03-02T07:33:22.195490", "lvl": "debug", "msg": "progress  25% (1MB)"}
- {"dt": "2023-03-02T07:33:22.279732", "lvl": "debug", "msg": "progress  30% (1MB)"}
- {"dt": "2023-03-02T07:33:22.363815", "lvl": "debug", "msg": "progress  35% (2MB)"}
- {"dt": "2023-03-02T07:33:22.447668", "lvl": "debug", "msg": "progress  40% (2MB)"}
- {"dt": "2023-03-02T07:33:22.523627", "lvl": "debug", "msg": "progress  45% (2MB)"}
- {"dt": "2023-03-02T07:33:22.611786", "lvl": "debug", "msg": "progress  50% (3MB)"}
- {"dt": "2023-03-02T07:33:22.703757", "lvl": "debug", "msg": "progress  55% (3MB)"}
- {"dt": "2023-03-02T07:33:22.787023", "lvl": "debug", "msg": "progress  60% (3MB)"}
- {"dt": "2023-03-02T07:33:22.867737", "lvl": "debug", "msg": "progress  65% (3MB)"}
- {"dt": "2023-03-02T07:33:22.938216", "lvl": "debug", "msg": "progress  70% (4MB)"}
- {"dt": "2023-03-02T07:33:23.011513", "lvl": "debug", "msg": "progress  75% (4MB)"}
- {"dt": "2023-03-02T07:33:23.087244", "lvl": "debug", "msg": "progress  80% (4MB)"}
- {"dt": "2023-03-02T07:33:23.147162", "lvl": "debug", "msg": "progress  85% (5MB)"}
- {"dt": "2023-03-02T07:33:23.223014", "lvl": "debug", "msg": "progress  90% (5MB)"}
- {"dt": "2023-03-02T07:33:23.303566", "lvl": "debug", "msg": "progress  95% (5MB)"}
- {"dt": "2023-03-02T07:33:23.368763", "lvl": "debug", "msg": "progress 100% (6MB)"}
- {"dt": "2023-03-02T07:33:23.388579", "lvl": "info", "msg": "6MB downloaded in 2.13s (2.86MB/s)"}
- {"dt": "2023-03-02T07:33:23.390444", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2023-03-02T07:33:23.391350", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "2.14", "extra": {"label": "modules", "md5sum": "0724e49cc73f2f495ae13aa5497b2bec", "sha256sum": "1dd2900e982fee1c2772266b84169ee4ebbb2f5410d241faff08c4642b1616a8", "sha512sum": "897029f872c5b8d5e70944a473d61ea0441f43dd2eaefc1c68a44d11330a77629738f741db40957f5c97c5b7072f48c67373fc47794abfda6e35af8893df9785", "size": ! "6392588"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-02T07:33:23.393059", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:02) [common]"}
- {"dt": "2023-03-02T07:33:23.393903", "lvl": "debug", "msg": "start: 1.5 prepare-tftp-overlay (timeout 00:09:55) [common]"}
- {"dt": "2023-03-02T07:33:23.394735", "lvl": "debug", "msg": "start: 1.5.1 extract-nfsrootfs (timeout 00:09:55) [common]"}
- {"dt": "2023-03-02T07:33:23.396244", "lvl": "debug", "msg": "end: 1.5.1 extract-nfsrootfs (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:23.397124", "lvl": "debug", "msg": "start: 1.5.2 lava-overlay (timeout 00:09:55) [common]"}
- {"dt": "2023-03-02T07:33:23.397822", "lvl": "info", "msg": "[common] skipped lava-overlay - no test action."}
- {"dt": "2023-03-02T07:33:23.398549", "lvl": "debug", "msg": "end: 1.5.2 lava-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:23.399418", "lvl": "debug", "msg": "start: 1.5.3 extract-overlay-ramdisk (timeout 00:09:55) [common]"}
- {"dt": "2023-03-02T07:33:24.430377", "lvl": "debug", "msg": "end: 1.5.3 extract-overlay-ramdisk (duration 00:00:01) [common]"}
- {"dt": "2023-03-02T07:33:24.432551", "lvl": "debug", "msg": "start: 1.5.4 extract-modules (timeout 00:09:54) [common]"}
- {"dt": "2023-03-02T07:33:24.433380", "lvl": "info", "msg": "extracting modules file /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/modules/modules.tar to /var/lib/lava/dispatcher/tmp/32086/extract-overlay-ramdisk-n5cqb14l/ramdisk"}
- {"dt": "2023-03-02T07:33:25.901222", "lvl": "debug", "msg": "end: 1.5.4 extract-modules (duration 00:00:01) [common]"}
- {"dt": "2023-03-02T07:33:25.902266", "lvl": "debug", "msg": "start: 1.5.5 apply-overlay-tftp (timeout 00:09:52) [common]"}
- {"dt": "2023-03-02T07:33:25.903260", "lvl": "debug", "msg": "end: 1.5.5 apply-overlay-tftp (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:25.904057", "lvl": "debug", "msg": "start: 1.5.6 prepare-kernel (timeout 00:09:52) [common]"}
- {"dt": "2023-03-02T07:33:25.904751", "lvl": "debug", "msg": "start: 1.5.6.1 uboot-prepare-kernel (timeout 00:09:52) [common]"}
- {"dt": "2023-03-02T07:33:25.905475", "lvl": "debug", "msg": "end: 1.5.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:25.906110", "lvl": "debug", "msg": "end: 1.5.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:25.906757", "lvl": "debug", "msg": "start: 1.5.7 configure-preseed-file (timeout 00:09:52) [common]"}
- {"dt": "2023-03-02T07:33:25.907436", "lvl": "debug", "msg": "end: 1.5.7 configure-preseed-file (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:25.908076", "lvl": "debug", "msg": "start: 1.5.8 compress-ramdisk (timeout 00:09:52) [common]"}
- {"dt": "2023-03-02T07:33:25.908612", "lvl": "info", "msg": "Building ramdisk /var/lib/lava/dispatcher/tmp/32086/extract-overlay-ramdisk-n5cqb14l/ramdisk.cpio containing /var/lib/lava/dispatcher/tmp/32086/extract-overlay-ramdisk-n5cqb14l/ramdisk"}
- {"dt": "2023-03-02T07:33:28.565403", "lvl": "debug", "msg": ">> 90939 blocks\n"}
- {"dt": "2023-03-02T07:33:34.542236", "lvl": "debug", "msg": "Adding RAMdisk u-boot header."}
- {"dt": "2023-03-02T07:33:34.544331", "lvl": "debug", "msg": "mkimage -A arm64 -T ramdisk -C none -d /var/lib/lava/dispatcher/tmp/32086/extract-overlay-ramdisk-n5cqb14l/ramdisk.cpio.gz /var/lib/lava/dispatcher/tmp/32086/extract-overlay-ramdisk-n5cqb14l/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-02T07:33:34.694192", "lvl": "debug", "msg": "output: Image Name:   "}
- {"dt": "2023-03-02T07:33:34.697200", "lvl": "debug", "msg": "output: Created:      Thu Mar  2 07:33:34 2023"}
- {"dt": "2023-03-02T07:33:34.698166", "lvl": "debug", "msg": "output: Image Type:   AArch64 Linux RAMDisk Image (uncompressed)"}
- {"dt": "2023-03-02T07:33:34.699122", "lvl": "debug", "msg": "output: Data Size:    13780580 Bytes = 13457.60 KiB = 13.14 MiB"}
- {"dt": "2023-03-02T07:33:34.700013", "lvl": "debug", "msg": "output: Load Address: 00000000"}
- {"dt": "2023-03-02T07:33:34.700881", "lvl": "debug", "msg": "output: Entry Point:  00000000"}
- {"dt": "2023-03-02T07:33:34.701749", "lvl": "debug", "msg": "output: "}
- {"dt": "2023-03-02T07:33:34.703262", "lvl": "debug", "msg": "rename /var/lib/lava/dispatcher/tmp/32086/extract-overlay-ramdisk-n5cqb14l/ramdisk.cpio.gz.uboot to /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-02T07:33:34.705532", "lvl": "debug", "msg": "end: 1.5.8 compress-ramdisk (duration 00:00:09) [common]"}
- {"dt": "2023-03-02T07:33:34.707136", "lvl": "debug", "msg": "end: 1.5 prepare-tftp-overlay (duration 00:00:11) [common]"}
- {"dt": "2023-03-02T07:33:34.707924", "lvl": "debug", "msg": "start: 1.6 lxc-create-udev-rule-action (timeout 00:09:43) [common]"}
- {"dt": "2023-03-02T07:33:34.708531", "lvl": "debug", "msg": "No LXC device requested"}
- {"dt": "2023-03-02T07:33:34.709136", "lvl": "debug", "msg": "end: 1.6 lxc-create-udev-rule-action (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:34.709682", "lvl": "debug", "msg": "Checking files for TFTP limit of 4294967296 bytes."}
- {"dt": "2023-03-02T07:33:34.713591", "lvl": "info", "msg": "end: 1 tftp-deploy (duration 00:00:17) [common]"}
- {"dt": "2023-03-02T07:33:34.714493", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:05:00) [common]"}
- {"dt": "2023-03-02T07:33:34.715345", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:05:00) [common]"}
- {"dt": "2023-03-02T07:33:34.716038", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:34.716724", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:05:00) [common]"}
- {"dt": "2023-03-02T07:33:34.717719", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2023-03-02T07:33:34.718258", "lvl": "debug", "msg": "- {BOOTX}: booti 0x00080000 0x02700000 0x02400000"}
- {"dt": "2023-03-02T07:33:34.718783", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x02400000"}
- {"dt": "2023-03-02T07:33:34.719309", "lvl": "debug", "msg": "- {DTB}: 32086/tftp-deploy-lt5ngdk0/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-02T07:33:34.719759", "lvl": "debug", "msg": "- {INITRD}: 32086/tftp-deploy-lt5ngdk0/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-02T07:33:34.720192", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x00080000"}
- {"dt": "2023-03-02T07:33:34.720624", "lvl": "debug", "msg": "- {KERNEL}: 32086/tftp-deploy-lt5ngdk0/kernel/Image"}
- {"dt": "2023-03-02T07:33:34.721055", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2023-03-02T07:33:34.721487", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2023-03-02T07:33:34.721918", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2023-03-02T07:33:34.722344", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x02700000"}
- {"dt": "2023-03-02T07:33:34.722769", "lvl": "debug", "msg": "- {RAMDISK}: 32086/tftp-deploy-lt5ngdk0/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-02T07:33:34.723248", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2023-03-02T07:33:34.723683", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2023-03-02T07:33:34.724117", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2023-03-02T07:33:34.724547", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2023-03-02T07:33:34.724978", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2023-03-02T07:33:34.725410", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2023-03-02T07:33:34.725831", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2023-03-02T07:33:34.726286", "lvl": "info", "msg": "- setenv initrd_high 0xffffffff"}
- {"dt": "2023-03-02T07:33:34.726736", "lvl": "info", "msg": "- setenv fdt_high 0xffffffff"}
- {"dt": "2023-03-02T07:33:34.727238", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2023-03-02T07:33:34.727684", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2023-03-02T07:33:34.728119", "lvl": "info", "msg": "- tftp 0x00080000 32086/tftp-deploy-lt5ngdk0/kernel/Image"}
- {"dt": "2023-03-02T07:33:34.728552", "lvl": "info", "msg": "- tftp 0x02700000 32086/tftp-deploy-lt5ngdk0/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-02T07:33:34.729012", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2023-03-02T07:33:34.729452", "lvl": "info", "msg": "- tftp 0x02400000 32086/tftp-deploy-lt5ngdk0/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-02T07:33:34.729892", "lvl": "info", "msg": "- setenv bootargs 'console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp'"}
- {"dt": "2023-03-02T07:33:34.730328", "lvl": "info", "msg": "- fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000 0x02400000"}
- {"dt": "2023-03-02T07:33:34.730980", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-03-02T07:33:34.731559", "lvl": "results", "msg": {"case": "bootloader-overlay", "definition": "lava", "duration": "0.01", "extra": {"dtb_addr": "0x02400000", "kernel_addr": "0x00080000", "ramdisk_addr": "0x02700000", "tee_addr": "0x83000000"}, "level": "2.2", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-02T07:33:34.733024", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:05:00) [common]"}
- {"dt": "2023-03-02T07:33:34.733644", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63003'"}
- {"dt": "2023-03-02T07:33:38.543977", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2023-03-02T07:33:38.546456", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:04) [common]"}
- {"dt": "2023-03-02T07:33:38.549158", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:04:56) [common]"}
- {"dt": "2023-03-02T07:33:38.550131", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:04:56) [common]"}
- {"dt": "2023-03-02T07:33:38.551074", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:04:56) [common]"}
- {"dt": "2023-03-02T07:33:38.552906", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '7'"}
- {"dt": "2023-03-02T07:33:42.280300", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-03-02T07:33:43.352722", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-03-02T07:33:43.388689", "lvl": "debug", "msg": "Returned 0 in 4 seconds"}
- {"dt": "2023-03-02T07:33:43.491984", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:05) [common]"}
- {"dt": "2023-03-02T07:33:43.494265", "lvl": "results", "msg": {"case": "pdu-reboot", "definition": "lava", "duration": "4.94", "extra": {"status": "success"}, "level": "2.4.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-02T07:33:43.498630", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:05) [common]"}
- {"dt": "2023-03-02T07:33:43.501144", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:04:51) [common]"}
- {"dt": "2023-03-02T07:33:43.503329", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2023-03-02T07:33:43.504145", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:05:00)"}
- {"dt": "2023-03-02T07:33:43.506076", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2023-03-02T07:33:43.506802", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2023-03-02T07:33:43.507427", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2023-03-02T07:33:49.926814", "lvl": "target", "msg": "\0"}
- {"dt": "2023-03-02T07:33:49.928972", "lvl": "target", "msg": ""}
- {"dt": "2023-03-02T07:33:49.943026", "lvl": "target", "msg": "U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)"}
- {"dt": "2023-03-02T07:33:49.944976", "lvl": "target", "msg": ""}
- {"dt": "2023-03-02T07:33:50.086714", "lvl": "target", "msg": "DRAM:  3.9 GiB"}
- {"dt": "2023-03-02T07:33:50.118751", "lvl": "target", "msg": "RPI 4 Model B (0xc03111)"}
- {"dt": "2023-03-02T07:33:50.155454", "lvl": "target", "msg": "MMC:   emmc2@7e340000: 0, mmcnr@7e300000: 1"}
- {"dt": "2023-03-02T07:33:50.221526", "lvl": "target", "msg": "Loading Environment from FAT... *** Warning - bad CRC, using default environment"}
- {"dt": "2023-03-02T07:33:50.223615", "lvl": "target", "msg": ""}
- {"dt": "2023-03-02T07:33:50.250095", "lvl": "target", "msg": "In:    serial"}
- {"dt": "2023-03-02T07:33:50.252045", "lvl": "target", "msg": "Out:   serial"}
- {"dt": "2023-03-02T07:33:50.253812", "lvl": "target", "msg": "Err:   serial"}
- {"dt": "2023-03-02T07:33:50.256304", "lvl": "target", "msg": "Net:   eth0: genet@7d580000"}
- {"dt": "2023-03-02T07:33:50.258189", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2023-03-02T07:33:50.260062", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2023-03-02T07:33:50.262436", "lvl": "input", "msg": "c"}
- {"dt": "2023-03-02T07:33:50.263452", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:00:07) [common]"}
- {"dt": "2023-03-02T07:33:50.264313", "lvl": "debug", "msg": "start: 2.4.3 bootloader-commands (timeout 00:04:44) [common]"}
- {"dt": "2023-03-02T07:33:50.264991", "lvl": "debug", "msg": "Setting prompt string to ['U-Boot>']"}
- {"dt": "2023-03-02T07:33:50.265678", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>'] (timeout 00:04:44)"}
- {"dt": "2023-03-02T07:33:50.284399", "lvl": "target", "msg": "Hit any key to stop autoboot:  2 \x03\b\b\b 0 "}
- {"dt": "2023-03-02T07:33:50.286205", "lvl": "debug", "msg": "Setting prompt string to ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image']"}
- {"dt": "2023-03-02T07:33:50.287322", "lvl": "input", "msg": "setenv autoload no\n"}
- {"dt": "2023-03-02T07:33:50.389288", "lvl": "target", "msg": "U-Boot> setenv autoload no"}
- {"dt": "2023-03-02T07:33:50.391182", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:44)"}
- {"dt": "2023-03-02T07:33:50.405740", "lvl": "target", "msg": "setenv autoload no"}
- {"dt": "2023-03-02T07:33:50.406742", "lvl": "input", "msg": "setenv initrd_high 0xffffffff\n"}
- {"dt": "2023-03-02T07:33:50.508356", "lvl": "target", "msg": "U-Boot> setenv initrd_high 0xffffffff"}
- {"dt": "2023-03-02T07:33:50.510539", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:44)"}
- {"dt": "2023-03-02T07:33:50.524245", "lvl": "target", "msg": "setenv initrd_high 0xffffffff"}
- {"dt": "2023-03-02T07:33:50.525849", "lvl": "input", "msg": "setenv fdt_high 0xffffffff\n"}
- {"dt": "2023-03-02T07:33:50.627935", "lvl": "target", "msg": "U-Boot> setenv fdt_high 0xffffffff"}
- {"dt": "2023-03-02T07:33:50.630084", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:44)"}
- {"dt": "2023-03-02T07:33:50.636084", "lvl": "target", "msg": "setenv fdt_high 0xffffffff"}
- {"dt": "2023-03-02T07:33:50.638163", "lvl": "input", "msg": "dhcp\n"}
- {"dt": "2023-03-02T07:33:50.740572", "lvl": "target", "msg": "U-Boot> dhcp"}
- {"dt": "2023-03-02T07:33:50.742709", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:44)"}
- {"dt": "2023-03-02T07:33:50.747986", "lvl": "target", "msg": "dhcp"}
- {"dt": "2023-03-02T07:33:53.066370", "lvl": "target", "msg": "genet@7d580000 Waiting for PHY auto negotiation to complete..... done"}
- {"dt": "2023-03-02T07:33:53.067172", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2023-03-02T07:33:53.305795", "lvl": "target", "msg": "BOOTP broadcast 2"}
- {"dt": "2023-03-02T07:33:53.817338", "lvl": "target", "msg": "BOOTP broadcast 3"}
- {"dt": "2023-03-02T07:33:54.102196", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (1029 ms)"}
- {"dt": "2023-03-02T07:33:54.103939", "lvl": "input", "msg": "setenv serverip 192.168.66.1\n"}
- {"dt": "2023-03-02T07:33:54.206105", "lvl": "target", "msg": "U-Boot> setenv serverip 192.168.66.1"}
- {"dt": "2023-03-02T07:33:54.208427", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:41)"}
- {"dt": "2023-03-02T07:33:54.214862", "lvl": "target", "msg": "setenv serverip 192.168.66.1"}
- {"dt": "2023-03-02T07:33:54.217467", "lvl": "input", "msg": "tftp 0x00080000 32086/tftp-deploy-lt5ngdk0/kernel/Image\n"}
- {"dt": "2023-03-02T07:33:54.320335", "lvl": "target", "msg": "U-Boot> tftp 0x00080000 32086/tftp-deploy-lt5ngdk0/kernel/Image"}
- {"dt": "2023-03-02T07:33:54.322430", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:40)"}
- {"dt": "2023-03-02T07:33:54.350315", "lvl": "target", "msg": "tftp 0x00080000 32086/tftp-deploy-lt5ngdk0/kernel/Image"}
- {"dt": "2023-03-02T07:33:54.351206", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-03-02T07:33:54.352203", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-03-02T07:33:54.353270", "lvl": "target", "msg": "Filename '32086/tftp-deploy-lt5ngdk0/kernel/Image'."}
- {"dt": "2023-03-02T07:33:54.353966", "lvl": "target", "msg": "Load address: 0x80000"}
- {"dt": "2023-03-02T07:34:21.404849", "lvl": "target", "msg": "Loading: *\bT #T #################################################  26 MiB"}
- {"dt": "2023-03-02T07:34:21.406818", "lvl": "target", "msg": "\t 983.4 KiB/s"}
- {"dt": "2023-03-02T07:34:21.408652", "lvl": "target", "msg": "done"}
- {"dt": "2023-03-02T07:34:21.411240", "lvl": "target", "msg": "Bytes transferred = 27247104 (19fc200 hex)"}
- {"dt": "2023-03-02T07:34:21.413734", "lvl": "input", "msg": "tftp 0x02700000 32086/tftp-deploy-lt5ngdk0/ramdisk/ramdisk.cpio.gz.uboot\n"}
- {"dt": "2023-03-02T07:34:21.516563", "lvl": "target", "msg": "U-Boot> tftp 0x02700000 32086/tftp-deploy-lt5ngdk0/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-02T07:34:21.518708", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:13)"}
- {"dt": "2023-03-02T07:34:21.552916", "lvl": "target", "msg": "tftp 0x02700000 32086/tftp-deploy-lt5ngdk0/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-02T07:34:21.555032", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-03-02T07:34:21.557730", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-03-02T07:34:21.559704", "lvl": "target", "msg": "Filename '32086/tftp-deploy-lt5ngdk0/ramdisk/ramdisk.cpio.gz.uboot'."}
- {"dt": "2023-03-02T07:34:21.561410", "lvl": "target", "msg": "Load address: 0x2700000"}
- {"dt": "2023-03-02T07:34:30.182091", "lvl": "target", "msg": "Loading: *\b##################################################  13.1 MiB"}
- {"dt": "2023-03-02T07:34:30.184152", "lvl": "target", "msg": "\t 1.5 MiB/s"}
- {"dt": "2023-03-02T07:34:30.186036", "lvl": "target", "msg": "done"}
- {"dt": "2023-03-02T07:34:30.188912", "lvl": "target", "msg": "Bytes transferred = 13780644 (d246a4 hex)"}
- {"dt": "2023-03-02T07:34:30.191790", "lvl": "input", "msg": "setenv initrd_size ${filesize}\n"}
- {"dt": "2023-03-02T07:34:30.294545", "lvl": "target", "msg": "U-Boot> setenv initrd_size ${filesize}"}
- {"dt": "2023-03-02T07:34:30.296582", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:04)"}
- {"dt": "2023-03-02T07:34:30.311489", "lvl": "target", "msg": "setenv initrd_size ${filesize}"}
- {"dt": "2023-03-02T07:34:30.312771", "lvl": "input", "msg": "tftp 0x02400000 32086/tftp-deploy-lt5ngdk0/dtb/bcm2711-rpi-4-b.dtb\n"}
- {"dt": "2023-03-02T07:34:30.414639", "lvl": "target", "msg": "U-Boot> tftp 0x02400000 32086/tftp-deploy-lt5ngdk0/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-02T07:34:30.416915", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:04)"}
- {"dt": "2023-03-02T07:34:30.451221", "lvl": "target", "msg": "tftp 0x02400000 32086/tftp-deploy-lt5ngdk0/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-02T07:34:30.452711", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-03-02T07:34:30.454149", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-03-02T07:34:30.455408", "lvl": "target", "msg": "Filename '32086/tftp-deploy-lt5ngdk0/dtb/bcm2711-rpi-4-b.dtb'."}
- {"dt": "2023-03-02T07:34:30.456439", "lvl": "target", "msg": "Load address: 0x2400000"}
- {"dt": "2023-03-02T07:34:30.477412", "lvl": "target", "msg": "Loading: *\b##################################################  21.7 KiB"}
- {"dt": "2023-03-02T07:34:30.478657", "lvl": "target", "msg": "\t 903.3 KiB/s"}
- {"dt": "2023-03-02T07:34:30.480054", "lvl": "target", "msg": "done"}
- {"dt": "2023-03-02T07:34:30.482125", "lvl": "target", "msg": "Bytes transferred = 22210 (56c2 hex)"}
- {"dt": "2023-03-02T07:34:30.484473", "lvl": "input", "msg": "setenv bootargs 'console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp'\n"}
- {"dt": "2023-03-02T07:34:30.587060", "lvl": "target", "msg": "U-Boot> setenv bootargs 'console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp'"}
- {"dt": "2023-03-02T07:34:30.589221", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:04)"}
- {"dt": "2023-03-02T07:34:30.607957", "lvl": "target", "msg": "setenv bootargs 'console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp'"}
- {"dt": "2023-03-02T07:34:30.610523", "lvl": "input", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000 0x02400000\n"}
- {"dt": "2023-03-02T07:34:30.713682", "lvl": "target", "msg": "U-Boot> fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000 0x02400000"}
- {"dt": "2023-03-02T07:34:30.716020", "lvl": "debug", "msg": "Setting prompt string to ['Starting kernel', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image']"}
- {"dt": "2023-03-02T07:34:30.717965", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['Starting kernel', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:04:04)"}
- {"dt": "2023-03-02T07:34:30.761678", "lvl": "target", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000 0x02400000"}
- {"dt": "2023-03-02T07:34:30.763811", "lvl": "target", "msg": "libfdt fdt_path_offset() returned FDT_ERR_BADPATH"}
- {"dt": "2023-03-02T07:34:30.766844", "lvl": "target", "msg": "## Loading init Ramdisk from Legacy Image at 02700000 ..."}
- {"dt": "2023-03-02T07:34:30.768841", "lvl": "target", "msg": "   Image Name:   "}
- {"dt": "2023-03-02T07:34:30.770512", "lvl": "target", "msg": "   Image Type:   AArch64 Linux RAMDisk Image (uncompressed)"}
- {"dt": "2023-03-02T07:34:30.772226", "lvl": "target", "msg": "   Data Size:    13780580 Bytes = 13.1 MiB"}
- {"dt": "2023-03-02T07:34:30.773819", "lvl": "target", "msg": "   Load Address: 00000000"}
- {"dt": "2023-03-02T07:34:30.775401", "lvl": "target", "msg": "   Entry Point:  00000000"}
- {"dt": "2023-03-02T07:34:30.938617", "lvl": "target", "msg": "   Verifying Checksum ... OK"}
- {"dt": "2023-03-02T07:34:30.940412", "lvl": "target", "msg": "## Flattened Device Tree blob at 02400000"}
- {"dt": "2023-03-02T07:34:30.941981", "lvl": "target", "msg": "   Booting using the fdt blob at 0x2400000"}
- {"dt": "2023-03-02T07:34:31.020808", "lvl": "target", "msg": "   Loading Ramdisk to 3a224000, end 3af48664 ... OK"}
- {"dt": "2023-03-02T07:34:31.041479", "lvl": "target", "msg": "   Loading Device Tree to 000000003a21b000, end 000000003a223fff ... OK"}
- {"dt": "2023-03-02T07:34:31.043483", "lvl": "target", "msg": ""}
- {"dt": "2023-03-02T07:34:31.046053", "lvl": "debug", "msg": "end: 2.4.3 bootloader-commands (duration 00:00:41) [common]"}
- {"dt": "2023-03-02T07:34:31.048247", "lvl": "debug", "msg": "start: 2.4.4 auto-login-action (timeout 00:04:04) [common]"}
- {"dt": "2023-03-02T07:34:31.049934", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2023-03-02T07:34:31.051670", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image']"}
- {"dt": "2023-03-02T07:34:31.053358", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:05:00)"}
- {"dt": "2023-03-02T07:34:31.056066", "lvl": "target", "msg": "Starting kernel ..."}
- {"dt": "2023-03-02T07:34:31.056747", "lvl": "target", "msg": ""}
- {"dt": "2023-03-02T07:34:32.901205", "lvl": "target", "msg": "<6>[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]"}
- {"dt": "2023-03-02T07:34:32.903719", "lvl": "target", "msg": "<5>[    0.000000] Linux version 5.6.12 (KernelCI@44cce1cf70dc) (gcc version 8.3.0 (Debian 8.3.0-2)) #1 SMP PREEMPT Sun May 10 14:46:40 UTC 2020"}
- {"dt": "2023-03-02T07:34:32.905525", "lvl": "target", "msg": "<6>[    0.000000] Machine model: Raspberry Pi 4 Model B"}
- {"dt": "2023-03-02T07:34:32.906433", "lvl": "target", "msg": "<6>[    0.000000] efi: Getting EFI parameters from FDT:"}
- {"dt": "2023-03-02T07:34:32.907366", "lvl": "target", "msg": "<6>[    0.000000] efi: UEFI not found."}
- {"dt": "2023-03-02T07:34:32.908323", "lvl": "target", "msg": "<6>[    0.000000] Reserved memory: created CMA memory pool at 0x0000000036000000, size 64 MiB"}
- {"dt": "2023-03-02T07:34:32.909910", "lvl": "debug", "msg": "start: 2.4.4.1 login-action (timeout 00:04:02) [common]"}
- {"dt": "2023-03-02T07:34:32.910729", "lvl": "warning", "msg": "The string '/ #' does not look like a typical prompt and could match status messages instead. Please check the job log files and use a prompt string which matches the actual prompt string more closely."}
- {"dt": "2023-03-02T07:34:32.911627", "lvl": "debug", "msg": "Setting prompt string to ['-\\\\[ cut here \\\\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing']"}
- {"dt": "2023-03-02T07:34:32.912337", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2023-03-02T07:34:32.912977", "lvl": "debug", "msg": "No login prompt set."}
- {"dt": "2023-03-02T07:34:32.913767", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2023-03-02T07:34:32.914379", "lvl": "debug", "msg": ["-\\[ cut here \\]", "Unhandled fault", "BUG: KCSAN:", "BUG: KASAN:", "BUG: KFENCE:", "Oops(?: -|:)", "WARNING:", "(kernel BUG at|BUG:)", "invalid opcode:", "Kernel panic - not syncing", "/ #", "Login timed out", "Login incorrect"]}
- {"dt": "2023-03-02T07:34:32.915431", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:04:02)"}
- {"dt": "2023-03-02T07:34:32.944017", "lvl": "target", "msg": "<6>[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool"}
- {"dt": "2023-03-02T07:34:32.945102", "lvl": "target", "msg": "<6>[    0.000000] NUMA: No NUMA configuration found"}
- {"dt": "2023-03-02T07:34:32.946138", "lvl": "target", "msg": "<6>[    0.000000] NUMA: Faking a node at [mem 0x0000000000000000-0x00000000fbffffff]"}
- {"dt": "2023-03-02T07:34:32.947058", "lvl": "target", "msg": "<6>[    0.000000] NUMA: NODE_DATA [mem 0xfb81d100-0xfb81efff]"}
- {"dt": "2023-03-02T07:34:32.947889", "lvl": "target", "msg": "<6>[    0.000000] Zone ranges:"}
- {"dt": "2023-03-02T07:34:32.948792", "lvl": "target", "msg": "<6>[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003fffffff]"}
- {"dt": "2023-03-02T07:34:32.949800", "lvl": "target", "msg": "<6>[    0.000000]   DMA32    [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2023-03-02T07:34:32.950632", "lvl": "target", "msg": "<6>[    0.000000]   Normal   empty"}
- {"dt": "2023-03-02T07:34:32.987984", "lvl": "target", "msg": "<6>[    0.000000] Movable zone start for each node"}
- {"dt": "2023-03-02T07:34:32.989374", "lvl": "target", "msg": "<6>[    0.000000] Early memory node ranges"}
- {"dt": "2023-03-02T07:34:32.990588", "lvl": "target", "msg": "<6>[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]"}
- {"dt": "2023-03-02T07:34:32.992742", "lvl": "target", "msg": "<6>[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2023-03-02T07:34:32.994032", "lvl": "target", "msg": "<6>[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]"}
- {"dt": "2023-03-02T07:34:32.995301", "lvl": "target", "msg": "<6>[    0.000000] percpu: Embedded 23 pages/cpu s53272 r8192 d32744 u94208"}
- {"dt": "2023-03-02T07:34:32.996476", "lvl": "target", "msg": "<6>[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2023-03-02T07:34:33.031628", "lvl": "target", "msg": "<6>[    0.000000] CPU features: detected: EL2 vector hardening"}
- {"dt": "2023-03-02T07:34:33.033081", "lvl": "target", "msg": "<4>[    0.000000] ARM_SMCCC_ARCH_WORKAROUND_1 missing from firmware"}
- {"dt": "2023-03-02T07:34:33.035332", "lvl": "target", "msg": "<6>[    0.000000] CPU features: detected: ARM erratum 1319367"}
- {"dt": "2023-03-02T07:34:33.036570", "lvl": "target", "msg": "<6>[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 996912"}
- {"dt": "2023-03-02T07:34:33.037749", "lvl": "target", "msg": "<6>[    0.000000] Policy zone: DMA32"}
- {"dt": "2023-03-02T07:34:33.038940", "lvl": "target", "msg": "<5>[    0.000000] Kernel command line: console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp"}
- {"dt": "2023-03-02T07:34:33.040365", "lvl": "target", "msg": "<6>[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.076300", "lvl": "target", "msg": "<6>[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.078041", "lvl": "target", "msg": "<6>[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off"}
- {"dt": "2023-03-02T07:34:33.079603", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: mapped [mem 0x32000000-0x36000000] (64MB)"}
- {"dt": "2023-03-02T07:34:33.081340", "lvl": "target", "msg": "<6>[    0.000000] Memory: 3798776K/4050944K available (12348K kernel code, 1968K rwdata, 6952K rodata, 5312K init, 462K bss, 186632K reserved, 65536K cma-reserved)"}
- {"dt": "2023-03-02T07:34:33.083001", "lvl": "target", "msg": "<6>[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1"}
- {"dt": "2023-03-02T07:34:33.119040", "lvl": "target", "msg": "<6>[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2023-03-02T07:34:33.121480", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2023-03-02T07:34:33.122985", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4."}
- {"dt": "2023-03-02T07:34:33.124088", "lvl": "target", "msg": "<6>[    0.000000] \tTasks RCU enabled."}
- {"dt": "2023-03-02T07:34:33.125112", "lvl": "target", "msg": "<6>[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2023-03-02T07:34:33.126131", "lvl": "target", "msg": "<6>[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4"}
- {"dt": "2023-03-02T07:34:33.127217", "lvl": "target", "msg": "<6>[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2023-03-02T07:34:33.162807", "lvl": "target", "msg": "<6>[    0.000000] GIC: Using split EOI/Deactivate mode"}
- {"dt": "2023-03-02T07:34:33.165579", "lvl": "target", "msg": "<5>[    0.000000] random: get_random_bytes called from start_kernel+0x2a8/0x434 with crng_init=0"}
- {"dt": "2023-03-02T07:34:33.167207", "lvl": "target", "msg": "<6>[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys)."}
- {"dt": "2023-03-02T07:34:33.168778", "lvl": "target", "msg": "<6>[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns"}
- {"dt": "2023-03-02T07:34:33.170214", "lvl": "target", "msg": "<6>[    0.000005] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns"}
- {"dt": "2023-03-02T07:34:33.172059", "lvl": "target", "msg": "<6>[    0.000180] Console: colour dummy device 80x25"}
- {"dt": "2023-03-02T07:34:33.207753", "lvl": "target", "msg": "<6>[    0.000269] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)"}
- {"dt": "2023-03-02T07:34:33.209422", "lvl": "target", "msg": "<6>[    0.000284] pid_max: default: 32768 minimum: 301"}
- {"dt": "2023-03-02T07:34:33.210932", "lvl": "target", "msg": "<6>[    0.000384] LSM: Security Framework initializing"}
- {"dt": "2023-03-02T07:34:33.212268", "lvl": "target", "msg": "<6>[    0.000512] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.213591", "lvl": "target", "msg": "<6>[    0.000584] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.215201", "lvl": "target", "msg": "<6>[    0.032019] rcu: Hierarchical SRCU implementation."}
- {"dt": "2023-03-02T07:34:33.216565", "lvl": "target", "msg": "<6>[    0.041793] EFI services will not be available."}
- {"dt": "2023-03-02T07:34:33.250479", "lvl": "target", "msg": "<6>[    0.048060] smp: Bringing up secondary CPUs ..."}
- {"dt": "2023-03-02T07:34:33.253225", "lvl": "target", "msg": "<6>[    0.080192] Detected PIPT I-cache on CPU1"}
- {"dt": "2023-03-02T07:34:33.254867", "lvl": "target", "msg": "<6>[    0.080245] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]"}
- {"dt": "2023-03-02T07:34:33.256037", "lvl": "target", "msg": "<6>[    0.112260] Detected PIPT I-cache on CPU2"}
- {"dt": "2023-03-02T07:34:33.257100", "lvl": "target", "msg": "<6>[    0.112298] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]"}
- {"dt": "2023-03-02T07:34:33.258127", "lvl": "target", "msg": "<6>[    0.144342] Detected PIPT I-cache on CPU3"}
- {"dt": "2023-03-02T07:34:33.259191", "lvl": "target", "msg": "<6>[    0.144381] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]"}
- {"dt": "2023-03-02T07:34:33.260447", "lvl": "target", "msg": "<6>[    0.144463] smp: Brought up 1 node, 4 CPUs"}
- {"dt": "2023-03-02T07:34:33.294259", "lvl": "target", "msg": "<6>[    0.144491] SMP: Total of 4 processors activated."}
- {"dt": "2023-03-02T07:34:33.296449", "lvl": "target", "msg": "<6>[    0.144501] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2023-03-02T07:34:33.297429", "lvl": "target", "msg": "<6>[    0.144510] CPU features: detected: CRC32 instructions"}
- {"dt": "2023-03-02T07:34:33.298347", "lvl": "target", "msg": "<6>[    0.161248] CPU: All CPU(s) started at EL2"}
- {"dt": "2023-03-02T07:34:33.299430", "lvl": "target", "msg": "<6>[    0.161286] alternatives: patching kernel code"}
- {"dt": "2023-03-02T07:34:33.300334", "lvl": "target", "msg": "<6>[    0.162982] devtmpfs: initialized"}
- {"dt": "2023-03-02T07:34:33.301229", "lvl": "target", "msg": "<4>[    0.167386] KASLR disabled due to lack of seed"}
- {"dt": "2023-03-02T07:34:33.302301", "lvl": "target", "msg": "<6>[    0.167788] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2023-03-02T07:34:33.337793", "lvl": "target", "msg": "<6>[    0.167810] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.339642", "lvl": "target", "msg": "<6>[    0.169624] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2023-03-02T07:34:33.340674", "lvl": "target", "msg": "<6>[    0.170899] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2023-03-02T07:34:33.341593", "lvl": "target", "msg": "<6>[    0.170904] thermal_sys: Registered thermal governor 'power_allocator'"}
- {"dt": "2023-03-02T07:34:33.342558", "lvl": "target", "msg": "<6>[    0.171105] DMI not present or invalid."}
- {"dt": "2023-03-02T07:34:33.343513", "lvl": "target", "msg": "<6>[    0.171720] NET: Registered protocol family 16"}
- {"dt": "2023-03-02T07:34:33.344381", "lvl": "target", "msg": "<6>[    0.173229] DMA: preallocated 256 KiB pool for atomic allocations"}
- {"dt": "2023-03-02T07:34:33.381842", "lvl": "target", "msg": "<6>[    0.173247] audit: initializing netlink subsys (disabled)"}
- {"dt": "2023-03-02T07:34:33.384379", "lvl": "target", "msg": "<5>[    0.173419] audit: type=2000 audit(0.172:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2023-03-02T07:34:33.385691", "lvl": "target", "msg": "<6>[    0.174546] cpuidle: using governor menu"}
- {"dt": "2023-03-02T07:34:33.386951", "lvl": "target", "msg": "<6>[    0.174815] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2023-03-02T07:34:33.388201", "lvl": "target", "msg": "<6>[    0.174905] ASID allocator initialised with 65536 entries"}
- {"dt": "2023-03-02T07:34:33.389387", "lvl": "target", "msg": "<6>[    0.176155] Serial: AMBA PL011 UART driver"}
- {"dt": "2023-03-02T07:34:33.390581", "lvl": "target", "msg": "<6>[    0.196123] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages"}
- {"dt": "2023-03-02T07:34:33.425968", "lvl": "target", "msg": "<6>[    0.196139] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages"}
- {"dt": "2023-03-02T07:34:33.429309", "lvl": "target", "msg": "<6>[    0.196149] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages"}
- {"dt": "2023-03-02T07:34:33.430995", "lvl": "target", "msg": "<6>[    0.196159] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages"}
- {"dt": "2023-03-02T07:34:33.432544", "lvl": "target", "msg": "<6>[    0.198775] cryptd: max_cpu_qlen set to 1000"}
- {"dt": "2023-03-02T07:34:33.434071", "lvl": "target", "msg": "<6>[    0.203647] ACPI: Interpreter disabled."}
- {"dt": "2023-03-02T07:34:33.435416", "lvl": "target", "msg": "<6>[    0.204878] iommu: Default domain type: Translated "}
- {"dt": "2023-03-02T07:34:33.435947", "lvl": "target", "msg": "<6>[    0.205101] vgaarb: loaded"}
- {"dt": "2023-03-02T07:34:33.436465", "lvl": "target", "msg": "<5>[    0.205417] SCSI subsystem initialized"}
- {"dt": "2023-03-02T07:34:33.437111", "lvl": "target", "msg": "<6>[    0.205812] usbcore: registered new interface driver usbfs"}
- {"dt": "2023-03-02T07:34:33.469314", "lvl": "target", "msg": "<6>[    0.205855] usbcore: registered new interface driver hub"}
- {"dt": "2023-03-02T07:34:33.471270", "lvl": "target", "msg": "<6>[    0.205928] usbcore: registered new device driver usb"}
- {"dt": "2023-03-02T07:34:33.472285", "lvl": "target", "msg": "<4>[    0.206081] usb_phy_generic phy: phy supply vcc not found, using dummy regulator"}
- {"dt": "2023-03-02T07:34:33.473283", "lvl": "target", "msg": "<6>[    0.206682] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2023-03-02T07:34:33.474671", "lvl": "target", "msg": "<6>[    0.206692] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2023-03-02T07:34:33.476047", "lvl": "target", "msg": "<6>[    0.206709] PTP clock support registered"}
- {"dt": "2023-03-02T07:34:33.477568", "lvl": "target", "msg": "<6>[    0.206828] EDAC MC: Ver: 3.0.0"}
- {"dt": "2023-03-02T07:34:33.478978", "lvl": "target", "msg": "<6>[    0.207998] FPGA manager framework"}
- {"dt": "2023-03-02T07:34:33.513781", "lvl": "target", "msg": "<6>[    0.208078] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2023-03-02T07:34:33.514802", "lvl": "target", "msg": "<6>[    0.208827] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2023-03-02T07:34:33.515786", "lvl": "target", "msg": "<5>[    0.209055] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2023-03-02T07:34:33.516662", "lvl": "target", "msg": "<6>[    0.209119] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2023-03-02T07:34:33.517552", "lvl": "target", "msg": "<6>[    0.209313] pnp: PnP ACPI: disabled"}
- {"dt": "2023-03-02T07:34:33.518522", "lvl": "target", "msg": "<6>[    0.215782] NET: Registered protocol family 2"}
- {"dt": "2023-03-02T07:34:33.519605", "lvl": "target", "msg": "<6>[    0.216220] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.558007", "lvl": "target", "msg": "<6>[    0.216260] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.559427", "lvl": "target", "msg": "<6>[    0.216447] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.560653", "lvl": "target", "msg": "<6>[    0.216913] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2023-03-02T07:34:33.561835", "lvl": "target", "msg": "<6>[    0.217098] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.563134", "lvl": "target", "msg": "<6>[    0.217148] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-02T07:34:33.564569", "lvl": "target", "msg": "<6>[    0.217342] NET: Registered protocol family 1"}
- {"dt": "2023-03-02T07:34:33.601055", "lvl": "target", "msg": "<6>[    0.217840] RPC: Registered named UNIX socket transport module."}
- {"dt": "2023-03-02T07:34:33.603589", "lvl": "target", "msg": "<6>[    0.217850] RPC: Registered udp transport module."}
- {"dt": "2023-03-02T07:34:33.604804", "lvl": "target", "msg": "<6>[    0.217857] RPC: Registered tcp transport module."}
- {"dt": "2023-03-02T07:34:33.605939", "lvl": "target", "msg": "<6>[    0.217864] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2023-03-02T07:34:33.607103", "lvl": "target", "msg": "<6>[    0.217877] PCI: CLS 0 bytes, default 64"}
- {"dt": "2023-03-02T07:34:33.608173", "lvl": "target", "msg": "<6>[    0.218064] Unpacking initramfs..."}
- {"dt": "2023-03-02T07:34:33.609238", "lvl": "target", "msg": "<6>[    1.261757] Freeing initrd memory: 13456K"}
- {"dt": "2023-03-02T07:34:33.610500", "lvl": "target", "msg": "<6>[    1.262662] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available"}
- {"dt": "2023-03-02T07:34:33.644542", "lvl": "target", "msg": "<6>[    1.262788] kvm [1]: IPA Size Limit: 44bits"}
- {"dt": "2023-03-02T07:34:33.645661", "lvl": "target", "msg": "<6>[    1.263786] kvm [1]: vgic interrupt IRQ1"}
- {"dt": "2023-03-02T07:34:33.647822", "lvl": "target", "msg": "<6>[    1.263931] kvm [1]: Hyp mode initialized successfully"}
- {"dt": "2023-03-02T07:34:33.648862", "lvl": "target", "msg": "<5>[    1.338068] Initialise system trusted keyrings"}
- {"dt": "2023-03-02T07:34:33.649820", "lvl": "target", "msg": "<6>[    1.338253] workingset: timestamp_bits=44 max_order=20 bucket_order=0"}
- {"dt": "2023-03-02T07:34:33.650736", "lvl": "target", "msg": "<6>[    1.345352] squashfs: version 4.0 (2009/01/31) Phillip Lougher"}
- {"dt": "2023-03-02T07:34:33.651630", "lvl": "target", "msg": "<5>[    1.346131] NFS: Registering the id_resolver key type"}
- {"dt": "2023-03-02T07:34:33.652390", "lvl": "target", "msg": "<5>[    1.346157] Key type id_resolver registered"}
- {"dt": "2023-03-02T07:34:33.653284", "lvl": "target", "msg": "<5>[    1.346166] Key type id_legacy registered"}
- {"dt": "2023-03-02T07:34:33.690036", "lvl": "target", "msg": "<6>[    1.346182] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2023-03-02T07:34:33.691830", "lvl": "target", "msg": "<6>[    1.346343] 9p: Installing v9fs 9p2000 file system support"}
- {"dt": "2023-03-02T07:34:33.693442", "lvl": "target", "msg": "<5>[    1.381695] Key type asymmetric registered"}
- {"dt": "2023-03-02T07:34:33.695069", "lvl": "target", "msg": "<5>[    1.381709] Asymmetric key parser 'x509' registered"}
- {"dt": "2023-03-02T07:34:33.696605", "lvl": "target", "msg": "<6>[    1.381765] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)"}
- {"dt": "2023-03-02T07:34:33.698128", "lvl": "target", "msg": "<6>[    1.381775] io scheduler mq-deadline registered"}
- {"dt": "2023-03-02T07:34:33.699436", "lvl": "target", "msg": "<6>[    1.381783] io scheduler kyber registered"}
- {"dt": "2023-03-02T07:34:33.700087", "lvl": "target", "msg": "<4>[    1.392006] EINJ: ACPI disabled."}
- {"dt": "2023-03-02T07:34:33.744755", "lvl": "target", "msg": "<6>[    1.405690] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled"}
- {"dt": "2023-03-02T07:34:33.746826", "lvl": "target", "msg": "<6>[    1.407417] printk: console [ttyS1] disabled"}
- {"dt": "2023-03-02T07:34:33.747976", "lvl": "target", "msg": "<6>[    1.407503] fe215040.serial: ttyS1 at MMIO 0xfe215040 (irq = 18, base_baud = 62499999) is a 16550"}
- {"dt": "2023-03-02T07:34:33.748990", "lvl": "target", "msg": "<6>[    2.258495] printk: console [ttyS1] enabled"}
- {"dt": "2023-03-02T07:34:33.750034", "lvl": "target", "msg": "<6>[    2.264056] SuperH (H)SCI(F) driver initialized"}
- {"dt": "2023-03-02T07:34:33.751069", "lvl": "target", "msg": "<6>[    2.269411] msm_serial: driver initialized"}
- {"dt": "2023-03-02T07:34:33.752071", "lvl": "target", "msg": "<4>[    2.275200] cacheinfo: Unable to detect cache hierarchy for CPU 0"}
- {"dt": "2023-03-02T07:34:33.753233", "lvl": "target", "msg": "<6>[    2.289975] loop: module loaded"}
- {"dt": "2023-03-02T07:34:33.795481", "lvl": "target", "msg": "<6>[    2.294500] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver"}
- {"dt": "2023-03-02T07:34:33.797267", "lvl": "target", "msg": "<6>[    2.306705] libphy: Fixed MDIO Bus: probed"}
- {"dt": "2023-03-02T07:34:33.799943", "lvl": "target", "msg": "<6>[    2.311431] tun: Universal TUN/TAP device driver, 1.6"}
- {"dt": "2023-03-02T07:34:33.801407", "lvl": "target", "msg": "<6>[    2.317537] thunder_xcv, ver 1.0"}
- {"dt": "2023-03-02T07:34:33.802750", "lvl": "target", "msg": "<6>[    2.321137] thunder_bgx, ver 1.0"}
- {"dt": "2023-03-02T07:34:33.803665", "lvl": "target", "msg": "<6>[    2.324703] nicpf, ver 1.0"}
- {"dt": "2023-03-02T07:34:33.804244", "lvl": "target", "msg": "<6>[    2.328266] hclge is initializing"}
- {"dt": "2023-03-02T07:34:33.804803", "lvl": "target", "msg": "<6>[    2.332091] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version"}
- {"dt": "2023-03-02T07:34:33.805493", "lvl": "target", "msg": "<6>[    2.339704] hns3: Copyright (c) 2017 Huawei Corporation."}
- {"dt": "2023-03-02T07:34:33.840155", "lvl": "target", "msg": "<6>[    2.345431] e1000e: Intel(R) PRO/1000 Network Driver - 3.2.6-k"}
- {"dt": "2023-03-02T07:34:33.842271", "lvl": "target", "msg": "<6>[    2.351625] e1000e: Copyright(c) 1999 - 2015 Intel Corporation."}
- {"dt": "2023-03-02T07:34:33.843447", "lvl": "target", "msg": "<6>[    2.357943] igb: Intel(R) Gigabit Ethernet Network Driver - version 5.6.0-k"}
- {"dt": "2023-03-02T07:34:33.844458", "lvl": "target", "msg": "<6>[    2.365281] igb: Copyright (c) 2007-2014 Intel Corporation."}
- {"dt": "2023-03-02T07:34:33.845488", "lvl": "target", "msg": "<6>[    2.371250] igbvf: Intel(R) Gigabit Virtual Function Network Driver - version 2.4.0-k"}
- {"dt": "2023-03-02T07:34:33.846472", "lvl": "target", "msg": "<6>[    2.379467] igbvf: Copyright (c) 2009 - 2012 Intel Corporation."}
- {"dt": "2023-03-02T07:34:33.847720", "lvl": "target", "msg": "<6>[    2.386085] sky2: driver version 1.30"}
- {"dt": "2023-03-02T07:34:33.886547", "lvl": "target", "msg": "<6>[    2.390764] VFIO - User Level meta-driver version: 0.3"}
- {"dt": "2023-03-02T07:34:33.890261", "lvl": "target", "msg": "<6>[    2.397933] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"}
- {"dt": "2023-03-02T07:34:33.892303", "lvl": "target", "msg": "<6>[    2.404841] ehci-pci: EHCI PCI platform driver"}
- {"dt": "2023-03-02T07:34:33.893965", "lvl": "target", "msg": "<6>[    2.409653] ehci-platform: EHCI generic platform driver"}
- {"dt": "2023-03-02T07:34:33.895642", "lvl": "target", "msg": "<6>[    2.415345] ehci-orion: EHCI orion driver"}
- {"dt": "2023-03-02T07:34:33.897194", "lvl": "target", "msg": "<6>[    2.419778] ehci-exynos: EHCI Exynos driver"}
- {"dt": "2023-03-02T07:34:33.898626", "lvl": "target", "msg": "<6>[    2.424383] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"}
- {"dt": "2023-03-02T07:34:33.899499", "lvl": "target", "msg": "<6>[    2.430942] ohci-pci: OHCI PCI platform driver"}
- {"dt": "2023-03-02T07:34:33.939857", "lvl": "target", "msg": "<6>[    2.435755] ohci-platform: OHCI generic platform driver"}
- {"dt": "2023-03-02T07:34:33.941966", "lvl": "target", "msg": "<6>[    2.441429] ohci-exynos: OHCI Exynos driver"}
- {"dt": "2023-03-02T07:34:33.943083", "lvl": "target", "msg": "<6>[    2.446377] usbcore: registered new interface driver usb-storage"}
- {"dt": "2023-03-02T07:34:33.944043", "lvl": "target", "msg": "<6>[    2.455340] i2c /dev entries driver"}
- {"dt": "2023-03-02T07:34:33.944958", "lvl": "target", "msg": "<6>[    2.463602] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer"}
- {"dt": "2023-03-02T07:34:33.946337", "lvl": "target", "msg": "<6>[    2.471283] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2023-03-02T07:34:33.947342", "lvl": "target", "msg": "<6>[    2.477833] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2023-03-02T07:34:33.948457", "lvl": "target", "msg": "<6>[    2.482920] Synopsys Designware Multimedia Card Interface Driver"}
- {"dt": "2023-03-02T07:34:33.992688", "lvl": "target", "msg": "<6>[    2.490223] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2023-03-02T07:34:33.995296", "lvl": "target", "msg": "<6>[    2.498438] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2023-03-02T07:34:33.996666", "lvl": "target", "msg": "<6>[    2.506336] usbcore: registered new interface driver usbhid"}
- {"dt": "2023-03-02T07:34:33.997915", "lvl": "target", "msg": "<6>[    2.512270] usbhid: USB HID core driver"}
- {"dt": "2023-03-02T07:34:33.999167", "lvl": "target", "msg": "<6>[    2.517285] bcm2835-mbox fe00b880.mailbox: mailbox enabled"}
- {"dt": "2023-03-02T07:34:34.000356", "lvl": "target", "msg": "<6>[    2.526510] NET: Registered protocol family 17"}
- {"dt": "2023-03-02T07:34:34.001551", "lvl": "target", "msg": "<6>[    2.531483] 9pnet: Installing 9P2000 support"}
- {"dt": "2023-03-02T07:34:34.003008", "lvl": "target", "msg": "<5>[    2.536142] Key type dns_resolver registered"}
- {"dt": "2023-03-02T07:34:34.055201", "lvl": "target", "msg": "<6>[    2.541075] registered taskstats version 1"}
- {"dt": "2023-03-02T07:34:34.057478", "lvl": "target", "msg": "<5>[    2.545514] Loading compiled-in X.509 certificates"}
- {"dt": "2023-03-02T07:34:34.058555", "lvl": "target", "msg": "<6>[    2.555144] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 16, base_baud = 0) is a PL011 rev2"}
- {"dt": "2023-03-02T07:34:34.059681", "lvl": "target", "msg": "<6>[    2.564612] serial serial0: tty port ttyAMA0 registered"}
- {"dt": "2023-03-02T07:34:34.060751", "lvl": "target", "msg": "<6>[    2.580157] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-01-22 17:23"}
- {"dt": "2023-03-02T07:34:34.061746", "lvl": "target", "msg": "<4>[    2.593159] dwc2 fe980000.usb: fe980000.usb supply vusb_d not found, using dummy regulator"}
- {"dt": "2023-03-02T07:34:34.073194", "lvl": "target", "msg": "<4>[    2.601922] dwc2 fe980000.usb: fe980000.usb supply vusb_a not found, using dummy regulator"}
- {"dt": "2023-03-02T07:34:34.191361", "lvl": "target", "msg": "<6>[    2.711400] dwc2 fe980000.usb: EPs: 8, dedicated fifos, 4080 entries in SPRAM"}
- {"dt": "2023-03-02T07:34:34.194711", "lvl": "target", "msg": "<6>[    2.722727] sdhci-iproc fe300000.sdhci: allocated mmc-pwrseq"}
- {"dt": "2023-03-02T07:34:34.233585", "lvl": "target", "msg": "<6>[    2.760888] mmc0: SDHCI controller on fe300000.sdhci [fe300000.sdhci] using PIO"}
- {"dt": "2023-03-02T07:34:34.299583", "lvl": "target", "msg": "<4>[    2.786869] mmc0: queuing unknown CIS tuple 0x80 (2 bytes)"}
- {"dt": "2023-03-02T07:34:34.303525", "lvl": "target", "msg": "<4>[    2.794406] mmc0: queuing unknown CIS tuple 0x80 (3 bytes)"}
- {"dt": "2023-03-02T07:34:34.305482", "lvl": "target", "msg": "<4>[    2.801933] mmc0: queuing unknown CIS tuple 0x80 (3 bytes)"}
- {"dt": "2023-03-02T07:34:34.307385", "lvl": "target", "msg": "<4>[    2.810947] mmc0: queuing unknown CIS tuple 0x80 (7 bytes)"}
- {"dt": "2023-03-02T07:34:34.309174", "lvl": "target", "msg": "<4>[    2.818460] mmc0: queuing unknown CIS tuple 0x80 (3 bytes)"}
- {"dt": "2023-03-02T07:34:34.311007", "lvl": "target", "msg": "<6>[    2.824322] mmc1: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA"}
- {"dt": "2023-03-02T07:34:34.311945", "lvl": "target", "msg": "<6>[    2.833896] hctosys: unable to open rtc device (rtc0)"}
- {"dt": "2023-03-02T07:34:34.349428", "lvl": "target", "msg": "<5>[    2.885162] random: fast init done"}
- {"dt": "2023-03-02T07:34:34.374523", "lvl": "target", "msg": "<6>[    2.901598] mmc0: new high speed SDIO card at address 0001"}
- {"dt": "2023-03-02T07:34:34.421543", "lvl": "target", "msg": "<6>[    2.944514] mmc1: new ultra high speed DDR50 SDHC card at address 59b4"}
- {"dt": "2023-03-02T07:34:34.423952", "lvl": "target", "msg": "<6>[    2.952098] mmcblk1: mmc1:59b4 USDU1 7.51 GiB "}
- {"dt": "2023-03-02T07:34:34.425796", "lvl": "target", "msg": "<6>[    2.958564]  mmcblk1: p1 p2"}
- {"dt": "2023-03-02T07:34:46.612420", "lvl": "target", "msg": "<6>[   15.132881] ALSA device list:"}
- {"dt": "2023-03-02T07:34:46.615083", "lvl": "target", "msg": "<6>[   15.136160]   No soundcards found."}
- {"dt": "2023-03-02T07:34:46.616243", "lvl": "target", "msg": "<6>[   15.144761] Freeing unused kernel memory: 5312K"}
- {"dt": "2023-03-02T07:34:46.617182", "lvl": "target", "msg": "<6>[   15.149834] Run /init as init process"}
- {"dt": "2023-03-02T07:34:46.647006", "lvl": "target", "msg": "Starting syslogd: OK"}
- {"dt": "2023-03-02T07:34:46.713257", "lvl": "target", "msg": "Starting klogd: OK"}
- {"dt": "2023-03-02T07:34:46.716646", "lvl": "target", "msg": "Populating /dev using udev: <30>[   15.206653] udevd[149]: starting version 3.2.7"}
- {"dt": "2023-03-02T07:34:46.718498", "lvl": "target", "msg": "<5>[   15.212288] random: udevd: uninitialized urandom read (16 bytes read)"}
- {"dt": "2023-03-02T07:34:46.720375", "lvl": "target", "msg": "<5>[   15.219309] random: udevd: uninitialized urandom read (16 bytes read)"}
- {"dt": "2023-03-02T07:34:46.722063", "lvl": "target", "msg": "<5>[   15.226175] random: udevd: uninitialized urandom read (16 bytes read)"}
- {"dt": "2023-03-02T07:34:46.723832", "lvl": "target", "msg": "<27>[   15.235181] udevd[149]: specified group 'kvm' unknown"}
- {"dt": "2023-03-02T07:34:46.725777", "lvl": "target", "msg": "<30>[   15.246083] udevd[150]: starting eudev-3.2.7"}
- {"dt": "2023-03-02T07:34:46.921569", "lvl": "target", "msg": "<6>[   15.421132] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:"}
- {"dt": "2023-03-02T07:34:46.924702", "lvl": "target", "msg": "<6>[   15.428604] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]"}
- {"dt": "2023-03-02T07:34:46.926606", "lvl": "target", "msg": "<4>[   15.441582] bcmgenet fd580000.ethernet: failed to get enet clock"}
- {"dt": "2023-03-02T07:34:46.928493", "lvl": "target", "msg": "<6>[   15.446313] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x0603ffffff -> 0x00f8000000"}
- {"dt": "2023-03-02T07:34:46.930306", "lvl": "target", "msg": "<6>[   15.457482] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000"}
- {"dt": "2023-03-02T07:34:46.932464", "lvl": "target", "msg": "<6>[   15.458028] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000"}
- {"dt": "2023-03-02T07:34:46.982494", "lvl": "target", "msg": "<4>[   15.469608] bcmgenet fd580000.ethernet: failed to get enet-wol clock"}
- {"dt": "2023-03-02T07:34:46.984516", "lvl": "target", "msg": "<6>[   15.479647] raspberrypi-clk raspberrypi-clk: CPU frequency range: min 600000000, max 1500000000"}
- {"dt": "2023-03-02T07:34:46.986277", "lvl": "target", "msg": "<4>[   15.483298] bcmgenet fd580000.ethernet: failed to get enet-eee clock"}
- {"dt": "2023-03-02T07:34:46.987606", "lvl": "target", "msg": "<6>[   15.502272] iproc-rng200 fe104000.rng: hwrng registered"}
- {"dt": "2023-03-02T07:34:46.988431", "lvl": "target", "msg": "<5>[   15.511057] cfg80211: Loading compiled-in X.509 certificates for regulatory database"}
- {"dt": "2023-03-02T07:34:47.028520", "lvl": "target", "msg": "<6>[   15.531126] brcm-pcie fd500000.pcie: link up, 5 GT/s x1 (SSC)"}
- {"dt": "2023-03-02T07:34:47.030659", "lvl": "target", "msg": "<6>[   15.538203] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2023-03-02T07:34:47.031892", "lvl": "target", "msg": "<6>[   15.547442] Bluetooth: Core ver 2.22"}
- {"dt": "2023-03-02T07:34:47.032974", "lvl": "target", "msg": "<6>[   15.551077] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2023-03-02T07:34:47.034055", "lvl": "target", "msg": "<6>[   15.551635] NET: Registered protocol family 31"}
- {"dt": "2023-03-02T07:34:47.035191", "lvl": "target", "msg": "<6>[   15.557462] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])"}
- {"dt": "2023-03-02T07:34:47.036475", "lvl": "target", "msg": "<6>[   15.561987] Bluetooth: HCI device and connection manager initialized"}
- {"dt": "2023-03-02T07:34:47.072984", "lvl": "target", "msg": "<6>[   15.562005] Bluetooth: HCI socket layer initialized"}
- {"dt": "2023-03-02T07:34:47.075885", "lvl": "target", "msg": "<6>[   15.562017] Bluetooth: L2CAP socket layer initialized"}
- {"dt": "2023-03-02T07:34:47.077485", "lvl": "target", "msg": "<5>[   15.574192] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'"}
- {"dt": "2023-03-02T07:34:47.079044", "lvl": "target", "msg": "<6>[   15.579533] Bluetooth: SCO socket layer initialized"}
- {"dt": "2023-03-02T07:34:47.080585", "lvl": "target", "msg": "<6>[   15.602832] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400"}
- {"dt": "2023-03-02T07:34:47.082124", "lvl": "target", "msg": "<6>[   15.603186] Bluetooth: HCI UART driver ver 2.3"}
- {"dt": "2023-03-02T07:34:47.083416", "lvl": "target", "msg": "<6>[   15.610277] pci 0000:00:00.0: PME# supported from D0 D3hot"}
- {"dt": "2023-03-02T07:34:47.116808", "lvl": "target", "msg": "<6>[   15.614668] Bluetooth: HCI UART protocol H4 registered"}
- {"dt": "2023-03-02T07:34:47.118693", "lvl": "target", "msg": "<4>[   15.621072] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2"}
- {"dt": "2023-03-02T07:34:47.119789", "lvl": "target", "msg": "<6>[   15.626605] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring"}
- {"dt": "2023-03-02T07:34:47.120720", "lvl": "target", "msg": "<6>[   15.627093] Bluetooth: HCI UART protocol LL registered"}
- {"dt": "2023-03-02T07:34:47.121644", "lvl": "target", "msg": "<6>[   15.627361] Bluetooth: HCI UART protocol Broadcom registered"}
- {"dt": "2023-03-02T07:34:47.122561", "lvl": "target", "msg": "<6>[   15.627403] Bluetooth: HCI UART protocol QCA registered"}
- {"dt": "2023-03-02T07:34:47.123698", "lvl": "target", "msg": "<6>[   15.632841] libphy: bcmgenet MII bus: probed"}
- {"dt": "2023-03-02T07:34:47.160693", "lvl": "target", "msg": "<4>[   15.635047] platform regulatory.0: Falling back to sysfs fallback for: regulatory.db"}
- {"dt": "2023-03-02T07:34:47.162319", "lvl": "target", "msg": "<4>[   15.635946] hci_uart_bcm serial0-0: serial0-0 supply vbat not found, using dummy regulator"}
- {"dt": "2023-03-02T07:34:47.163549", "lvl": "target", "msg": "<4>[   15.635988] hci_uart_bcm serial0-0: serial0-0 supply vddio not found, using dummy regulator"}
- {"dt": "2023-03-02T07:34:47.164626", "lvl": "target", "msg": "<6>[   15.643246] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330"}
- {"dt": "2023-03-02T07:34:47.165892", "lvl": "target", "msg": "<6>[   15.663137] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6"}
- {"dt": "2023-03-02T07:34:47.204433", "lvl": "target", "msg": "<6>[   15.664730] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]"}
- {"dt": "2023-03-02T07:34:47.206848", "lvl": "target", "msg": "<6>[   15.665241] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus"}
- {"dt": "2023-03-02T07:34:47.208552", "lvl": "target", "msg": "<4>[   15.672811] brcmfmac mmc0:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.bin failed with error -2"}
- {"dt": "2023-03-02T07:34:47.210014", "lvl": "target", "msg": "<6>[   15.681356] pci 0000:01:00.0: PME# supported from D0 D3cold"}
- {"dt": "2023-03-02T07:34:47.211617", "lvl": "target", "msg": "<4>[   15.690031] brcmfmac mmc0:0001:1: Falling back to sysfs fallback for: brcm/brcmfmac43455-sdio.bin"}
- {"dt": "2023-03-02T07:34:47.213145", "lvl": "target", "msg": "<6>[   15.697395] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01"}
- {"dt": "2023-03-02T07:34:47.248809", "lvl": "target", "msg": "<6>[   15.751278] pci 0000:00:00.0: BAR 14: assigned [mem 0x600000000-0x6000fffff]"}
- {"dt": "2023-03-02T07:34:47.252645", "lvl": "target", "msg": "<6>[   15.752949] uart-pl011 fe201000.serial: no DMA platform data"}
- {"dt": "2023-03-02T07:34:47.254541", "lvl": "target", "msg": "<6>[   15.758702] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]"}
- {"dt": "2023-03-02T07:34:47.256450", "lvl": "target", "msg": "<6>[   15.772555] pci 0000:00:00.0: PCI bridge to [bus 01]"}
- {"dt": "2023-03-02T07:34:47.258232", "lvl": "target", "msg": "<6>[   15.777861] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]"}
- {"dt": "2023-03-02T07:34:47.259578", "lvl": "target", "msg": "<6>[   15.785323] pcieport 0000:00:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2023-03-02T07:34:47.260226", "lvl": "target", "msg": "<6>[   15.791864] pcieport 0000:00:00.0: PME: Signaling with IRQ 40"}
- {"dt": "2023-03-02T07:34:47.293998", "lvl": "target", "msg": "<6>[   15.798114] pcieport 0000:00:00.0: AER: enabled with IRQ 40"}
- {"dt": "2023-03-02T07:34:47.296196", "lvl": "target", "msg": "<6>[   15.804155] pci 0000:01:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2023-03-02T07:34:47.297374", "lvl": "target", "msg": "<6>[   15.810311] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2023-03-02T07:34:47.298437", "lvl": "target", "msg": "<6>[   15.815892] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1"}
- {"dt": "2023-03-02T07:34:47.299556", "lvl": "target", "msg": "<6>[   15.823998] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000000000000090"}
- {"dt": "2023-03-02T07:34:47.300540", "lvl": "target", "msg": "<6>[   15.834057] hub 1-0:1.0: USB hub found"}
- {"dt": "2023-03-02T07:34:47.301700", "lvl": "target", "msg": "<6>[   15.838141] hub 1-0:1.0: 1 port detected"}
- {"dt": "2023-03-02T07:34:47.342724", "lvl": "target", "msg": "<6>[   15.842610] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2023-03-02T07:34:47.345333", "lvl": "target", "msg": "<6>[   15.848179] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2"}
- {"dt": "2023-03-02T07:34:47.346763", "lvl": "target", "msg": "<6>[   15.855957] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed"}
- {"dt": "2023-03-02T07:34:47.348162", "lvl": "target", "msg": "<6>[   15.862609] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM."}
- {"dt": "2023-03-02T07:34:47.349514", "lvl": "target", "msg": "<6>[   15.871335] hub 2-0:1.0: USB hub found"}
- {"dt": "2023-03-02T07:34:47.351146", "lvl": "target", "msg": "<6>[   15.875423] hub 2-0:1.0: 4 ports detected"}
- {"dt": "2023-03-02T07:34:47.352554", "lvl": "target", "msg": "done"}
- {"dt": "2023-03-02T07:34:47.367761", "lvl": "target", "msg": "Initializing random number generator... done."}
- {"dt": "2023-03-02T07:34:47.371355", "lvl": "target", "msg": "Starting network: OK"}
- {"dt": "2023-03-02T07:34:47.420705", "lvl": "target", "msg": "Starting dropbear sshd: <6>[   15.939491] NET: Registered protocol family 10"}
- {"dt": "2023-03-02T07:34:47.423867", "lvl": "target", "msg": "<6>[   15.944812] Segment Routing with IPv6"}
- {"dt": "2023-03-02T07:34:47.425734", "lvl": "target", "msg": "OK"}
- {"dt": "2023-03-02T07:34:47.427857", "lvl": "target", "msg": "/bin/sh: can't access tty; job control turned off"}
- {"dt": "2023-03-02T07:34:47.431328", "lvl": "debug", "msg": "Matched prompt #10: / #"}
- {"dt": "2023-03-02T07:34:47.432073", "lvl": "results", "msg": {"case": "kernel-messages", "definition": "lava", "duration": "14.52", "extra": {"extra": []}, "level": "2.4.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-02T07:34:47.433209", "lvl": "debug", "msg": "Setting prompt string to ['/ #']"}
- {"dt": "2023-03-02T07:34:47.433967", "lvl": "debug", "msg": "end: 2.4.4.1 login-action (duration 00:00:15) [common]"}
- {"dt": "2023-03-02T07:34:47.434589", "lvl": "results", "msg": {"case": "login-action", "definition": "lava", "duration": "14.52", "extra": {"success": "No kernel warnings or errors detected."}, "level": "2.4.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-02T07:34:47.435858", "lvl": "debug", "msg": "end: 2.4.4 auto-login-action (duration 00:00:16) [common]"}
- {"dt": "2023-03-02T07:34:47.436673", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:01:09) [common]"}
- {"dt": "2023-03-02T07:34:47.437508", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:01:13) [common]"}
- {"dt": "2023-03-02T07:34:47.438312", "lvl": "info", "msg": "start: 3 finalize (timeout 00:08:31) [common]"}
- {"dt": "2023-03-02T07:34:47.439181", "lvl": "debug", "msg": "start: 3.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2023-03-02T07:34:47.440238", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '7'"}
- {"dt": "2023-03-02T07:34:50.888837", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-03-02T07:34:50.924798", "lvl": "debug", "msg": "Returned 0 in 3 seconds"}
- {"dt": "2023-03-02T07:34:51.028261", "lvl": "debug", "msg": "end: 3.1 power-off (duration 00:00:04) [common]"}
- {"dt": "2023-03-02T07:34:51.030526", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "3.59", "extra": {"status": "success"}, "level": "3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-02T07:34:51.035050", "lvl": "debug", "msg": "start: 3.2 read-feedback (timeout 00:08:27) [common]"}
- {"dt": "2023-03-02T07:34:51.039840", "lvl": "feedback", "msg": "/ # <6>[   16.005344] Bluetooth: hci0: BCM: chip id 107", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.040612", "lvl": "feedback", "msg": "<6>[   16.010280] Bluetooth: hci0: BCM: features 0x2f", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.041272", "lvl": "feedback", "msg": "<6>[   16.016626] Bluetooth: hci0: BCM4345C0", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.041888", "lvl": "feedback", "msg": "<6>[   16.020696] Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.042513", "lvl": "feedback", "msg": "<4>[   16.027003] bluetooth hci0: Direct firmware load for brcm/BCM4345C0.hcd failed with error -2", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.043184", "lvl": "feedback", "msg": "<4>[   16.035831] bluetooth hci0: Falling back to sysfs fallback for: brcm/BCM4345C0.hcd", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.043797", "lvl": "feedback", "msg": "<6>[   16.176828] usb 1-1: new high-speed USB device number 2 using xhci_hcd", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.044388", "lvl": "feedback", "msg": "<6>[   16.330991] hub 1-1:1.0: USB hub found", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.044973", "lvl": "feedback", "msg": "<6>[   16.335200] hub 1-1:1.0: 4 ports detected", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.045556", "lvl": "feedback", "msg": "<6>[   16.632829] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.046142", "lvl": "feedback", "msg": "<6>[   16.739400] hub 1-1.3:1.0: USB hub found", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.046724", "lvl": "feedback", "msg": "<6>[   16.743798] hub 1-1.3:1.0: 4 ports detected", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.047359", "lvl": "feedback", "msg": "<6>[   17.052829] usb 1-1.3.1: new high-speed USB device number 4 using xhci_hcd", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.047959", "lvl": "feedback", "msg": "<6>[   17.175388] hub 1-1.3.1:1.0: USB hub found", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.048542", "lvl": "feedback", "msg": "<6>[   17.180040] hub 1-1.3.1:1.0: 4 ports detected", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.049126", "lvl": "feedback", "msg": "<3>[   18.309141] usb 1-1.3.1-port1: Cannot enable. Maybe the USB cable is bad?", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.049718", "lvl": "feedback", "msg": "<3>[   19.229128] usb 1-1.3.1-port1: Cannot enable. Maybe the USB cable is bad?", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.050304", "lvl": "feedback", "msg": "<6>[   19.236444] usb 1-1.3.1-port1: attempt power cycle", "ns": "common"}
- {"dt": "2023-03-02T07:34:51.051287", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2023-03-02T07:34:52.042754", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2023-03-02T07:34:52.044258", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2023-03-02T07:34:52.147276", "lvl": "debug", "msg": "end: 3.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2023-03-02T07:34:52.149228", "lvl": "info", "msg": "end: 3 finalize (duration 00:00:05) [common]"}
- {"dt": "2023-03-02T07:34:52.151292", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2023-03-02T07:34:52.152992", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/ramdisk"}
- {"dt": "2023-03-02T07:34:52.162873", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/kernel"}
- {"dt": "2023-03-02T07:34:52.173168", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/dtb"}
- {"dt": "2023-03-02T07:34:52.174558", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32086/tftp-deploy-lt5ngdk0/modules"}
- {"dt": "2023-03-02T07:34:52.186754", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/32086"}
- {"dt": "2023-03-02T07:34:52.388390", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/32086"}
- {"dt": "2023-03-02T07:34:52.389337", "lvl": "info", "msg": "Job finished correctly"}
- {"dt": "2023-03-02T07:34:52.389884", "lvl": "results", "msg": {"case": "job", "definition": "lava", "result": "pass"}}
