- {"dt": "2023-11-16T16:51:08.011860", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.01"}
- {"dt": "2023-11-16T16:51:08.013373", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2023-11-16T16:51:08.014377", "lvl": "info", "msg": "Start time: 2023-11-16 16:51:08.014319+00:00 (UTC)"}
- {"dt": "2023-11-16T16:51:08.015542", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29437/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz exists"}
- {"dt": "2023-11-16T16:51:08.235269", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29437/1/raspberrypi4/Image exists"}
- {"dt": "2023-11-16T16:51:08.454605", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29437/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb exists"}
- {"dt": "2023-11-16T16:51:08.673060", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29437/1/raspberrypi4/agl-demo-platform-raspberrypi4-64.ext4.xz exists"}
- {"dt": "2023-11-16T16:51:08.895874", "lvl": "info", "msg": "validate duration: 0.88"}
- {"dt": "2023-11-16T16:51:08.896839", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2023-11-16T16:51:08.898081", "lvl": "info", "msg": "start: 1 nbd-deploy (timeout 01:30:00) [common]"}
- {"dt": "2023-11-16T16:51:08.898823", "lvl": "info", "msg": "Making protocol call for nbd-deploy using lava-xnbd"}
- {"dt": "2023-11-16T16:51:08.899464", "lvl": "debug", "msg": "[nbd-deploy] Checking protocol data for lava-xnbd"}
- {"dt": "2023-11-16T16:51:08.900092", "lvl": "debug", "msg": "Get a port from pool"}
- {"dt": "2023-11-16T16:51:08.901890", "lvl": "debug", "msg": "Set_port 61971"}
- {"dt": "2023-11-16T16:51:08.902839", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 01:30:00) [common]"}
- {"dt": "2023-11-16T16:51:08.903730", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 01:30:00) [common]"}
- {"dt": "2023-11-16T16:51:08.905067", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29437/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-16T16:51:08.905822", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/33547/nbd-deploy-ky0tlcay/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-16T16:51:08.906527", "lvl": "debug", "msg": "total size: 2066915 (1MB)"}
- {"dt": "2023-11-16T16:51:08.907242", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-11-16T16:51:09.215329", "lvl": "debug", "msg": "progress   1% (0MB)"}
- {"dt": "2023-11-16T16:51:09.413408", "lvl": "debug", "msg": "progress   6% (0MB)"}
- {"dt": "2023-11-16T16:51:09.513600", "lvl": "debug", "msg": "progress  11% (0MB)"}
- {"dt": "2023-11-16T16:51:09.519567", "lvl": "debug", "msg": "progress  17% (0MB)"}
- {"dt": "2023-11-16T16:51:09.613267", "lvl": "debug", "msg": "progress  22% (0MB)"}
- {"dt": "2023-11-16T16:51:09.619639", "lvl": "debug", "msg": "progress  28% (0MB)"}
- {"dt": "2023-11-16T16:51:09.624399", "lvl": "debug", "msg": "progress  33% (0MB)"}
- {"dt": "2023-11-16T16:51:09.628985", "lvl": "debug", "msg": "progress  38% (0MB)"}
- {"dt": "2023-11-16T16:51:09.714417", "lvl": "debug", "msg": "progress  44% (0MB)"}
- {"dt": "2023-11-16T16:51:09.720013", "lvl": "debug", "msg": "progress  49% (0MB)"}
- {"dt": "2023-11-16T16:51:09.726678", "lvl": "debug", "msg": "progress  55% (1MB)"}
- {"dt": "2023-11-16T16:51:09.732012", "lvl": "debug", "msg": "progress  60% (1MB)"}
- {"dt": "2023-11-16T16:51:09.739747", "lvl": "debug", "msg": "progress  66% (1MB)"}
- {"dt": "2023-11-16T16:51:09.744722", "lvl": "debug", "msg": "progress  71% (1MB)"}
- {"dt": "2023-11-16T16:51:09.749400", "lvl": "debug", "msg": "progress  76% (1MB)"}
- {"dt": "2023-11-16T16:51:09.813077", "lvl": "debug", "msg": "progress  82% (1MB)"}
- {"dt": "2023-11-16T16:51:09.818235", "lvl": "debug", "msg": "progress  87% (1MB)"}
- {"dt": "2023-11-16T16:51:09.824231", "lvl": "debug", "msg": "progress  93% (1MB)"}
- {"dt": "2023-11-16T16:51:09.829031", "lvl": "debug", "msg": "progress  98% (1MB)"}
- {"dt": "2023-11-16T16:51:09.833268", "lvl": "info", "msg": "1MB downloaded in 0.93s (2.13MB/s)"}
- {"dt": "2023-11-16T16:51:09.834687", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T16:51:09.835491", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.93", "extra": {"label": "initrd", "md5sum": "5e2ba93069dc119181565a48b530ed64", "sha256sum": "0be5dca165efe208c1478e8a7c4d76d3fc560c9f7c75eeaae9ce97aa6def760c", "sha512sum": "ef8572320066188e1adaa47ee8ac923f9401c3a84b5e0aec98dc49b4908528bacf76d92300c867ad64a8810661e469dd4a71308b7fc5b02b5d708b78b9b969fd", "size": ! "2066915"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:51:09.837282", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T16:51:09.838242", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 01:29:59) [common]"}
- {"dt": "2023-11-16T16:51:09.839187", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 01:29:59) [common]"}
- {"dt": "2023-11-16T16:51:09.840919", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29437/1/raspberrypi4/Image"}
- {"dt": "2023-11-16T16:51:09.841715", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/33547/nbd-deploy-ky0tlcay/kernel/Image"}
- {"dt": "2023-11-16T16:51:09.842388", "lvl": "debug", "msg": "total size: 24244736 (23MB)"}
- {"dt": "2023-11-16T16:51:09.843045", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-11-16T16:51:10.152395", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-11-16T16:51:10.646925", "lvl": "debug", "msg": "progress   5% (1MB)"}
- {"dt": "2023-11-16T16:51:10.754981", "lvl": "debug", "msg": "progress  10% (2MB)"}
- {"dt": "2023-11-16T16:51:10.854486", "lvl": "debug", "msg": "progress  15% (3MB)"}
- {"dt": "2023-11-16T16:51:10.954895", "lvl": "debug", "msg": "progress  20% (4MB)"}
- {"dt": "2023-11-16T16:51:11.054240", "lvl": "debug", "msg": "progress  25% (5MB)"}
- {"dt": "2023-11-16T16:51:11.157219", "lvl": "debug", "msg": "progress  30% (6MB)"}
- {"dt": "2023-11-16T16:51:11.264570", "lvl": "debug", "msg": "progress  35% (8MB)"}
- {"dt": "2023-11-16T16:51:11.375363", "lvl": "debug", "msg": "progress  40% (9MB)"}
- {"dt": "2023-11-16T16:51:11.466294", "lvl": "debug", "msg": "progress  45% (10MB)"}
- {"dt": "2023-11-16T16:51:11.574022", "lvl": "debug", "msg": "progress  50% (11MB)"}
- {"dt": "2023-11-16T16:51:11.657838", "lvl": "debug", "msg": "progress  55% (12MB)"}
- {"dt": "2023-11-16T16:51:11.770691", "lvl": "debug", "msg": "progress  60% (13MB)"}
- {"dt": "2023-11-16T16:51:11.869306", "lvl": "debug", "msg": "progress  65% (15MB)"}
- {"dt": "2023-11-16T16:51:11.964062", "lvl": "debug", "msg": "progress  70% (16MB)"}
- {"dt": "2023-11-16T16:51:12.053967", "lvl": "debug", "msg": "progress  75% (17MB)"}
- {"dt": "2023-11-16T16:51:12.161863", "lvl": "debug", "msg": "progress  80% (18MB)"}
- {"dt": "2023-11-16T16:51:12.252673", "lvl": "debug", "msg": "progress  85% (19MB)"}
- {"dt": "2023-11-16T16:51:12.354816", "lvl": "debug", "msg": "progress  90% (20MB)"}
- {"dt": "2023-11-16T16:51:12.451298", "lvl": "debug", "msg": "progress  95% (21MB)"}
- {"dt": "2023-11-16T16:51:12.530622", "lvl": "debug", "msg": "progress 100% (23MB)"}
- {"dt": "2023-11-16T16:51:12.532906", "lvl": "info", "msg": "23MB downloaded in 2.69s (8.59MB/s)"}
- {"dt": "2023-11-16T16:51:12.534205", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:03) [common]"}
- {"dt": "2023-11-16T16:51:12.534991", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "2.70", "extra": {"label": "kernel", "md5sum": "66b8fd214f2f7be835a17bec1ca3c3bb", "sha256sum": "67454e961704ae6231674c1ca03d89f0abc16886ccb74d10b3da661d5e311c4b", "sha512sum": "049ce1c442751dd48a568a1f62bb4e6217ad3d57a570b9c4913020b9a701525c2bfa22a79d5eca35a1cc0386fbf528fe2df0bbfa219cf0514731439bc8b4fcda", "size": ! "24244736"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:51:12.537228", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:03) [common]"}
- {"dt": "2023-11-16T16:51:12.538250", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 01:29:56) [common]"}
- {"dt": "2023-11-16T16:51:12.539212", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 01:29:56) [common]"}
- {"dt": "2023-11-16T16:51:12.541260", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29437/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-16T16:51:12.542114", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/33547/nbd-deploy-ky0tlcay/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-16T16:51:12.542762", "lvl": "debug", "msg": "total size: 52323 (0MB)"}
- {"dt": "2023-11-16T16:51:12.543278", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-11-16T16:51:12.861918", "lvl": "debug", "msg": "progress  62% (0MB)"}
- {"dt": "2023-11-16T16:51:12.963902", "lvl": "debug", "msg": "progress 100% (0MB)"}
- {"dt": "2023-11-16T16:51:12.965616", "lvl": "info", "msg": "0MB downloaded in 0.42s (0.12MB/s)"}
- {"dt": "2023-11-16T16:51:12.966787", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:51:12.967547", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.43", "extra": {"label": "dtb", "md5sum": "d7a4cb0280ed4fd58429b66aa7c47c35", "sha256sum": "269fa995628c3cc9d2c61733476fd57a7097aabb09c0ea3834733ad1dccd8a34", "sha512sum": "ddc53aa3b527bd7de40f6adc176407cacfc66ae7c52e4776c33116167e306b83e4408eed562c53c91c57bab665eea1d917c62aa781a363ce5253d43c380d20ca", "size": ! "52323"}, "level": "1.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:51:12.969256", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:51:12.970217", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 01:29:56) [common]"}
- {"dt": "2023-11-16T16:51:12.971083", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 01:29:56) [common]"}
- {"dt": "2023-11-16T16:51:12.972250", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29437/1/raspberrypi4/agl-demo-platform-raspberrypi4-64.ext4.xz"}
- {"dt": "2023-11-16T16:51:12.972975", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/33547/nbd-deploy-ky0tlcay/nbdroot/agl-demo-platform-raspberrypi4-64.ext4"}
- {"dt": "2023-11-16T16:51:12.973551", "lvl": "debug", "msg": "total size: 796007132 (759MB)"}
- {"dt": "2023-11-16T16:51:12.974196", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2023-11-16T16:51:13.292642", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-11-16T16:51:24.576847", "lvl": "debug", "msg": "progress   5% (37MB)"}
- {"dt": "2023-11-16T16:51:35.256638", "lvl": "debug", "msg": "progress  10% (75MB)"}
- {"dt": "2023-11-16T16:51:50.800724", "lvl": "debug", "msg": "progress  15% (113MB)"}
- {"dt": "2023-11-16T16:52:06.366988", "lvl": "debug", "msg": "progress  20% (151MB)"}
- {"dt": "2023-11-16T16:52:15.514759", "lvl": "debug", "msg": "progress  25% (189MB)"}
- {"dt": "2023-11-16T16:52:21.072537", "lvl": "debug", "msg": "progress  30% (227MB)"}
- {"dt": "2023-11-16T16:52:24.343086", "lvl": "debug", "msg": "progress  35% (265MB)"}
- {"dt": "2023-11-16T16:52:27.739293", "lvl": "debug", "msg": "progress  40% (303MB)"}
- {"dt": "2023-11-16T16:52:31.411304", "lvl": "debug", "msg": "progress  45% (341MB)"}
- {"dt": "2023-11-16T16:52:35.729761", "lvl": "debug", "msg": "progress  50% (379MB)"}
- {"dt": "2023-11-16T16:52:39.821717", "lvl": "debug", "msg": "progress  55% (417MB)"}
- {"dt": "2023-11-16T16:52:55.486799", "lvl": "debug", "msg": "progress  60% (455MB)"}
- {"dt": "2023-11-16T16:53:02.872818", "lvl": "debug", "msg": "progress  65% (493MB)"}
- {"dt": "2023-11-16T16:53:13.736062", "lvl": "debug", "msg": "progress  70% (531MB)"}
- {"dt": "2023-11-16T16:53:23.612060", "lvl": "debug", "msg": "progress  75% (569MB)"}
- {"dt": "2023-11-16T16:53:33.504260", "lvl": "debug", "msg": "progress  80% (607MB)"}
- {"dt": "2023-11-16T16:53:42.336679", "lvl": "debug", "msg": "progress  85% (645MB)"}
- {"dt": "2023-11-16T16:53:51.113615", "lvl": "debug", "msg": "progress  90% (683MB)"}
- {"dt": "2023-11-16T16:53:59.432234", "lvl": "debug", "msg": "progress  95% (721MB)"}
- {"dt": "2023-11-16T16:54:11.031338", "lvl": "debug", "msg": "progress 100% (759MB)"}
- {"dt": "2023-11-16T16:54:14.314629", "lvl": "info", "msg": "759MB downloaded in 181.34s (4.19MB/s)"}
- {"dt": "2023-11-16T16:54:14.317119", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:03:01) [common]"}
- {"dt": "2023-11-16T16:54:14.318217", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "181.35", "extra": {"label": "nbdroot", "md5sum": "a9c251e50f7f63dbf199e2e595eb363d", "sha256sum": "053285cbbc5e7133597fed3b0a112de2ae544db4ff530c7322f0ee1b8ad79378", "sha512sum": "94b16b8817907b74d297a68dbe430326cc718a3071808c5e6e853e74e28ff68f9e9fb985f7543e7c8669e638d2d9aba704780ae22a6124db171de454927eb430", "size": ! "796007132"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:14.321657", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:03:01) [common]"}
- {"dt": "2023-11-16T16:54:14.323303", "lvl": "debug", "msg": "start: 1.5 lava-overlay (timeout 01:26:55) [common]"}
- {"dt": "2023-11-16T16:54:14.326462", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42"}
- {"dt": "2023-11-16T16:54:14.328759", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin"}
- {"dt": "2023-11-16T16:54:14.329836", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/tests"}
- {"dt": "2023-11-16T16:54:14.330850", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/results"}
- {"dt": "2023-11-16T16:54:14.331908", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-add-keys"}
- {"dt": "2023-11-16T16:54:14.333497", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-add-sources"}
- {"dt": "2023-11-16T16:54:14.334933", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-background-process-start"}
- {"dt": "2023-11-16T16:54:14.336394", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-background-process-stop"}
- {"dt": "2023-11-16T16:54:14.337813", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-common-functions"}
- {"dt": "2023-11-16T16:54:14.339230", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-echo-ipv4"}
- {"dt": "2023-11-16T16:54:14.340688", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-install-packages"}
- {"dt": "2023-11-16T16:54:14.342042", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-installed-packages"}
- {"dt": "2023-11-16T16:54:14.343419", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-os-build"}
- {"dt": "2023-11-16T16:54:14.344837", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-probe-channel"}
- {"dt": "2023-11-16T16:54:14.346228", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-probe-ip"}
- {"dt": "2023-11-16T16:54:14.347574", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-target-ip"}
- {"dt": "2023-11-16T16:54:14.348998", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-target-mac"}
- {"dt": "2023-11-16T16:54:14.350406", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-target-storage"}
- {"dt": "2023-11-16T16:54:14.351699", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-test-case"}
- {"dt": "2023-11-16T16:54:14.353029", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-test-event"}
- {"dt": "2023-11-16T16:54:14.354295", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-test-feedback"}
- {"dt": "2023-11-16T16:54:14.355511", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-test-raise"}
- {"dt": "2023-11-16T16:54:14.356824", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-test-reference"}
- {"dt": "2023-11-16T16:54:14.358068", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-test-runner"}
- {"dt": "2023-11-16T16:54:14.359272", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-test-set"}
- {"dt": "2023-11-16T16:54:14.360597", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-test-shell"}
- {"dt": "2023-11-16T16:54:14.361908", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-install-packages (oe)"}
- {"dt": "2023-11-16T16:54:14.363393", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/bin/lava-installed-packages (oe)"}
- {"dt": "2023-11-16T16:54:14.364694", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/environment"}
- {"dt": "2023-11-16T16:54:14.365831", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2023-11-16T16:54:14.366509", "lvl": "debug", "msg": "- LAVA_JOB_ID=33547"}
- {"dt": "2023-11-16T16:54:14.367012", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.66.1"}
- {"dt": "2023-11-16T16:54:14.367921", "lvl": "debug", "msg": "start: 1.5.1 ssh-authorize (timeout 01:26:55) [common]"}
- {"dt": "2023-11-16T16:54:14.370209", "lvl": "debug", "msg": "end: 1.5.1 ssh-authorize (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:14.371067", "lvl": "debug", "msg": "start: 1.5.2 lava-vland-overlay (timeout 01:26:55) [common]"}
- {"dt": "2023-11-16T16:54:14.371659", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2023-11-16T16:54:14.372344", "lvl": "debug", "msg": "end: 1.5.2 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:14.373159", "lvl": "debug", "msg": "start: 1.5.3 lava-multinode-overlay (timeout 01:26:55) [common]"}
- {"dt": "2023-11-16T16:54:14.373776", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2023-11-16T16:54:14.374495", "lvl": "debug", "msg": "end: 1.5.3 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:14.375381", "lvl": "debug", "msg": "start: 1.5.4 test-definition (timeout 01:26:55) [common]"}
- {"dt": "2023-11-16T16:54:14.376140", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2023-11-16T16:54:14.377119", "lvl": "debug", "msg": "start: 1.5.4.1 git-repo-action (timeout 01:26:55) [common]"}
- {"dt": "2023-11-16T16:54:14.377838", "lvl": "debug", "msg": "Using /lava-33547 at stage 0"}
- {"dt": "2023-11-16T16:54:14.378808", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-16T16:54:14.379574", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/0/tests/0_network-veth'"}
- {"dt": "2023-11-16T16:54:14.992384", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/0/tests/0_network-veth/test-suites/short-smoke/network-veth.yaml"}
- {"dt": "2023-11-16T16:54:14.997931", "lvl": "debug", "msg": "uuid=33547_1.5.4.1 testdef=None"}
- {"dt": "2023-11-16T16:54:14.999546", "lvl": "debug", "msg": "end: 1.5.4.1 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T16:54:15.000419", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.62", "extra": {"commit": "b4aef27928ee7897aae9de1b5fa47d0aad61803c", "path": "test-suites/short-smoke/network-veth.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions"}, "level": "1.5.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:15.002773", "lvl": "debug", "msg": "start: 1.5.4.2 test-overlay (timeout 01:26:54) [common]"}
- {"dt": "2023-11-16T16:54:15.008120", "lvl": "debug", "msg": "end: 1.5.4.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:15.008878", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "network-veth", "path": "test-suites/short-smoke/network-veth.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.1"}, "level": "1.5.4.2", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:15.010444", "lvl": "debug", "msg": "start: 1.5.4.3 test-install-overlay (timeout 01:26:54) [common]"}
- {"dt": "2023-11-16T16:54:15.016505", "lvl": "debug", "msg": "end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:15.017270", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "network-veth", "path": "test-suites/short-smoke/network-veth.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "skipped test-install-overlay": "33547_1.5.4.1", "uuid": "33547_1.5.4.1"}, "level": "1.5.4.3", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:15.018908", "lvl": "debug", "msg": "start: 1.5.4.4 test-runscript-overlay (timeout 01:26:54) [common]"}
- {"dt": "2023-11-16T16:54:15.024942", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/0/tests/0_network-veth test_uuid 33547_1.5.4.1"}
- {"dt": "2023-11-16T16:54:15.026572", "lvl": "debug", "msg": "end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:15.027321", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/0/tests/0_network-veth/run.sh", "from": "git", "name": "network-veth", "path": "test-suites/short-smoke/network-veth.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.1"}, "level": "1.5.4.4", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:15.028979", "lvl": "debug", "msg": "start: 1.5.4.5 git-repo-action (timeout 01:26:54) [common]"}
- {"dt": "2023-11-16T16:54:15.029714", "lvl": "debug", "msg": "Using /lava-33547 at stage 1"}
- {"dt": "2023-11-16T16:54:15.030711", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-16T16:54:15.031475", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/1_ci-busybox'"}
- {"dt": "2023-11-16T16:54:15.631667", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/1_ci-busybox"}
- {"dt": "2023-11-16T16:54:15.647206", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/1_ci-busybox/test-suites/short-smoke/busybox.yaml"}
- {"dt": "2023-11-16T16:54:15.650879", "lvl": "debug", "msg": "uuid=33547_1.5.4.5 testdef={'testdef_pattern': {'pattern': '^(?P<test_case_id>[a-zA-Z0-9_-]+):\\\\s(?P<result>\\\\w+)', 'fixupdict': {'PASS': 'pass', 'FAIL': 'fail'}}}"}
- {"dt": "2023-11-16T16:54:15.651997", "lvl": "debug", "msg": "end: 1.5.4.5 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T16:54:15.652870", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.62", "extra": {"commit": "b4aef27928ee7897aae9de1b5fa47d0aad61803c", "path": "test-suites/short-smoke/busybox.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions"}, "level": "1.5.4.5", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:15.654421", "lvl": "debug", "msg": "start: 1.5.4.6 test-overlay (timeout 01:26:53) [common]"}
- {"dt": "2023-11-16T16:54:15.660866", "lvl": "debug", "msg": "end: 1.5.4.6 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:15.661638", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-busybox", "path": "test-suites/short-smoke/busybox.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.5"}, "level": "1.5.4.6", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:15.663228", "lvl": "debug", "msg": "start: 1.5.4.7 test-install-overlay (timeout 01:26:53) [common]"}
- {"dt": "2023-11-16T16:54:15.671036", "lvl": "debug", "msg": "end: 1.5.4.7 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:15.671788", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-busybox", "path": "test-suites/short-smoke/busybox.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "skipped test-install-overlay": "33547_1.5.4.5", "uuid": "33547_1.5.4.5"}, "level": "1.5.4.7", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:15.673451", "lvl": "debug", "msg": "start: 1.5.4.8 test-runscript-overlay (timeout 01:26:53) [common]"}
- {"dt": "2023-11-16T16:54:15.681133", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/1_ci-busybox test_uuid 33547_1.5.4.5"}
- {"dt": "2023-11-16T16:54:15.682815", "lvl": "debug", "msg": "end: 1.5.4.8 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:15.683544", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/1_ci-busybox/run.sh", "from": "git", "name": "ci-busybox", "path": "test-suites/short-smoke/busybox.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.5"}, "level": "1.5.4.8", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:15.685160", "lvl": "debug", "msg": "start: 1.5.4.9 git-repo-action (timeout 01:26:53) [common]"}
- {"dt": "2023-11-16T16:54:15.685887", "lvl": "debug", "msg": "Using /lava-33547 at stage 1"}
- {"dt": "2023-11-16T16:54:15.686900", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-16T16:54:15.687686", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/2_ci-smoke-tests-basic'"}
- {"dt": "2023-11-16T16:54:16.313340", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/2_ci-smoke-tests-basic"}
- {"dt": "2023-11-16T16:54:16.324061", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/2_ci-smoke-tests-basic/test-suites/short-smoke/smoke-tests-basic.yaml"}
- {"dt": "2023-11-16T16:54:16.327137", "lvl": "debug", "msg": "uuid=33547_1.5.4.9 testdef=None"}
- {"dt": "2023-11-16T16:54:16.328438", "lvl": "debug", "msg": "end: 1.5.4.9 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T16:54:16.329208", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.64", "extra": {"commit": "b4aef27928ee7897aae9de1b5fa47d0aad61803c", "path": "test-suites/short-smoke/smoke-tests-basic.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions"}, "level": "1.5.4.9", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:16.330775", "lvl": "debug", "msg": "start: 1.5.4.10 test-overlay (timeout 01:26:53) [common]"}
- {"dt": "2023-11-16T16:54:16.336721", "lvl": "debug", "msg": "end: 1.5.4.10 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:16.337571", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-smoke-tests-basic", "path": "test-suites/short-smoke/smoke-tests-basic.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.9"}, "level": "1.5.4.10", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:16.339140", "lvl": "debug", "msg": "start: 1.5.4.11 test-install-overlay (timeout 01:26:53) [common]"}
- {"dt": "2023-11-16T16:54:16.346694", "lvl": "debug", "msg": "end: 1.5.4.11 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:16.347496", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-smoke-tests-basic", "path": "test-suites/short-smoke/smoke-tests-basic.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "skipped test-install-overlay": "33547_1.5.4.9", "uuid": "33547_1.5.4.9"}, "level": "1.5.4.11", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:16.349194", "lvl": "debug", "msg": "start: 1.5.4.12 test-runscript-overlay (timeout 01:26:53) [common]"}
- {"dt": "2023-11-16T16:54:16.356353", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/2_ci-smoke-tests-basic test_uuid 33547_1.5.4.9"}
- {"dt": "2023-11-16T16:54:16.359212", "lvl": "debug", "msg": "end: 1.5.4.12 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:16.359983", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/2_ci-smoke-tests-basic/run.sh", "from": "git", "name": "ci-smoke-tests-basic", "path": "test-suites/short-smoke/smoke-tests-basic.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.9"}, "level": "1.5.4.12", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:16.361699", "lvl": "debug", "msg": "start: 1.5.4.13 git-repo-action (timeout 01:26:53) [common]"}
- {"dt": "2023-11-16T16:54:16.362475", "lvl": "debug", "msg": "Using /lava-33547 at stage 1"}
- {"dt": "2023-11-16T16:54:16.363570", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-16T16:54:16.364475", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/3_ci-service-check'"}
- {"dt": "2023-11-16T16:54:16.983442", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/3_ci-service-check"}
- {"dt": "2023-11-16T16:54:16.995470", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/3_ci-service-check/test-suites/short-smoke/service-check.yaml"}
- {"dt": "2023-11-16T16:54:16.999070", "lvl": "debug", "msg": "uuid=33547_1.5.4.13 testdef=None"}
- {"dt": "2023-11-16T16:54:17.000112", "lvl": "debug", "msg": "end: 1.5.4.13 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T16:54:17.000982", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.64", "extra": {"commit": "b4aef27928ee7897aae9de1b5fa47d0aad61803c", "path": "test-suites/short-smoke/service-check.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions"}, "level": "1.5.4.13", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:17.002454", "lvl": "debug", "msg": "start: 1.5.4.14 test-overlay (timeout 01:26:52) [common]"}
- {"dt": "2023-11-16T16:54:17.007672", "lvl": "debug", "msg": "end: 1.5.4.14 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:17.008874", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-service-check", "path": "test-suites/short-smoke/service-check.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.13"}, "level": "1.5.4.14", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:17.010544", "lvl": "debug", "msg": "start: 1.5.4.15 test-install-overlay (timeout 01:26:52) [common]"}
- {"dt": "2023-11-16T16:54:17.017763", "lvl": "debug", "msg": "end: 1.5.4.15 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:17.018544", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-service-check", "path": "test-suites/short-smoke/service-check.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "skipped test-install-overlay": "33547_1.5.4.13", "uuid": "33547_1.5.4.13"}, "level": "1.5.4.15", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:17.020108", "lvl": "debug", "msg": "start: 1.5.4.16 test-runscript-overlay (timeout 01:26:52) [common]"}
- {"dt": "2023-11-16T16:54:17.027137", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/3_ci-service-check test_uuid 33547_1.5.4.13"}
- {"dt": "2023-11-16T16:54:17.027882", "lvl": "debug", "msg": "BUILD_TAGS=''"}
- {"dt": "2023-11-16T16:54:17.028528", "lvl": "debug", "msg": "DEVICE_TAGS=''"}
- {"dt": "2023-11-16T16:54:17.029954", "lvl": "debug", "msg": "end: 1.5.4.16 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:17.030665", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1/tests/3_ci-service-check/run.sh", "from": "git", "name": "ci-service-check", "path": "test-suites/short-smoke/service-check.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.13"}, "level": "1.5.4.16", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:17.032243", "lvl": "debug", "msg": "start: 1.5.4.17 git-repo-action (timeout 01:26:52) [common]"}
- {"dt": "2023-11-16T16:54:17.032976", "lvl": "debug", "msg": "Using /lava-33547 at stage 2"}
- {"dt": "2023-11-16T16:54:17.034029", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-16T16:54:17.034786", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/2/tests/4_screenshooter'"}
- {"dt": "2023-11-16T16:54:17.655341", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/2/tests/4_screenshooter/test-suites/short-smoke/screenshooter.yaml"}
- {"dt": "2023-11-16T16:54:17.661843", "lvl": "debug", "msg": "uuid=33547_1.5.4.17 testdef=None"}
- {"dt": "2023-11-16T16:54:17.663984", "lvl": "debug", "msg": "end: 1.5.4.17 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T16:54:17.665648", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.63", "extra": {"commit": "b4aef27928ee7897aae9de1b5fa47d0aad61803c", "path": "test-suites/short-smoke/screenshooter.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions"}, "level": "1.5.4.17", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:17.667509", "lvl": "debug", "msg": "start: 1.5.4.18 test-overlay (timeout 01:26:51) [common]"}
- {"dt": "2023-11-16T16:54:17.672232", "lvl": "debug", "msg": "end: 1.5.4.18 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:17.672972", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "git", "name": "screenshooter", "path": "test-suites/short-smoke/screenshooter.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.17"}, "level": "1.5.4.18", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:17.674538", "lvl": "debug", "msg": "start: 1.5.4.19 test-install-overlay (timeout 01:26:51) [common]"}
- {"dt": "2023-11-16T16:54:17.680688", "lvl": "debug", "msg": "end: 1.5.4.19 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:17.681393", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "screenshooter", "path": "test-suites/short-smoke/screenshooter.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "skipped test-install-overlay": "33547_1.5.4.17", "uuid": "33547_1.5.4.17"}, "level": "1.5.4.19", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:17.682987", "lvl": "debug", "msg": "start: 1.5.4.20 test-runscript-overlay (timeout 01:26:51) [common]"}
- {"dt": "2023-11-16T16:54:17.688978", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/2/tests/4_screenshooter test_uuid 33547_1.5.4.17"}
- {"dt": "2023-11-16T16:54:17.690571", "lvl": "debug", "msg": "end: 1.5.4.20 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:17.691282", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/2/tests/4_screenshooter/run.sh", "from": "git", "name": "screenshooter", "path": "test-suites/short-smoke/screenshooter.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.17"}, "level": "1.5.4.20", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:17.692928", "lvl": "debug", "msg": "start: 1.5.4.21 git-repo-action (timeout 01:26:51) [common]"}
- {"dt": "2023-11-16T16:54:17.693648", "lvl": "debug", "msg": "Using /lava-33547 at stage 3"}
- {"dt": "2023-11-16T16:54:17.694654", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-16T16:54:17.695465", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/3/tests/5_ci-dumpjournal'"}
- {"dt": "2023-11-16T16:54:18.307815", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/3/tests/5_ci-dumpjournal"}
- {"dt": "2023-11-16T16:54:18.322097", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/3/tests/5_ci-dumpjournal/test-suites/short-smoke/dumpjournal.yaml"}
- {"dt": "2023-11-16T16:54:18.325275", "lvl": "debug", "msg": "uuid=33547_1.5.4.21 testdef={'testdef_pattern': {'pattern': '^(?P<test_case_id>[a-zA-Z0-9_-]+):\\\\s(?P<result>\\\\w+)', 'fixupdict': {'PASS': 'pass', 'FAIL': 'fail'}}}"}
- {"dt": "2023-11-16T16:54:18.326363", "lvl": "debug", "msg": "end: 1.5.4.21 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T16:54:18.327094", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.63", "extra": {"commit": "b4aef27928ee7897aae9de1b5fa47d0aad61803c", "path": "test-suites/short-smoke/dumpjournal.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions"}, "level": "1.5.4.21", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:18.328938", "lvl": "debug", "msg": "start: 1.5.4.22 test-overlay (timeout 01:26:51) [common]"}
- {"dt": "2023-11-16T16:54:18.334484", "lvl": "debug", "msg": "end: 1.5.4.22 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:18.335157", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-dumpjournal", "path": "test-suites/short-smoke/dumpjournal.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.21"}, "level": "1.5.4.22", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:18.336732", "lvl": "debug", "msg": "start: 1.5.4.23 test-install-overlay (timeout 01:26:51) [common]"}
- {"dt": "2023-11-16T16:54:18.344100", "lvl": "debug", "msg": "end: 1.5.4.23 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:18.344970", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-dumpjournal", "path": "test-suites/short-smoke/dumpjournal.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "skipped test-install-overlay": "33547_1.5.4.21", "uuid": "33547_1.5.4.21"}, "level": "1.5.4.23", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:18.346564", "lvl": "debug", "msg": "start: 1.5.4.24 test-runscript-overlay (timeout 01:26:51) [common]"}
- {"dt": "2023-11-16T16:54:18.353881", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/3/tests/5_ci-dumpjournal test_uuid 33547_1.5.4.21"}
- {"dt": "2023-11-16T16:54:18.355617", "lvl": "debug", "msg": "end: 1.5.4.24 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:18.356446", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/3/tests/5_ci-dumpjournal/run.sh", "from": "git", "name": "ci-dumpjournal", "path": "test-suites/short-smoke/dumpjournal.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "33547_1.5.4.21"}, "level": "1.5.4.24", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:54:18.357976", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2023-11-16T16:54:18.358732", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/0 for stage 0"}
- {"dt": "2023-11-16T16:54:18.359831", "lvl": "debug", "msg": "- 0_network-veth"}
- {"dt": "2023-11-16T16:54:18.360852", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/1 for stage 1"}
- {"dt": "2023-11-16T16:54:18.361885", "lvl": "debug", "msg": "- 1_ci-busybox"}
- {"dt": "2023-11-16T16:54:18.362561", "lvl": "debug", "msg": "- 2_ci-smoke-tests-basic"}
- {"dt": "2023-11-16T16:54:18.363139", "lvl": "debug", "msg": "- 3_ci-service-check"}
- {"dt": "2023-11-16T16:54:18.363851", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/2 for stage 2"}
- {"dt": "2023-11-16T16:54:18.364893", "lvl": "debug", "msg": "- 4_screenshooter"}
- {"dt": "2023-11-16T16:54:18.365719", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33547/lava-overlay-caxw1u42/lava-33547/3 for stage 3"}
- {"dt": "2023-11-16T16:54:18.366718", "lvl": "debug", "msg": "- 5_ci-dumpjournal"}
- {"dt": "2023-11-16T16:54:18.367752", "lvl": "debug", "msg": "end: 1.5.4 test-definition (duration 00:00:04) [common]"}
- {"dt": "2023-11-16T16:54:18.368712", "lvl": "debug", "msg": "start: 1.5.5 compress-overlay (timeout 01:26:51) [common]"}
- {"dt": "2023-11-16T16:54:19.049396", "lvl": "debug", "msg": "end: 1.5.5 compress-overlay (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T16:54:19.050398", "lvl": "debug", "msg": "start: 1.5.6 persistent-nfs-overlay (timeout 01:26:50) [common]"}
- {"dt": "2023-11-16T16:54:19.051810", "lvl": "debug", "msg": "end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:19.052826", "lvl": "debug", "msg": "end: 1.5 lava-overlay (duration 00:00:05) [common]"}
- {"dt": "2023-11-16T16:54:19.053674", "lvl": "debug", "msg": "start: 1.6 prepare-kernel (timeout 01:26:50) [common]"}
- {"dt": "2023-11-16T16:54:19.054504", "lvl": "debug", "msg": "start: 1.6.1 uboot-prepare-kernel (timeout 01:26:50) [common]"}
- {"dt": "2023-11-16T16:54:19.055330", "lvl": "debug", "msg": "end: 1.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:19.056079", "lvl": "debug", "msg": "end: 1.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:19.057000", "lvl": "debug", "msg": "start: 1.7 xnbd-server-deploy (timeout 01:26:50) [common]"}
- {"dt": "2023-11-16T16:54:19.057667", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server"}
- {"dt": "2023-11-16T16:54:19.058327", "lvl": "debug", "msg": "NBD-IP: 192.168.66.1, NBD-PORT: 61971, NBD-ROOT: 33547/nbd-deploy-ky0tlcay/nbdroot/agl-demo-platform-raspberrypi4-64.ext4"}
- {"dt": "2023-11-16T16:54:19.061906", "lvl": "debug", "msg": "nbd-server 61971 /var/lib/lava/dispatcher/tmp/33547/nbd-deploy-ky0tlcay/nbdroot/agl-demo-platform-raspberrypi4-64.ext4"}
- {"dt": "2023-11-16T16:54:19.082197", "lvl": "debug", "msg": "output: "}
- {"dt": "2023-11-16T16:54:19.086981", "lvl": "debug", "msg": "output: ** (process:3862): WARNING **: 16:54:19.080: Specifying an export on the command line no longer uses the oldstyle protocol."}
- {"dt": "2023-11-16T16:54:19.088146", "lvl": "debug", "msg": "output: "}
- {"dt": "2023-11-16T16:54:19.089043", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server done"}
- {"dt": "2023-11-16T16:54:19.090378", "lvl": "debug", "msg": "end: 1.7 xnbd-server-deploy (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:19.091510", "lvl": "info", "msg": "end: 1 nbd-deploy (duration 00:03:10) [common]"}
- {"dt": "2023-11-16T16:54:19.093077", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:20:00) [common]"}
- {"dt": "2023-11-16T16:54:19.094261", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:20:00) [common]"}
- {"dt": "2023-11-16T16:54:19.095349", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:19.096894", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:20:00) [common]"}
- {"dt": "2023-11-16T16:54:19.098586", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2023-11-16T16:54:19.099456", "lvl": "debug", "msg": "- {BOOTX}: booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2023-11-16T16:54:19.100144", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x02400000"}
- {"dt": "2023-11-16T16:54:19.100800", "lvl": "debug", "msg": "- {DTB}: 33547/nbd-deploy-ky0tlcay/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-16T16:54:19.101375", "lvl": "debug", "msg": "- {INITRD}: 33547/nbd-deploy-ky0tlcay/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-16T16:54:19.101951", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x00080000"}
- {"dt": "2023-11-16T16:54:19.102482", "lvl": "debug", "msg": "- {KERNEL}: 33547/nbd-deploy-ky0tlcay/kernel/Image"}
- {"dt": "2023-11-16T16:54:19.103003", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2023-11-16T16:54:19.103546", "lvl": "debug", "msg": "- {NBDSERVERIP}: 192.168.66.1"}
- {"dt": "2023-11-16T16:54:19.104081", "lvl": "debug", "msg": "- {NBDSERVERPORT}: 61971"}
- {"dt": "2023-11-16T16:54:19.104709", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2023-11-16T16:54:19.105246", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2023-11-16T16:54:19.105762", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x02700000"}
- {"dt": "2023-11-16T16:54:19.106273", "lvl": "debug", "msg": "- {RAMDISK}: 33547/nbd-deploy-ky0tlcay/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-16T16:54:19.106804", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2023-11-16T16:54:19.107319", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2023-11-16T16:54:19.107831", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2023-11-16T16:54:19.108404", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2023-11-16T16:54:19.108959", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2023-11-16T16:54:19.109490", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2023-11-16T16:54:19.110005", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2023-11-16T16:54:19.110529", "lvl": "info", "msg": "- setenv initrd_high 0xffffffff"}
- {"dt": "2023-11-16T16:54:19.111066", "lvl": "info", "msg": "- setenv fdt_high 0xffffffff"}
- {"dt": "2023-11-16T16:54:19.111605", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2023-11-16T16:54:19.112119", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2023-11-16T16:54:19.112700", "lvl": "info", "msg": "- tftp 0x00080000 33547/nbd-deploy-ky0tlcay/kernel/Image"}
- {"dt": "2023-11-16T16:54:19.113225", "lvl": "info", "msg": "- tftp 0x02700000 33547/nbd-deploy-ky0tlcay/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-16T16:54:19.113749", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2023-11-16T16:54:19.114286", "lvl": "info", "msg": "- tftp 0x02400000 33547/nbd-deploy-ky0tlcay/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-16T16:54:19.114807", "lvl": "info", "msg": "- setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61971 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'"}
- {"dt": "2023-11-16T16:54:19.115404", "lvl": "info", "msg": "- fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2023-11-16T16:54:19.116147", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-16T16:54:19.116871", "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-11-16T16:54:19.118434", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:20:00) [common]"}
- {"dt": "2023-11-16T16:54:19.119122", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63003'"}
- {"dt": "2023-11-16T16:54:22.271642", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2023-11-16T16:54:22.277687", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:03) [common]"}
- {"dt": "2023-11-16T16:54:22.280352", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:19:57) [common]"}
- {"dt": "2023-11-16T16:54:22.282447", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:19:57) [common]"}
- {"dt": "2023-11-16T16:54:22.284397", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:19:57) [common]"}
- {"dt": "2023-11-16T16:54:22.285531", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '7'"}
- {"dt": "2023-11-16T16:54:25.730977", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-11-16T16:54:26.803296", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-11-16T16:54:26.840612", "lvl": "debug", "msg": "Returned 0 in 4 seconds"}
- {"dt": "2023-11-16T16:54:26.943600", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:05) [common]"}
- {"dt": "2023-11-16T16:54:26.945488", "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-11-16T16:54:26.949042", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:05) [common]"}
- {"dt": "2023-11-16T16:54:26.951436", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:19:52) [common]"}
- {"dt": "2023-11-16T16:54:26.953547", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2023-11-16T16:54:26.955347", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:20:00)"}
- {"dt": "2023-11-16T16:54:26.959996", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2023-11-16T16:54:26.960894", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2023-11-16T16:54:26.961453", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2023-11-16T16:54:33.482101", "lvl": "target", "msg": "\0"}
- {"dt": "2023-11-16T16:54:33.484090", "lvl": "target", "msg": ""}
- {"dt": "2023-11-16T16:54:33.486657", "lvl": "target", "msg": "U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)"}
- {"dt": "2023-11-16T16:54:33.488645", "lvl": "target", "msg": ""}
- {"dt": "2023-11-16T16:54:33.628036", "lvl": "target", "msg": "DRAM:  3.9 GiB"}
- {"dt": "2023-11-16T16:54:33.659989", "lvl": "target", "msg": "RPI 4 Model B (0xc03111)"}
- {"dt": "2023-11-16T16:54:33.696395", "lvl": "target", "msg": "MMC:   emmc2@7e340000: 0, mmcnr@7e300000: 1"}
- {"dt": "2023-11-16T16:54:33.762942", "lvl": "target", "msg": "Loading Environment from FAT... *** Warning - bad CRC, using default environment"}
- {"dt": "2023-11-16T16:54:33.764992", "lvl": "target", "msg": ""}
- {"dt": "2023-11-16T16:54:33.790567", "lvl": "target", "msg": "In:    serial"}
- {"dt": "2023-11-16T16:54:33.792580", "lvl": "target", "msg": "Out:   serial"}
- {"dt": "2023-11-16T16:54:33.794407", "lvl": "target", "msg": "Err:   serial"}
- {"dt": "2023-11-16T16:54:33.796937", "lvl": "target", "msg": "Net:   eth0: genet@7d580000"}
- {"dt": "2023-11-16T16:54:33.798860", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2023-11-16T16:54:33.800722", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2023-11-16T16:54:33.803100", "lvl": "input", "msg": "c"}
- {"dt": "2023-11-16T16:54:33.804086", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:00:07) [common]"}
- {"dt": "2023-11-16T16:54:33.805014", "lvl": "debug", "msg": "start: 2.4.3 bootloader-commands (timeout 00:19:45) [common]"}
- {"dt": "2023-11-16T16:54:33.805731", "lvl": "debug", "msg": "Setting prompt string to ['U-Boot>']"}
- {"dt": "2023-11-16T16:54:33.806422", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>'] (timeout 00:19:45)"}
- {"dt": "2023-11-16T16:54:33.824883", "lvl": "target", "msg": "Hit any key to stop autoboot:  2 \x03\b\b\b 0 "}
- {"dt": "2023-11-16T16:54:33.826659", "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-11-16T16:54:33.827696", "lvl": "input", "msg": "setenv autoload no\n"}
- {"dt": "2023-11-16T16:54:33.929705", "lvl": "target", "msg": "U-Boot> setenv autoload no"}
- {"dt": "2023-11-16T16:54:33.931771", "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:19:45)"}
- {"dt": "2023-11-16T16:54:33.944469", "lvl": "target", "msg": "setenv autoload no"}
- {"dt": "2023-11-16T16:54:33.945508", "lvl": "input", "msg": "setenv initrd_high 0xffffffff\n"}
- {"dt": "2023-11-16T16:54:34.047147", "lvl": "target", "msg": "U-Boot> setenv initrd_high 0xffffffff"}
- {"dt": "2023-11-16T16:54:34.049400", "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:19:45)"}
- {"dt": "2023-11-16T16:54:34.064638", "lvl": "target", "msg": "setenv initrd_high 0xffffffff"}
- {"dt": "2023-11-16T16:54:34.066229", "lvl": "input", "msg": "setenv fdt_high 0xffffffff\n"}
- {"dt": "2023-11-16T16:54:34.168341", "lvl": "target", "msg": "U-Boot> setenv fdt_high 0xffffffff"}
- {"dt": "2023-11-16T16:54:34.170456", "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:19:45)"}
- {"dt": "2023-11-16T16:54:34.176613", "lvl": "target", "msg": "setenv fdt_high 0xffffffff"}
- {"dt": "2023-11-16T16:54:34.179103", "lvl": "input", "msg": "dhcp\n"}
- {"dt": "2023-11-16T16:54:34.280714", "lvl": "target", "msg": "U-Boot> dhcp"}
- {"dt": "2023-11-16T16:54:34.282852", "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:19:45)"}
- {"dt": "2023-11-16T16:54:34.288860", "lvl": "target", "msg": "dhcp"}
- {"dt": "2023-11-16T16:54:37.694164", "lvl": "target", "msg": "genet@7d580000 Waiting for PHY auto negotiation to complete....... done"}
- {"dt": "2023-11-16T16:54:37.710065", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2023-11-16T16:54:37.949675", "lvl": "target", "msg": "BOOTP broadcast 2"}
- {"dt": "2023-11-16T16:54:38.461640", "lvl": "target", "msg": "BOOTP broadcast 3"}
- {"dt": "2023-11-16T16:54:38.995480", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (1282 ms)"}
- {"dt": "2023-11-16T16:54:38.997152", "lvl": "input", "msg": "setenv serverip 192.168.66.1\n"}
- {"dt": "2023-11-16T16:54:39.099664", "lvl": "target", "msg": "U-Boot> setenv serverip 192.168.66.1"}
- {"dt": "2023-11-16T16:54:39.100652", "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:19:40)"}
- {"dt": "2023-11-16T16:54:39.106670", "lvl": "target", "msg": "setenv serverip 192.168.66.1"}
- {"dt": "2023-11-16T16:54:39.107655", "lvl": "input", "msg": "tftp 0x00080000 33547/nbd-deploy-ky0tlcay/kernel/Image\n"}
- {"dt": "2023-11-16T16:54:39.209282", "lvl": "target", "msg": "U-Boot> tftp 0x00080000 33547/nbd-deploy-ky0tlcay/kernel/Image"}
- {"dt": "2023-11-16T16:54:39.211203", "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:19:40)"}
- {"dt": "2023-11-16T16:54:39.219835", "lvl": "target", "msg": "tftp 0x00080000 33547/nbd-deploy-ky0tlcay/kernel/Image"}
- {"dt": "2023-11-16T16:54:39.221028", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-11-16T16:54:39.242022", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-11-16T16:54:39.243156", "lvl": "target", "msg": "Filename '33547/nbd-deploy-ky0tlcay/kernel/Image'."}
- {"dt": "2023-11-16T16:54:39.245565", "lvl": "target", "msg": "Load address: 0x80000"}
- {"dt": "2023-11-16T16:55:13.450104", "lvl": "target", "msg": "Loading: *\bT #T ######################################T ###########  23.1 MiB"}
- {"dt": "2023-11-16T16:55:13.450938", "lvl": "target", "msg": "\t 691.4 KiB/s"}
- {"dt": "2023-11-16T16:55:13.451656", "lvl": "target", "msg": "done"}
- {"dt": "2023-11-16T16:55:13.457082", "lvl": "target", "msg": "Bytes transferred = 24244736 (171f200 hex)"}
- {"dt": "2023-11-16T16:55:13.458255", "lvl": "input", "msg": "tftp 0x02700000 33547/nbd-deploy-ky0tlcay/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz\n"}
- {"dt": "2023-11-16T16:55:13.559917", "lvl": "target", "msg": "U-Boot> tftp 0x02700000 33547/nbd-deploy-ky0tlcay/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-16T16:55:13.561322", "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:19:06)"}
- {"dt": "2023-11-16T16:55:13.595337", "lvl": "target", "msg": "tftp 0x02700000 33547/nbd-deploy-ky0tlcay/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-16T16:55:13.596095", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-11-16T16:55:13.598340", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-11-16T16:55:13.599367", "lvl": "target", "msg": "Filename '33547/nbd-deploy-ky0tlcay/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz'."}
- {"dt": "2023-11-16T16:55:13.603640", "lvl": "target", "msg": "Load address: 0x2700000"}
- {"dt": "2023-11-16T16:55:14.279600", "lvl": "target", "msg": "Loading: *\b##################################################  2 MiB"}
- {"dt": "2023-11-16T16:55:14.280625", "lvl": "target", "msg": "\t 2.9 MiB/s"}
- {"dt": "2023-11-16T16:55:14.281503", "lvl": "target", "msg": "done"}
- {"dt": "2023-11-16T16:55:14.283143", "lvl": "target", "msg": "Bytes transferred = 2066915 (1f89e3 hex)"}
- {"dt": "2023-11-16T16:55:14.284451", "lvl": "input", "msg": "setenv initrd_size ${filesize}\n"}
- {"dt": "2023-11-16T16:55:14.386327", "lvl": "target", "msg": "U-Boot> setenv initrd_size ${filesize}"}
- {"dt": "2023-11-16T16:55:14.388072", "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:19:05)"}
- {"dt": "2023-11-16T16:55:14.394303", "lvl": "target", "msg": "setenv initrd_size ${filesize}"}
- {"dt": "2023-11-16T16:55:14.398759", "lvl": "input", "msg": "tftp 0x02400000 33547/nbd-deploy-ky0tlcay/dtb/bcm2711-rpi-4-b+vc4.dtb\n"}
- {"dt": "2023-11-16T16:55:14.500999", "lvl": "target", "msg": "U-Boot> tftp 0x02400000 33547/nbd-deploy-ky0tlcay/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-16T16:55:14.501928", "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:19:05)"}
- {"dt": "2023-11-16T16:55:14.536717", "lvl": "target", "msg": "tftp 0x02400000 33547/nbd-deploy-ky0tlcay/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-16T16:55:14.537502", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-11-16T16:55:14.538153", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-11-16T16:55:14.538838", "lvl": "target", "msg": "Filename '33547/nbd-deploy-ky0tlcay/dtb/bcm2711-rpi-4-b+vc4.dtb'."}
- {"dt": "2023-11-16T16:55:14.539943", "lvl": "target", "msg": "Load address: 0x2400000"}
- {"dt": "2023-11-16T16:55:14.561551", "lvl": "target", "msg": "Loading: *\b##################################################  51.1 KiB"}
- {"dt": "2023-11-16T16:55:14.562340", "lvl": "target", "msg": "\t 2.4 MiB/s"}
- {"dt": "2023-11-16T16:55:14.562938", "lvl": "target", "msg": "done"}
- {"dt": "2023-11-16T16:55:14.564866", "lvl": "target", "msg": "Bytes transferred = 52323 (cc63 hex)"}
- {"dt": "2023-11-16T16:55:14.566014", "lvl": "input", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61971 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'\n"}
- {"dt": "2023-11-16T16:55:14.669396", "lvl": "target", "msg": "U-Boot> setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61971 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'"}
- {"dt": "2023-11-16T16:55:14.670346", "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:19:04)"}
- {"dt": "2023-11-16T16:55:14.675454", "lvl": "target", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61971 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'"}
- {"dt": "2023-11-16T16:55:14.677307", "lvl": "input", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000\n"}
- {"dt": "2023-11-16T16:55:14.779626", "lvl": "target", "msg": "U-Boot>fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2023-11-16T16:55:14.781279", "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-11-16T16:55:14.782611", "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:19:04)"}
- {"dt": "2023-11-16T16:55:14.792652", "lvl": "target", "msg": " fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2023-11-16T16:55:14.979121", "lvl": "target", "msg": "## Flattened Device Tree blob at 02400000"}
- {"dt": "2023-11-16T16:55:14.979856", "lvl": "target", "msg": "   Booting using the fdt blob at 0x2400000"}
- {"dt": "2023-11-16T16:55:14.982375", "lvl": "target", "msg": "   Loading Ramdisk to 3ad50000, end 3af489e3 ... OK"}
- {"dt": "2023-11-16T16:55:15.003905", "lvl": "target", "msg": "   Loading Device Tree to 000000003ad40000, end 000000003ad4ffff ... OK"}
- {"dt": "2023-11-16T16:55:15.004717", "lvl": "target", "msg": ""}
- {"dt": "2023-11-16T16:55:15.007437", "lvl": "target", "msg": "Starting kernel ..."}
- {"dt": "2023-11-16T16:55:15.008135", "lvl": "target", "msg": ""}
- {"dt": "2023-11-16T16:55:15.009275", "lvl": "debug", "msg": "end: 2.4.3 bootloader-commands (duration 00:00:41) [common]"}
- {"dt": "2023-11-16T16:55:15.010088", "lvl": "debug", "msg": "start: 2.4.4 auto-login-action (timeout 00:19:04) [common]"}
- {"dt": "2023-11-16T16:55:15.010694", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2023-11-16T16:55:15.011211", "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-11-16T16:55:15.011721", "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:20:00)"}
- {"dt": "2023-11-16T16:55:16.842825", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]"}
- {"dt": "2023-11-16T16:55:16.843564", "lvl": "target", "msg": "[    0.000000] Linux version 5.15.34-v8 (oe-user@oe-host) (aarch64-agl-linux-gcc (GCC) 11.4.0, GNU ld (GNU Binutils) 2.38.20220708) #1 SMP PREEMPT Wed Aug 2 18:13:20 UTC 2023"}
- {"dt": "2023-11-16T16:55:16.844164", "lvl": "target", "msg": "[    0.000000] Machine model: Raspberry Pi 4 Model B"}
- {"dt": "2023-11-16T16:55:16.844680", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2023-11-16T16:55:16.845119", "lvl": "target", "msg": "[    0.000000] Reserved memory: created CMA memory pool at 0x000000001c400000, size 316 MiB"}
- {"dt": "2023-11-16T16:55:16.846634", "lvl": "debug", "msg": "start: 2.4.4.1 login-action (timeout 00:19:02) [common]"}
- {"dt": "2023-11-16T16:55:16.847415", "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-11-16T16:55:16.848067", "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-11-16T16:55:16.848718", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2023-11-16T16:55:16.849201", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2023-11-16T16:55:16.849662", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2023-11-16T16:55:16.850095", "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", "root@raspberrypi4-64:~", "raspberrypi4-64:~#", "/ #", "login:", "Login incorrect"]}
- {"dt": "2023-11-16T16:55:16.851036", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:19:02)"}
- {"dt": "2023-11-16T16:55:16.886674", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool"}
- {"dt": "2023-11-16T16:55:16.887467", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2023-11-16T16:55:16.887953", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003fffffff]"}
- {"dt": "2023-11-16T16:55:16.888505", "lvl": "target", "msg": "[    0.000000]   DMA32    [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2023-11-16T16:55:16.888970", "lvl": "target", "msg": "[    0.000000]   Normal   empty"}
- {"dt": "2023-11-16T16:55:16.889876", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2023-11-16T16:55:16.890451", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2023-11-16T16:55:16.890905", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]"}
- {"dt": "2023-11-16T16:55:16.891761", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2023-11-16T16:55:16.930467", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]"}
- {"dt": "2023-11-16T16:55:16.931189", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 29 pages/cpu s77848 r8192 d32744 u118784"}
- {"dt": "2023-11-16T16:55:16.931670", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2023-11-16T16:55:16.932113", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v2"}
- {"dt": "2023-11-16T16:55:16.932629", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v3a"}
- {"dt": "2023-11-16T16:55:16.933071", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v4"}
- {"dt": "2023-11-16T16:55:16.934076", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-BHB"}
- {"dt": "2023-11-16T16:55:16.935043", "lvl": "target", "msg": "[    0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923"}
- {"dt": "2023-11-16T16:55:16.974257", "lvl": "target", "msg": "[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 996912"}
- {"dt": "2023-11-16T16:55:16.975003", "lvl": "target", "msg": "[    0.000000] Kernel command line: console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61971 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw"}
- {"dt": "2023-11-16T16:55:16.977460", "lvl": "target", "msg": "[    0.000000] Unknown kernel command line parameters \\\"verbose earlyprintk ${extraargs} fstab=no\\\", will be passed to user space."}
- {"dt": "2023-11-16T16:55:17.018074", "lvl": "target", "msg": "[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.018830", "lvl": "target", "msg": "[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.019332", "lvl": "target", "msg": "[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off"}
- {"dt": "2023-11-16T16:55:17.019782", "lvl": "target", "msg": "[    0.000000] software IO TLB: mapped [mem 0x0000000036d40000-0x000000003ad40000] (64MB)"}
- {"dt": "2023-11-16T16:55:17.021349", "lvl": "target", "msg": "[    0.000000] Memory: 3553928K/4050944K available (12928K kernel code, 2044K rwdata, 4504K rodata, 4096K init, 1007K bss, 173432K reserved, 323584K cma-reserved)"}
- {"dt": "2023-11-16T16:55:17.061855", "lvl": "target", "msg": "[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1"}
- {"dt": "2023-11-16T16:55:17.062593", "lvl": "target", "msg": "[    0.000000] ftrace: allocating 40745 entries in 160 pages"}
- {"dt": "2023-11-16T16:55:17.063097", "lvl": "target", "msg": "[    0.000000] ftrace: allocated 160 pages with 2 groups"}
- {"dt": "2023-11-16T16:55:17.063553", "lvl": "target", "msg": "[    0.000000] trace event string verifier disabled"}
- {"dt": "2023-11-16T16:55:17.063994", "lvl": "target", "msg": "[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2023-11-16T16:55:17.064517", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2023-11-16T16:55:17.065594", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4."}
- {"dt": "2023-11-16T16:55:17.067243", "lvl": "target", "msg": "[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2023-11-16T16:55:17.105796", "lvl": "target", "msg": "[    0.000000] \tRude variant of Tasks RCU enabled."}
- {"dt": "2023-11-16T16:55:17.106867", "lvl": "target", "msg": "[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2023-11-16T16:55:17.107639", "lvl": "target", "msg": "[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2023-11-16T16:55:17.108478", "lvl": "target", "msg": "[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4"}
- {"dt": "2023-11-16T16:55:17.109252", "lvl": "target", "msg": "[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2023-11-16T16:55:17.109985", "lvl": "target", "msg": "[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2023-11-16T16:55:17.111038", "lvl": "target", "msg": "[    0.000000] GIC: Using split EOI/Deactivate mode"}
- {"dt": "2023-11-16T16:55:17.150248", "lvl": "target", "msg": "[    0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 10)"}
- {"dt": "2023-11-16T16:55:17.151894", "lvl": "target", "msg": "[    0.000000] random: get_random_bytes called from start_kernel+0x514/0x708 with crng_init=0"}
- {"dt": "2023-11-16T16:55:17.153952", "lvl": "target", "msg": "[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys)."}
- {"dt": "2023-11-16T16:55:17.154787", "lvl": "target", "msg": "[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns"}
- {"dt": "2023-11-16T16:55:17.155368", "lvl": "target", "msg": "[    0.000001] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns"}
- {"dt": "2023-11-16T16:55:17.155939", "lvl": "target", "msg": "[    0.000252] Console: colour dummy device 80x25"}
- {"dt": "2023-11-16T16:55:17.192951", "lvl": "target", "msg": "[    0.000332] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)"}
- {"dt": "2023-11-16T16:55:17.194735", "lvl": "target", "msg": "[    0.000362] pid_max: default: 32768 minimum: 301"}
- {"dt": "2023-11-16T16:55:17.195639", "lvl": "target", "msg": "[    0.000494] LSM: Security Framework initializing"}
- {"dt": "2023-11-16T16:55:17.196515", "lvl": "target", "msg": "[    0.000744] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.197814", "lvl": "target", "msg": "[    0.000806] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.198541", "lvl": "target", "msg": "[    0.002000] cgroup: Disabling memory control group subsystem"}
- {"dt": "2023-11-16T16:55:17.236765", "lvl": "target", "msg": "[    0.004548] rcu: Hierarchical SRCU implementation."}
- {"dt": "2023-11-16T16:55:17.237756", "lvl": "target", "msg": "[    0.005574] EFI services will not be available."}
- {"dt": "2023-11-16T16:55:17.239474", "lvl": "target", "msg": "[    0.006084] smp: Bringing up secondary CPUs ..."}
- {"dt": "2023-11-16T16:55:17.240406", "lvl": "target", "msg": "[    0.007138] Detected PIPT I-cache on CPU1"}
- {"dt": "2023-11-16T16:55:17.241503", "lvl": "target", "msg": "[    0.007210] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]"}
- {"dt": "2023-11-16T16:55:17.242418", "lvl": "target", "msg": "[    0.008469] Detected PIPT I-cache on CPU2"}
- {"dt": "2023-11-16T16:55:17.243190", "lvl": "target", "msg": "[    0.008518] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]"}
- {"dt": "2023-11-16T16:55:17.244051", "lvl": "target", "msg": "[    0.009637] Detected PIPT I-cache on CPU3"}
- {"dt": "2023-11-16T16:55:17.245197", "lvl": "target", "msg": "[    0.009685] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]"}
- {"dt": "2023-11-16T16:55:17.280763", "lvl": "target", "msg": "[    0.009868] smp: Brought up 1 node, 4 CPUs"}
- {"dt": "2023-11-16T16:55:17.281839", "lvl": "target", "msg": "[    0.009914] SMP: Total of 4 processors activated."}
- {"dt": "2023-11-16T16:55:17.283556", "lvl": "target", "msg": "[    0.009930] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2023-11-16T16:55:17.284534", "lvl": "target", "msg": "[    0.009942] CPU features: detected: 32-bit EL1 Support"}
- {"dt": "2023-11-16T16:55:17.285842", "lvl": "target", "msg": "[    0.009958] CPU features: detected: CRC32 instructions"}
- {"dt": "2023-11-16T16:55:17.286686", "lvl": "target", "msg": "[    0.042671] CPU: All CPU(s) started at EL2"}
- {"dt": "2023-11-16T16:55:17.287486", "lvl": "target", "msg": "[    0.042755] alternatives: patching kernel code"}
- {"dt": "2023-11-16T16:55:17.288314", "lvl": "target", "msg": "[    0.044356] devtmpfs: initialized"}
- {"dt": "2023-11-16T16:55:17.288909", "lvl": "target", "msg": "[    0.054690] Enabled cp15_barrier support"}
- {"dt": "2023-11-16T16:55:17.289602", "lvl": "target", "msg": "[    0.054736] Enabled setend support"}
- {"dt": "2023-11-16T16:55:17.324599", "lvl": "target", "msg": "[    0.054759] KASLR disabled due to lack of seed"}
- {"dt": "2023-11-16T16:55:17.326017", "lvl": "target", "msg": "[    0.055087] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2023-11-16T16:55:17.326683", "lvl": "target", "msg": "[    0.055122] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.327241", "lvl": "target", "msg": "[    0.065535] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2023-11-16T16:55:17.327774", "lvl": "target", "msg": "[    0.066319] DMI not present or invalid."}
- {"dt": "2023-11-16T16:55:17.328471", "lvl": "target", "msg": "[    0.066922] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2023-11-16T16:55:17.329393", "lvl": "target", "msg": "[    0.070392] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations"}
- {"dt": "2023-11-16T16:55:17.369517", "lvl": "target", "msg": "[    0.070690] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations"}
- {"dt": "2023-11-16T16:55:17.370730", "lvl": "target", "msg": "[    0.071579] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations"}
- {"dt": "2023-11-16T16:55:17.371765", "lvl": "target", "msg": "[    0.071678] audit: initializing netlink subsys (disabled)"}
- {"dt": "2023-11-16T16:55:17.373000", "lvl": "target", "msg": "[    0.071960] audit: type=2000 audit(0.068:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2023-11-16T16:55:17.374217", "lvl": "target", "msg": "[    0.072498] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2023-11-16T16:55:17.375421", "lvl": "target", "msg": "[    0.072726] cpuidle: using governor menu"}
- {"dt": "2023-11-16T16:55:17.413355", "lvl": "target", "msg": "[    0.072954] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2023-11-16T16:55:17.414118", "lvl": "target", "msg": "[    0.073140] ASID allocator initialised with 65536 entries"}
- {"dt": "2023-11-16T16:55:17.414614", "lvl": "target", "msg": "[    0.073291] Serial: AMBA PL011 UART driver"}
- {"dt": "2023-11-16T16:55:17.415080", "lvl": "target", "msg": "[    0.084974] bcm2835-mbox fe00b880.mailbox: mailbox enabled"}
- {"dt": "2023-11-16T16:55:17.415541", "lvl": "target", "msg": "[    0.112330] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-01-22T17:23:15, variant start"}
- {"dt": "2023-11-16T16:55:17.415989", "lvl": "target", "msg": "[    0.116348] raspberrypi-firmware soc:firmware: Firmware hash is acb03c7d18aa08f25f6419d696d0cc39761d3e62"}
- {"dt": "2023-11-16T16:55:17.417738", "lvl": "target", "msg": "[    0.166922] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1"}
- {"dt": "2023-11-16T16:55:17.457439", "lvl": "target", "msg": "[    0.171212] vgaarb: loaded"}
- {"dt": "2023-11-16T16:55:17.458274", "lvl": "target", "msg": "[    0.171632] SCSI subsystem initialized"}
- {"dt": "2023-11-16T16:55:17.459077", "lvl": "target", "msg": "[    0.171839] usbcore: registered new interface driver usbfs"}
- {"dt": "2023-11-16T16:55:17.459759", "lvl": "target", "msg": "[    0.171898] usbcore: registered new interface driver hub"}
- {"dt": "2023-11-16T16:55:17.460582", "lvl": "target", "msg": "[    0.171967] usbcore: registered new device driver usb"}
- {"dt": "2023-11-16T16:55:17.461295", "lvl": "target", "msg": "[    0.172319] usb_phy_generic phy: supply vcc not found, using dummy regulator"}
- {"dt": "2023-11-16T16:55:17.461971", "lvl": "target", "msg": "[    0.172891] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2023-11-16T16:55:17.463289", "lvl": "target", "msg": "[    0.172910] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2023-11-16T16:55:17.501482", "lvl": "target", "msg": "[    0.172946] PTP clock support registered"}
- {"dt": "2023-11-16T16:55:17.502255", "lvl": "target", "msg": "[    0.173205] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2023-11-16T16:55:17.502735", "lvl": "target", "msg": "[    0.174406] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2023-11-16T16:55:17.503175", "lvl": "target", "msg": "[    0.262977] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2023-11-16T16:55:17.503604", "lvl": "target", "msg": "[    0.263099] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2023-11-16T16:55:17.504034", "lvl": "target", "msg": "[    0.263266] FS-Cache: Loaded"}
- {"dt": "2023-11-16T16:55:17.505813", "lvl": "target", "msg": "[    0.263491] CacheFiles: Loaded"}
- {"dt": "2023-11-16T16:55:17.506426", "lvl": "target", "msg": "[    0.274214] NET: Registered PF_INET protocol family"}
- {"dt": "2023-11-16T16:55:17.545748", "lvl": "target", "msg": "[    0.274700] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.546601", "lvl": "target", "msg": "[    0.278031] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.547344", "lvl": "target", "msg": "[    0.278093] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.548047", "lvl": "target", "msg": "[    0.278312] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.548844", "lvl": "target", "msg": "[    0.278864] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2023-11-16T16:55:17.549529", "lvl": "target", "msg": "[    0.279094] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.589509", "lvl": "target", "msg": "[    0.279161] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-16T16:55:17.590383", "lvl": "target", "msg": "[    0.279462] NET: Registered PF_UNIX/PF_LOCAL protocol family"}
- {"dt": "2023-11-16T16:55:17.591026", "lvl": "target", "msg": "[    0.280464] RPC: Registered named UNIX socket transport module."}
- {"dt": "2023-11-16T16:55:17.591610", "lvl": "target", "msg": "[    0.280487] RPC: Registered udp transport module."}
- {"dt": "2023-11-16T16:55:17.592169", "lvl": "target", "msg": "[    0.280501] RPC: Registered tcp transport module."}
- {"dt": "2023-11-16T16:55:17.593717", "lvl": "target", "msg": "[    0.280515] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2023-11-16T16:55:17.594425", "lvl": "target", "msg": "[    0.280536] PCI: CLS 0 bytes, default 64"}
- {"dt": "2023-11-16T16:55:17.595001", "lvl": "target", "msg": "[    0.281072] Trying to unpack rootfs image as initramfs..."}
- {"dt": "2023-11-16T16:55:17.633068", "lvl": "target", "msg": "[    0.281482] rootfs image is not initramfs (no cpio magic); looks like an initrd"}
- {"dt": "2023-11-16T16:55:17.634080", "lvl": "target", "msg": "[    0.288646] Freeing initrd memory: 2016K"}
- {"dt": "2023-11-16T16:55:17.634869", "lvl": "target", "msg": "[    0.290556] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available"}
- {"dt": "2023-11-16T16:55:17.636706", "lvl": "target", "msg": "[    0.290901] kvm [1]: IPA Size Limit: 44 bits"}
- {"dt": "2023-11-16T16:55:17.637721", "lvl": "target", "msg": "[    0.292142] kvm [1]: vgic interrupt IRQ9"}
- {"dt": "2023-11-16T16:55:17.638562", "lvl": "target", "msg": "[    0.292411] kvm [1]: Hyp mode initialized successfully"}
- {"dt": "2023-11-16T16:55:17.639372", "lvl": "target", "msg": "[    1.054147] Initialise system trusted keyrings"}
- {"dt": "2023-11-16T16:55:17.640306", "lvl": "target", "msg": "[    1.054545] workingset: timestamp_bits=46 max_order=20 bucket_order=0"}
- {"dt": "2023-11-16T16:55:17.643137", "lvl": "target", "msg": "[    1.061159] zbud: loaded"}
- {"dt": "2023-11-16T16:55:17.676879", "lvl": "target", "msg": "[    1.062977] FS-Cache: Netfs 'nfs' registered for caching"}
- {"dt": "2023-11-16T16:55:17.677804", "lvl": "target", "msg": "[    1.063629] NFS: Registering the id_resolver key type"}
- {"dt": "2023-11-16T16:55:17.678520", "lvl": "target", "msg": "[    1.063676] Key type id_resolver registered"}
- {"dt": "2023-11-16T16:55:17.679195", "lvl": "target", "msg": "[    1.063691] Key type id_legacy registered"}
- {"dt": "2023-11-16T16:55:17.679899", "lvl": "target", "msg": "[    1.063797] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2023-11-16T16:55:17.681612", "lvl": "target", "msg": "[    1.063815] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering..."}
- {"dt": "2023-11-16T16:55:17.682448", "lvl": "target", "msg": "[    1.065099] NET: Registered PF_ALG protocol family"}
- {"dt": "2023-11-16T16:55:17.683249", "lvl": "target", "msg": "[    1.065123] Key type asymmetric registered"}
- {"dt": "2023-11-16T16:55:17.720827", "lvl": "target", "msg": "[    1.065137] Asymmetric key parser 'x509' registered"}
- {"dt": "2023-11-16T16:55:17.721639", "lvl": "target", "msg": "[    1.065221] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 246)"}
- {"dt": "2023-11-16T16:55:17.722326", "lvl": "target", "msg": "[    1.065472] io scheduler mq-deadline registered"}
- {"dt": "2023-11-16T16:55:17.723003", "lvl": "target", "msg": "[    1.065491] io scheduler kyber registered"}
- {"dt": "2023-11-16T16:55:17.723682", "lvl": "target", "msg": "[    1.073366] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:"}
- {"dt": "2023-11-16T16:55:17.724453", "lvl": "target", "msg": "[    1.073415] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]"}
- {"dt": "2023-11-16T16:55:17.725872", "lvl": "target", "msg": "[    1.073503] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000"}
- {"dt": "2023-11-16T16:55:17.764903", "lvl": "target", "msg": "[    1.073587] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000"}
- {"dt": "2023-11-16T16:55:17.766704", "lvl": "target", "msg": "[    1.120504] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)"}
- {"dt": "2023-11-16T16:55:17.768414", "lvl": "target", "msg": "[    1.120892] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2023-11-16T16:55:17.770035", "lvl": "target", "msg": "[    1.120915] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2023-11-16T16:55:17.771726", "lvl": "target", "msg": "[    1.120936] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])"}
- {"dt": "2023-11-16T16:55:17.774493", "lvl": "target", "msg": "[    1.121024] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400"}
- {"dt": "2023-11-16T16:55:17.808486", "lvl": "target", "msg": "[    1.121270] pci 0000:00:00.0: PME# supported from D0 D3hot"}
- {"dt": "2023-11-16T16:55:17.809625", "lvl": "target", "msg": "[    1.124997] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring"}
- {"dt": "2023-11-16T16:55:17.810671", "lvl": "target", "msg": "[    1.125273] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330"}
- {"dt": "2023-11-16T16:55:17.811521", "lvl": "target", "msg": "[    1.125344] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]"}
- {"dt": "2023-11-16T16:55:17.812308", "lvl": "target", "msg": "[    1.125589] pci 0000:01:00.0: PME# supported from D0 D3cold"}
- {"dt": "2023-11-16T16:55:17.813037", "lvl": "target", "msg": "[    1.129183] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01"}
- {"dt": "2023-11-16T16:55:17.814775", "lvl": "target", "msg": "[    1.129231] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]"}
- {"dt": "2023-11-16T16:55:17.852413", "lvl": "target", "msg": "[    1.129256] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]"}
- {"dt": "2023-11-16T16:55:17.854311", "lvl": "target", "msg": "[    1.129300] pci 0000:00:00.0: PCI bridge to [bus 01]"}
- {"dt": "2023-11-16T16:55:17.856042", "lvl": "target", "msg": "[    1.129324] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]"}
- {"dt": "2023-11-16T16:55:17.857622", "lvl": "target", "msg": "[    1.135514] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled"}
- {"dt": "2023-11-16T16:55:17.858362", "lvl": "target", "msg": "[    1.138326] iproc-rng200 fe104000.rng: hwrng registered"}
- {"dt": "2023-11-16T16:55:17.859080", "lvl": "target", "msg": "[    1.138850] vc-mem: phys_addr:0x00000000 mem_base=0x00000000 mem_size:0x00000000(0 MiB)"}
- {"dt": "2023-11-16T16:55:17.895956", "lvl": "target", "msg": "[    1.140283] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000"}
- {"dt": "2023-11-16T16:55:17.896983", "lvl": "target", "msg": "[    1.153021] brd: module loaded"}
- {"dt": "2023-11-16T16:55:17.897648", "lvl": "target", "msg": "[    1.162644] loop: module loaded"}
- {"dt": "2023-11-16T16:55:17.898267", "lvl": "target", "msg": "[    1.193389] Loading iSCSI transport class v2.0-870."}
- {"dt": "2023-11-16T16:55:17.898933", "lvl": "target", "msg": "[    1.198027] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000"}
- {"dt": "2023-11-16T16:55:17.899591", "lvl": "target", "msg": "[    1.258559] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus"}
- {"dt": "2023-11-16T16:55:17.900328", "lvl": "target", "msg": "[    1.259620] usbcore: registered new interface driver r8152"}
- {"dt": "2023-11-16T16:55:17.901046", "lvl": "target", "msg": "[    1.259687] usbcore: registered new interface driver lan78xx"}
- {"dt": "2023-11-16T16:55:17.939680", "lvl": "target", "msg": "[    1.259704] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"}
- {"dt": "2023-11-16T16:55:17.940630", "lvl": "target", "msg": "[    1.259720] ehci-pci: EHCI PCI platform driver"}
- {"dt": "2023-11-16T16:55:17.941330", "lvl": "target", "msg": "[    1.259781] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"}
- {"dt": "2023-11-16T16:55:17.941996", "lvl": "target", "msg": "[    1.259818] ohci-pci: OHCI PCI platform driver"}
- {"dt": "2023-11-16T16:55:17.942772", "lvl": "target", "msg": "[    1.261378] pci 0000:00:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2023-11-16T16:55:17.943633", "lvl": "target", "msg": "[    1.261420] xhci_hcd 0000:01:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2023-11-16T16:55:17.944513", "lvl": "target", "msg": "[    1.261525] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2023-11-16T16:55:17.946042", "lvl": "target", "msg": "[    1.261559] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1"}
- {"dt": "2023-11-16T16:55:17.983379", "lvl": "target", "msg": "[    1.262256] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00003c0000000890"}
- {"dt": "2023-11-16T16:55:17.984356", "lvl": "target", "msg": "[    1.263210] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15"}
- {"dt": "2023-11-16T16:55:17.985269", "lvl": "target", "msg": "[    1.263236] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2023-11-16T16:55:17.986087", "lvl": "target", "msg": "[    1.263255] usb usb1: Product: xHCI Host Controller"}
- {"dt": "2023-11-16T16:55:17.986898", "lvl": "target", "msg": "[    1.263272] usb usb1: Manufacturer: Linux 5.15.34-v8 xhci-hcd"}
- {"dt": "2023-11-16T16:55:17.987670", "lvl": "target", "msg": "[    1.263289] usb usb1: SerialNumber: 0000:01:00.0"}
- {"dt": "2023-11-16T16:55:17.989386", "lvl": "target", "msg": "[    1.264015] hub 1-0:1.0: USB hub found"}
- {"dt": "2023-11-16T16:55:18.027082", "lvl": "target", "msg": "[    1.264096] hub 1-0:1.0: 1 port detected"}
- {"dt": "2023-11-16T16:55:18.028018", "lvl": "target", "msg": "[    1.264747] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2023-11-16T16:55:18.028769", "lvl": "target", "msg": "[    1.264774] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2"}
- {"dt": "2023-11-16T16:55:18.029383", "lvl": "target", "msg": "[    1.264813] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed"}
- {"dt": "2023-11-16T16:55:18.029981", "lvl": "target", "msg": "[    1.265191] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15"}
- {"dt": "2023-11-16T16:55:18.030585", "lvl": "target", "msg": "[    1.265214] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2023-11-16T16:55:18.031969", "lvl": "target", "msg": "[    1.265232] usb usb2: Product: xHCI Host Controller"}
- {"dt": "2023-11-16T16:55:18.070892", "lvl": "target", "msg": "[    1.265248] usb usb2: Manufacturer: Linux 5.15.34-v8 xhci-hcd"}
- {"dt": "2023-11-16T16:55:18.071725", "lvl": "target", "msg": "[    1.265264] usb usb2: SerialNumber: 0000:01:00.0"}
- {"dt": "2023-11-16T16:55:18.072503", "lvl": "target", "msg": "[    1.265949] hub 2-0:1.0: USB hub found"}
- {"dt": "2023-11-16T16:55:18.073230", "lvl": "target", "msg": "[    1.266018] hub 2-0:1.0: 4 ports detected"}
- {"dt": "2023-11-16T16:55:18.073960", "lvl": "target", "msg": "[    1.267647] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)"}
- {"dt": "2023-11-16T16:55:18.074663", "lvl": "target", "msg": "[    1.268524] usbcore: registered new interface driver uas"}
- {"dt": "2023-11-16T16:55:18.075422", "lvl": "target", "msg": "[    1.268615] usbcore: registered new interface driver usb-storage"}
- {"dt": "2023-11-16T16:55:18.076241", "lvl": "target", "msg": "[    1.268741] usbcore: registered new interface driver usbserial_generic"}
- {"dt": "2023-11-16T16:55:18.114205", "lvl": "target", "msg": "[    1.268779] usbserial: USB Serial support registered for generic"}
- {"dt": "2023-11-16T16:55:18.115083", "lvl": "target", "msg": "[    1.268842] usbcore: registered new interface driver cp210x"}
- {"dt": "2023-11-16T16:55:18.115694", "lvl": "target", "msg": "[    1.268884] usbserial: USB Serial support registered for cp210x"}
- {"dt": "2023-11-16T16:55:18.116991", "lvl": "target", "msg": "[    1.269113] mousedev: PS/2 mouse device common for all mice"}
- {"dt": "2023-11-16T16:55:18.117696", "lvl": "target", "msg": "[    1.269719] usbcore: registered new interface driver i2c-tiny-usb"}
- {"dt": "2023-11-16T16:55:18.118389", "lvl": "target", "msg": "[    1.274758] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2023-11-16T16:55:18.118986", "lvl": "target", "msg": "[    1.274781] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2023-11-16T16:55:18.119654", "lvl": "target", "msg": "[    1.275413] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2023-11-16T16:55:18.157786", "lvl": "target", "msg": "[    1.278854] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2023-11-16T16:55:18.158697", "lvl": "target", "msg": "[    1.279425] hid: raw HID events driver (C) Jiri Kosina"}
- {"dt": "2023-11-16T16:55:18.160262", "lvl": "target", "msg": "[    1.279773] usbcore: registered new interface driver usbhid"}
- {"dt": "2023-11-16T16:55:18.161329", "lvl": "target", "msg": "[    1.279790] usbhid: USB HID core driver"}
- {"dt": "2023-11-16T16:55:18.162182", "lvl": "target", "msg": "[    1.280105] ashmem: initialized"}
- {"dt": "2023-11-16T16:55:18.163011", "lvl": "target", "msg": "[    1.288303] usbcore: registered new interface driver snd-usb-audio"}
- {"dt": "2023-11-16T16:55:18.163730", "lvl": "target", "msg": "[    1.289294] Initializing XFRM netlink socket"}
- {"dt": "2023-11-16T16:55:18.164541", "lvl": "target", "msg": "[    1.289338] NET: Registered PF_PACKET protocol family"}
- {"dt": "2023-11-16T16:55:18.165424", "lvl": "target", "msg": "[    1.289466] Key type dns_resolver registered"}
- {"dt": "2023-11-16T16:55:18.202287", "lvl": "target", "msg": "[    1.290705] registered taskstats version 1"}
- {"dt": "2023-11-16T16:55:18.203127", "lvl": "target", "msg": "[    1.290743] Loading compiled-in X.509 certificates"}
- {"dt": "2023-11-16T16:55:18.203836", "lvl": "target", "msg": "[    1.291683] Key type ._fscrypt registered"}
- {"dt": "2023-11-16T16:55:18.204599", "lvl": "target", "msg": "[    1.291703] Key type .fscrypt registered"}
- {"dt": "2023-11-16T16:55:18.205245", "lvl": "target", "msg": "[    1.291716] Key type fscrypt-provisioning registered"}
- {"dt": "2023-11-16T16:55:18.205817", "lvl": "target", "msg": "[    1.303011] uart-pl011 fe201000.serial: there is not valid maps for state default"}
- {"dt": "2023-11-16T16:55:18.206399", "lvl": "target", "msg": "[    1.303293] uart-pl011 fe201000.serial: cts_event_workaround enabled"}
- {"dt": "2023-11-16T16:55:18.207635", "lvl": "target", "msg": "[    1.303473] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 19, base_baud = 0) is a PL011 rev2"}
- {"dt": "2023-11-16T16:55:18.246141", "lvl": "target", "msg": "[    1.311496] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default"}
- {"dt": "2023-11-16T16:55:18.247279", "lvl": "target", "msg": "[    1.312195] printk: console [ttyS0] disabled"}
- {"dt": "2023-11-16T16:55:18.248301", "lvl": "target", "msg": "[    1.312312] fe215040.serial: ttyS0 at MMIO 0xfe215040 (irq = 20, base_baud = 62500000) is a 16550"}
- {"dt": "2023-11-16T16:55:18.249509", "lvl": "target", "msg": "[    1.518445] usb 1-1: new high-speed USB device number 2 using xhci_hcd"}
- {"dt": "2023-11-16T16:55:18.250615", "lvl": "target", "msg": "[    1.531015] printk: console [ttyS0] enabled"}
- {"dt": "2023-11-16T16:55:18.252958", "lvl": "target", "msg": "[    1.684033] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.20"}
- {"dt": "2023-11-16T16:55:18.289708", "lvl": "target", "msg": "[    1.690124] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer"}
- {"dt": "2023-11-16T16:55:18.291476", "lvl": "target", "msg": "[    1.696606] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0"}
- {"dt": "2023-11-16T16:55:18.292857", "lvl": "target", "msg": "[    1.702840] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver"}
- {"dt": "2023-11-16T16:55:18.294326", "lvl": "target", "msg": "[    1.707227] usb 1-1: Product: USB2.0 Hub"}
- {"dt": "2023-11-16T16:55:18.295760", "lvl": "target", "msg": "[    1.713014] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0"}
- {"dt": "2023-11-16T16:55:18.296668", "lvl": "target", "msg": "[    1.717932] hub 1-1:1.0: USB hub found"}
- {"dt": "2023-11-16T16:55:18.297171", "lvl": "target", "msg": "[    1.720556] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated"}
- {"dt": "2023-11-16T16:55:18.298368", "lvl": "target", "msg": "[    1.727640] hub 1-1:1.0: 4 ports detected"}
- {"dt": "2023-11-16T16:55:18.299177", "lvl": "target", "msg": "[    1.760693] of_cfs_init"}
- {"dt": "2023-11-16T16:55:18.339167", "lvl": "target", "msg": "[    1.795162] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA"}
- {"dt": "2023-11-16T16:55:18.340481", "lvl": "target", "msg": "[    1.797317] of_cfs_init: OK"}
- {"dt": "2023-11-16T16:55:18.341433", "lvl": "target", "msg": "[    2.098449] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd"}
- {"dt": "2023-11-16T16:55:18.342307", "lvl": "target", "msg": "[    2.109220] random: fast init done"}
- {"dt": "2023-11-16T16:55:18.343174", "lvl": "target", "msg": "[    2.823515] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)"}
- {"dt": "2023-11-16T16:55:18.344048", "lvl": "target", "msg": "[    2.832329] bcmgenet fd580000.ethernet eth0: Link is Down"}
- {"dt": "2023-11-16T16:55:18.372492", "lvl": "target", "msg": "[    2.866811] mmc1: new high speed SDIO card at address 0001"}
- {"dt": "2023-11-16T16:55:18.458021", "lvl": "target", "msg": "[    2.924544] mmc0: new ultra high speed DDR50 SDHC card at address 59b4"}
- {"dt": "2023-11-16T16:55:18.458815", "lvl": "target", "msg": "[    2.932131] mmcblk0: mmc0:59b4 USDU1 7.51 GiB "}
- {"dt": "2023-11-16T16:55:18.459543", "lvl": "target", "msg": "[    2.936654] usb 1-1.3: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2023-11-16T16:55:18.460288", "lvl": "target", "msg": "[    2.936675] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2023-11-16T16:55:18.460999", "lvl": "target", "msg": "[    2.948204]  mmcblk0: p1 p2"}
- {"dt": "2023-11-16T16:55:18.461641", "lvl": "target", "msg": "[    2.952592] usb 1-1.3: Product: USB2.0 Hub             "}
- {"dt": "2023-11-16T16:55:18.462187", "lvl": "target", "msg": "[    2.955939] mmcblk0: mmc0:59b4 USDU1 7.51 GiB"}
- {"dt": "2023-11-16T16:55:18.475855", "lvl": "target", "msg": "[    2.960741] usb 1-1.3: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2023-11-16T16:55:18.477015", "lvl": "target", "msg": "[    2.962332] hub 1-1.3:1.0: USB hub found"}
- {"dt": "2023-11-16T16:55:18.479275", "lvl": "target", "msg": "[    2.975097] hub 1-1.3:1.0: 4 ports detected"}
- {"dt": "2023-11-16T16:55:18.797232", "lvl": "target", "msg": "[    3.286437] usb 1-1.3.1: new high-speed USB device number 4 using xhci_hcd"}
- {"dt": "2023-11-16T16:55:18.944558", "lvl": "target", "msg": "[    3.408406] usb 1-1.3.1: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2023-11-16T16:55:18.946503", "lvl": "target", "msg": "[    3.417087] usb 1-1.3.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2023-11-16T16:55:18.947478", "lvl": "target", "msg": "[    3.424706] usb 1-1.3.1: Product: USB2.0 Hub             "}
- {"dt": "2023-11-16T16:55:18.948526", "lvl": "target", "msg": "[    3.430202] usb 1-1.3.1: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2023-11-16T16:55:18.949506", "lvl": "target", "msg": "[    3.437564] hub 1-1.3.1:1.0: USB hub found"}
- {"dt": "2023-11-16T16:55:18.950644", "lvl": "target", "msg": "[    3.441989] hub 1-1.3.1:1.0: 4 ports detected"}
- {"dt": "2023-11-16T16:55:19.260589", "lvl": "target", "msg": "[    3.750435] usb 1-1.3.1.1: new high-speed USB device number 5 using xhci_hcd"}
- {"dt": "2023-11-16T16:55:19.411760", "lvl": "target", "msg": "[    3.882112] usb 1-1.3.1.1: New USB device found, idVendor=0bda, idProduct=2838, bcdDevice= 1.00"}
- {"dt": "2023-11-16T16:55:19.413268", "lvl": "target", "msg": "[    3.890967] usb 1-1.3.1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3"}
- {"dt": "2023-11-16T16:55:19.413934", "lvl": "target", "msg": "[    3.898768] usb 1-1.3.1.1: Product: RTL2838UHIDIR"}
- {"dt": "2023-11-16T16:55:19.414571", "lvl": "target", "msg": "[    3.903566] usb 1-1.3.1.1: Manufacturer: Realtek"}
- {"dt": "2023-11-16T16:55:19.415724", "lvl": "target", "msg": "[    3.908269] usb 1-1.3.1.1: SerialNumber: 00000001"}
- {"dt": "2023-11-16T16:55:22.419312", "lvl": "target", "msg": "[    6.910670] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx"}
- {"dt": "2023-11-16T16:55:22.482527", "lvl": "target", "msg": "[    6.934428] Sending DHCP requests ., OK"}
- {"dt": "2023-11-16T16:55:22.486035", "lvl": "target", "msg": "[    6.954448] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.241"}
- {"dt": "2023-11-16T16:55:22.487884", "lvl": "target", "msg": "[    6.962529] IP-Config: Complete:"}
- {"dt": "2023-11-16T16:55:22.489766", "lvl": "target", "msg": "[    6.965805]      device=eth0, hwaddr=dc:a6:32:54:fa:25, ipaddr=192.168.66.241, mask=255.255.255.0, gw=192.168.66.1"}
- {"dt": "2023-11-16T16:55:22.491515", "lvl": "target", "msg": "[    6.976332]      host=192.168.66.241, domain=, nis-domain=(none)"}
- {"dt": "2023-11-16T16:55:22.493355", "lvl": "target", "msg": "[    6.982443]      bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath="}
- {"dt": "2023-11-16T16:55:22.495418", "lvl": "target", "msg": "[    6.982456]      nameserver0=10.1.1.1"}
- {"dt": "2023-11-16T16:55:22.503844", "lvl": "target", "msg": "[    6.994282] ALSA device list:"}
- {"dt": "2023-11-16T16:55:22.504592", "lvl": "target", "msg": "[    6.997370]   No soundcards found."}
- {"dt": "2023-11-16T16:55:22.507524", "lvl": "target", "msg": "[    7.001283] Waiting 7 sec before mounting root device..."}
- {"dt": "2023-11-16T16:55:29.554588", "lvl": "target", "msg": "[   14.046623] RAMDISK: gzip image found at block 0"}
- {"dt": "2023-11-16T16:55:29.894536", "lvl": "target", "msg": "[   14.359206] EXT4-fs (ram0): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none."}
- {"dt": "2023-11-16T16:55:29.896569", "lvl": "target", "msg": "[   14.368830] VFS: Mounted root (ext4 filesystem) on device 1:0."}
- {"dt": "2023-11-16T16:55:29.897715", "lvl": "target", "msg": "[   14.375131] devtmpfs: mounted"}
- {"dt": "2023-11-16T16:55:29.899059", "lvl": "target", "msg": "[   14.387445] Freeing unused kernel memory: 4096K"}
- {"dt": "2023-11-16T16:55:29.900159", "lvl": "target", "msg": "[   14.392262] Run /sbin/init as init process"}
- {"dt": "2023-11-16T16:55:29.946757", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2023-11-16T16:55:29.948713", "lvl": "target", "msg": "         ___   ________                _   __     __  __                __"}
- {"dt": "2023-11-16T16:55:29.950559", "lvl": "target", "msg": "        /   | / ____/ /               / | / /__  / /_/ /_  ____  ____  / /_"}
- {"dt": "2023-11-16T16:55:29.952367", "lvl": "target", "msg": "       / /| |/ / __/ /      ______   /  |/ / _ \\/ __/ __ \\/ __ \\/ __ \\/ __/"}
- {"dt": "2023-11-16T16:55:29.954465", "lvl": "target", "msg": "      / ___ / /_/ / /___   /_____/  / /|  /  __/ /_/ /_/ / /_/ / /_/ / /_"}
- {"dt": "2023-11-16T16:55:29.956342", "lvl": "target", "msg": "     /_/  |_\\____/_____/           /_/ |_/\\___/\\__/_.___/\\____/\\____/\\__/"}
- {"dt": "2023-11-16T16:55:29.993430", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2023-11-16T16:55:29.996489", "lvl": "target", "msg": "/sbin/init[1]: starting initrd script"}
- {"dt": "2023-11-16T16:55:29.997911", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: proc /proc"}
- {"dt": "2023-11-16T16:55:29.999316", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: sysfs /sys"}
- {"dt": "2023-11-16T16:55:30.000688", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devtmpfs /dev"}
- {"dt": "2023-11-16T16:55:30.002024", "lvl": "target", "msg": "/sbin/init[1]: /dev (devtmpfs) already mounted"}
- {"dt": "2023-11-16T16:55:30.003331", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devpts /dev/pts"}
- {"dt": "2023-11-16T16:55:30.004665", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /dev/shm"}
- {"dt": "2023-11-16T16:55:30.005317", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /tmp"}
- {"dt": "2023-11-16T16:55:30.012688", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /run"}
- {"dt": "2023-11-16T16:55:30.037611", "lvl": "target", "msg": "/sbin/init[1]: NBD parameters: device /dev/nbd0, server 192.168.66.1:61971"}
- {"dt": "2023-11-16T16:55:30.038846", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2023-11-16T16:55:30.071749", "lvl": "target", "msg": "[   14.563554] nbd0: detected capacity change from 0 to 7215232"}
- {"dt": "2023-11-16T16:55:30.075594", "lvl": "target", "msg": "/sbin/init[1]: NBD client successfully started"}
- {"dt": "2023-11-16T16:55:30.521046", "lvl": "target", "msg": "[   14.976005] EXT4-fs (nbd0): recovery complete"}
- {"dt": "2023-11-16T16:55:30.523915", "lvl": "target", "msg": "[   14.981602] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none."}
- {"dt": "2023-11-16T16:55:30.525004", "lvl": "target", "msg": "/sbin/init[1]: Moving /dev to new rootfs"}
- {"dt": "2023-11-16T16:55:30.525872", "lvl": "target", "msg": "/sbin/init[1]: Moving /proc to new rootfs"}
- {"dt": "2023-11-16T16:55:30.526719", "lvl": "target", "msg": "/sbin/init[1]: Moving /sys to new rootfs"}
- {"dt": "2023-11-16T16:55:30.527594", "lvl": "target", "msg": "/sbin/init[1]: Moving /tmp to new rootfs"}
- {"dt": "2023-11-16T16:55:30.528408", "lvl": "target", "msg": "/sbin/init[1]: Moving /run to new rootfs"}
- {"dt": "2023-11-16T16:55:30.529076", "lvl": "target", "msg": "/sbin/init[1]: Switching to new rootfs"}
- {"dt": "2023-11-16T16:55:30.909595", "lvl": "target", "msg": "/sbin/init[1]: find_active_interface: first active interface is eth0"}
- {"dt": "2023-11-16T16:55:30.913181", "lvl": "target", "msg": "/sbin/init[1]: Adjusting Connman command line. Will be: 'connmand -r -n -I eth0'"}
- {"dt": "2023-11-16T16:55:30.992438", "lvl": "target", "msg": "/sbin/init[1]: Unmounting /tmp and /run"}
- {"dt": "2023-11-16T16:55:31.088881", "lvl": "target", "msg": "/sbin/init[1]: Exec'ing systemd"}
- {"dt": "2023-11-16T16:55:31.139634", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2023-11-16T16:55:31.141382", "lvl": "target", "msg": "      ___   ________       ____              __  _"}
- {"dt": "2023-11-16T16:55:31.143756", "lvl": "target", "msg": "     /   | / ____/ /      / __ )____  ____  / /_(_)___  ____ _"}
- {"dt": "2023-11-16T16:55:31.144597", "lvl": "target", "msg": "    / /| |/ / __/ /      / __  / __ \\/ __ \\/ __/ / __ \\/ __ `/"}
- {"dt": "2023-11-16T16:55:31.145322", "lvl": "target", "msg": "   / ___ / /_/ / /___   / /_/ / /_/ / /_/ / /_/ / / / / /_/ /   _     _     _"}
- {"dt": "2023-11-16T16:55:31.145997", "lvl": "target", "msg": "  /_/  |_\\____/_____/  /_____/\\____/\\____/\\__/_/_/ /_/\\__, /   (_)   (_)   (_)"}
- {"dt": "2023-11-16T16:55:31.146859", "lvl": "target", "msg": "_____________________________________________________/____/_____________________"}
- {"dt": "2023-11-16T16:55:31.237100", "lvl": "target", "msg": "[   15.738038] random: crng init done"}
- {"dt": "2023-11-16T16:55:31.604795", "lvl": "target", "msg": "[   16.098539] systemd[1]: System time before build time, advancing clock."}
- {"dt": "2023-11-16T16:55:31.757752", "lvl": "target", "msg": "[   16.218864] systemd[1]: systemd 250.5+ running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA -SMACK +SECCOMP -GCRYPT -GNUTLS -OPENSSL +ACL +BLKID -CURL -ELFUTILS -FIDO2 -IDN2 -IDN +IPTC +KMOD -LIBCRYPTSETUP +LIBFDISK -PCRE2 -PWQUALITY -P11KIT -QRENCODE -BZIP2 -LZ4 -XZ -ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=hybrid)"}
- {"dt": "2023-11-16T16:55:31.762736", "lvl": "target", "msg": "[   16.251591] systemd[1]: Detected architecture arm64."}
- {"dt": "2023-11-16T16:55:31.788804", "lvl": "target", "msg": ""}
- {"dt": "2023-11-16T16:55:31.790174", "lvl": "target", "msg": "Welcome to Automotive Grade Linux 16.90.0 (quillback)!"}
- {"dt": "2023-11-16T16:55:31.791396", "lvl": "target", "msg": ""}
- {"dt": "2023-11-16T16:55:31.820785", "lvl": "target", "msg": "[   16.312511] systemd[1]: Hostname set to <h3ulcb>."}
- {"dt": "2023-11-16T16:55:32.400979", "lvl": "target", "msg": "[   16.891315] systemd[1]: Binding to IPv6 address not available since kernel does not support IPv6."}
- {"dt": "2023-11-16T16:55:32.575002", "lvl": "target", "msg": "[   17.064104] systemd[1]: Queued start job for default target Graphical Interface."}
- {"dt": "2023-11-16T16:55:32.635328", "lvl": "target", "msg": "[   17.127908] systemd[1]: Created slice Slice /system/getty."}
- {"dt": "2023-11-16T16:55:32.638734", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/getty."}
- {"dt": "2023-11-16T16:55:32.656156", "lvl": "target", "msg": "[   17.148929] systemd[1]: Created slice Slice /system/modprobe."}
- {"dt": "2023-11-16T16:55:32.659684", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/modprobe."}
- {"dt": "2023-11-16T16:55:32.682593", "lvl": "target", "msg": "[   17.172758] systemd[1]: Created slice Slice /system/serial-getty."}
- {"dt": "2023-11-16T16:55:32.684294", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/serial-getty."}
- {"dt": "2023-11-16T16:55:32.706700", "lvl": "target", "msg": "[   17.196660] systemd[1]: Created slice Slice /system/wireplumber."}
- {"dt": "2023-11-16T16:55:32.708177", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/wireplumber."}
- {"dt": "2023-11-16T16:55:32.779678", "lvl": "target", "msg": "[   17.220292] systemd[1]: Created slice User and Session Slice."}
- {"dt": "2023-11-16T16:55:32.781692", "lvl": "target", "msg": "[  OK  ] Created slice User and Session Slice."}
- {"dt": "2023-11-16T16:55:32.783350", "lvl": "target", "msg": "[   17.238999] systemd[1]: Started Dispatch Password Requests to Console Directory Watch."}
- {"dt": "2023-11-16T16:55:32.784598", "lvl": "target", "msg": "[  OK  ] Started Dispatch Password Requests to Console Directory Watch."}
- {"dt": "2023-11-16T16:55:32.785565", "lvl": "target", "msg": "[   17.262916] systemd[1]: Started Forward Password Requests to Wall Directory Watch."}
- {"dt": "2023-11-16T16:55:32.786504", "lvl": "target", "msg": "[  OK  ] Started Forward Password Requests to Wall Directory Watch."}
- {"dt": "2023-11-16T16:55:32.813663", "lvl": "target", "msg": "[   17.286785] systemd[1]: Reached target Host and Network Name Lookups."}
- {"dt": "2023-11-16T16:55:32.815435", "lvl": "target", "msg": "[  OK  ] Reached target Host and Network Name Lookups."}
- {"dt": "2023-11-16T16:55:32.817178", "lvl": "target", "msg": "[   17.306578] systemd[1]: Reached target Path Units."}
- {"dt": "2023-11-16T16:55:32.820767", "lvl": "target", "msg": "[  OK  ] Reached target Path Units."}
- {"dt": "2023-11-16T16:55:32.834110", "lvl": "target", "msg": "[   17.326619] systemd[1]: Reached target Remote File Systems."}
- {"dt": "2023-11-16T16:55:32.837351", "lvl": "target", "msg": "[  OK  ] Reached target Remote File Systems."}
- {"dt": "2023-11-16T16:55:32.854941", "lvl": "target", "msg": "[   17.346579] systemd[1]: Reached target Slice Units."}
- {"dt": "2023-11-16T16:55:32.858281", "lvl": "target", "msg": "[  OK  ] Reached target Slice Units."}
- {"dt": "2023-11-16T16:55:32.873357", "lvl": "target", "msg": "[   17.366626] systemd[1]: Reached target Swaps."}
- {"dt": "2023-11-16T16:55:32.874581", "lvl": "target", "msg": "[  OK  ] Reached target Swaps."}
- {"dt": "2023-11-16T16:55:32.925188", "lvl": "target", "msg": "[   17.390875] systemd[1]: Listening on Process Core Dump Socket."}
- {"dt": "2023-11-16T16:55:32.926375", "lvl": "target", "msg": "[  OK  ] Listening on Process Core Dump Socket."}
- {"dt": "2023-11-16T16:55:32.927367", "lvl": "target", "msg": "[   17.411003] systemd[1]: Listening on initctl Compatibility Named Pipe."}
- {"dt": "2023-11-16T16:55:32.928466", "lvl": "target", "msg": "[  OK  ] Listening on initctl Compatibility Named Pipe."}
- {"dt": "2023-11-16T16:55:32.944936", "lvl": "target", "msg": "[   17.435673] systemd[1]: Listening on Journal Audit Socket."}
- {"dt": "2023-11-16T16:55:32.948449", "lvl": "target", "msg": "[  OK  ] Listening on Journal Audit Socket."}
- {"dt": "2023-11-16T16:55:32.981123", "lvl": "target", "msg": "[   17.455381] systemd[1]: Listening on Journal Socket (/dev/log)."}
- {"dt": "2023-11-16T16:55:32.983724", "lvl": "target", "msg": "[  OK  ] Listening on Journal Socket (/dev/log)."}
- {"dt": "2023-11-16T16:55:32.985718", "lvl": "target", "msg": "[   17.475422] systemd[1]: Listening on Journal Socket."}
- {"dt": "2023-11-16T16:55:32.987289", "lvl": "target", "msg": "[  OK  ] Listening on Journal Socket."}
- {"dt": "2023-11-16T16:55:33.009011", "lvl": "target", "msg": "[   17.495620] systemd[1]: Listening on Network Service Netlink Socket."}
- {"dt": "2023-11-16T16:55:33.010363", "lvl": "target", "msg": "[  OK  ] Listening on Network Service Netlink Socket."}
- {"dt": "2023-11-16T16:55:33.028545", "lvl": "target", "msg": "[   17.519555] systemd[1]: Listening on udev Control Socket."}
- {"dt": "2023-11-16T16:55:33.032020", "lvl": "target", "msg": "[  OK  ] Listening on udev Control Socket."}
- {"dt": "2023-11-16T16:55:33.049867", "lvl": "target", "msg": "[   17.539215] systemd[1]: Listening on udev Kernel Socket."}
- {"dt": "2023-11-16T16:55:33.051331", "lvl": "target", "msg": "[  OK  ] Listening on udev Kernel Socket."}
- {"dt": "2023-11-16T16:55:33.107709", "lvl": "target", "msg": "[   17.559258] systemd[1]: Listening on User Database Manager Socket."}
- {"dt": "2023-11-16T16:55:33.111289", "lvl": "target", "msg": "[  OK  ] Listening on User Database Manager Socket."}
- {"dt": "2023-11-16T16:55:33.113249", "lvl": "target", "msg": "[   17.579361] systemd[1]: Huge Pages File System was skipped because of a failed condition check (ConditionPathExists=/sys/kernel/mm/hugepages)."}
- {"dt": "2023-11-16T16:55:33.115019", "lvl": "target", "msg": "[   17.597792] systemd[1]: Mounting POSIX Message Queue File System..."}
- {"dt": "2023-11-16T16:55:33.117141", "lvl": "target", "msg": "         Mounting POSIX Message Queue File System..."}
- {"dt": "2023-11-16T16:55:33.133094", "lvl": "target", "msg": "[   17.623989] systemd[1]: Mounting Kernel Debug File System..."}
- {"dt": "2023-11-16T16:55:33.134146", "lvl": "target", "msg": "         Mounting Kernel Debug File System..."}
- {"dt": "2023-11-16T16:55:33.162022", "lvl": "target", "msg": "[   17.651987] systemd[1]: Mounting Kernel Trace File System..."}
- {"dt": "2023-11-16T16:55:33.163376", "lvl": "target", "msg": "         Mounting Kernel Trace File System..."}
- {"dt": "2023-11-16T16:55:33.187154", "lvl": "target", "msg": "[   17.677468] systemd[1]: Mounting Temporary Directory /tmp..."}
- {"dt": "2023-11-16T16:55:33.188878", "lvl": "target", "msg": "         Mounting Temporary Directory /tmp..."}
- {"dt": "2023-11-16T16:55:33.229570", "lvl": "target", "msg": "[   17.699291] systemd[1]: Create List of Static Device Nodes was skipped because of a failed condition check (ConditionFileNotEmpty=/lib/modules/5.15.34-v8/modules.devname)."}
- {"dt": "2023-11-16T16:55:33.230741", "lvl": "target", "msg": "[   17.720407] systemd[1]: Starting Load Kernel Module configfs..."}
- {"dt": "2023-11-16T16:55:33.233074", "lvl": "target", "msg": "         Starting Load Kernel Module configfs..."}
- {"dt": "2023-11-16T16:55:33.254328", "lvl": "target", "msg": "[   17.747845] systemd[1]: Starting Load Kernel Module drm..."}
- {"dt": "2023-11-16T16:55:33.257797", "lvl": "target", "msg": "         Starting Load Kernel Module drm..."}
- {"dt": "2023-11-16T16:55:33.278695", "lvl": "target", "msg": "[   17.772111] systemd[1]: Starting Load Kernel Module fuse..."}
- {"dt": "2023-11-16T16:55:33.282106", "lvl": "target", "msg": "         Starting Load Kernel Module fuse..."}
- {"dt": "2023-11-16T16:55:33.310942", "lvl": "target", "msg": "[   17.796175] systemd[1]: Starting Start psplash boot splash screen..."}
- {"dt": "2023-11-16T16:55:33.312517", "lvl": "target", "msg": "         Starting Start psplash boot splash screen..."}
- {"dt": "2023-11-16T16:55:33.338249", "lvl": "target", "msg": "[   17.824325] systemd[1]: Starting SELinux autorelabel service loading..."}
- {"dt": "2023-11-16T16:55:33.340804", "lvl": "target", "msg": "         Starting SELinux autorelabel service loading..."}
- {"dt": "2023-11-16T16:55:33.365213", "lvl": "target", "msg": "[   17.852388] systemd[1]: Starting SELinux init for /dev service loading..."}
- {"dt": "2023-11-16T16:55:33.368778", "lvl": "target", "msg": "         Starting SELinux init for /dev service loading..."}
- {"dt": "2023-11-16T16:55:33.423521", "lvl": "target", "msg": "[   17.892986] systemd[1]: Rebuild Hardware Database was skipped because of a failed condition check (ConditionNeedsUpdate=/etc)."}
- {"dt": "2023-11-16T16:55:33.425118", "lvl": "target", "msg": "[   17.914494] systemd[1]: Starting Journal Service..."}
- {"dt": "2023-11-16T16:55:33.427578", "lvl": "target", "msg": "         Starting Journal Service..."}
- {"dt": "2023-11-16T16:55:33.486013", "lvl": "target", "msg": "[   17.979126] systemd[1]: Starting Load Kernel Modules..."}
- {"dt": "2023-11-16T16:55:33.489151", "lvl": "target", "msg": "         Starting Load Kernel Modules..."}
- {"dt": "2023-11-16T16:55:33.548895", "lvl": "target", "msg": "[   17.998916] systemd[1]: Platform Persistent Storage Archival was skipped because of a failed condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore)."}
- {"dt": "2023-11-16T16:55:33.550454", "lvl": "target", "msg": "[   18.014077] systemd[1]: Create System Users was skipped because of a failed condition check (ConditionNeedsUpdate=/etc)."}
- {"dt": "2023-11-16T16:55:33.551916", "lvl": "target", "msg": "[   18.035448] systemd[1]: Starting Create Static Device Nodes in /dev..."}
- {"dt": "2023-11-16T16:55:33.553799", "lvl": "target", "msg": "         Starting Create Static Device Nodes in /dev..."}
- {"dt": "2023-11-16T16:55:33.587925", "lvl": "target", "msg": "[   18.073904] systemd[1]: Starting Coldplug All udev Devices..."}
- {"dt": "2023-11-16T16:55:33.591416", "lvl": "target", "msg": "         Starting Coldplug All udev Devices..."}
- {"dt": "2023-11-16T16:55:33.638001", "lvl": "target", "msg": "[   18.099117] systemd[1]: Bind mount volatile /var/cache was skipped because of a failed condition check (ConditionPathIsReadWrite=!/var/cache)."}
- {"dt": "2023-11-16T16:55:33.639360", "lvl": "target", "msg": "[   18.112611] systemd[1]: Bind mount volatile /var/lib was skipped because of a failed condition check (ConditionPathIsReadWrite=!/var/lib)."}
- {"dt": "2023-11-16T16:55:33.640730", "lvl": "target", "msg": "[   18.131116] systemd[1]: Starting Load/Save Random Seed..."}
- {"dt": "2023-11-16T16:55:33.642496", "lvl": "target", "msg": "         Starting Load/Save Random Seed..."}
- {"dt": "2023-11-16T16:55:33.678072", "lvl": "target", "msg": "[   18.154901] systemd[1]: Bind mount volatile /var/spool was skipped because of a failed condition check (ConditionPathIsReadWrite=!/var/spool)."}
- {"dt": "2023-11-16T16:55:33.681289", "lvl": "target", "msg": "[   18.168214] systemd[1]: Bind mount volatile /srv was skipped because of a failed condition check (ConditionPathIsReadWrite=!/srv)."}
- {"dt": "2023-11-16T16:55:33.705215", "lvl": "target", "msg": "[   18.195409] systemd[1]: Mounted POSIX Message Queue File System."}
- {"dt": "2023-11-16T16:55:33.705952", "lvl": "target", "msg": "[  OK  ] Mounted POSIX Message Queue File System."}
- {"dt": "2023-11-16T16:55:33.726714", "lvl": "target", "msg": "[   18.219401] systemd[1]: Started Journal Service."}
- {"dt": "2023-11-16T16:55:33.729893", "lvl": "target", "msg": "[  OK  ] Started Journal Service."}
- {"dt": "2023-11-16T16:55:33.762872", "lvl": "target", "msg": "[   18.239436] audit: type=1130 audit(1691000002.147:2): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-journald comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2023-11-16T16:55:33.764706", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Debug File System."}
- {"dt": "2023-11-16T16:55:33.776986", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Trace File System."}
- {"dt": "2023-11-16T16:55:33.809098", "lvl": "target", "msg": "[  OK  ] Mounted Temporary Directory /tmp."}
- {"dt": "2023-11-16T16:55:33.861031", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module configfs."}
- {"dt": "2023-11-16T16:55:33.864639", "lvl": "target", "msg": "[   18.334863] audit: type=1130 audit(1691000002.243:3): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@configfs comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2023-11-16T16:55:33.866203", "lvl": "target", "msg": "[   18.354155] audit: type=1131 audit(1691000002.243:4): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@configfs comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2023-11-16T16:55:33.914242", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module drm."}
- {"dt": "2023-11-16T16:55:33.917548", "lvl": "target", "msg": "[   18.386747] audit: type=1130 audit(1691000002.295:5): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@drm comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2023-11-16T16:55:33.919605", "lvl": "target", "msg": "[   18.405588] audit: type=1131 audit(1691000002.295:6): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@drm comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2023-11-16T16:55:33.932353", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module fuse."}
- {"dt": "2023-11-16T16:55:33.985070", "lvl": "target", "msg": "[   18.442705] audit: type=1130 audit(1691000002.351:7): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@fuse comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2023-11-16T16:55:33.986845", "lvl": "target", "msg": "[   18.461575] audit: type=1131 audit(1691000002.351:8): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@fuse comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2023-11-16T16:55:33.988701", "lvl": "target", "msg": "[FAILED] Failed to start Start psplash boot splash screen."}
- {"dt": "2023-11-16T16:55:34.001493", "lvl": "target", "msg": "See 'systemctl status psplash-start.service' for details."}
- {"dt": "2023-11-16T16:55:34.025121", "lvl": "target", "msg": "[DEPEND] Dependency failed for Start psplash\u2026emd progress communication helper."}
- {"dt": "2023-11-16T16:55:34.076873", "lvl": "target", "msg": "[   18.534746] audit: type=1130 audit(1691000002.443:9): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=psplash-start comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=failed'"}
- {"dt": "2023-11-16T16:55:34.078789", "lvl": "target", "msg": "[  OK  ] Finished SELinux autorelabel service loading."}
- {"dt": "2023-11-16T16:55:34.081034", "lvl": "target", "msg": "[   18.567009] audit: type=1130 audit(1691000002.475:10): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=selinux-autorelabel comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2023-11-16T16:55:34.112289", "lvl": "target", "msg": "[   18.586558] audit: type=1131 audit(1691000002.475:11): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=selinux-autorelabel comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2023-11-16T16:55:34.115325", "lvl": "target", "msg": "[  OK  ] Finished SELinux init for /dev service loading."}
- {"dt": "2023-11-16T16:55:34.129640", "lvl": "target", "msg": "[FAILED] Failed to start Load Kernel Modules."}
- {"dt": "2023-11-16T16:55:34.153193", "lvl": "target", "msg": "See 'systemctl status systemd-modules-load.service' for details."}
- {"dt": "2023-11-16T16:55:34.167617", "lvl": "target", "msg": "[  OK  ] Finished Create Static Device Nodes in /dev."}
- {"dt": "2023-11-16T16:55:34.183747", "lvl": "target", "msg": "[  OK  ] Finished Load/Save Random Seed."}
- {"dt": "2023-11-16T16:55:34.200073", "lvl": "target", "msg": "[  OK  ] Reached target Local File Systems."}
- {"dt": "2023-11-16T16:55:34.231623", "lvl": "target", "msg": "         Mounting Kernel Configuration File System..."}
- {"dt": "2023-11-16T16:55:34.247441", "lvl": "target", "msg": "         Starting SELinux resolv.conf relabeling..."}
- {"dt": "2023-11-16T16:55:34.263264", "lvl": "target", "msg": "         Starting SELinux init service loading..."}
- {"dt": "2023-11-16T16:55:34.307142", "lvl": "target", "msg": "         Starting Flush Journal to Persistent Storage..."}
- {"dt": "2023-11-16T16:55:34.310977", "lvl": "target", "msg": "         Starting Apply Kernel Variables..."}
- {"dt": "2023-11-16T16:55:34.349811", "lvl": "target", "msg": "[   18.826982] systemd-journald[191]: Received client request to flush runtime journal."}
- {"dt": "2023-11-16T16:55:34.353466", "lvl": "target", "msg": "         Starting Rule-based Manager for Device Events and Files..."}
- {"dt": "2023-11-16T16:55:34.367268", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Configuration File System."}
- {"dt": "2023-11-16T16:55:34.383465", "lvl": "target", "msg": "[  OK  ] Finished SELinux resolv.conf relabeling."}
- {"dt": "2023-11-16T16:55:34.415762", "lvl": "target", "msg": "[  OK  ] Finished SELinux init service loading."}
- {"dt": "2023-11-16T16:55:34.431845", "lvl": "target", "msg": "[  OK  ] Finished Flush Journal to Persistent Storage."}
- {"dt": "2023-11-16T16:55:34.447468", "lvl": "target", "msg": "[  OK  ] Finished Apply Kernel Variables."}
- {"dt": "2023-11-16T16:55:34.479443", "lvl": "target", "msg": "         Starting Create Volatile Files and Directories..."}
- {"dt": "2023-11-16T16:55:34.559614", "lvl": "target", "msg": "[  OK  ] Finished Coldplug All udev Devices."}
- {"dt": "2023-11-16T16:55:34.590970", "lvl": "target", "msg": "[  OK  ] Finished Create Volatile Files and Directories."}
- {"dt": "2023-11-16T16:55:34.607264", "lvl": "target", "msg": "[  OK  ] Started Rule-based Manager for Device Events and Files."}
- {"dt": "2023-11-16T16:55:34.623926", "lvl": "target", "msg": "         Starting Security Auditing Service..."}
- {"dt": "2023-11-16T16:55:34.652138", "lvl": "target", "msg": "         Starting Wait for udev To Complete Device Initialization..."}
- {"dt": "2023-11-16T16:55:34.843841", "lvl": "target", "msg": "[  OK  ] Started Security Auditing Service."}
- {"dt": "2023-11-16T16:55:34.875973", "lvl": "target", "msg": "         Starting Record System Boot/Shutdown in UTMP..."}
- {"dt": "2023-11-16T16:55:34.923359", "lvl": "target", "msg": "[  OK  ] Finished Record System Boot/Shutdown in UTMP."}
- {"dt": "2023-11-16T16:55:35.561315", "lvl": "target", "msg": "[  OK  ] Finished Wait for udev To Complete Device Initialization."}
- {"dt": "2023-11-16T16:55:35.575881", "lvl": "target", "msg": "[  OK  ] Started Hardware RNG Entropy Gatherer Daemon."}
- {"dt": "2023-11-16T16:55:35.591890", "lvl": "target", "msg": "[  OK  ] Reached target System Initialization."}
- {"dt": "2023-11-16T16:55:35.608286", "lvl": "target", "msg": "[  OK  ] Started Daily Cleanup of Temporary Directories."}
- {"dt": "2023-11-16T16:55:35.624141", "lvl": "target", "msg": "[  OK  ] Reached target Timer Units."}
- {"dt": "2023-11-16T16:55:35.645726", "lvl": "target", "msg": "[  OK  ] Listening on agl-compositor, a Wayl\u2026ositor, as a systemd user service."}
- {"dt": "2023-11-16T16:55:35.673663", "lvl": "target", "msg": "[  OK  ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket."}
- {"dt": "2023-11-16T16:55:35.677170", "lvl": "target", "msg": "[  OK  ] Listening on D-Bus System Message Bus Socket."}
- {"dt": "2023-11-16T16:55:35.706199", "lvl": "target", "msg": "[  OK  ] Listening on GPS (Global Positioning System) Daemon Sockets."}
- {"dt": "2023-11-16T16:55:35.720662", "lvl": "target", "msg": "[  OK  ] Listening on mpd.socket."}
- {"dt": "2023-11-16T16:55:35.737482", "lvl": "target", "msg": "         Starting PipeWire Multimedia System Sockets..."}
- {"dt": "2023-11-16T16:55:35.769567", "lvl": "target", "msg": "         Starting sshd.socket..."}
- {"dt": "2023-11-16T16:55:35.784508", "lvl": "target", "msg": "[  OK  ] Listening on PipeWire Multimedia System Sockets."}
- {"dt": "2023-11-16T16:55:35.832793", "lvl": "target", "msg": "[  OK  ] Listening on sshd.socket."}
- {"dt": "2023-11-16T16:55:35.849474", "lvl": "target", "msg": "[  OK  ] Reached target Socket Units."}
- {"dt": "2023-11-16T16:55:35.864919", "lvl": "target", "msg": "[  OK  ] Reached target Basic System."}
- {"dt": "2023-11-16T16:55:35.881106", "lvl": "target", "msg": "         Starting CAN interface helper..."}
- {"dt": "2023-11-16T16:55:35.896770", "lvl": "target", "msg": "         Starting D-Bus System Message Bus..."}
- {"dt": "2023-11-16T16:55:35.912796", "lvl": "target", "msg": "         Starting IPv6 Packet Filtering Framework..."}
- {"dt": "2023-11-16T16:55:35.960163", "lvl": "target", "msg": "         Starting IPv4 Packet Filtering Framework..."}
- {"dt": "2023-11-16T16:55:35.976263", "lvl": "target", "msg": "         Starting Telephony service..."}
- {"dt": "2023-11-16T16:55:36.008386", "lvl": "target", "msg": "[  OK  ] Started PipeWire Multimedia Service."}
- {"dt": "2023-11-16T16:55:36.040325", "lvl": "target", "msg": "         Starting Authorization Manager..."}
- {"dt": "2023-11-16T16:55:36.072276", "lvl": "target", "msg": "         Starting User Login Management..."}
- {"dt": "2023-11-16T16:55:36.104390", "lvl": "target", "msg": "         Starting Disk Manager..."}
- {"dt": "2023-11-16T16:55:36.136124", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager."}
- {"dt": "2023-11-16T16:55:36.166187", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager (bluetooth)."}
- {"dt": "2023-11-16T16:55:36.189676", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager (policy)."}
- {"dt": "2023-11-16T16:55:36.205679", "lvl": "target", "msg": "         Starting OpenSSH Key Generation..."}
- {"dt": "2023-11-16T16:55:36.237970", "lvl": "target", "msg": "[  OK  ] Finished IPv6 Packet Filtering Framework."}
- {"dt": "2023-11-16T16:55:36.253065", "lvl": "target", "msg": "[  OK  ] Finished IPv4 Packet Filtering Framework."}
- {"dt": "2023-11-16T16:55:36.269655", "lvl": "target", "msg": "[  OK  ] Reached target Preparation for Network."}
- {"dt": "2023-11-16T16:55:36.316904", "lvl": "target", "msg": "         Starting Network Configuration..."}
- {"dt": "2023-11-16T16:55:36.412574", "lvl": "target", "msg": "[  OK  ] Finished OpenSSH Key Generation."}
- {"dt": "2023-11-16T16:55:36.733084", "lvl": "target", "msg": "[  OK  ] Finished CAN interface helper."}
- {"dt": "2023-11-16T16:55:37.276681", "lvl": "target", "msg": "[  OK  ] Started Network Configuration."}
- {"dt": "2023-11-16T16:55:37.371947", "lvl": "target", "msg": "[  OK  ] Started D-Bus System Message Bus."}
- {"dt": "2023-11-16T16:55:37.404501", "lvl": "target", "msg": "         Starting Connection service..."}
- {"dt": "2023-11-16T16:55:37.435754", "lvl": "target", "msg": "[  OK  ] Started User Login Management."}
- {"dt": "2023-11-16T16:55:37.515174", "lvl": "target", "msg": "[  OK  ] Started Telephony service."}
- {"dt": "2023-11-16T16:55:37.626951", "lvl": "target", "msg": "[  OK  ] Started Authorization Manager."}
- {"dt": "2023-11-16T16:55:38.329714", "lvl": "target", "msg": "[  OK  ] Started Connection service."}
- {"dt": "2023-11-16T16:55:38.345979", "lvl": "target", "msg": "[  OK  ] Reached target Network."}
- {"dt": "2023-11-16T16:55:38.378616", "lvl": "target", "msg": "[  OK  ] Started agl-service-radio.service."}
- {"dt": "2023-11-16T16:55:38.394317", "lvl": "target", "msg": "         Starting applaunchd.service..."}
- {"dt": "2023-11-16T16:55:38.409380", "lvl": "target", "msg": "         Starting Avahi mDNS/DNS-SD Stack..."}
- {"dt": "2023-11-16T16:55:38.457980", "lvl": "target", "msg": "[  OK  ] Started Eclipse KUKSA.val databroker."}
- {"dt": "2023-11-16T16:55:38.489862", "lvl": "target", "msg": "[  OK  ] Started agl-service-audiomixer.service."}
- {"dt": "2023-11-16T16:55:38.505678", "lvl": "target", "msg": "[  OK  ] Started agl-service-hvac.service."}
- {"dt": "2023-11-16T16:55:38.537413", "lvl": "target", "msg": "[  OK  ] Started Eclipse KUKSA.val DBC feeder."}
- {"dt": "2023-11-16T16:55:38.554298", "lvl": "target", "msg": "         Starting Permit User Sessions..."}
- {"dt": "2023-11-16T16:55:38.665637", "lvl": "target", "msg": "[  OK  ] Finished Permit User Sessions."}
- {"dt": "2023-11-16T16:55:38.697513", "lvl": "target", "msg": "         Starting AGL compositor..."}
- {"dt": "2023-11-16T16:55:38.729023", "lvl": "target", "msg": "[  OK  ] Started Getty on tty1."}
- {"dt": "2023-11-16T16:55:38.745165", "lvl": "target", "msg": "[  OK  ] Started Serial Getty on ttyS0."}
- {"dt": "2023-11-16T16:55:38.761075", "lvl": "target", "msg": "[  OK  ] Reached target Login Prompts."}
- {"dt": "2023-11-16T16:55:38.969191", "lvl": "target", "msg": "[  OK  ] Started Avahi mDNS/DNS-SD Stack."}
- {"dt": "2023-11-16T16:55:39.240832", "lvl": "target", "msg": "         Starting Hostname Service..."}
- {"dt": "2023-11-16T16:55:39.272742", "lvl": "target", "msg": "         Starting WPA supplicant..."}
- {"dt": "2023-11-16T16:55:39.544885", "lvl": "target", "msg": "         Starting User Database Manager..."}
- {"dt": "2023-11-16T16:55:39.784028", "lvl": "target", "msg": "[  OK  ] Started WPA supplicant."}
- {"dt": "2023-11-16T16:55:39.815802", "lvl": "target", "msg": "[  OK  ] Started Hostname Service."}
- {"dt": "2023-11-16T16:55:39.879898", "lvl": "target", "msg": "[  OK  ] Started User Database Manager."}
- {"dt": "2023-11-16T16:55:40.055498", "lvl": "target", "msg": "[  OK  ] Created slice User Slice of UID 1001."}
- {"dt": "2023-11-16T16:55:40.071436", "lvl": "target", "msg": "         Starting User Runtime Directory /run/user/1001..."}
- {"dt": "2023-11-16T16:55:40.231547", "lvl": "target", "msg": "[  OK  ] Finished User Runtime Directory /run/user/1001."}
- {"dt": "2023-11-16T16:55:40.247428", "lvl": "target", "msg": "         Starting User Manager for UID 1001..."}
- {"dt": "2023-11-16T16:55:40.758434", "lvl": "target", "msg": "[  OK  ] Started Disk Manager."}
- {"dt": "2023-11-16T16:55:40.774860", "lvl": "target", "msg": "[  OK  ] Started Automount Disk Manager."}
- {"dt": "2023-11-16T16:55:41.477461", "lvl": "target", "msg": "[  OK  ] Started User Manager for UID 1001."}
- {"dt": "2023-11-16T16:55:41.493517", "lvl": "target", "msg": "[  OK  ] Started Session c1 of User agl-driver."}
- {"dt": "2023-11-16T16:55:42.388318", "lvl": "target", "msg": "[FAILED] Failed to start AGL compositor."}
- {"dt": "2023-11-16T16:55:42.404135", "lvl": "target", "msg": "See 'systemctl status agl-compositor.service' for details."}
- {"dt": "2023-11-16T16:55:42.424011", "lvl": "target", "msg": "[DEPEND] Dependency failed for homescreen.service."}
- {"dt": "2023-11-16T16:55:42.427298", "lvl": "target", "msg": "[DEPEND] Dependency failed for launcher.service."}
- {"dt": "2023-11-16T16:55:42.729655", "lvl": "target", "msg": "[  OK  ] Started applaunchd.service."}
- {"dt": "2023-11-16T16:55:42.745589", "lvl": "target", "msg": "[  OK  ] Reached target Multi-User System."}
- {"dt": "2023-11-16T16:55:42.762095", "lvl": "target", "msg": "[  OK  ] Reached target Graphical Interface."}
- {"dt": "2023-11-16T16:55:42.778399", "lvl": "target", "msg": "         Starting Record Runlevel Change in UTMP..."}
- {"dt": "2023-11-16T16:55:42.841414", "lvl": "target", "msg": "[  OK  ] Finished Record Runlevel Change in UTMP."}
- {"dt": "2023-11-16T16:55:43.891298", "lvl": "target", "msg": ""}
- {"dt": "2023-11-16T16:55:43.892541", "lvl": "target", "msg": "Automotive Grade Linux 16.90.0 h3ulcb ttyS0"}
- {"dt": "2023-11-16T16:55:43.893867", "lvl": "target", "msg": ""}
- {"dt": "2023-11-16T16:55:43.896092", "lvl": "debug", "msg": "Matched prompt #13: login:"}
- {"dt": "2023-11-16T16:55:43.897364", "lvl": "results", "msg": {"case": "kernel-messages", "definition": "lava", "duration": "27.05", "extra": {"extra": []}, "level": "2.4.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T16:55:43.899133", "lvl": "debug", "msg": "Sending username root"}
- {"dt": "2023-11-16T16:55:43.900105", "lvl": "input", "msg": "root\n"}
- {"dt": "2023-11-16T16:55:44.002555", "lvl": "target", "msg": "h3ulcb login: root"}
- {"dt": "2023-11-16T16:55:44.006127", "lvl": "debug", "msg": "Setting prompt string to ['root@raspberrypi4-64:~', 'raspberrypi4-64:~#', '/ #']"}
- {"dt": "2023-11-16T16:55:44.008132", "lvl": "debug", "msg": "login-action: Wait for prompt ['root@raspberrypi4-64:~', 'raspberrypi4-64:~#', '/ #', 'Login incorrect', 'Login timed out'] (timeout 00:18:35)"}
- {"dt": "2023-11-16T16:55:44.021806", "lvl": "target", "msg": "root"}
- {"dt": "2023-11-16T16:55:53.354840", "lvl": "target", "msg": "7[r[999;999H[6nroot@h3ulcb:~# [   37.854532] cam-dummy-reg: disabling"}
- {"dt": "2023-11-16T16:56:26.009942", "lvl": "target", "msg": "[   70.504069] block nbd0: Receive control failed (result -32)"}
- {"dt": "2023-11-16T16:56:26.013623", "lvl": "target", "msg": "[   70.510049] block nbd0: shutting down sockets"}
- {"dt": "2023-11-16T16:56:26.109523", "lvl": "target", "msg": "[   70.567387] blk_update_request: I/O error, dev nbd0, sector 3143104 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.111659", "lvl": "target", "msg": "[   70.578589] blk_update_request: I/O error, dev nbd0, sector 3143104 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.113038", "lvl": "target", "msg": "[   70.590737] blk_update_request: I/O error, dev nbd0, sector 3143072 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.113948", "lvl": "target", "msg": "[   70.602876] blk_update_request: I/O error, dev nbd0, sector 3143072 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.156531", "lvl": "target", "msg": "[   70.617667] blk_update_request: I/O error, dev nbd0, sector 482040 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.158720", "lvl": "target", "msg": "[   70.630643] blk_update_request: I/O error, dev nbd0, sector 482040 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.160485", "lvl": "target", "msg": "[   70.641480] blk_update_request: I/O error, dev nbd0, sector 482040 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.161869", "lvl": "target", "msg": "[   70.652554] blk_update_request: I/O error, dev nbd0, sector 482040 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.183280", "lvl": "target", "msg": "[   70.664024] blk_update_request: I/O error, dev nbd0, sector 3054864 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.186832", "lvl": "target", "msg": "[   70.675150] blk_update_request: I/O error, dev nbd0, sector 3054864 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:26.249086", "lvl": "target", "msg": "[   70.717588] Buffer I/O error on dev nbd0, logical block 0, lost async page write"}
- {"dt": "2023-11-16T16:56:26.251203", "lvl": "target", "msg": "[   70.725287] Buffer I/O error on dev nbd0, logical block 1, lost async page write"}
- {"dt": "2023-11-16T16:56:26.252792", "lvl": "target", "msg": "[   70.732959] Buffer I/O error on dev nbd0, logical block 461, lost async page write"}
- {"dt": "2023-11-16T16:56:26.254271", "lvl": "target", "msg": "[   70.741617] Buffer I/O error on dev nbd0, logical block 491, lost async page write"}
- {"dt": "2023-11-16T16:56:26.255762", "lvl": "target", "msg": "[   70.749485] Buffer I/O error on dev nbd0, logical block 6526, lost async page write"}
- {"dt": "2023-11-16T16:56:26.298553", "lvl": "target", "msg": "[   70.757363] Buffer I/O error on dev nbd0, logical block 524291, lost async page write"}
- {"dt": "2023-11-16T16:56:26.300050", "lvl": "target", "msg": "[   70.765558] Buffer I/O error on dev nbd0, logical block 524292, lost async page write"}
- {"dt": "2023-11-16T16:56:26.300938", "lvl": "target", "msg": "[   70.773758] Buffer I/O error on dev nbd0, logical block 524298, lost async page write"}
- {"dt": "2023-11-16T16:56:26.301626", "lvl": "target", "msg": "[   70.781996] Buffer I/O error on dev nbd0, logical block 655873, lost async page write"}
- {"dt": "2023-11-16T16:56:26.302311", "lvl": "target", "msg": "[   70.791053]  nbd0: unable to read partition table"}
- {"dt": "2023-11-16T16:56:26.303248", "lvl": "target", "msg": "[   70.796377]  nbd0: unable to read partition table"}
- {"dt": "2023-11-16T16:56:26.355745", "lvl": "target", "msg": "[   70.816057] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.357973", "lvl": "target", "msg": "[   70.827486] EXT4-fs (nbd0): previous I/O error to superblock detected"}
- {"dt": "2023-11-16T16:56:26.359561", "lvl": "target", "msg": "[   70.838854] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #820: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.360910", "lvl": "target", "msg": "[   70.854949] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #57690: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.422209", "lvl": "target", "msg": "[   70.867401] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.424568", "lvl": "target", "msg": "[   70.883036] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.425970", "lvl": "target", "msg": "[   70.898953] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #57131: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.427612", "lvl": "target", "msg": "[   70.914873] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.471544", "lvl": "target", "msg": "[   70.934886] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.473812", "lvl": "target", "msg": "[   70.950836] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.475796", "lvl": "target", "msg": "[   70.963155] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #820: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2023-11-16T16:56:26.489057", "lvl": "target", "msg": "[   70.987468]  nbd0: unable to read partition table"}
- {"dt": "2023-11-16T16:56:26.687185", "lvl": "target", "msg": "[   71.175363] EXT4-fs warning (device nbd0): dx_probe:788: inode #61706: lblock 0: comm (elper.sh): error -5 reading directory block"}
- {"dt": "2023-11-16T16:56:28.443809", "lvl": "target", "msg": "[   72.926729] Aborting journal on device nbd0-8."}
- {"dt": "2023-11-16T16:56:28.446772", "lvl": "target", "msg": "[   72.931347] Buffer I/O error on dev nbd0, logical block 393216, lost sync page write"}
- {"dt": "2023-11-16T16:56:28.448978", "lvl": "target", "msg": "[   72.939269] JBD2: Error -5 detected when updating journal superblock for nbd0-8."}
- {"dt": "2023-11-16T16:56:42.028457", "lvl": "target", "msg": "[   86.494533] EXT4-fs error: 80 callbacks suppressed"}
- {"dt": "2023-11-16T16:56:42.031311", "lvl": "target", "msg": "[   86.494555] EXT4-fs error (device nbd0): ext4_journal_check_start:83: comm kworker/u8:0: Detected aborted journal"}
- {"dt": "2023-11-16T16:56:42.033129", "lvl": "target", "msg": "[   86.514555] print_req_error: 117 callbacks suppressed"}
- {"dt": "2023-11-16T16:56:42.034806", "lvl": "target", "msg": "[   86.514572] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T16:56:42.036544", "lvl": "target", "msg": "[   86.530202] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T16:56:42.060405", "lvl": "target", "msg": "[   86.537699] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T16:56:42.062415", "lvl": "target", "msg": "[   86.544683] EXT4-fs (nbd0): Remounting filesystem read-only"}
- {"dt": "2023-11-16T16:56:42.064794", "lvl": "target", "msg": "[   86.554455] EXT4-fs (nbd0): ext4_writepages: jbd2_start: 10240 pages, ino 76184; err -30"}
- {"dt": "2023-11-16T17:01:02.634244", "lvl": "target", "msg": "[  347.108393] blk_update_request: I/O error, dev nbd0, sector 339592 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.635083", "lvl": "target", "msg": "[  347.119270] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #20: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.635618", "lvl": "target", "msg": "[  347.130913] blk_update_request: I/O error, dev nbd0, sector 339592 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.640576", "lvl": "target", "msg": "[  347.141835] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.679423", "lvl": "target", "msg": "[  347.141846] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #20: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.680140", "lvl": "target", "msg": "[  347.152307] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:02.680770", "lvl": "target", "msg": "[  347.172094] blk_update_request: I/O error, dev nbd0, sector 3719160 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.682374", "lvl": "target", "msg": "[  347.183064] blk_update_request: I/O error, dev nbd0, sector 339592 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.724906", "lvl": "target", "msg": "[  347.183105] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #57131: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.725641", "lvl": "target", "msg": "[  347.193932] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:01:02.726108", "lvl": "target", "msg": "[  347.211538] blk_update_request: I/O error, dev nbd0, sector 3719160 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.726548", "lvl": "target", "msg": "[  347.211546] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #20: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.767570", "lvl": "target", "msg": "[  347.222550] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.768336", "lvl": "target", "msg": "[  347.222986] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #57131: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.768824", "lvl": "target", "msg": "[  347.255971] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:02.769248", "lvl": "target", "msg": "[  347.263450] blk_update_request: I/O error, dev nbd0, sector 3719160 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.811582", "lvl": "target", "msg": "[  347.274543] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #57131: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.812492", "lvl": "target", "msg": "[  347.274569] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:01:02.813033", "lvl": "target", "msg": "[  347.286416] blk_update_request: I/O error, dev nbd0, sector 3719160 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.813484", "lvl": "target", "msg": "[  347.303086] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:01:02.814500", "lvl": "target", "msg": "[  347.303094] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #57131: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.856492", "lvl": "target", "msg": "[  347.313589] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:02.857242", "lvl": "target", "msg": "[  347.332688] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:01:02.857712", "lvl": "target", "msg": "[  347.332711] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #57131: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.858157", "lvl": "target", "msg": "[  347.338711] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:02.858620", "lvl": "target", "msg": "[  347.357804] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:01:02.900422", "lvl": "target", "msg": "[  347.357805] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #57131: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.901138", "lvl": "target", "msg": "[  347.363826] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:02.901597", "lvl": "target", "msg": "[  347.383685] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #57131: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2023-11-16T17:01:02.902040", "lvl": "target", "msg": "[  347.383690] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:01:02.902471", "lvl": "target", "msg": "[  347.395478] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:02.904918", "lvl": "target", "msg": "[  347.408809] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:01:02.944518", "lvl": "target", "msg": "[  347.409946] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:02.945245", "lvl": "target", "msg": "[  347.414843] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:02.945703", "lvl": "target", "msg": "[  347.434523] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:01:02.946128", "lvl": "target", "msg": "[  347.434524] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:02.989753", "lvl": "target", "msg": "[  347.452925] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:02.990489", "lvl": "target", "msg": "[  347.465361] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:02.990947", "lvl": "target", "msg": "[  347.477789] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:02.991383", "lvl": "target", "msg": "[  347.491024] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:03.034204", "lvl": "target", "msg": "[  347.503577] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:03.034936", "lvl": "target", "msg": "[  347.516032] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:03.035394", "lvl": "target", "msg": "[  347.528497] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:03.089862", "lvl": "target", "msg": "[  347.541033] EXT4-fs warning (device nbd0): dx_probe:788: inode #5448: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2023-11-16T17:01:03.090594", "lvl": "target", "msg": "[  347.554264] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:03.091054", "lvl": "target", "msg": "[  347.561830] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:01:03.091483", "lvl": "target", "msg": "[  347.567951] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:03.091901", "lvl": "target", "msg": "[  347.575556] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:01:03.094721", "lvl": "target", "msg": "[  347.581694] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:01:03.095919", "lvl": "target", "msg": "[  347.589307] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:10:32.170734", "lvl": "target", "msg": "[  916.651963] print_req_error: 1121 callbacks suppressed"}
- {"dt": "2023-11-16T17:10:32.173736", "lvl": "target", "msg": "[  916.651984] blk_update_request: I/O error, dev nbd0, sector 354192 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:10:32.175541", "lvl": "target", "msg": "[  916.668094] EXT4-fs error: 475 callbacks suppressed"}
- {"dt": "2023-11-16T17:10:32.177148", "lvl": "target", "msg": "[  916.668110] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #820: comm (tmpfiles): reading directory lblock 0"}
- {"dt": "2023-11-16T17:10:32.178103", "lvl": "target", "msg": "[  916.684294] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:10:32.214764", "lvl": "target", "msg": "[  916.694787] buffer_io_error: 346 callbacks suppressed"}
- {"dt": "2023-11-16T17:10:32.217733", "lvl": "target", "msg": "[  916.694805] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:10:32.219560", "lvl": "target", "msg": "[  916.707449] blk_update_request: I/O error, dev nbd0, sector 354192 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:10:32.220951", "lvl": "target", "msg": "[  916.718298] EXT4-fs: 346 callbacks suppressed"}
- {"dt": "2023-11-16T17:10:32.221729", "lvl": "target", "msg": "[  916.718307] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:10:32.222621", "lvl": "target", "msg": "[  916.718327] EXT4-fs error (device nbd0): __ext4_find_entry:1612: inode #820: comm (tmpfiles): reading directory lblock 0"}
- {"dt": "2023-11-16T17:10:32.259087", "lvl": "target", "msg": "[  916.739929] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:10:32.260134", "lvl": "target", "msg": "[  916.750411] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2023-11-16T17:10:32.261372", "lvl": "target", "msg": "[  916.757904] blk_update_request: I/O error, dev nbd0, sector 3995104 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:10:32.262537", "lvl": "target", "msg": "[  916.768842] EXT4-fs warning: 325 callbacks suppressed"}
- {"dt": "2023-11-16T17:10:32.263877", "lvl": "target", "msg": "[  916.768846] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2023-11-16T17:10:32.302602", "lvl": "target", "msg": "[  916.768854] EXT4-fs warning (device nbd0): dx_probe:788: inode #61706: lblock 0: comm (tmpfiles): error -5 reading directory block"}
- {"dt": "2023-11-16T17:10:32.304035", "lvl": "target", "msg": "[  916.792057] blk_update_request: I/O error, dev nbd0, sector 354216 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2023-11-16T17:10:32.306942", "lvl": "target", "msg": "[  916.802936] EXT4-fs warning (device nbd0): dx_probe:788: inode #834: lblock 0: comm (tmpfiles): error -5 reading directory block"}
- {"dt": "2023-11-16T17:14:18.847409", "lvl": "exception", "msg": "login-action timed out after 1142 seconds"}
- {"dt": "2023-11-16T17:14:18.849593", "lvl": "debug", "msg": "end: 2.4.4.1 login-action (duration 00:19:02) [common]"}
- {"dt": "2023-11-16T17:14:18.851515", "lvl": "results", "msg": {"case": "login-action", "definition": "lava", "duration": "1142.00", "extra": {"fail": "login-action timed out after 1142 seconds", "success": "No kernel warnings or errors detected."}, "level": "2.4.4.1", "namespace": "common", "result": "fail"}}
- {"dt": "2023-11-16T17:14:18.855220", "lvl": "error", "msg": "auto-login-action failed: 1 of 1 attempts. 'login-action timed out after 1142 seconds'"}
- {"dt": "2023-11-16T17:14:18.857266", "lvl": "exception", "msg": "login-action timed out after 1142 seconds"}
- {"dt": "2023-11-16T17:14:18.859171", "lvl": "debug", "msg": "end: 2.4.4 auto-login-action (duration 00:19:04) [common]"}
- {"dt": "2023-11-16T17:14:18.860911", "lvl": "results", "msg": {"case": "auto-login-action", "definition": "lava", "duration": "1143.85", "extra": {"fail": "login-action timed out after 1142 seconds"}, "level": "2.4.4", "namespace": "common", "result": "fail"}}
- {"dt": "2023-11-16T17:14:18.864045", "lvl": "exception", "msg": "login-action timed out after 1142 seconds"}
- {"dt": "2023-11-16T17:14:18.864757", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:19:57) [common]"}
- {"dt": "2023-11-16T17:14:18.865323", "lvl": "results", "msg": {"case": "uboot-commands", "definition": "lava", "duration": "1196.58", "extra": {"fail": "login-action timed out after 1142 seconds"}, "level": "2.4", "namespace": "common", "result": "fail"}}
- {"dt": "2023-11-16T17:14:18.866273", "lvl": "error", "msg": "uboot-action failed: 1 of 1 attempts. 'login-action timed out after 1142 seconds'"}
- {"dt": "2023-11-16T17:14:18.866857", "lvl": "exception", "msg": "login-action timed out after 1142 seconds"}
- {"dt": "2023-11-16T17:14:18.867351", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:20:00) [common]"}
- {"dt": "2023-11-16T17:14:18.867882", "lvl": "results", "msg": {"case": "uboot-action", "definition": "lava", "duration": "1199.77", "extra": {"fail": "login-action timed out after 1142 seconds"}, "level": "2", "namespace": "common", "result": "fail"}}
- {"dt": "2023-11-16T17:14:18.869151", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2023-11-16T17:14:18.869952", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33547/nbd-deploy-ky0tlcay/initrd"}
- {"dt": "2023-11-16T17:14:18.871303", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33547/nbd-deploy-ky0tlcay/kernel"}
- {"dt": "2023-11-16T17:14:18.872642", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33547/nbd-deploy-ky0tlcay/dtb"}
- {"dt": "2023-11-16T17:14:18.873958", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33547/nbd-deploy-ky0tlcay/nbdroot"}
- {"dt": "2023-11-16T17:14:18.876365", "lvl": "debug", "msg": "start: 7.1 power-off (timeout 00:00:10) [common]"}
- {"dt": "2023-11-16T17:14:18.877480", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '7'"}
- {"dt": "2023-11-16T17:14:22.325999", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-11-16T17:14:22.363313", "lvl": "debug", "msg": "Returned 0 in 3 seconds"}
- {"dt": "2023-11-16T17:14:22.466482", "lvl": "debug", "msg": "end: 7.1 power-off (duration 00:00:04) [common]"}
- {"dt": "2023-11-16T17:14:22.468577", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "3.59", "extra": {"status": "success"}, "level": "7.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-16T17:14:22.472377", "lvl": "debug", "msg": "start: 7.2 read-feedback (timeout 00:29:56) [common]"}
- {"dt": "2023-11-16T17:14:22.476581", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2023-11-16T17:14:23.480443", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2023-11-16T17:14:23.482822", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2023-11-16T17:14:23.586691", "lvl": "debug", "msg": "end: 7.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2023-11-16T17:14:23.588883", "lvl": "debug", "msg": "lava-xnbd cleanup"}
- {"dt": "2023-11-16T17:14:23.590786", "lvl": "debug", "msg": "clean NBD port 61971"}
- {"dt": "2023-11-16T17:14:26.856535", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/33547"}
- {"dt": "2023-11-16T17:14:26.955072", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/33547"}
- {"dt": "2023-11-16T17:14:26.956114", "lvl": "error", "msg": "JobError: Your job cannot terminate cleanly."}
- {"dt": "2023-11-16T17:14:26.956959", "lvl": "results", "msg": {"case": "job", "definition": "lava", "error_msg": "login-action timed out after 1142 seconds", "error_type": "Job", "result": "fail"}}
