- {"dt": "2023-03-08T07:33:41.016458", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.01"}
- {"dt": "2023-03-08T07:33:41.017811", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2023-03-08T07:33:41.018970", "lvl": "info", "msg": "Start time: 2023-03-08 07:33:41.018855+00:00 (UTC)"}
- {"dt": "2023-03-08T07:33:41.020154", "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-08T07:33:42.230088", "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-08T07:33:42.770438", "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-08T07:33:43.757108", "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-08T07:33:44.144530", "lvl": "info", "msg": "validate duration: 3.13"}
- {"dt": "2023-03-08T07:33:44.145364", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2023-03-08T07:33:44.146635", "lvl": "info", "msg": "start: 1 tftp-deploy (timeout 00:10:00) [common]"}
- {"dt": "2023-03-08T07:33:44.148217", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 00:10:00) [common]"}
- {"dt": "2023-03-08T07:33:44.149115", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 00:10:00) [common]"}
- {"dt": "2023-03-08T07:33:44.150156", "lvl": "debug", "msg": "Not decompressing ramdisk as can be used compressed."}
- {"dt": "2023-03-08T07:33:44.151752", "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-08T07:33:44.152543", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/ramdisk/rootfs.cpio.gz"}
- {"dt": "2023-03-08T07:33:44.153214", "lvl": "debug", "msg": "total size: 4192947 (3MB)"}
- {"dt": "2023-03-08T07:33:44.389910", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-03-08T07:33:44.419201", "lvl": "debug", "msg": "progress   5% (0MB)"}
- {"dt": "2023-03-08T07:33:44.431821", "lvl": "debug", "msg": "progress  10% (0MB)"}
- {"dt": "2023-03-08T07:33:44.444119", "lvl": "debug", "msg": "progress  15% (0MB)"}
- {"dt": "2023-03-08T07:33:44.455847", "lvl": "debug", "msg": "progress  20% (0MB)"}
- {"dt": "2023-03-08T07:33:44.466344", "lvl": "debug", "msg": "progress  25% (1MB)"}
- {"dt": "2023-03-08T07:33:44.478401", "lvl": "debug", "msg": "progress  30% (1MB)"}
- {"dt": "2023-03-08T07:33:44.488417", "lvl": "debug", "msg": "progress  35% (1MB)"}
- {"dt": "2023-03-08T07:33:44.499816", "lvl": "debug", "msg": "progress  40% (1MB)"}
- {"dt": "2023-03-08T07:33:44.511018", "lvl": "debug", "msg": "progress  45% (1MB)"}
- {"dt": "2023-03-08T07:33:44.521331", "lvl": "debug", "msg": "progress  50% (2MB)"}
- {"dt": "2023-03-08T07:33:44.533035", "lvl": "debug", "msg": "progress  55% (2MB)"}
- {"dt": "2023-03-08T07:33:44.542759", "lvl": "debug", "msg": "progress  60% (2MB)"}
- {"dt": "2023-03-08T07:33:44.554241", "lvl": "debug", "msg": "progress  65% (2MB)"}
- {"dt": "2023-03-08T07:33:44.563666", "lvl": "debug", "msg": "progress  70% (2MB)"}
- {"dt": "2023-03-08T07:33:44.572957", "lvl": "debug", "msg": "progress  75% (3MB)"}
- {"dt": "2023-03-08T07:33:44.583846", "lvl": "debug", "msg": "progress  80% (3MB)"}
- {"dt": "2023-03-08T07:33:44.593188", "lvl": "debug", "msg": "progress  85% (3MB)"}
- {"dt": "2023-03-08T07:33:44.604062", "lvl": "debug", "msg": "progress  90% (3MB)"}
- {"dt": "2023-03-08T07:33:44.613392", "lvl": "debug", "msg": "progress  95% (3MB)"}
- {"dt": "2023-03-08T07:33:44.622778", "lvl": "debug", "msg": "progress 100% (3MB)"}
- {"dt": "2023-03-08T07:33:44.624814", "lvl": "info", "msg": "3MB downloaded in 0.47s (8.48MB/s)"}
- {"dt": "2023-03-08T07:33:44.625983", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:44.626675", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.48", "extra": {"label": "ramdisk", "md5sum": "dc99d8359b36a4a5fd569a984bb84bdf", "sha256sum": "cc73f153f47870c8ec995a00a0ad2aec3f05b6d22fc90b37a61f5066faa1b684", "sha512sum": "8fc07bd282f59a659b6417e8faca6c464be64927ab091cb2a9908805d12a680377bb58c5e52a1ed4d877b6f68783c02335e94ecf2764f5198816d2afd293923a", "size": ! "4192947"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-08T07:33:44.628361", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:44.629299", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 00:10:00) [common]"}
- {"dt": "2023-03-08T07:33:44.630239", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 00:10:00) [common]"}
- {"dt": "2023-03-08T07:33:44.631441", "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-08T07:33:44.632157", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/kernel/Image"}
- {"dt": "2023-03-08T07:33:44.632749", "lvl": "debug", "msg": "total size: 27247104 (25MB)"}
- {"dt": "2023-03-08T07:33:44.633321", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-03-08T07:33:44.994501", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-03-08T07:33:45.065741", "lvl": "debug", "msg": "progress   5% (1MB)"}
- {"dt": "2023-03-08T07:33:45.129372", "lvl": "debug", "msg": "progress  10% (2MB)"}
- {"dt": "2023-03-08T07:33:45.189382", "lvl": "debug", "msg": "progress  15% (3MB)"}
- {"dt": "2023-03-08T07:33:45.252307", "lvl": "debug", "msg": "progress  20% (5MB)"}
- {"dt": "2023-03-08T07:33:45.314548", "lvl": "debug", "msg": "progress  25% (6MB)"}
- {"dt": "2023-03-08T07:33:45.378686", "lvl": "debug", "msg": "progress  30% (7MB)"}
- {"dt": "2023-03-08T07:33:45.442106", "lvl": "debug", "msg": "progress  35% (9MB)"}
- {"dt": "2023-03-08T07:33:45.503855", "lvl": "debug", "msg": "progress  40% (10MB)"}
- {"dt": "2023-03-08T07:33:45.566931", "lvl": "debug", "msg": "progress  45% (11MB)"}
- {"dt": "2023-03-08T07:33:45.629323", "lvl": "debug", "msg": "progress  50% (13MB)"}
- {"dt": "2023-03-08T07:33:45.692797", "lvl": "debug", "msg": "progress  55% (14MB)"}
- {"dt": "2023-03-08T07:33:45.755349", "lvl": "debug", "msg": "progress  60% (15MB)"}
- {"dt": "2023-03-08T07:33:45.818872", "lvl": "debug", "msg": "progress  65% (16MB)"}
- {"dt": "2023-03-08T07:33:45.880524", "lvl": "debug", "msg": "progress  70% (18MB)"}
- {"dt": "2023-03-08T07:33:45.943454", "lvl": "debug", "msg": "progress  75% (19MB)"}
- {"dt": "2023-03-08T07:33:46.026631", "lvl": "debug", "msg": "progress  80% (20MB)"}
- {"dt": "2023-03-08T07:33:46.221922", "lvl": "debug", "msg": "progress  85% (22MB)"}
- {"dt": "2023-03-08T07:33:46.437729", "lvl": "debug", "msg": "progress  90% (23MB)"}
- {"dt": "2023-03-08T07:33:46.630634", "lvl": "debug", "msg": "progress  95% (24MB)"}
- {"dt": "2023-03-08T07:33:46.810080", "lvl": "debug", "msg": "progress 100% (25MB)"}
- {"dt": "2023-03-08T07:33:46.812116", "lvl": "info", "msg": "25MB downloaded in 2.18s (11.92MB/s)"}
- {"dt": "2023-03-08T07:33:46.813475", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2023-03-08T07:33:46.814247", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "2.18", "extra": {"label": "kernel", "md5sum": "72d29fea218746b728a438f8a5b06fcd", "sha256sum": "038284bca9e8e0d7a7f18c35684550365ede71fa430f977f893544ddbbc358c3", "sha512sum": "1677e3adf0de7906c97fbce4dcdde51fcf68b4fd7131c17fdbbd7e9d573686d2adb5fe65a35184ecbffd2bde054d852ec80dafe5699e26491c46bcf588e8208e", "size": ! "27247104"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-08T07:33:46.815897", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:02) [common]"}
- {"dt": "2023-03-08T07:33:46.816561", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 00:09:57) [common]"}
- {"dt": "2023-03-08T07:33:46.817206", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 00:09:57) [common]"}
- {"dt": "2023-03-08T07:33:46.818194", "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-08T07:33:46.818840", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-08T07:33:46.819397", "lvl": "debug", "msg": "total size: 22210 (0MB)"}
- {"dt": "2023-03-08T07:33:46.819870", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-03-08T07:33:47.177062", "lvl": "debug", "msg": "progress 100% (0MB)"}
- {"dt": "2023-03-08T07:33:47.182034", "lvl": "info", "msg": "0MB downloaded in 0.36s (0.06MB/s)"}
- {"dt": "2023-03-08T07:33:47.183926", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:47.184624", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.37", "extra": {"label": "dtb", "md5sum": "35e07c8c1178357e2ca07c7c96d27eb2", "sha256sum": "afaf477d22603c52e823a22f64edf96f8a5ff2899f37159fe03a087a8cef7afd", "sha512sum": "f8b5cd80677a91eabd047d7d044b1e1880560f578b31b1beec8d700e455804d74ed10ece7f61b8870189da08c83d121b0f140ae6b7d1752cbdaba48b0dea3cab", "size": ! "22210"}, "level": "1.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-08T07:33:47.186118", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:47.186937", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 00:09:57) [common]"}
- {"dt": "2023-03-08T07:33:47.187736", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 00:09:57) [common]"}
- {"dt": "2023-03-08T07:33:47.188833", "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-08T07:33:47.189528", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/modules/modules.tar"}
- {"dt": "2023-03-08T07:33:47.190106", "lvl": "debug", "msg": "total size: 6392588 (6MB)"}
- {"dt": "2023-03-08T07:33:47.190680", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2023-03-08T07:33:47.399473", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-03-08T07:33:47.471731", "lvl": "debug", "msg": "progress   5% (0MB)"}
- {"dt": "2023-03-08T07:33:47.541844", "lvl": "debug", "msg": "progress  10% (0MB)"}
- {"dt": "2023-03-08T07:33:47.607659", "lvl": "debug", "msg": "progress  15% (0MB)"}
- {"dt": "2023-03-08T07:33:47.689246", "lvl": "debug", "msg": "progress  20% (1MB)"}
- {"dt": "2023-03-08T07:33:47.761852", "lvl": "debug", "msg": "progress  25% (1MB)"}
- {"dt": "2023-03-08T07:33:47.835885", "lvl": "debug", "msg": "progress  30% (1MB)"}
- {"dt": "2023-03-08T07:33:47.911421", "lvl": "debug", "msg": "progress  35% (2MB)"}
- {"dt": "2023-03-08T07:33:47.983737", "lvl": "debug", "msg": "progress  40% (2MB)"}
- {"dt": "2023-03-08T07:33:48.046578", "lvl": "debug", "msg": "progress  45% (2MB)"}
- {"dt": "2023-03-08T07:33:48.117970", "lvl": "debug", "msg": "progress  50% (3MB)"}
- {"dt": "2023-03-08T07:33:48.196921", "lvl": "debug", "msg": "progress  55% (3MB)"}
- {"dt": "2023-03-08T07:33:48.272776", "lvl": "debug", "msg": "progress  60% (3MB)"}
- {"dt": "2023-03-08T07:33:48.339243", "lvl": "debug", "msg": "progress  65% (3MB)"}
- {"dt": "2023-03-08T07:33:48.409608", "lvl": "debug", "msg": "progress  70% (4MB)"}
- {"dt": "2023-03-08T07:33:48.481339", "lvl": "debug", "msg": "progress  75% (4MB)"}
- {"dt": "2023-03-08T07:33:48.554060", "lvl": "debug", "msg": "progress  80% (4MB)"}
- {"dt": "2023-03-08T07:33:48.613205", "lvl": "debug", "msg": "progress  85% (5MB)"}
- {"dt": "2023-03-08T07:33:48.688184", "lvl": "debug", "msg": "progress  90% (5MB)"}
- {"dt": "2023-03-08T07:33:48.760900", "lvl": "debug", "msg": "progress  95% (5MB)"}
- {"dt": "2023-03-08T07:33:48.826928", "lvl": "debug", "msg": "progress 100% (6MB)"}
- {"dt": "2023-03-08T07:33:48.846259", "lvl": "info", "msg": "6MB downloaded in 1.66s (3.68MB/s)"}
- {"dt": "2023-03-08T07:33:48.848668", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:00:02) [common]"}
- {"dt": "2023-03-08T07:33:48.849675", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "1.66", "extra": {"label": "modules", "md5sum": "0724e49cc73f2f495ae13aa5497b2bec", "sha256sum": "1dd2900e982fee1c2772266b84169ee4ebbb2f5410d241faff08c4642b1616a8", "sha512sum": "897029f872c5b8d5e70944a473d61ea0441f43dd2eaefc1c68a44d11330a77629738f741db40957f5c97c5b7072f48c67373fc47794abfda6e35af8893df9785", "size": ! "6392588"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-08T07:33:48.852068", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:00:02) [common]"}
- {"dt": "2023-03-08T07:33:48.853191", "lvl": "debug", "msg": "start: 1.5 prepare-tftp-overlay (timeout 00:09:55) [common]"}
- {"dt": "2023-03-08T07:33:48.854280", "lvl": "debug", "msg": "start: 1.5.1 extract-nfsrootfs (timeout 00:09:55) [common]"}
- {"dt": "2023-03-08T07:33:48.855371", "lvl": "debug", "msg": "end: 1.5.1 extract-nfsrootfs (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:48.856462", "lvl": "debug", "msg": "start: 1.5.2 lava-overlay (timeout 00:09:55) [common]"}
- {"dt": "2023-03-08T07:33:48.857334", "lvl": "info", "msg": "[common] skipped lava-overlay - no test action."}
- {"dt": "2023-03-08T07:33:48.858323", "lvl": "debug", "msg": "end: 1.5.2 lava-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:48.859449", "lvl": "debug", "msg": "start: 1.5.3 extract-overlay-ramdisk (timeout 00:09:55) [common]"}
- {"dt": "2023-03-08T07:33:49.819467", "lvl": "debug", "msg": "end: 1.5.3 extract-overlay-ramdisk (duration 00:00:01) [common]"}
- {"dt": "2023-03-08T07:33:49.822825", "lvl": "debug", "msg": "start: 1.5.4 extract-modules (timeout 00:09:54) [common]"}
- {"dt": "2023-03-08T07:33:49.824250", "lvl": "info", "msg": "extracting modules file /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/modules/modules.tar to /var/lib/lava/dispatcher/tmp/32164/extract-overlay-ramdisk-lz_gbb7k/ramdisk"}
- {"dt": "2023-03-08T07:33:51.237943", "lvl": "debug", "msg": "end: 1.5.4 extract-modules (duration 00:00:01) [common]"}
- {"dt": "2023-03-08T07:33:51.238921", "lvl": "debug", "msg": "start: 1.5.5 apply-overlay-tftp (timeout 00:09:53) [common]"}
- {"dt": "2023-03-08T07:33:51.239753", "lvl": "debug", "msg": "end: 1.5.5 apply-overlay-tftp (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:51.240462", "lvl": "debug", "msg": "start: 1.5.6 prepare-kernel (timeout 00:09:53) [common]"}
- {"dt": "2023-03-08T07:33:51.241134", "lvl": "debug", "msg": "start: 1.5.6.1 uboot-prepare-kernel (timeout 00:09:53) [common]"}
- {"dt": "2023-03-08T07:33:51.241825", "lvl": "debug", "msg": "end: 1.5.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:51.242455", "lvl": "debug", "msg": "end: 1.5.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:51.243135", "lvl": "debug", "msg": "start: 1.5.7 configure-preseed-file (timeout 00:09:53) [common]"}
- {"dt": "2023-03-08T07:33:51.243769", "lvl": "debug", "msg": "end: 1.5.7 configure-preseed-file (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:51.244407", "lvl": "debug", "msg": "start: 1.5.8 compress-ramdisk (timeout 00:09:53) [common]"}
- {"dt": "2023-03-08T07:33:51.244963", "lvl": "info", "msg": "Building ramdisk /var/lib/lava/dispatcher/tmp/32164/extract-overlay-ramdisk-lz_gbb7k/ramdisk.cpio containing /var/lib/lava/dispatcher/tmp/32164/extract-overlay-ramdisk-lz_gbb7k/ramdisk"}
- {"dt": "2023-03-08T07:33:53.760641", "lvl": "debug", "msg": ">> 90939 blocks\n"}
- {"dt": "2023-03-08T07:33:59.671156", "lvl": "debug", "msg": "Adding RAMdisk u-boot header."}
- {"dt": "2023-03-08T07:33:59.674469", "lvl": "debug", "msg": "mkimage -A arm64 -T ramdisk -C none -d /var/lib/lava/dispatcher/tmp/32164/extract-overlay-ramdisk-lz_gbb7k/ramdisk.cpio.gz /var/lib/lava/dispatcher/tmp/32164/extract-overlay-ramdisk-lz_gbb7k/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-08T07:33:59.832433", "lvl": "debug", "msg": "output: Image Name:   "}
- {"dt": "2023-03-08T07:33:59.834190", "lvl": "debug", "msg": "output: Created:      Wed Mar  8 07:33:59 2023"}
- {"dt": "2023-03-08T07:33:59.834837", "lvl": "debug", "msg": "output: Image Type:   AArch64 Linux RAMDisk Image (uncompressed)"}
- {"dt": "2023-03-08T07:33:59.835676", "lvl": "debug", "msg": "output: Data Size:    13780433 Bytes = 13457.45 KiB = 13.14 MiB"}
- {"dt": "2023-03-08T07:33:59.836507", "lvl": "debug", "msg": "output: Load Address: 00000000"}
- {"dt": "2023-03-08T07:33:59.837285", "lvl": "debug", "msg": "output: Entry Point:  00000000"}
- {"dt": "2023-03-08T07:33:59.838055", "lvl": "debug", "msg": "output: "}
- {"dt": "2023-03-08T07:33:59.839199", "lvl": "debug", "msg": "rename /var/lib/lava/dispatcher/tmp/32164/extract-overlay-ramdisk-lz_gbb7k/ramdisk.cpio.gz.uboot to /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-08T07:33:59.841268", "lvl": "debug", "msg": "end: 1.5.8 compress-ramdisk (duration 00:00:09) [common]"}
- {"dt": "2023-03-08T07:33:59.842621", "lvl": "debug", "msg": "end: 1.5 prepare-tftp-overlay (duration 00:00:11) [common]"}
- {"dt": "2023-03-08T07:33:59.843797", "lvl": "debug", "msg": "start: 1.6 lxc-create-udev-rule-action (timeout 00:09:44) [common]"}
- {"dt": "2023-03-08T07:33:59.844849", "lvl": "debug", "msg": "No LXC device requested"}
- {"dt": "2023-03-08T07:33:59.845922", "lvl": "debug", "msg": "end: 1.6 lxc-create-udev-rule-action (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:59.846840", "lvl": "debug", "msg": "Checking files for TFTP limit of 4294967296 bytes."}
- {"dt": "2023-03-08T07:33:59.850760", "lvl": "info", "msg": "end: 1 tftp-deploy (duration 00:00:16) [common]"}
- {"dt": "2023-03-08T07:33:59.851743", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:05:00) [common]"}
- {"dt": "2023-03-08T07:33:59.852623", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:05:00) [common]"}
- {"dt": "2023-03-08T07:33:59.853405", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:59.854201", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:05:00) [common]"}
- {"dt": "2023-03-08T07:33:59.855316", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2023-03-08T07:33:59.855968", "lvl": "debug", "msg": "- {BOOTX}: booti 0x00080000 0x02700000 0x02400000"}
- {"dt": "2023-03-08T07:33:59.856536", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x02400000"}
- {"dt": "2023-03-08T07:33:59.857078", "lvl": "debug", "msg": "- {DTB}: 32164/tftp-deploy-uxhk5i2y/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-08T07:33:59.857615", "lvl": "debug", "msg": "- {INITRD}: 32164/tftp-deploy-uxhk5i2y/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-08T07:33:59.858157", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x00080000"}
- {"dt": "2023-03-08T07:33:59.858689", "lvl": "debug", "msg": "- {KERNEL}: 32164/tftp-deploy-uxhk5i2y/kernel/Image"}
- {"dt": "2023-03-08T07:33:59.859275", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2023-03-08T07:33:59.859822", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2023-03-08T07:33:59.860363", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2023-03-08T07:33:59.860892", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x02700000"}
- {"dt": "2023-03-08T07:33:59.861413", "lvl": "debug", "msg": "- {RAMDISK}: 32164/tftp-deploy-uxhk5i2y/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-08T07:33:59.861937", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2023-03-08T07:33:59.862463", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2023-03-08T07:33:59.863077", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2023-03-08T07:33:59.863650", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2023-03-08T07:33:59.864191", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2023-03-08T07:33:59.864726", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2023-03-08T07:33:59.865244", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2023-03-08T07:33:59.865767", "lvl": "info", "msg": "- setenv initrd_high 0xffffffff"}
- {"dt": "2023-03-08T07:33:59.866282", "lvl": "info", "msg": "- setenv fdt_high 0xffffffff"}
- {"dt": "2023-03-08T07:33:59.866806", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2023-03-08T07:33:59.867373", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2023-03-08T07:33:59.867894", "lvl": "info", "msg": "- tftp 0x00080000 32164/tftp-deploy-uxhk5i2y/kernel/Image"}
- {"dt": "2023-03-08T07:33:59.868419", "lvl": "info", "msg": "- tftp 0x02700000 32164/tftp-deploy-uxhk5i2y/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-08T07:33:59.868973", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2023-03-08T07:33:59.869499", "lvl": "info", "msg": "- tftp 0x02400000 32164/tftp-deploy-uxhk5i2y/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-08T07:33:59.870024", "lvl": "info", "msg": "- setenv bootargs 'console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp'"}
- {"dt": "2023-03-08T07:33:59.870552", "lvl": "info", "msg": "- fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000 0x02400000"}
- {"dt": "2023-03-08T07:33:59.871325", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-03-08T07:33:59.871989", "lvl": "results", "msg": {"case": "bootloader-overlay", "definition": "lava", "duration": "0.02", "extra": {"dtb_addr": "0x02400000", "kernel_addr": "0x00080000", "ramdisk_addr": "0x02700000", "tee_addr": "0x83000000"}, "level": "2.2", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-08T07:33:59.873539", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:05:00) [common]"}
- {"dt": "2023-03-08T07:33:59.874251", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63003'"}
- {"dt": "2023-03-08T07:34:03.081489", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2023-03-08T07:34:03.084807", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:03) [common]"}
- {"dt": "2023-03-08T07:34:03.086071", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:04:57) [common]"}
- {"dt": "2023-03-08T07:34:03.087134", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:04:57) [common]"}
- {"dt": "2023-03-08T07:34:03.088181", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:04:57) [common]"}
- {"dt": "2023-03-08T07:34:03.089503", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '7'"}
- {"dt": "2023-03-08T07:34:06.538082", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-03-08T07:34:07.611265", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-03-08T07:34:07.647571", "lvl": "debug", "msg": "Returned 0 in 4 seconds"}
- {"dt": "2023-03-08T07:34:07.751895", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:05) [common]"}
- {"dt": "2023-03-08T07:34:07.754105", "lvl": "results", "msg": {"case": "pdu-reboot", "definition": "lava", "duration": "4.66", "extra": {"status": "success"}, "level": "2.4.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-08T07:34:07.758430", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:05) [common]"}
- {"dt": "2023-03-08T07:34:07.760967", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:04:52) [common]"}
- {"dt": "2023-03-08T07:34:07.763234", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2023-03-08T07:34:07.763928", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:05:00)"}
- {"dt": "2023-03-08T07:34:07.765835", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2023-03-08T07:34:07.766548", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2023-03-08T07:34:07.767155", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2023-03-08T07:34:14.300360", "lvl": "target", "msg": "\0"}
- {"dt": "2023-03-08T07:34:14.302376", "lvl": "target", "msg": ""}
- {"dt": "2023-03-08T07:34:14.316184", "lvl": "target", "msg": "U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)"}
- {"dt": "2023-03-08T07:34:14.318085", "lvl": "target", "msg": ""}
- {"dt": "2023-03-08T07:34:14.460307", "lvl": "target", "msg": "DRAM:  3.9 GiB"}
- {"dt": "2023-03-08T07:34:14.492045", "lvl": "target", "msg": "RPI 4 Model B (0xc03111)"}
- {"dt": "2023-03-08T07:34:14.529614", "lvl": "target", "msg": "MMC:   emmc2@7e340000: 0, mmcnr@7e300000: 1"}
- {"dt": "2023-03-08T07:34:14.596089", "lvl": "target", "msg": "Loading Environment from FAT... *** Warning - bad CRC, using default environment"}
- {"dt": "2023-03-08T07:34:14.597994", "lvl": "target", "msg": ""}
- {"dt": "2023-03-08T07:34:14.624807", "lvl": "target", "msg": "In:    serial"}
- {"dt": "2023-03-08T07:34:14.626733", "lvl": "target", "msg": "Out:   serial"}
- {"dt": "2023-03-08T07:34:14.628503", "lvl": "target", "msg": "Err:   serial"}
- {"dt": "2023-03-08T07:34:14.630996", "lvl": "target", "msg": "Net:   eth0: genet@7d580000"}
- {"dt": "2023-03-08T07:34:14.632887", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2023-03-08T07:34:14.634619", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2023-03-08T07:34:14.637218", "lvl": "input", "msg": "c"}
- {"dt": "2023-03-08T07:34:14.639788", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:00:07) [common]"}
- {"dt": "2023-03-08T07:34:14.640813", "lvl": "debug", "msg": "start: 2.4.3 bootloader-commands (timeout 00:04:45) [common]"}
- {"dt": "2023-03-08T07:34:14.641659", "lvl": "debug", "msg": "Setting prompt string to ['U-Boot>']"}
- {"dt": "2023-03-08T07:34:14.642422", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>'] (timeout 00:04:45)"}
- {"dt": "2023-03-08T07:34:14.659611", "lvl": "target", "msg": "Hit any key to stop autoboot:  2 \x03\b\b\b 0 "}
- {"dt": "2023-03-08T07:34:14.661297", "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-08T07:34:14.662233", "lvl": "input", "msg": "setenv autoload no\n"}
- {"dt": "2023-03-08T07:34:14.764126", "lvl": "target", "msg": "U-Boot> setenv autoload no"}
- {"dt": "2023-03-08T07:34:14.766110", "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:45)"}
- {"dt": "2023-03-08T07:34:14.778564", "lvl": "target", "msg": "setenv autoload no"}
- {"dt": "2023-03-08T07:34:14.779621", "lvl": "input", "msg": "setenv initrd_high 0xffffffff\n"}
- {"dt": "2023-03-08T07:34:14.881086", "lvl": "target", "msg": "U-Boot> setenv initrd_high 0xffffffff"}
- {"dt": "2023-03-08T07:34:14.882649", "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:45)"}
- {"dt": "2023-03-08T07:34:14.898743", "lvl": "target", "msg": "setenv initrd_high 0xffffffff"}
- {"dt": "2023-03-08T07:34:14.900968", "lvl": "input", "msg": "setenv fdt_high 0xffffffff\n"}
- {"dt": "2023-03-08T07:34:15.003531", "lvl": "target", "msg": "U-Boot> setenv fdt_high 0xffffffff"}
- {"dt": "2023-03-08T07:34:15.005694", "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:45)"}
- {"dt": "2023-03-08T07:34:15.010822", "lvl": "target", "msg": "setenv fdt_high 0xffffffff"}
- {"dt": "2023-03-08T07:34:15.012037", "lvl": "input", "msg": "dhcp\n"}
- {"dt": "2023-03-08T07:34:15.113800", "lvl": "target", "msg": "U-Boot> dhcp"}
- {"dt": "2023-03-08T07:34:15.116001", "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:45)"}
- {"dt": "2023-03-08T07:34:15.122759", "lvl": "target", "msg": "dhcp"}
- {"dt": "2023-03-08T07:34:17.441525", "lvl": "target", "msg": "genet@7d580000 Waiting for PHY auto negotiation to complete..... done"}
- {"dt": "2023-03-08T07:34:17.443584", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2023-03-08T07:34:17.681481", "lvl": "target", "msg": "BOOTP broadcast 2"}
- {"dt": "2023-03-08T07:34:18.193174", "lvl": "target", "msg": "BOOTP broadcast 3"}
- {"dt": "2023-03-08T07:34:18.473762", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (1028 ms)"}
- {"dt": "2023-03-08T07:34:18.476315", "lvl": "input", "msg": "setenv serverip 192.168.66.1\n"}
- {"dt": "2023-03-08T07:34:18.578856", "lvl": "target", "msg": "U-Boot> setenv serverip 192.168.66.1"}
- {"dt": "2023-03-08T07:34:18.580817", "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-08T07:34:18.585550", "lvl": "target", "msg": "setenv serverip 192.168.66.1"}
- {"dt": "2023-03-08T07:34:18.587935", "lvl": "input", "msg": "tftp 0x00080000 32164/tftp-deploy-uxhk5i2y/kernel/Image\n"}
- {"dt": "2023-03-08T07:34:18.690759", "lvl": "target", "msg": "U-Boot> tftp 0x00080000 32164/tftp-deploy-uxhk5i2y/kernel/Image"}
- {"dt": "2023-03-08T07:34:18.693022", "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-08T07:34:18.697777", "lvl": "target", "msg": "tftp 0x00080000 32164/tftp-deploy-uxhk5i2y/kernel/Image"}
- {"dt": "2023-03-08T07:34:18.721707", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-03-08T07:34:18.722825", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-03-08T07:34:18.725088", "lvl": "target", "msg": "Filename '32164/tftp-deploy-uxhk5i2y/kernel/Image'."}
- {"dt": "2023-03-08T07:34:18.726118", "lvl": "target", "msg": "Load address: 0x80000"}
- {"dt": "2023-03-08T07:34:45.791909", "lvl": "target", "msg": "Loading: *\bT #T #################################################  26 MiB"}
- {"dt": "2023-03-08T07:34:45.793865", "lvl": "target", "msg": "\t 982.4 KiB/s"}
- {"dt": "2023-03-08T07:34:45.795798", "lvl": "target", "msg": "done"}
- {"dt": "2023-03-08T07:34:45.798219", "lvl": "target", "msg": "Bytes transferred = 27247104 (19fc200 hex)"}
- {"dt": "2023-03-08T07:34:45.800645", "lvl": "input", "msg": "tftp 0x02700000 32164/tftp-deploy-uxhk5i2y/ramdisk/ramdisk.cpio.gz.uboot\n"}
- {"dt": "2023-03-08T07:34:45.903380", "lvl": "target", "msg": "U-Boot> tftp 0x02700000 32164/tftp-deploy-uxhk5i2y/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-08T07:34:45.905536", "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:14)"}
- {"dt": "2023-03-08T07:34:45.911084", "lvl": "target", "msg": "tftp 0x02700000 32164/tftp-deploy-uxhk5i2y/ramdisk/ramdisk.cpio.gz.uboot"}
- {"dt": "2023-03-08T07:34:45.940683", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-03-08T07:34:45.943124", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-03-08T07:34:45.944589", "lvl": "target", "msg": "Filename '32164/tftp-deploy-uxhk5i2y/ramdisk/ramdisk.cpio.gz.uboot'."}
- {"dt": "2023-03-08T07:34:45.945688", "lvl": "target", "msg": "Load address: 0x2700000"}
- {"dt": "2023-03-08T07:34:54.961286", "lvl": "target", "msg": "Loading: *\b##################################################  13.1 MiB"}
- {"dt": "2023-03-08T07:34:54.963331", "lvl": "target", "msg": "\t 1.5 MiB/s"}
- {"dt": "2023-03-08T07:34:54.965125", "lvl": "target", "msg": "done"}
- {"dt": "2023-03-08T07:34:54.976835", "lvl": "target", "msg": "Bytes transferred = 13780497 (d24611 hex)"}
- {"dt": "2023-03-08T07:34:54.978148", "lvl": "input", "msg": "setenv initrd_size ${filesize}\n"}
- {"dt": "2023-03-08T07:34:55.080080", "lvl": "target", "msg": "U-Boot> setenv initrd_size ${filesize}"}
- {"dt": "2023-03-08T07:34:55.082347", "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:05)"}
- {"dt": "2023-03-08T07:34:55.089179", "lvl": "target", "msg": "setenv initrd_size ${filesize}"}
- {"dt": "2023-03-08T07:34:55.091791", "lvl": "input", "msg": "tftp 0x02400000 32164/tftp-deploy-uxhk5i2y/dtb/bcm2711-rpi-4-b.dtb\n"}
- {"dt": "2023-03-08T07:34:55.194746", "lvl": "target", "msg": "U-Boot> tftp 0x02400000 32164/tftp-deploy-uxhk5i2y/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-08T07:34:55.197015", "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:05)"}
- {"dt": "2023-03-08T07:34:55.230646", "lvl": "target", "msg": "tftp 0x02400000 32164/tftp-deploy-uxhk5i2y/dtb/bcm2711-rpi-4-b.dtb"}
- {"dt": "2023-03-08T07:34:55.232628", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-03-08T07:34:55.235581", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-03-08T07:34:55.237458", "lvl": "target", "msg": "Filename '32164/tftp-deploy-uxhk5i2y/dtb/bcm2711-rpi-4-b.dtb'."}
- {"dt": "2023-03-08T07:34:55.239188", "lvl": "target", "msg": "Load address: 0x2400000"}
- {"dt": "2023-03-08T07:34:55.256649", "lvl": "target", "msg": "Loading: *\b##################################################  21.7 KiB"}
- {"dt": "2023-03-08T07:34:55.258257", "lvl": "target", "msg": "\t 942.4 KiB/s"}
- {"dt": "2023-03-08T07:34:55.259876", "lvl": "target", "msg": "done"}
- {"dt": "2023-03-08T07:34:55.261923", "lvl": "target", "msg": "Bytes transferred = 22210 (56c2 hex)"}
- {"dt": "2023-03-08T07:34:55.263124", "lvl": "input", "msg": "setenv bootargs 'console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp'\n"}
- {"dt": "2023-03-08T07:34:55.364967", "lvl": "target", "msg": "U-Boot> setenv bootargs 'console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp'"}
- {"dt": "2023-03-08T07:34:55.367221", "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-08T07:34:55.386631", "lvl": "target", "msg": "setenv bootargs 'console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp'"}
- {"dt": "2023-03-08T07:34:55.388030", "lvl": "input", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000 0x02400000\n"}
- {"dt": "2023-03-08T07:34:55.489985", "lvl": "target", "msg": "U-Boot> fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000 0x02400000"}
- {"dt": "2023-03-08T07:34:55.492310", "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-08T07:34:55.494801", "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-08T07:34:55.498948", "lvl": "target", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000 0x02400000"}
- {"dt": "2023-03-08T07:34:55.538766", "lvl": "target", "msg": "libfdt fdt_path_offset() returned FDT_ERR_BADPATH"}
- {"dt": "2023-03-08T07:34:55.540219", "lvl": "target", "msg": "## Loading init Ramdisk from Legacy Image at 02700000 ..."}
- {"dt": "2023-03-08T07:34:55.541452", "lvl": "target", "msg": "   Image Name:   "}
- {"dt": "2023-03-08T07:34:55.542642", "lvl": "target", "msg": "   Image Type:   AArch64 Linux RAMDisk Image (uncompressed)"}
- {"dt": "2023-03-08T07:34:55.543480", "lvl": "target", "msg": "   Data Size:    13780433 Bytes = 13.1 MiB"}
- {"dt": "2023-03-08T07:34:55.544544", "lvl": "target", "msg": "   Load Address: 00000000"}
- {"dt": "2023-03-08T07:34:55.545234", "lvl": "target", "msg": "   Entry Point:  00000000"}
- {"dt": "2023-03-08T07:34:55.714208", "lvl": "target", "msg": "   Verifying Checksum ... OK"}
- {"dt": "2023-03-08T07:34:55.715398", "lvl": "target", "msg": "## Flattened Device Tree blob at 02400000"}
- {"dt": "2023-03-08T07:34:55.716415", "lvl": "target", "msg": "   Booting using the fdt blob at 0x2400000"}
- {"dt": "2023-03-08T07:34:55.796617", "lvl": "target", "msg": "   Loading Ramdisk to 3a224000, end 3af485d1 ... OK"}
- {"dt": "2023-03-08T07:34:55.817400", "lvl": "target", "msg": "   Loading Device Tree to 000000003a21b000, end 000000003a223fff ... OK"}
- {"dt": "2023-03-08T07:34:55.818830", "lvl": "target", "msg": ""}
- {"dt": "2023-03-08T07:34:55.821500", "lvl": "debug", "msg": "end: 2.4.3 bootloader-commands (duration 00:00:41) [common]"}
- {"dt": "2023-03-08T07:34:55.823636", "lvl": "debug", "msg": "start: 2.4.4 auto-login-action (timeout 00:04:04) [common]"}
- {"dt": "2023-03-08T07:34:55.825403", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2023-03-08T07:34:55.827150", "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-08T07:34:55.828870", "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-08T07:34:55.831922", "lvl": "target", "msg": "Starting kernel ..."}
- {"dt": "2023-03-08T07:34:55.832599", "lvl": "target", "msg": ""}
- {"dt": "2023-03-08T07:34:57.675477", "lvl": "target", "msg": "<6>[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]"}
- {"dt": "2023-03-08T07:34:57.677807", "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-08T07:34:57.679699", "lvl": "target", "msg": "<6>[    0.000000] Machine model: Raspberry Pi 4 Model B"}
- {"dt": "2023-03-08T07:34:57.681476", "lvl": "target", "msg": "<6>[    0.000000] efi: Getting EFI parameters from FDT:"}
- {"dt": "2023-03-08T07:34:57.683362", "lvl": "target", "msg": "<6>[    0.000000] efi: UEFI not found."}
- {"dt": "2023-03-08T07:34:57.685527", "lvl": "target", "msg": "<6>[    0.000000] Reserved memory: created CMA memory pool at 0x0000000036000000, size 64 MiB"}
- {"dt": "2023-03-08T07:34:57.687943", "lvl": "debug", "msg": "start: 2.4.4.1 login-action (timeout 00:04:02) [common]"}
- {"dt": "2023-03-08T07:34:57.688606", "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-08T07:34:57.689192", "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-08T07:34:57.689718", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2023-03-08T07:34:57.690174", "lvl": "debug", "msg": "No login prompt set."}
- {"dt": "2023-03-08T07:34:57.690643", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2023-03-08T07:34:57.691150", "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-08T07:34:57.692025", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:04:02)"}
- {"dt": "2023-03-08T07:34:57.718598", "lvl": "target", "msg": "<6>[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool"}
- {"dt": "2023-03-08T07:34:57.719575", "lvl": "target", "msg": "<6>[    0.000000] NUMA: No NUMA configuration found"}
- {"dt": "2023-03-08T07:34:57.720381", "lvl": "target", "msg": "<6>[    0.000000] NUMA: Faking a node at [mem 0x0000000000000000-0x00000000fbffffff]"}
- {"dt": "2023-03-08T07:34:57.721163", "lvl": "target", "msg": "<6>[    0.000000] NUMA: NODE_DATA [mem 0xfb81d100-0xfb81efff]"}
- {"dt": "2023-03-08T07:34:57.721983", "lvl": "target", "msg": "<6>[    0.000000] Zone ranges:"}
- {"dt": "2023-03-08T07:34:57.722950", "lvl": "target", "msg": "<6>[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003fffffff]"}
- {"dt": "2023-03-08T07:34:57.723766", "lvl": "target", "msg": "<6>[    0.000000]   DMA32    [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2023-03-08T07:34:57.724577", "lvl": "target", "msg": "<6>[    0.000000]   Normal   empty"}
- {"dt": "2023-03-08T07:34:57.762078", "lvl": "target", "msg": "<6>[    0.000000] Movable zone start for each node"}
- {"dt": "2023-03-08T07:34:57.763649", "lvl": "target", "msg": "<6>[    0.000000] Early memory node ranges"}
- {"dt": "2023-03-08T07:34:57.764925", "lvl": "target", "msg": "<6>[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]"}
- {"dt": "2023-03-08T07:34:57.766113", "lvl": "target", "msg": "<6>[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2023-03-08T07:34:57.767372", "lvl": "target", "msg": "<6>[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]"}
- {"dt": "2023-03-08T07:34:57.768597", "lvl": "target", "msg": "<6>[    0.000000] percpu: Embedded 23 pages/cpu s53272 r8192 d32744 u94208"}
- {"dt": "2023-03-08T07:34:57.769792", "lvl": "target", "msg": "<6>[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2023-03-08T07:34:57.805883", "lvl": "target", "msg": "<6>[    0.000000] CPU features: detected: EL2 vector hardening"}
- {"dt": "2023-03-08T07:34:57.808439", "lvl": "target", "msg": "<4>[    0.000000] ARM_SMCCC_ARCH_WORKAROUND_1 missing from firmware"}
- {"dt": "2023-03-08T07:34:57.810073", "lvl": "target", "msg": "<6>[    0.000000] CPU features: detected: ARM erratum 1319367"}
- {"dt": "2023-03-08T07:34:57.811670", "lvl": "target", "msg": "<6>[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 996912"}
- {"dt": "2023-03-08T07:34:57.813169", "lvl": "target", "msg": "<6>[    0.000000] Policy zone: DMA32"}
- {"dt": "2023-03-08T07:34:57.814630", "lvl": "target", "msg": "<5>[    0.000000] Kernel command line: console=ttyS1,115200n8 root=/dev/ram0 console_msg_format=syslog ip=dhcp"}
- {"dt": "2023-03-08T07:34:57.816485", "lvl": "target", "msg": "<6>[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2023-03-08T07:34:57.850225", "lvl": "target", "msg": "<6>[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2023-03-08T07:34:57.851493", "lvl": "target", "msg": "<6>[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off"}
- {"dt": "2023-03-08T07:34:57.852937", "lvl": "target", "msg": "<6>[    0.000000] software IO TLB: mapped [mem 0x32000000-0x36000000] (64MB)"}
- {"dt": "2023-03-08T07:34:57.854135", "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-08T07:34:57.855592", "lvl": "target", "msg": "<6>[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1"}
- {"dt": "2023-03-08T07:34:57.893745", "lvl": "target", "msg": "<6>[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2023-03-08T07:34:57.896439", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2023-03-08T07:34:57.898094", "lvl": "target", "msg": "<6>[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4."}
- {"dt": "2023-03-08T07:34:57.899703", "lvl": "target", "msg": "<6>[    0.000000] \tTasks RCU enabled."}
- {"dt": "2023-03-08T07:34:57.901181", "lvl": "target", "msg": "<6>[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2023-03-08T07:34:57.902652", "lvl": "target", "msg": "<6>[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4"}
- {"dt": "2023-03-08T07:34:57.904252", "lvl": "target", "msg": "<6>[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2023-03-08T07:34:57.937487", "lvl": "target", "msg": "<6>[    0.000000] GIC: Using split EOI/Deactivate mode"}
- {"dt": "2023-03-08T07:34:57.938870", "lvl": "target", "msg": "<5>[    0.000000] random: get_random_bytes called from start_kernel+0x2a8/0x434 with crng_init=0"}
- {"dt": "2023-03-08T07:34:57.940033", "lvl": "target", "msg": "<6>[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys)."}
- {"dt": "2023-03-08T07:34:57.941124", "lvl": "target", "msg": "<6>[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns"}
- {"dt": "2023-03-08T07:34:57.942400", "lvl": "target", "msg": "<6>[    0.000005] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns"}
- {"dt": "2023-03-08T07:34:57.943752", "lvl": "target", "msg": "<6>[    0.000176] Console: colour dummy device 80x25"}
- {"dt": "2023-03-08T07:34:57.982143", "lvl": "target", "msg": "<6>[    0.000260] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)"}
- {"dt": "2023-03-08T07:34:57.983598", "lvl": "target", "msg": "<6>[    0.000275] pid_max: default: 32768 minimum: 301"}
- {"dt": "2023-03-08T07:34:57.984925", "lvl": "target", "msg": "<6>[    0.000376] LSM: Security Framework initializing"}
- {"dt": "2023-03-08T07:34:57.986478", "lvl": "target", "msg": "<6>[    0.000501] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-08T07:34:57.987932", "lvl": "target", "msg": "<6>[    0.000569] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-08T07:34:57.989260", "lvl": "target", "msg": "<6>[    0.032022] rcu: Hierarchical SRCU implementation."}
- {"dt": "2023-03-08T07:34:57.990566", "lvl": "target", "msg": "<6>[    0.041802] EFI services will not be available."}
- {"dt": "2023-03-08T07:34:58.025065", "lvl": "target", "msg": "<6>[    0.048062] smp: Bringing up secondary CPUs ..."}
- {"dt": "2023-03-08T07:34:58.027307", "lvl": "target", "msg": "<6>[    0.080197] Detected PIPT I-cache on CPU1"}
- {"dt": "2023-03-08T07:34:58.028560", "lvl": "target", "msg": "<6>[    0.080251] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]"}
- {"dt": "2023-03-08T07:34:58.029753", "lvl": "target", "msg": "<6>[    0.112263] Detected PIPT I-cache on CPU2"}
- {"dt": "2023-03-08T07:34:58.030997", "lvl": "target", "msg": "<6>[    0.112302] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]"}
- {"dt": "2023-03-08T07:34:58.032225", "lvl": "target", "msg": "<6>[    0.144343] Detected PIPT I-cache on CPU3"}
- {"dt": "2023-03-08T07:34:58.033392", "lvl": "target", "msg": "<6>[    0.144381] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]"}
- {"dt": "2023-03-08T07:34:58.034768", "lvl": "target", "msg": "<6>[    0.144464] smp: Brought up 1 node, 4 CPUs"}
- {"dt": "2023-03-08T07:34:58.071429", "lvl": "target", "msg": "<6>[    0.144491] SMP: Total of 4 processors activated."}
- {"dt": "2023-03-08T07:34:58.072392", "lvl": "target", "msg": "<6>[    0.144501] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2023-03-08T07:34:58.073394", "lvl": "target", "msg": "<6>[    0.144511] CPU features: detected: CRC32 instructions"}
- {"dt": "2023-03-08T07:34:58.074314", "lvl": "target", "msg": "<6>[    0.161238] CPU: All CPU(s) started at EL2"}
- {"dt": "2023-03-08T07:34:58.075318", "lvl": "target", "msg": "<6>[    0.161278] alternatives: patching kernel code"}
- {"dt": "2023-03-08T07:34:58.076128", "lvl": "target", "msg": "<6>[    0.162994] devtmpfs: initialized"}
- {"dt": "2023-03-08T07:34:58.076929", "lvl": "target", "msg": "<4>[    0.167395] KASLR disabled due to lack of seed"}
- {"dt": "2023-03-08T07:34:58.078559", "lvl": "target", "msg": "<6>[    0.167784] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2023-03-08T07:34:58.112125", "lvl": "target", "msg": "<6>[    0.167806] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-08T07:34:58.112706", "lvl": "target", "msg": "<6>[    0.169609] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2023-03-08T07:34:58.114005", "lvl": "target", "msg": "<6>[    0.170887] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2023-03-08T07:34:58.114992", "lvl": "target", "msg": "<6>[    0.170891] thermal_sys: Registered thermal governor 'power_allocator'"}
- {"dt": "2023-03-08T07:34:58.115871", "lvl": "target", "msg": "<6>[    0.171095] DMI not present or invalid."}
- {"dt": "2023-03-08T07:34:58.116741", "lvl": "target", "msg": "<6>[    0.171709] NET: Registered protocol family 16"}
- {"dt": "2023-03-08T07:34:58.117629", "lvl": "target", "msg": "<6>[    0.173222] DMA: preallocated 256 KiB pool for atomic allocations"}
- {"dt": "2023-03-08T07:34:58.156107", "lvl": "target", "msg": "<6>[    0.173239] audit: initializing netlink subsys (disabled)"}
- {"dt": "2023-03-08T07:34:58.158095", "lvl": "target", "msg": "<5>[    0.173414] audit: type=2000 audit(0.172:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2023-03-08T07:34:58.159404", "lvl": "target", "msg": "<6>[    0.174542] cpuidle: using governor menu"}
- {"dt": "2023-03-08T07:34:58.160551", "lvl": "target", "msg": "<6>[    0.174812] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2023-03-08T07:34:58.161736", "lvl": "target", "msg": "<6>[    0.174901] ASID allocator initialised with 65536 entries"}
- {"dt": "2023-03-08T07:34:58.162990", "lvl": "target", "msg": "<6>[    0.176153] Serial: AMBA PL011 UART driver"}
- {"dt": "2023-03-08T07:34:58.164226", "lvl": "target", "msg": "<6>[    0.196123] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages"}
- {"dt": "2023-03-08T07:34:58.200150", "lvl": "target", "msg": "<6>[    0.196138] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages"}
- {"dt": "2023-03-08T07:34:58.203062", "lvl": "target", "msg": "<6>[    0.196148] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages"}
- {"dt": "2023-03-08T07:34:58.204675", "lvl": "target", "msg": "<6>[    0.196157] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages"}
- {"dt": "2023-03-08T07:34:58.206175", "lvl": "target", "msg": "<6>[    0.198805] cryptd: max_cpu_qlen set to 1000"}
- {"dt": "2023-03-08T07:34:58.207757", "lvl": "target", "msg": "<6>[    0.203631] ACPI: Interpreter disabled."}
- {"dt": "2023-03-08T07:34:58.209242", "lvl": "target", "msg": "<6>[    0.204867] iommu: Default domain type: Translated "}
- {"dt": "2023-03-08T07:34:58.210735", "lvl": "target", "msg": "<6>[    0.205088] vgaarb: loaded"}
- {"dt": "2023-03-08T07:34:58.211617", "lvl": "target", "msg": "<5>[    0.205407] SCSI subsystem initialized"}
- {"dt": "2023-03-08T07:34:58.212155", "lvl": "target", "msg": "<6>[    0.205804] usbcore: registered new interface driver usbfs"}
- {"dt": "2023-03-08T07:34:58.244180", "lvl": "target", "msg": "<6>[    0.205848] usbcore: registered new interface driver hub"}
- {"dt": "2023-03-08T07:34:58.246006", "lvl": "target", "msg": "<6>[    0.205921] usbcore: registered new device driver usb"}
- {"dt": "2023-03-08T07:34:58.247182", "lvl": "target", "msg": "<4>[    0.206074] usb_phy_generic phy: phy supply vcc not found, using dummy regulator"}
- {"dt": "2023-03-08T07:34:58.248424", "lvl": "target", "msg": "<6>[    0.206676] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2023-03-08T07:34:58.249749", "lvl": "target", "msg": "<6>[    0.206685] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2023-03-08T07:34:58.251127", "lvl": "target", "msg": "<6>[    0.206703] PTP clock support registered"}
- {"dt": "2023-03-08T07:34:58.252644", "lvl": "target", "msg": "<6>[    0.206822] EDAC MC: Ver: 3.0.0"}
- {"dt": "2023-03-08T07:34:58.253937", "lvl": "target", "msg": "<6>[    0.207995] FPGA manager framework"}
- {"dt": "2023-03-08T07:34:58.289690", "lvl": "target", "msg": "<6>[    0.208075] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2023-03-08T07:34:58.291814", "lvl": "target", "msg": "<6>[    0.208829] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2023-03-08T07:34:58.293624", "lvl": "target", "msg": "<5>[    0.209060] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2023-03-08T07:34:58.295492", "lvl": "target", "msg": "<6>[    0.209123] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2023-03-08T07:34:58.296181", "lvl": "target", "msg": "<6>[    0.209313] pnp: PnP ACPI: disabled"}
- {"dt": "2023-03-08T07:34:58.296867", "lvl": "target", "msg": "<6>[    0.215773] NET: Registered protocol family 2"}
- {"dt": "2023-03-08T07:34:58.297677", "lvl": "target", "msg": "<6>[    0.216209] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2023-03-08T07:34:58.332778", "lvl": "target", "msg": "<6>[    0.216248] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2023-03-08T07:34:58.333966", "lvl": "target", "msg": "<6>[    0.216434] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)"}
- {"dt": "2023-03-08T07:34:58.335133", "lvl": "target", "msg": "<6>[    0.216873] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2023-03-08T07:34:58.336426", "lvl": "target", "msg": "<6>[    0.217047] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-08T07:34:58.337529", "lvl": "target", "msg": "<6>[    0.217097] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-03-08T07:34:58.338810", "lvl": "target", "msg": "<6>[    0.217273] NET: Registered protocol family 1"}
- {"dt": "2023-03-08T07:34:58.375716", "lvl": "target", "msg": "<6>[    0.217787] RPC: Registered named UNIX socket transport module."}
- {"dt": "2023-03-08T07:34:58.378062", "lvl": "target", "msg": "<6>[    0.217797] RPC: Registered udp transport module."}
- {"dt": "2023-03-08T07:34:58.379600", "lvl": "target", "msg": "<6>[    0.217804] RPC: Registered tcp transport module."}
- {"dt": "2023-03-08T07:34:58.381081", "lvl": "target", "msg": "<6>[    0.217811] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2023-03-08T07:34:58.382636", "lvl": "target", "msg": "<6>[    0.217825] PCI: CLS 0 bytes, default 64"}
- {"dt": "2023-03-08T07:34:58.384270", "lvl": "target", "msg": "<6>[    0.218009] Unpacking initramfs..."}
- {"dt": "2023-03-08T07:34:58.385807", "lvl": "target", "msg": "<6>[    1.261356] Freeing initrd memory: 13456K"}
- {"dt": "2023-03-08T07:34:58.387668", "lvl": "target", "msg": "<6>[    1.262245] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available"}
- {"dt": "2023-03-08T07:34:58.419426", "lvl": "target", "msg": "<6>[    1.262369] kvm [1]: IPA Size Limit: 44bits"}
- {"dt": "2023-03-08T07:34:58.420550", "lvl": "target", "msg": "<6>[    1.263354] kvm [1]: vgic interrupt IRQ1"}
- {"dt": "2023-03-08T07:34:58.422621", "lvl": "target", "msg": "<6>[    1.263502] kvm [1]: Hyp mode initialized successfully"}
- {"dt": "2023-03-08T07:34:58.423879", "lvl": "target", "msg": "<5>[    1.338048] Initialise system trusted keyrings"}
- {"dt": "2023-03-08T07:34:58.424974", "lvl": "target", "msg": "<6>[    1.338218] workingset: timestamp_bits=44 max_order=20 bucket_order=0"}
- {"dt": "2023-03-08T07:34:58.426069", "lvl": "target", "msg": "<6>[    1.345333] squashfs: version 4.0 (2009/01/31) Phillip Lougher"}
- {"dt": "2023-03-08T07:34:58.427225", "lvl": "target", "msg": "<5>[    1.346091] NFS: Registering the id_resolver key type"}
- {"dt": "2023-03-08T07:34:58.428369", "lvl": "target", "msg": "<5>[    1.346120] Key type id_resolver registered"}
- {"dt": "2023-03-08T07:34:58.429663", "lvl": "target", "msg": "<5>[    1.346128] Key type id_legacy registered"}
- {"dt": "2023-03-08T07:34:58.464233", "lvl": "target", "msg": "<6>[    1.346144] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2023-03-08T07:34:58.465446", "lvl": "target", "msg": "<6>[    1.346310] 9p: Installing v9fs 9p2000 file system support"}
- {"dt": "2023-03-08T07:34:58.466545", "lvl": "target", "msg": "<5>[    1.380063] Key type asymmetric registered"}
- {"dt": "2023-03-08T07:34:58.467745", "lvl": "target", "msg": "<5>[    1.380076] Asymmetric key parser 'x509' registered"}
- {"dt": "2023-03-08T07:34:58.468957", "lvl": "target", "msg": "<6>[    1.380132] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)"}
- {"dt": "2023-03-08T07:34:58.470184", "lvl": "target", "msg": "<6>[    1.380142] io scheduler mq-deadline registered"}
- {"dt": "2023-03-08T07:34:58.471464", "lvl": "target", "msg": "<6>[    1.380150] io scheduler kyber registered"}
- {"dt": "2023-03-08T07:34:58.472889", "lvl": "target", "msg": "<4>[    1.390426] EINJ: ACPI disabled."}
- {"dt": "2023-03-08T07:34:58.519402", "lvl": "target", "msg": "<6>[    1.404093] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled"}
- {"dt": "2023-03-08T07:34:58.521921", "lvl": "target", "msg": "<6>[    1.405872] printk: console [ttyS1] disabled"}
- {"dt": "2023-03-08T07:34:58.523458", "lvl": "target", "msg": "<6>[    1.405958] fe215040.serial: ttyS1 at MMIO 0xfe215040 (irq = 18, base_baud = 62499999) is a 16550"}
- {"dt": "2023-03-08T07:34:58.524961", "lvl": "target", "msg": "<6>[    2.256907] printk: console [ttyS1] enabled"}
- {"dt": "2023-03-08T07:34:58.526502", "lvl": "target", "msg": "<6>[    2.262466] SuperH (H)SCI(F) driver initialized"}
- {"dt": "2023-03-08T07:34:58.528157", "lvl": "target", "msg": "<6>[    2.267823] msm_serial: driver initialized"}
- {"dt": "2023-03-08T07:34:58.529709", "lvl": "target", "msg": "<4>[    2.273637] cacheinfo: Unable to detect cache hierarchy for CPU 0"}
- {"dt": "2023-03-08T07:34:58.531420", "lvl": "target", "msg": "<6>[    2.288354] loop: module loaded"}
- {"dt": "2023-03-08T07:34:58.570428", "lvl": "target", "msg": "<6>[    2.292925] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver"}
- {"dt": "2023-03-08T07:34:58.571572", "lvl": "target", "msg": "<6>[    2.305109] libphy: Fixed MDIO Bus: probed"}
- {"dt": "2023-03-08T07:34:58.572606", "lvl": "target", "msg": "<6>[    2.309829] tun: Universal TUN/TAP device driver, 1.6"}
- {"dt": "2023-03-08T07:34:58.573611", "lvl": "target", "msg": "<6>[    2.315941] thunder_xcv, ver 1.0"}
- {"dt": "2023-03-08T07:34:58.574797", "lvl": "target", "msg": "<6>[    2.319538] thunder_bgx, ver 1.0"}
- {"dt": "2023-03-08T07:34:58.575876", "lvl": "target", "msg": "<6>[    2.323120] nicpf, ver 1.0"}
- {"dt": "2023-03-08T07:34:58.576869", "lvl": "target", "msg": "<6>[    2.326678] hclge is initializing"}
- {"dt": "2023-03-08T07:34:58.577850", "lvl": "target", "msg": "<6>[    2.330509] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version"}
- {"dt": "2023-03-08T07:34:58.579068", "lvl": "target", "msg": "<6>[    2.338117] hns3: Copyright (c) 2017 Huawei Corporation."}
- {"dt": "2023-03-08T07:34:58.614711", "lvl": "target", "msg": "<6>[    2.343845] e1000e: Intel(R) PRO/1000 Network Driver - 3.2.6-k"}
- {"dt": "2023-03-08T07:34:58.617091", "lvl": "target", "msg": "<6>[    2.350035] e1000e: Copyright(c) 1999 - 2015 Intel Corporation."}
- {"dt": "2023-03-08T07:34:58.618399", "lvl": "target", "msg": "<6>[    2.356350] igb: Intel(R) Gigabit Ethernet Network Driver - version 5.6.0-k"}
- {"dt": "2023-03-08T07:34:58.619726", "lvl": "target", "msg": "<6>[    2.363686] igb: Copyright (c) 2007-2014 Intel Corporation."}
- {"dt": "2023-03-08T07:34:58.620949", "lvl": "target", "msg": "<6>[    2.369663] igbvf: Intel(R) Gigabit Virtual Function Network Driver - version 2.4.0-k"}
- {"dt": "2023-03-08T07:34:58.622163", "lvl": "target", "msg": "<6>[    2.377884] igbvf: Copyright (c) 2009 - 2012 Intel Corporation."}
- {"dt": "2023-03-08T07:34:58.623654", "lvl": "target", "msg": "<6>[    2.384477] sky2: driver version 1.30"}
- {"dt": "2023-03-08T07:34:58.660627", "lvl": "target", "msg": "<6>[    2.389155] VFIO - User Level meta-driver version: 0.3"}
- {"dt": "2023-03-08T07:34:58.663103", "lvl": "target", "msg": "<6>[    2.396267] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"}
- {"dt": "2023-03-08T07:34:58.664561", "lvl": "target", "msg": "<6>[    2.403182] ehci-pci: EHCI PCI platform driver"}
- {"dt": "2023-03-08T07:34:58.665912", "lvl": "target", "msg": "<6>[    2.408005] ehci-platform: EHCI generic platform driver"}
- {"dt": "2023-03-08T07:34:58.667356", "lvl": "target", "msg": "<6>[    2.413693] ehci-orion: EHCI orion driver"}
- {"dt": "2023-03-08T07:34:58.668716", "lvl": "target", "msg": "<6>[    2.418125] ehci-exynos: EHCI Exynos driver"}
- {"dt": "2023-03-08T07:34:58.670077", "lvl": "target", "msg": "<6>[    2.422730] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"}
- {"dt": "2023-03-08T07:34:58.671468", "lvl": "target", "msg": "<6>[    2.429289] ohci-pci: OHCI PCI platform driver"}
- {"dt": "2023-03-08T07:34:58.714400", "lvl": "target", "msg": "<6>[    2.434099] ohci-platform: OHCI generic platform driver"}
- {"dt": "2023-03-08T07:34:58.716260", "lvl": "target", "msg": "<6>[    2.439784] ohci-exynos: OHCI Exynos driver"}
- {"dt": "2023-03-08T07:34:58.717350", "lvl": "target", "msg": "<6>[    2.444721] usbcore: registered new interface driver usb-storage"}
- {"dt": "2023-03-08T07:34:58.718345", "lvl": "target", "msg": "<6>[    2.453698] i2c /dev entries driver"}
- {"dt": "2023-03-08T07:34:58.719443", "lvl": "target", "msg": "<6>[    2.461931] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer"}
- {"dt": "2023-03-08T07:34:58.720460", "lvl": "target", "msg": "<6>[    2.469625] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2023-03-08T07:34:58.721460", "lvl": "target", "msg": "<6>[    2.476175] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2023-03-08T07:34:58.722660", "lvl": "target", "msg": "<6>[    2.481253] Synopsys Designware Multimedia Card Interface Driver"}
- {"dt": "2023-03-08T07:34:58.766694", "lvl": "target", "msg": "<6>[    2.488547] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2023-03-08T07:34:58.769293", "lvl": "target", "msg": "<6>[    2.496756] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2023-03-08T07:34:58.770749", "lvl": "target", "msg": "<6>[    2.504614] usbcore: registered new interface driver usbhid"}
- {"dt": "2023-03-08T07:34:58.772179", "lvl": "target", "msg": "<6>[    2.510548] usbhid: USB HID core driver"}
- {"dt": "2023-03-08T07:34:58.773524", "lvl": "target", "msg": "<6>[    2.515536] bcm2835-mbox fe00b880.mailbox: mailbox enabled"}
- {"dt": "2023-03-08T07:34:58.774872", "lvl": "target", "msg": "<6>[    2.524738] NET: Registered protocol family 17"}
- {"dt": "2023-03-08T07:34:58.776272", "lvl": "target", "msg": "<6>[    2.529722] 9pnet: Installing 9P2000 support"}
- {"dt": "2023-03-08T07:34:58.777876", "lvl": "target", "msg": "<5>[    2.534374] Key type dns_resolver registered"}
- {"dt": "2023-03-08T07:34:58.830003", "lvl": "target", "msg": "<6>[    2.539312] registered taskstats version 1"}
- {"dt": "2023-03-08T07:34:58.832188", "lvl": "target", "msg": "<5>[    2.543751] Loading compiled-in X.509 certificates"}
- {"dt": "2023-03-08T07:34:58.833388", "lvl": "target", "msg": "<6>[    2.553367] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 16, base_baud = 0) is a PL011 rev2"}
- {"dt": "2023-03-08T07:34:58.834501", "lvl": "target", "msg": "<6>[    2.562834] serial serial0: tty port ttyAMA0 registered"}
- {"dt": "2023-03-08T07:34:58.835728", "lvl": "target", "msg": "<6>[    2.578498] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-01-22 17:23"}
- {"dt": "2023-03-08T07:34:58.836838", "lvl": "target", "msg": "<4>[    2.591553] dwc2 fe980000.usb: fe980000.usb supply vusb_d not found, using dummy regulator"}
- {"dt": "2023-03-08T07:34:58.848079", "lvl": "target", "msg": "<4>[    2.600317] dwc2 fe980000.usb: fe980000.usb supply vusb_a not found, using dummy regulator"}
- {"dt": "2023-03-08T07:34:58.966040", "lvl": "target", "msg": "<6>[    2.709811] dwc2 fe980000.usb: EPs: 8, dedicated fifos, 4080 entries in SPRAM"}
- {"dt": "2023-03-08T07:34:58.969601", "lvl": "target", "msg": "<6>[    2.721162] sdhci-iproc fe300000.sdhci: allocated mmc-pwrseq"}
- {"dt": "2023-03-08T07:34:59.008136", "lvl": "target", "msg": "<6>[    2.759273] mmc0: SDHCI controller on fe300000.sdhci [fe300000.sdhci] using PIO"}
- {"dt": "2023-03-08T07:34:59.074974", "lvl": "target", "msg": "<4>[    2.785172] mmc0: queuing unknown CIS tuple 0x80 (2 bytes)"}
- {"dt": "2023-03-08T07:34:59.076905", "lvl": "target", "msg": "<4>[    2.792699] mmc0: queuing unknown CIS tuple 0x80 (3 bytes)"}
- {"dt": "2023-03-08T07:34:59.078719", "lvl": "target", "msg": "<4>[    2.800210] mmc0: queuing unknown CIS tuple 0x80 (3 bytes)"}
- {"dt": "2023-03-08T07:34:59.080582", "lvl": "target", "msg": "<4>[    2.809215] mmc0: queuing unknown CIS tuple 0x80 (7 bytes)"}
- {"dt": "2023-03-08T07:34:59.082706", "lvl": "target", "msg": "<4>[    2.816726] mmc0: queuing unknown CIS tuple 0x80 (3 bytes)"}
- {"dt": "2023-03-08T07:34:59.084642", "lvl": "target", "msg": "<6>[    2.822586] mmc1: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA"}
- {"dt": "2023-03-08T07:34:59.086438", "lvl": "target", "msg": "<6>[    2.832108] hctosys: unable to open rtc device (rtc0)"}
- {"dt": "2023-03-08T07:34:59.124220", "lvl": "target", "msg": "<5>[    2.883072] random: fast init done"}
- {"dt": "2023-03-08T07:34:59.149495", "lvl": "target", "msg": "<6>[    2.901202] mmc0: new high speed SDIO card at address 0001"}
- {"dt": "2023-03-08T07:34:59.191381", "lvl": "target", "msg": "<6>[    2.938506] mmc1: new ultra high speed DDR50 SDHC card at address 59b4"}
- {"dt": "2023-03-08T07:34:59.194222", "lvl": "target", "msg": "<6>[    2.946052] mmcblk1: mmc1:59b4 USDU1 7.51 GiB "}
- {"dt": "2023-03-08T07:34:59.195972", "lvl": "target", "msg": "<6>[    2.952599]  mmcblk1: p1 p2"}
- {"dt": "2023-03-08T07:35:11.389995", "lvl": "target", "msg": "<6>[   15.132882] ALSA device list:"}
- {"dt": "2023-03-08T07:35:11.392067", "lvl": "target", "msg": "<6>[   15.136162]   No soundcards found."}
- {"dt": "2023-03-08T07:35:11.395378", "lvl": "target", "msg": "<6>[   15.144651] Freeing unused kernel memory: 5312K"}
- {"dt": "2023-03-08T07:35:11.397245", "lvl": "target", "msg": "<6>[   15.149722] Run /init as init process"}
- {"dt": "2023-03-08T07:35:11.424519", "lvl": "target", "msg": "Starting syslogd: OK"}
- {"dt": "2023-03-08T07:35:11.490359", "lvl": "target", "msg": "Starting klogd: OK"}
- {"dt": "2023-03-08T07:35:11.493732", "lvl": "target", "msg": "Populating /dev using udev: <30>[   15.206593] udevd[150]: starting version 3.2.7"}
- {"dt": "2023-03-08T07:35:11.495739", "lvl": "target", "msg": "<5>[   15.212241] random: udevd: uninitialized urandom read (16 bytes read)"}
- {"dt": "2023-03-08T07:35:11.497583", "lvl": "target", "msg": "<5>[   15.219272] random: udevd: uninitialized urandom read (16 bytes read)"}
- {"dt": "2023-03-08T07:35:11.499445", "lvl": "target", "msg": "<5>[   15.226139] random: udevd: uninitialized urandom read (16 bytes read)"}
- {"dt": "2023-03-08T07:35:11.499998", "lvl": "target", "msg": "<27>[   15.235081] udevd[150]: specified group 'kvm' unknown"}
- {"dt": "2023-03-08T07:35:11.500557", "lvl": "target", "msg": "<30>[   15.245751] udevd[151]: starting eudev-3.2.7"}
- {"dt": "2023-03-08T07:35:11.695612", "lvl": "target", "msg": "<6>[   15.420388] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:"}
- {"dt": "2023-03-08T07:35:11.699243", "lvl": "target", "msg": "<6>[   15.428932] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]"}
- {"dt": "2023-03-08T07:35:11.701179", "lvl": "target", "msg": "<6>[   15.438586] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x0603ffffff -> 0x00f8000000"}
- {"dt": "2023-03-08T07:35:11.703197", "lvl": "target", "msg": "<4>[   15.439424] bcmgenet fd580000.ethernet: failed to get enet clock"}
- {"dt": "2023-03-08T07:35:11.705030", "lvl": "target", "msg": "<6>[   15.447467] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000"}
- {"dt": "2023-03-08T07:35:11.707221", "lvl": "target", "msg": "<6>[   15.458641] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000"}
- {"dt": "2023-03-08T07:35:11.754260", "lvl": "target", "msg": "<4>[   15.468267] bcmgenet fd580000.ethernet: failed to get enet-wol clock"}
- {"dt": "2023-03-08T07:35:11.755483", "lvl": "target", "msg": "<6>[   15.468719] iproc-rng200 fe104000.rng: hwrng registered"}
- {"dt": "2023-03-08T07:35:11.757489", "lvl": "target", "msg": "<4>[   15.480188] bcmgenet fd580000.ethernet: failed to get enet-eee clock"}
- {"dt": "2023-03-08T07:35:11.758649", "lvl": "target", "msg": "<6>[   15.496744] raspberrypi-clk raspberrypi-clk: CPU frequency range: min 600000000, max 1500000000"}
- {"dt": "2023-03-08T07:35:11.759759", "lvl": "target", "msg": "<6>[   15.511055] brcm-pcie fd500000.pcie: link up, 5 GT/s x1 (SSC)"}
- {"dt": "2023-03-08T07:35:11.760950", "lvl": "target", "msg": "<5>[   15.511718] cfg80211: Loading compiled-in X.509 certificates for regulatory database"}
- {"dt": "2023-03-08T07:35:11.807992", "lvl": "target", "msg": "<6>[   15.517756] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2023-03-08T07:35:11.809147", "lvl": "target", "msg": "<6>[   15.536205] Bluetooth: Core ver 2.22"}
- {"dt": "2023-03-08T07:35:11.811488", "lvl": "target", "msg": "<6>[   15.545762] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2023-03-08T07:35:11.812920", "lvl": "target", "msg": "<6>[   15.546212] NET: Registered protocol family 31"}
- {"dt": "2023-03-08T07:35:11.814321", "lvl": "target", "msg": "<6>[   15.551997] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])"}
- {"dt": "2023-03-08T07:35:11.815775", "lvl": "target", "msg": "<6>[   15.557702] Bluetooth: HCI device and connection manager initialized"}
- {"dt": "2023-03-08T07:35:11.817382", "lvl": "target", "msg": "<6>[   15.567457] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400"}
- {"dt": "2023-03-08T07:35:11.853291", "lvl": "target", "msg": "<6>[   15.574647] Bluetooth: HCI socket layer initialized"}
- {"dt": "2023-03-08T07:35:11.854803", "lvl": "target", "msg": "<6>[   15.580710] pci 0000:00:00.0: PME# supported from D0 D3hot"}
- {"dt": "2023-03-08T07:35:11.857759", "lvl": "target", "msg": "<6>[   15.585808] Bluetooth: L2CAP socket layer initialized"}
- {"dt": "2023-03-08T07:35:11.859485", "lvl": "target", "msg": "<6>[   15.594277] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring"}
- {"dt": "2023-03-08T07:35:11.861074", "lvl": "target", "msg": "<6>[   15.596985] Bluetooth: SCO socket layer initialized"}
- {"dt": "2023-03-08T07:35:11.862614", "lvl": "target", "msg": "<6>[   15.605717] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330"}
- {"dt": "2023-03-08T07:35:11.863899", "lvl": "target", "msg": "<5>[   15.617997] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'"}
- {"dt": "2023-03-08T07:35:11.897659", "lvl": "target", "msg": "<4>[   15.625065] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2"}
- {"dt": "2023-03-08T07:35:11.900701", "lvl": "target", "msg": "<4>[   15.634213] platform regulatory.0: Falling back to sysfs fallback for: regulatory.db"}
- {"dt": "2023-03-08T07:35:11.902338", "lvl": "target", "msg": "<6>[   15.642668] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]"}
- {"dt": "2023-03-08T07:35:11.904012", "lvl": "target", "msg": "<6>[   15.643048] Bluetooth: HCI UART driver ver 2.3"}
- {"dt": "2023-03-08T07:35:11.905580", "lvl": "target", "msg": "<6>[   15.650134] pci 0000:01:00.0: PME# supported from D0 D3cold"}
- {"dt": "2023-03-08T07:35:11.907193", "lvl": "target", "msg": "<6>[   15.653413] libphy: bcmgenet MII bus: probed"}
- {"dt": "2023-03-08T07:35:11.908964", "lvl": "target", "msg": "<6>[   15.654774] Bluetooth: HCI UART protocol H4 registered"}
- {"dt": "2023-03-08T07:35:11.941370", "lvl": "target", "msg": "<6>[   15.661992] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01"}
- {"dt": "2023-03-08T07:35:11.942066", "lvl": "target", "msg": "<6>[   15.665333] Bluetooth: HCI UART protocol LL registered"}
- {"dt": "2023-03-08T07:35:11.943556", "lvl": "target", "msg": "<6>[   15.670779] pci 0000:00:00.0: BAR 14: assigned [mem 0x600000000-0x6000fffff]"}
- {"dt": "2023-03-08T07:35:11.944602", "lvl": "target", "msg": "<6>[   15.677872] Bluetooth: HCI UART protocol Broadcom registered"}
- {"dt": "2023-03-08T07:35:11.945583", "lvl": "target", "msg": "<4>[   15.679240] hci_uart_bcm serial0-0: serial0-0 supply vbat not found, using dummy regulator"}
- {"dt": "2023-03-08T07:35:11.946787", "lvl": "target", "msg": "<4>[   15.679285] hci_uart_bcm serial0-0: serial0-0 supply vddio not found, using dummy regulator"}
- {"dt": "2023-03-08T07:35:11.984988", "lvl": "target", "msg": "<6>[   15.687316] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]"}
- {"dt": "2023-03-08T07:35:11.987737", "lvl": "target", "msg": "<6>[   15.687456] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6"}
- {"dt": "2023-03-08T07:35:11.989178", "lvl": "target", "msg": "<4>[   15.687579] brcmfmac mmc0:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.bin failed with error -2"}
- {"dt": "2023-03-08T07:35:11.990543", "lvl": "target", "msg": "<4>[   15.687583] brcmfmac mmc0:0001:1: Falling back to sysfs fallback for: brcm/brcmfmac43455-sdio.bin"}
- {"dt": "2023-03-08T07:35:11.991875", "lvl": "target", "msg": "<6>[   15.690638] Bluetooth: HCI UART protocol QCA registered"}
- {"dt": "2023-03-08T07:35:12.029478", "lvl": "target", "msg": "<6>[   15.691945] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus"}
- {"dt": "2023-03-08T07:35:12.030189", "lvl": "target", "msg": "<6>[   15.697458] pci 0000:00:00.0: PCI bridge to [bus 01]"}
- {"dt": "2023-03-08T07:35:12.031682", "lvl": "target", "msg": "<6>[   15.767501] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]"}
- {"dt": "2023-03-08T07:35:12.032742", "lvl": "target", "msg": "<6>[   15.774975] pcieport 0000:00:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2023-03-08T07:35:12.033730", "lvl": "target", "msg": "<6>[   15.781535] pcieport 0000:00:00.0: PME: Signaling with IRQ 40"}
- {"dt": "2023-03-08T07:35:12.034730", "lvl": "target", "msg": "<6>[   15.787825] pcieport 0000:00:00.0: AER: enabled with IRQ 40"}
- {"dt": "2023-03-08T07:35:12.035780", "lvl": "target", "msg": "<6>[   15.793892] pci 0000:01:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2023-03-08T07:35:12.074228", "lvl": "target", "msg": "<6>[   15.796939] uart-pl011 fe201000.serial: no DMA platform data"}
- {"dt": "2023-03-08T07:35:12.075521", "lvl": "target", "msg": "<6>[   15.800058] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2023-03-08T07:35:12.078037", "lvl": "target", "msg": "<6>[   15.811468] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1"}
- {"dt": "2023-03-08T07:35:12.079620", "lvl": "target", "msg": "<6>[   15.819589] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000000000000090"}
- {"dt": "2023-03-08T07:35:12.080985", "lvl": "target", "msg": "<6>[   15.829643] hub 1-0:1.0: USB hub found"}
- {"dt": "2023-03-08T07:35:12.082316", "lvl": "target", "msg": "<6>[   15.833733] hub 1-0:1.0: 1 port detected"}
- {"dt": "2023-03-08T07:35:12.083627", "lvl": "target", "msg": "<6>[   15.838183] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2023-03-08T07:35:12.111665", "lvl": "target", "msg": "<6>[   15.843761] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2"}
- {"dt": "2023-03-08T07:35:12.113004", "lvl": "target", "msg": "<6>[   15.851533] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed"}
- {"dt": "2023-03-08T07:35:12.115353", "lvl": "target", "msg": "<6>[   15.858186] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM."}
- {"dt": "2023-03-08T07:35:12.116658", "lvl": "target", "msg": "<6>[   15.866889] hub 2-0:1.0: USB hub found"}
- {"dt": "2023-03-08T07:35:12.118097", "lvl": "target", "msg": "<6>[   15.870973] hub 2-0:1.0: 4 ports detected"}
- {"dt": "2023-03-08T07:35:12.161773", "lvl": "target", "msg": "done"}
- {"dt": "2023-03-08T07:35:12.178049", "lvl": "target", "msg": "Initializing random number generator... done."}
- {"dt": "2023-03-08T07:35:12.179815", "lvl": "target", "msg": "Starting network: OK"}
- {"dt": "2023-03-08T07:35:12.232718", "lvl": "target", "msg": "Starting dropbear sshd: <6>[   15.975256] NET: Registered protocol family 10"}
- {"dt": "2023-03-08T07:35:12.234416", "lvl": "target", "msg": "<6>[   15.980647] Segment Routing with IPv6"}
- {"dt": "2023-03-08T07:35:12.236032", "lvl": "target", "msg": "OK"}
- {"dt": "2023-03-08T07:35:12.238973", "lvl": "target", "msg": "/bin/sh: can't access tty; job control turned off"}
- {"dt": "2023-03-08T07:35:12.241894", "lvl": "debug", "msg": "Matched prompt #10: / #"}
- {"dt": "2023-03-08T07:35:12.243476", "lvl": "results", "msg": {"case": "kernel-messages", "definition": "lava", "duration": "14.55", "extra": {"extra": []}, "level": "2.4.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-08T07:35:12.244497", "lvl": "debug", "msg": "Setting prompt string to ['/ #']"}
- {"dt": "2023-03-08T07:35:12.245136", "lvl": "debug", "msg": "end: 2.4.4.1 login-action (duration 00:00:15) [common]"}
- {"dt": "2023-03-08T07:35:12.245654", "lvl": "results", "msg": {"case": "login-action", "definition": "lava", "duration": "14.56", "extra": {"success": "No kernel warnings or errors detected."}, "level": "2.4.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-08T07:35:12.246728", "lvl": "debug", "msg": "end: 2.4.4 auto-login-action (duration 00:00:16) [common]"}
- {"dt": "2023-03-08T07:35:12.247451", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:01:09) [common]"}
- {"dt": "2023-03-08T07:35:12.248099", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:01:12) [common]"}
- {"dt": "2023-03-08T07:35:12.248770", "lvl": "info", "msg": "start: 3 finalize (timeout 00:08:32) [common]"}
- {"dt": "2023-03-08T07:35:12.249442", "lvl": "debug", "msg": "start: 3.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2023-03-08T07:35:12.250342", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '7'"}
- {"dt": "2023-03-08T07:35:15.726762", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-03-08T07:35:15.761373", "lvl": "debug", "msg": "Returned 0 in 3 seconds"}
- {"dt": "2023-03-08T07:35:15.864727", "lvl": "debug", "msg": "end: 3.1 power-off (duration 00:00:04) [common]"}
- {"dt": "2023-03-08T07:35:15.866690", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "3.62", "extra": {"status": "success"}, "level": "3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-03-08T07:35:15.870598", "lvl": "debug", "msg": "start: 3.2 read-feedback (timeout 00:08:28) [common]"}
- {"dt": "2023-03-08T07:35:15.875106", "lvl": "feedback", "msg": "/ # <6>[   16.033349] Bluetooth: hci0: BCM: chip id 107", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.875855", "lvl": "feedback", "msg": "<6>[   16.038285] Bluetooth: hci0: BCM: features 0x2f", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.876408", "lvl": "feedback", "msg": "<6>[   16.044609] Bluetooth: hci0: BCM4345C0", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.876929", "lvl": "feedback", "msg": "<6>[   16.048680] Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.877459", "lvl": "feedback", "msg": "<4>[   16.054983] bluetooth hci0: Direct firmware load for brcm/BCM4345C0.hcd failed with error -2", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.877990", "lvl": "feedback", "msg": "<4>[   16.063812] bluetooth hci0: Falling back to sysfs fallback for: brcm/BCM4345C0.hcd", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.878503", "lvl": "feedback", "msg": "<6>[   16.172834] usb 1-1: new high-speed USB device number 2 using xhci_hcd", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.879052", "lvl": "feedback", "msg": "<6>[   16.327028] hub 1-1:1.0: USB hub found", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.879566", "lvl": "feedback", "msg": "<6>[   16.331224] hub 1-1:1.0: 4 ports detected", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.880076", "lvl": "feedback", "msg": "<6>[   16.628831] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.880581", "lvl": "feedback", "msg": "<6>[   16.735320] hub 1-1.3:1.0: USB hub found", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.881085", "lvl": "feedback", "msg": "<6>[   16.739713] hub 1-1.3:1.0: 4 ports detected", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.881587", "lvl": "feedback", "msg": "<6>[   17.048831] usb 1-1.3.1: new high-speed USB device number 4 using xhci_hcd", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.882091", "lvl": "feedback", "msg": "<6>[   17.171439] hub 1-1.3.1:1.0: USB hub found", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.882596", "lvl": "feedback", "msg": "<6>[   17.176088] hub 1-1.3.1:1.0: 4 ports detected", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.883134", "lvl": "feedback", "msg": "<6>[   17.484832] usb 1-1.3.1.1: new full-speed USB device number 5 using xhci_hcd", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.883644", "lvl": "feedback", "msg": "<3>[   18.405087] usb 1-1.3.1-port1: Cannot enable. Maybe the USB cable is bad?", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.884151", "lvl": "feedback", "msg": "<3>[   19.325085] usb 1-1.3.1-port1: Cannot enable. Maybe the USB cable is bad?", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.884659", "lvl": "feedback", "msg": "<6>[   19.332398] usb 1-1.3.1-port1: attempt power cycle", "ns": "common"}
- {"dt": "2023-03-08T07:35:15.885485", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2023-03-08T07:35:16.875511", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2023-03-08T07:35:16.877588", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2023-03-08T07:35:16.981235", "lvl": "debug", "msg": "end: 3.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2023-03-08T07:35:16.983495", "lvl": "info", "msg": "end: 3 finalize (duration 00:00:05) [common]"}
- {"dt": "2023-03-08T07:35:16.985686", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2023-03-08T07:35:16.987327", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/ramdisk"}
- {"dt": "2023-03-08T07:35:16.993790", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/kernel"}
- {"dt": "2023-03-08T07:35:17.004559", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/dtb"}
- {"dt": "2023-03-08T07:35:17.005959", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/32164/tftp-deploy-uxhk5i2y/modules"}
- {"dt": "2023-03-08T07:35:17.018123", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/32164"}
- {"dt": "2023-03-08T07:35:17.222604", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/32164"}
- {"dt": "2023-03-08T07:35:17.223805", "lvl": "info", "msg": "Job finished correctly"}
- {"dt": "2023-03-08T07:35:17.224381", "lvl": "results", "msg": {"case": "job", "definition": "lava", "result": "pass"}}
