- {"dt": "2023-11-14T17:30:24.949752", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.01"}
- {"dt": "2023-11-14T17:30:24.951218", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2023-11-14T17:30:24.952551", "lvl": "info", "msg": "Start time: 2023-11-14 17:30:24.952472+00:00 (UTC)"}
- {"dt": "2023-11-14T17:30:24.953857", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz exists"}
- {"dt": "2023-11-14T17:30:25.175300", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/Image exists"}
- {"dt": "2023-11-14T17:30:25.393058", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb exists"}
- {"dt": "2023-11-14T17:30:25.609836", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/agl-demo-platform-raspberrypi4-64.ext4.xz exists"}
- {"dt": "2023-11-14T17:30:25.833528", "lvl": "info", "msg": "validate duration: 0.88"}
- {"dt": "2023-11-14T17:30:25.834401", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2023-11-14T17:30:25.835616", "lvl": "info", "msg": "start: 1 nbd-deploy (timeout 01:30:00) [common]"}
- {"dt": "2023-11-14T17:30:25.836841", "lvl": "info", "msg": "Making protocol call for nbd-deploy using lava-xnbd"}
- {"dt": "2023-11-14T17:30:25.837581", "lvl": "debug", "msg": "[nbd-deploy] Checking protocol data for lava-xnbd"}
- {"dt": "2023-11-14T17:30:25.838229", "lvl": "debug", "msg": "Get a port from pool"}
- {"dt": "2023-11-14T17:30:25.839306", "lvl": "debug", "msg": "Set_port 61999"}
- {"dt": "2023-11-14T17:30:25.840332", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 01:30:00) [common]"}
- {"dt": "2023-11-14T17:30:25.841264", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 01:30:00) [common]"}
- {"dt": "2023-11-14T17:30:25.842593", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-14T17:30:25.843332", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-14T17:30:25.844052", "lvl": "debug", "msg": "total size: 2066870 (1MB)"}
- {"dt": "2023-11-14T17:30:25.845497", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-11-14T17:30:26.164569", "lvl": "debug", "msg": "progress   1% (0MB)"}
- {"dt": "2023-11-14T17:30:26.370898", "lvl": "debug", "msg": "progress   6% (0MB)"}
- {"dt": "2023-11-14T17:30:26.473396", "lvl": "debug", "msg": "progress  11% (0MB)"}
- {"dt": "2023-11-14T17:30:26.482352", "lvl": "debug", "msg": "progress  17% (0MB)"}
- {"dt": "2023-11-14T17:30:26.576416", "lvl": "debug", "msg": "progress  22% (0MB)"}
- {"dt": "2023-11-14T17:30:26.587695", "lvl": "debug", "msg": "progress  28% (0MB)"}
- {"dt": "2023-11-14T17:30:26.592399", "lvl": "debug", "msg": "progress  33% (0MB)"}
- {"dt": "2023-11-14T17:30:26.596866", "lvl": "debug", "msg": "progress  38% (0MB)"}
- {"dt": "2023-11-14T17:30:26.688736", "lvl": "debug", "msg": "progress  44% (0MB)"}
- {"dt": "2023-11-14T17:30:26.693884", "lvl": "debug", "msg": "progress  49% (0MB)"}
- {"dt": "2023-11-14T17:30:26.699548", "lvl": "debug", "msg": "progress  55% (1MB)"}
- {"dt": "2023-11-14T17:30:26.786907", "lvl": "debug", "msg": "progress  60% (1MB)"}
- {"dt": "2023-11-14T17:30:26.794179", "lvl": "debug", "msg": "progress  65% (1MB)"}
- {"dt": "2023-11-14T17:30:26.799738", "lvl": "debug", "msg": "progress  71% (1MB)"}
- {"dt": "2023-11-14T17:30:26.885708", "lvl": "debug", "msg": "progress  76% (1MB)"}
- {"dt": "2023-11-14T17:30:26.895809", "lvl": "debug", "msg": "progress  82% (1MB)"}
- {"dt": "2023-11-14T17:30:26.902039", "lvl": "debug", "msg": "progress  87% (1MB)"}
- {"dt": "2023-11-14T17:30:26.988075", "lvl": "debug", "msg": "progress  93% (1MB)"}
- {"dt": "2023-11-14T17:30:26.993387", "lvl": "debug", "msg": "progress  98% (1MB)"}
- {"dt": "2023-11-14T17:30:26.997391", "lvl": "info", "msg": "1MB downloaded in 1.15s (1.71MB/s)"}
- {"dt": "2023-11-14T17:30:26.998619", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:30:26.999305", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "1.16", "extra": {"label": "initrd", "md5sum": "0ffef2c4bfff2949cd6f1e81db47a269", "sha256sum": "858f6065905c33f932c8e037337fd7143b5e730ed25d7a46d4f39babcafd1cc6", "sha512sum": "82d8341b159b1ecf46ad5b1bcc2a81e6ee6f6c19791e5a635ba0042d31c3e4c5270f3ca4bdd43587fc513840b0152e37b8d49597cc254c0da3ca064622cf623a", "size": ! "2066870"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:30:27.000950", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:30:27.001757", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 01:29:59) [common]"}
- {"dt": "2023-11-14T17:30:27.002588", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 01:29:59) [common]"}
- {"dt": "2023-11-14T17:30:27.003750", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/Image"}
- {"dt": "2023-11-14T17:30:27.004475", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/kernel/Image"}
- {"dt": "2023-11-14T17:30:27.005050", "lvl": "debug", "msg": "total size: 24244736 (23MB)"}
- {"dt": "2023-11-14T17:30:27.005607", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-11-14T17:30:27.314991", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-11-14T17:30:27.918031", "lvl": "debug", "msg": "progress   5% (1MB)"}
- {"dt": "2023-11-14T17:30:28.223313", "lvl": "debug", "msg": "progress  10% (2MB)"}
- {"dt": "2023-11-14T17:30:28.526718", "lvl": "debug", "msg": "progress  15% (3MB)"}
- {"dt": "2023-11-14T17:30:28.822311", "lvl": "debug", "msg": "progress  20% (4MB)"}
- {"dt": "2023-11-14T17:30:29.045478", "lvl": "debug", "msg": "progress  25% (5MB)"}
- {"dt": "2023-11-14T17:30:29.337007", "lvl": "debug", "msg": "progress  30% (6MB)"}
- {"dt": "2023-11-14T17:30:29.551340", "lvl": "debug", "msg": "progress  35% (8MB)"}
- {"dt": "2023-11-14T17:30:29.824510", "lvl": "debug", "msg": "progress  40% (9MB)"}
- {"dt": "2023-11-14T17:30:30.035723", "lvl": "debug", "msg": "progress  45% (10MB)"}
- {"dt": "2023-11-14T17:30:30.240572", "lvl": "debug", "msg": "progress  50% (11MB)"}
- {"dt": "2023-11-14T17:30:30.439813", "lvl": "debug", "msg": "progress  55% (12MB)"}
- {"dt": "2023-11-14T17:30:30.628493", "lvl": "debug", "msg": "progress  60% (13MB)"}
- {"dt": "2023-11-14T17:30:30.777150", "lvl": "debug", "msg": "progress  65% (15MB)"}
- {"dt": "2023-11-14T17:30:30.967980", "lvl": "debug", "msg": "progress  70% (16MB)"}
- {"dt": "2023-11-14T17:30:31.152908", "lvl": "debug", "msg": "progress  75% (17MB)"}
- {"dt": "2023-11-14T17:30:31.293100", "lvl": "debug", "msg": "progress  80% (18MB)"}
- {"dt": "2023-11-14T17:30:31.474304", "lvl": "debug", "msg": "progress  85% (19MB)"}
- {"dt": "2023-11-14T17:30:31.697409", "lvl": "debug", "msg": "progress  90% (20MB)"}
- {"dt": "2023-11-14T17:30:31.807697", "lvl": "debug", "msg": "progress  95% (21MB)"}
- {"dt": "2023-11-14T17:30:32.031246", "lvl": "debug", "msg": "progress 100% (23MB)"}
- {"dt": "2023-11-14T17:30:32.033196", "lvl": "info", "msg": "23MB downloaded in 5.03s (4.60MB/s)"}
- {"dt": "2023-11-14T17:30:32.034644", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:05) [common]"}
- {"dt": "2023-11-14T17:30:32.035378", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "5.03", "extra": {"label": "kernel", "md5sum": "66b8fd214f2f7be835a17bec1ca3c3bb", "sha256sum": "67454e961704ae6231674c1ca03d89f0abc16886ccb74d10b3da661d5e311c4b", "sha512sum": "049ce1c442751dd48a568a1f62bb4e6217ad3d57a570b9c4913020b9a701525c2bfa22a79d5eca35a1cc0386fbf528fe2df0bbfa219cf0514731439bc8b4fcda", "size": ! "24244736"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:30:32.037835", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:05) [common]"}
- {"dt": "2023-11-14T17:30:32.038802", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 01:29:54) [common]"}
- {"dt": "2023-11-14T17:30:32.040672", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 01:29:54) [common]"}
- {"dt": "2023-11-14T17:30:32.042051", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-14T17:30:32.042788", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-14T17:30:32.043345", "lvl": "debug", "msg": "total size: 52323 (0MB)"}
- {"dt": "2023-11-14T17:30:32.043896", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-11-14T17:30:32.362441", "lvl": "debug", "msg": "progress  62% (0MB)"}
- {"dt": "2023-11-14T17:30:32.466476", "lvl": "debug", "msg": "progress 100% (0MB)"}
- {"dt": "2023-11-14T17:30:32.469781", "lvl": "info", "msg": "0MB downloaded in 0.43s (0.12MB/s)"}
- {"dt": "2023-11-14T17:30:32.472350", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:30:32.473679", "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-14T17:30:32.475981", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:30:32.477703", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 01:29:53) [common]"}
- {"dt": "2023-11-14T17:30:32.478633", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 01:29:53) [common]"}
- {"dt": "2023-11-14T17:30:32.480753", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29406/1/raspberrypi4/agl-demo-platform-raspberrypi4-64.ext4.xz"}
- {"dt": "2023-11-14T17:30:32.481722", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/nbdroot/agl-demo-platform-raspberrypi4-64.ext4"}
- {"dt": "2023-11-14T17:30:32.482641", "lvl": "debug", "msg": "total size: 795850408 (758MB)"}
- {"dt": "2023-11-14T17:30:32.483455", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2023-11-14T17:30:32.905664", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-11-14T17:30:42.268983", "lvl": "debug", "msg": "progress   5% (37MB)"}
- {"dt": "2023-11-14T17:30:50.873628", "lvl": "debug", "msg": "progress  10% (75MB)"}
- {"dt": "2023-11-14T17:31:00.840901", "lvl": "debug", "msg": "progress  15% (113MB)"}
- {"dt": "2023-11-14T17:31:13.444598", "lvl": "debug", "msg": "progress  20% (151MB)"}
- {"dt": "2023-11-14T17:31:23.876449", "lvl": "debug", "msg": "progress  25% (189MB)"}
- {"dt": "2023-11-14T17:31:32.547440", "lvl": "debug", "msg": "progress  30% (227MB)"}
- {"dt": "2023-11-14T17:31:37.374479", "lvl": "debug", "msg": "progress  35% (265MB)"}
- {"dt": "2023-11-14T17:31:40.668849", "lvl": "debug", "msg": "progress  40% (303MB)"}
- {"dt": "2023-11-14T17:31:43.637029", "lvl": "debug", "msg": "progress  45% (341MB)"}
- {"dt": "2023-11-14T17:32:04.826029", "lvl": "debug", "msg": "progress  50% (379MB)"}
- {"dt": "2023-11-14T17:32:13.370708", "lvl": "debug", "msg": "progress  55% (417MB)"}
- {"dt": "2023-11-14T17:32:18.682921", "lvl": "debug", "msg": "progress  60% (455MB)"}
- {"dt": "2023-11-14T17:32:26.434741", "lvl": "debug", "msg": "progress  65% (493MB)"}
- {"dt": "2023-11-14T17:32:37.474998", "lvl": "debug", "msg": "progress  70% (531MB)"}
- {"dt": "2023-11-14T17:32:46.978638", "lvl": "debug", "msg": "progress  75% (569MB)"}
- {"dt": "2023-11-14T17:32:56.849070", "lvl": "debug", "msg": "progress  80% (607MB)"}
- {"dt": "2023-11-14T17:33:05.845894", "lvl": "debug", "msg": "progress  85% (645MB)"}
- {"dt": "2023-11-14T17:33:14.391040", "lvl": "debug", "msg": "progress  90% (683MB)"}
- {"dt": "2023-11-14T17:33:22.846712", "lvl": "debug", "msg": "progress  95% (721MB)"}
- {"dt": "2023-11-14T17:33:35.521131", "lvl": "debug", "msg": "progress 100% (758MB)"}
- {"dt": "2023-11-14T17:33:39.092601", "lvl": "info", "msg": "758MB downloaded in 186.61s (4.07MB/s)"}
- {"dt": "2023-11-14T17:33:39.094730", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:03:07) [common]"}
- {"dt": "2023-11-14T17:33:39.095682", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "186.62", "extra": {"label": "nbdroot", "md5sum": "056f6ff86b156026d6cb21a1664d9c9c", "sha256sum": "b9b5dc5668a49a3c8bdbde7a3b200f370795eb06859f8be83bbf025b259cff8b", "sha512sum": "bd28f7ec5bb13ecbac50b67d7855eebe331938bea6f948ec49d1a0329bdf56b2f4a6dade6dc273b2ad08636a4eed78b726c35f06d002247e357f985c8fc38836", "size": ! "795850408"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:39.097477", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:03:07) [common]"}
- {"dt": "2023-11-14T17:33:39.098428", "lvl": "debug", "msg": "start: 1.5 lava-overlay (timeout 01:26:47) [common]"}
- {"dt": "2023-11-14T17:33:39.100490", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup"}
- {"dt": "2023-11-14T17:33:39.101934", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin"}
- {"dt": "2023-11-14T17:33:39.103124", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/tests"}
- {"dt": "2023-11-14T17:33:39.104515", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/results"}
- {"dt": "2023-11-14T17:33:39.105788", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-add-keys"}
- {"dt": "2023-11-14T17:33:39.107390", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-add-sources"}
- {"dt": "2023-11-14T17:33:39.108957", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-background-process-start"}
- {"dt": "2023-11-14T17:33:39.110457", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-background-process-stop"}
- {"dt": "2023-11-14T17:33:39.111971", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-common-functions"}
- {"dt": "2023-11-14T17:33:39.113482", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-echo-ipv4"}
- {"dt": "2023-11-14T17:33:39.114965", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-install-packages"}
- {"dt": "2023-11-14T17:33:39.116521", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-installed-packages"}
- {"dt": "2023-11-14T17:33:39.118006", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-os-build"}
- {"dt": "2023-11-14T17:33:39.119486", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-probe-channel"}
- {"dt": "2023-11-14T17:33:39.121204", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-probe-ip"}
- {"dt": "2023-11-14T17:33:39.122689", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-target-ip"}
- {"dt": "2023-11-14T17:33:39.124154", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-target-mac"}
- {"dt": "2023-11-14T17:33:39.125663", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-target-storage"}
- {"dt": "2023-11-14T17:33:39.127157", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-case"}
- {"dt": "2023-11-14T17:33:39.128717", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-event"}
- {"dt": "2023-11-14T17:33:39.130240", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-feedback"}
- {"dt": "2023-11-14T17:33:39.131732", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-raise"}
- {"dt": "2023-11-14T17:33:39.133301", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-reference"}
- {"dt": "2023-11-14T17:33:39.134769", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-runner"}
- {"dt": "2023-11-14T17:33:39.136286", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-set"}
- {"dt": "2023-11-14T17:33:39.137792", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-test-shell"}
- {"dt": "2023-11-14T17:33:39.139314", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-install-packages (oe)"}
- {"dt": "2023-11-14T17:33:39.141053", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/bin/lava-installed-packages (oe)"}
- {"dt": "2023-11-14T17:33:39.142514", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/environment"}
- {"dt": "2023-11-14T17:33:39.143751", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2023-11-14T17:33:39.144628", "lvl": "debug", "msg": "- LAVA_JOB_ID=33479"}
- {"dt": "2023-11-14T17:33:39.145368", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.66.1"}
- {"dt": "2023-11-14T17:33:39.146563", "lvl": "debug", "msg": "start: 1.5.1 ssh-authorize (timeout 01:26:47) [common]"}
- {"dt": "2023-11-14T17:33:39.149239", "lvl": "debug", "msg": "end: 1.5.1 ssh-authorize (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:39.150225", "lvl": "debug", "msg": "start: 1.5.2 lava-vland-overlay (timeout 01:26:47) [common]"}
- {"dt": "2023-11-14T17:33:39.151005", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2023-11-14T17:33:39.151824", "lvl": "debug", "msg": "end: 1.5.2 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:39.152749", "lvl": "debug", "msg": "start: 1.5.3 lava-multinode-overlay (timeout 01:26:47) [common]"}
- {"dt": "2023-11-14T17:33:39.153458", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2023-11-14T17:33:39.154304", "lvl": "debug", "msg": "end: 1.5.3 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:39.155292", "lvl": "debug", "msg": "start: 1.5.4 test-definition (timeout 01:26:47) [common]"}
- {"dt": "2023-11-14T17:33:39.156120", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2023-11-14T17:33:39.157166", "lvl": "debug", "msg": "start: 1.5.4.1 git-repo-action (timeout 01:26:47) [common]"}
- {"dt": "2023-11-14T17:33:39.157958", "lvl": "debug", "msg": "Using /lava-33479 at stage 0"}
- {"dt": "2023-11-14T17:33:39.159062", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-14T17:33:39.159930", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/0/tests/0_network-veth'"}
- {"dt": "2023-11-14T17:33:39.753786", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/0/tests/0_network-veth/test-suites/short-smoke/network-veth.yaml"}
- {"dt": "2023-11-14T17:33:39.759276", "lvl": "debug", "msg": "uuid=33479_1.5.4.1 testdef=None"}
- {"dt": "2023-11-14T17:33:39.760829", "lvl": "debug", "msg": "end: 1.5.4.1 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:33:39.761955", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.60", "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-14T17:33:39.764054", "lvl": "debug", "msg": "start: 1.5.4.2 test-overlay (timeout 01:26:46) [common]"}
- {"dt": "2023-11-14T17:33:39.768962", "lvl": "debug", "msg": "end: 1.5.4.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:39.769661", "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": "33479_1.5.4.1"}, "level": "1.5.4.2", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:39.771242", "lvl": "debug", "msg": "start: 1.5.4.3 test-install-overlay (timeout 01:26:46) [common]"}
- {"dt": "2023-11-14T17:33:39.777452", "lvl": "debug", "msg": "end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:39.778169", "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": "33479_1.5.4.1", "uuid": "33479_1.5.4.1"}, "level": "1.5.4.3", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:39.779783", "lvl": "debug", "msg": "start: 1.5.4.4 test-runscript-overlay (timeout 01:26:46) [common]"}
- {"dt": "2023-11-14T17:33:39.785787", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/0/tests/0_network-veth test_uuid 33479_1.5.4.1"}
- {"dt": "2023-11-14T17:33:39.787427", "lvl": "debug", "msg": "end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:39.788143", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/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": "33479_1.5.4.1"}, "level": "1.5.4.4", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:39.789798", "lvl": "debug", "msg": "start: 1.5.4.5 git-repo-action (timeout 01:26:46) [common]"}
- {"dt": "2023-11-14T17:33:39.790536", "lvl": "debug", "msg": "Using /lava-33479 at stage 1"}
- {"dt": "2023-11-14T17:33:39.791560", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-14T17:33:39.792383", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/1_ci-busybox'"}
- {"dt": "2023-11-14T17:33:40.371899", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/1_ci-busybox"}
- {"dt": "2023-11-14T17:33:40.383931", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/1_ci-busybox/test-suites/short-smoke/busybox.yaml"}
- {"dt": "2023-11-14T17:33:40.387429", "lvl": "debug", "msg": "uuid=33479_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-14T17:33:40.388683", "lvl": "debug", "msg": "end: 1.5.4.5 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:33:40.389456", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.60", "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-14T17:33:40.391038", "lvl": "debug", "msg": "start: 1.5.4.6 test-overlay (timeout 01:26:45) [common]"}
- {"dt": "2023-11-14T17:33:40.397855", "lvl": "debug", "msg": "end: 1.5.4.6 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:40.398556", "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": "33479_1.5.4.5"}, "level": "1.5.4.6", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:40.399943", "lvl": "debug", "msg": "start: 1.5.4.7 test-install-overlay (timeout 01:26:45) [common]"}
- {"dt": "2023-11-14T17:33:40.407574", "lvl": "debug", "msg": "end: 1.5.4.7 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:40.408427", "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": "33479_1.5.4.5", "uuid": "33479_1.5.4.5"}, "level": "1.5.4.7", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:40.409939", "lvl": "debug", "msg": "start: 1.5.4.8 test-runscript-overlay (timeout 01:26:45) [common]"}
- {"dt": "2023-11-14T17:33:40.417336", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/1_ci-busybox test_uuid 33479_1.5.4.5"}
- {"dt": "2023-11-14T17:33:40.418893", "lvl": "debug", "msg": "end: 1.5.4.8 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:40.419586", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/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": "33479_1.5.4.5"}, "level": "1.5.4.8", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:40.421111", "lvl": "debug", "msg": "start: 1.5.4.9 git-repo-action (timeout 01:26:45) [common]"}
- {"dt": "2023-11-14T17:33:40.421752", "lvl": "debug", "msg": "Using /lava-33479 at stage 1"}
- {"dt": "2023-11-14T17:33:40.422663", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-14T17:33:40.423355", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/2_ci-smoke-tests-basic'"}
- {"dt": "2023-11-14T17:33:41.018255", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/2_ci-smoke-tests-basic"}
- {"dt": "2023-11-14T17:33:41.028991", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/2_ci-smoke-tests-basic/test-suites/short-smoke/smoke-tests-basic.yaml"}
- {"dt": "2023-11-14T17:33:41.031925", "lvl": "debug", "msg": "uuid=33479_1.5.4.9 testdef=None"}
- {"dt": "2023-11-14T17:33:41.033032", "lvl": "debug", "msg": "end: 1.5.4.9 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:33:41.033695", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.61", "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-14T17:33:41.035062", "lvl": "debug", "msg": "start: 1.5.4.10 test-overlay (timeout 01:26:45) [common]"}
- {"dt": "2023-11-14T17:33:41.040532", "lvl": "debug", "msg": "end: 1.5.4.10 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:41.041352", "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": "33479_1.5.4.9"}, "level": "1.5.4.10", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:41.042961", "lvl": "debug", "msg": "start: 1.5.4.11 test-install-overlay (timeout 01:26:45) [common]"}
- {"dt": "2023-11-14T17:33:41.051150", "lvl": "debug", "msg": "end: 1.5.4.11 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:41.051882", "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": "33479_1.5.4.9", "uuid": "33479_1.5.4.9"}, "level": "1.5.4.11", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:41.053467", "lvl": "debug", "msg": "start: 1.5.4.12 test-runscript-overlay (timeout 01:26:45) [common]"}
- {"dt": "2023-11-14T17:33:41.060899", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/2_ci-smoke-tests-basic test_uuid 33479_1.5.4.9"}
- {"dt": "2023-11-14T17:33:41.063709", "lvl": "debug", "msg": "end: 1.5.4.12 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:41.064521", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/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": "33479_1.5.4.9"}, "level": "1.5.4.12", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:41.066137", "lvl": "debug", "msg": "start: 1.5.4.13 git-repo-action (timeout 01:26:45) [common]"}
- {"dt": "2023-11-14T17:33:41.066876", "lvl": "debug", "msg": "Using /lava-33479 at stage 1"}
- {"dt": "2023-11-14T17:33:41.067883", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-14T17:33:41.068731", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/3_ci-service-check'"}
- {"dt": "2023-11-14T17:33:41.664054", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/3_ci-service-check"}
- {"dt": "2023-11-14T17:33:41.678053", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/3_ci-service-check/test-suites/short-smoke/service-check.yaml"}
- {"dt": "2023-11-14T17:33:41.682237", "lvl": "debug", "msg": "uuid=33479_1.5.4.13 testdef=None"}
- {"dt": "2023-11-14T17:33:41.683284", "lvl": "debug", "msg": "end: 1.5.4.13 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:33:41.683928", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.62", "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-14T17:33:41.685309", "lvl": "debug", "msg": "start: 1.5.4.14 test-overlay (timeout 01:26:44) [common]"}
- {"dt": "2023-11-14T17:33:41.690442", "lvl": "debug", "msg": "end: 1.5.4.14 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:41.691093", "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": "33479_1.5.4.13"}, "level": "1.5.4.14", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:41.692749", "lvl": "debug", "msg": "start: 1.5.4.15 test-install-overlay (timeout 01:26:44) [common]"}
- {"dt": "2023-11-14T17:33:41.699988", "lvl": "debug", "msg": "end: 1.5.4.15 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:41.701315", "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": "33479_1.5.4.13", "uuid": "33479_1.5.4.13"}, "level": "1.5.4.15", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:41.702821", "lvl": "debug", "msg": "start: 1.5.4.16 test-runscript-overlay (timeout 01:26:44) [common]"}
- {"dt": "2023-11-14T17:33:41.709641", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1/tests/3_ci-service-check test_uuid 33479_1.5.4.13"}
- {"dt": "2023-11-14T17:33:41.710376", "lvl": "debug", "msg": "BUILD_TAGS=''"}
- {"dt": "2023-11-14T17:33:41.710888", "lvl": "debug", "msg": "DEVICE_TAGS=''"}
- {"dt": "2023-11-14T17:33:41.712172", "lvl": "debug", "msg": "end: 1.5.4.16 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:41.712911", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/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": "33479_1.5.4.13"}, "level": "1.5.4.16", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:41.714347", "lvl": "debug", "msg": "start: 1.5.4.17 git-repo-action (timeout 01:26:44) [common]"}
- {"dt": "2023-11-14T17:33:41.714963", "lvl": "debug", "msg": "Using /lava-33479 at stage 2"}
- {"dt": "2023-11-14T17:33:41.715844", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-14T17:33:41.716649", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/2/tests/4_screenshooter'"}
- {"dt": "2023-11-14T17:33:42.291323", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/2/tests/4_screenshooter/test-suites/short-smoke/screenshooter.yaml"}
- {"dt": "2023-11-14T17:33:42.295266", "lvl": "debug", "msg": "uuid=33479_1.5.4.17 testdef=None"}
- {"dt": "2023-11-14T17:33:42.296457", "lvl": "debug", "msg": "end: 1.5.4.17 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:33:42.297314", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.58", "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-14T17:33:42.298832", "lvl": "debug", "msg": "start: 1.5.4.18 test-overlay (timeout 01:26:44) [common]"}
- {"dt": "2023-11-14T17:33:42.303572", "lvl": "debug", "msg": "end: 1.5.4.18 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:42.304298", "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": "33479_1.5.4.17"}, "level": "1.5.4.18", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:42.305859", "lvl": "debug", "msg": "start: 1.5.4.19 test-install-overlay (timeout 01:26:44) [common]"}
- {"dt": "2023-11-14T17:33:42.312044", "lvl": "debug", "msg": "end: 1.5.4.19 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:42.312851", "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": "33479_1.5.4.17", "uuid": "33479_1.5.4.17"}, "level": "1.5.4.19", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:42.314447", "lvl": "debug", "msg": "start: 1.5.4.20 test-runscript-overlay (timeout 01:26:44) [common]"}
- {"dt": "2023-11-14T17:33:42.320663", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/2/tests/4_screenshooter test_uuid 33479_1.5.4.17"}
- {"dt": "2023-11-14T17:33:42.322262", "lvl": "debug", "msg": "end: 1.5.4.20 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:42.323025", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/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": "33479_1.5.4.17"}, "level": "1.5.4.20", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:42.324728", "lvl": "debug", "msg": "start: 1.5.4.21 git-repo-action (timeout 01:26:44) [common]"}
- {"dt": "2023-11-14T17:33:42.325466", "lvl": "debug", "msg": "Using /lava-33479 at stage 3"}
- {"dt": "2023-11-14T17:33:42.326511", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-11-14T17:33:42.327289", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3/tests/5_ci-dumpjournal'"}
- {"dt": "2023-11-14T17:33:42.937753", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3/tests/5_ci-dumpjournal"}
- {"dt": "2023-11-14T17:33:42.952345", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3/tests/5_ci-dumpjournal/test-suites/short-smoke/dumpjournal.yaml"}
- {"dt": "2023-11-14T17:33:42.955647", "lvl": "debug", "msg": "uuid=33479_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-14T17:33:42.956905", "lvl": "debug", "msg": "end: 1.5.4.21 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:33:42.957732", "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-14T17:33:42.959218", "lvl": "debug", "msg": "start: 1.5.4.22 test-overlay (timeout 01:26:43) [common]"}
- {"dt": "2023-11-14T17:33:42.964865", "lvl": "debug", "msg": "end: 1.5.4.22 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:42.965558", "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": "33479_1.5.4.21"}, "level": "1.5.4.22", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:42.967070", "lvl": "debug", "msg": "start: 1.5.4.23 test-install-overlay (timeout 01:26:43) [common]"}
- {"dt": "2023-11-14T17:33:42.975194", "lvl": "debug", "msg": "end: 1.5.4.23 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:42.975890", "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": "33479_1.5.4.21", "uuid": "33479_1.5.4.21"}, "level": "1.5.4.23", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:42.977504", "lvl": "debug", "msg": "start: 1.5.4.24 test-runscript-overlay (timeout 01:26:43) [common]"}
- {"dt": "2023-11-14T17:33:42.984948", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3/tests/5_ci-dumpjournal test_uuid 33479_1.5.4.21"}
- {"dt": "2023-11-14T17:33:42.986556", "lvl": "debug", "msg": "end: 1.5.4.24 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:42.987345", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/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": "33479_1.5.4.21"}, "level": "1.5.4.24", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:42.988897", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2023-11-14T17:33:42.989576", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/0 for stage 0"}
- {"dt": "2023-11-14T17:33:42.990559", "lvl": "debug", "msg": "- 0_network-veth"}
- {"dt": "2023-11-14T17:33:42.991448", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/1 for stage 1"}
- {"dt": "2023-11-14T17:33:42.992508", "lvl": "debug", "msg": "- 1_ci-busybox"}
- {"dt": "2023-11-14T17:33:42.993211", "lvl": "debug", "msg": "- 2_ci-smoke-tests-basic"}
- {"dt": "2023-11-14T17:33:42.993789", "lvl": "debug", "msg": "- 3_ci-service-check"}
- {"dt": "2023-11-14T17:33:42.994511", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/2 for stage 2"}
- {"dt": "2023-11-14T17:33:42.995509", "lvl": "debug", "msg": "- 4_screenshooter"}
- {"dt": "2023-11-14T17:33:42.996366", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/33479/lava-overlay-p59yeeup/lava-33479/3 for stage 3"}
- {"dt": "2023-11-14T17:33:42.997388", "lvl": "debug", "msg": "- 5_ci-dumpjournal"}
- {"dt": "2023-11-14T17:33:42.998417", "lvl": "debug", "msg": "end: 1.5.4 test-definition (duration 00:00:04) [common]"}
- {"dt": "2023-11-14T17:33:42.999297", "lvl": "debug", "msg": "start: 1.5.5 compress-overlay (timeout 01:26:43) [common]"}
- {"dt": "2023-11-14T17:33:43.706172", "lvl": "debug", "msg": "end: 1.5.5 compress-overlay (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:33:43.707253", "lvl": "debug", "msg": "start: 1.5.6 persistent-nfs-overlay (timeout 01:26:42) [common]"}
- {"dt": "2023-11-14T17:33:43.708663", "lvl": "debug", "msg": "end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:43.709618", "lvl": "debug", "msg": "end: 1.5 lava-overlay (duration 00:00:05) [common]"}
- {"dt": "2023-11-14T17:33:43.710439", "lvl": "debug", "msg": "start: 1.6 prepare-kernel (timeout 01:26:42) [common]"}
- {"dt": "2023-11-14T17:33:43.711241", "lvl": "debug", "msg": "start: 1.6.1 uboot-prepare-kernel (timeout 01:26:42) [common]"}
- {"dt": "2023-11-14T17:33:43.712163", "lvl": "debug", "msg": "end: 1.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:43.712967", "lvl": "debug", "msg": "end: 1.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:43.713808", "lvl": "debug", "msg": "start: 1.7 xnbd-server-deploy (timeout 01:26:42) [common]"}
- {"dt": "2023-11-14T17:33:43.714481", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server"}
- {"dt": "2023-11-14T17:33:43.715132", "lvl": "debug", "msg": "NBD-IP: 192.168.66.1, NBD-PORT: 61999, NBD-ROOT: 33479/nbd-deploy-85hoc_z8/nbdroot/agl-demo-platform-raspberrypi4-64.ext4"}
- {"dt": "2023-11-14T17:33:43.718695", "lvl": "debug", "msg": "nbd-server 61999 /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/nbdroot/agl-demo-platform-raspberrypi4-64.ext4"}
- {"dt": "2023-11-14T17:33:43.738515", "lvl": "debug", "msg": "output: "}
- {"dt": "2023-11-14T17:33:43.740978", "lvl": "debug", "msg": "output: ** (process:1551): WARNING **: 17:33:43.736: Specifying an export on the command line no longer uses the oldstyle protocol."}
- {"dt": "2023-11-14T17:33:43.741898", "lvl": "debug", "msg": "output: "}
- {"dt": "2023-11-14T17:33:43.742732", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server done"}
- {"dt": "2023-11-14T17:33:43.744040", "lvl": "debug", "msg": "end: 1.7 xnbd-server-deploy (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:43.745323", "lvl": "info", "msg": "end: 1 nbd-deploy (duration 00:03:18) [common]"}
- {"dt": "2023-11-14T17:33:43.746248", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:20:00) [common]"}
- {"dt": "2023-11-14T17:33:43.747138", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:20:00) [common]"}
- {"dt": "2023-11-14T17:33:43.747937", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:43.749069", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:20:00) [common]"}
- {"dt": "2023-11-14T17:33:43.751078", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2023-11-14T17:33:43.752086", "lvl": "debug", "msg": "- {BOOTX}: booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2023-11-14T17:33:43.752744", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x02400000"}
- {"dt": "2023-11-14T17:33:43.753316", "lvl": "debug", "msg": "- {DTB}: 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-14T17:33:43.753875", "lvl": "debug", "msg": "- {INITRD}: 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-14T17:33:43.754427", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x00080000"}
- {"dt": "2023-11-14T17:33:43.755016", "lvl": "debug", "msg": "- {KERNEL}: 33479/nbd-deploy-85hoc_z8/kernel/Image"}
- {"dt": "2023-11-14T17:33:43.755569", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2023-11-14T17:33:43.756153", "lvl": "debug", "msg": "- {NBDSERVERIP}: 192.168.66.1"}
- {"dt": "2023-11-14T17:33:43.756755", "lvl": "debug", "msg": "- {NBDSERVERPORT}: 61999"}
- {"dt": "2023-11-14T17:33:43.757358", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2023-11-14T17:33:43.757902", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2023-11-14T17:33:43.758450", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x02700000"}
- {"dt": "2023-11-14T17:33:43.758971", "lvl": "debug", "msg": "- {RAMDISK}: 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-14T17:33:43.759549", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2023-11-14T17:33:43.760072", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2023-11-14T17:33:43.760689", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2023-11-14T17:33:43.761224", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2023-11-14T17:33:43.761751", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2023-11-14T17:33:43.762279", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2023-11-14T17:33:43.762793", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2023-11-14T17:33:43.763311", "lvl": "info", "msg": "- setenv initrd_high 0xffffffff"}
- {"dt": "2023-11-14T17:33:43.763826", "lvl": "info", "msg": "- setenv fdt_high 0xffffffff"}
- {"dt": "2023-11-14T17:33:43.764393", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2023-11-14T17:33:43.764954", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2023-11-14T17:33:43.765493", "lvl": "info", "msg": "- tftp 0x00080000 33479/nbd-deploy-85hoc_z8/kernel/Image"}
- {"dt": "2023-11-14T17:33:43.766017", "lvl": "info", "msg": "- tftp 0x02700000 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-14T17:33:43.766546", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2023-11-14T17:33:43.767070", "lvl": "info", "msg": "- tftp 0x02400000 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-14T17:33:43.767595", "lvl": "info", "msg": "- setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 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-14T17:33:43.768224", "lvl": "info", "msg": "- fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2023-11-14T17:33:43.768981", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-11-14T17:33:43.769652", "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-14T17:33:43.771337", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:20:00) [common]"}
- {"dt": "2023-11-14T17:33:43.772113", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63003'"}
- {"dt": "2023-11-14T17:33:47.264455", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2023-11-14T17:33:47.267564", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:03) [common]"}
- {"dt": "2023-11-14T17:33:47.268859", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:19:56) [common]"}
- {"dt": "2023-11-14T17:33:47.269853", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:19:56) [common]"}
- {"dt": "2023-11-14T17:33:47.270638", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:19:56) [common]"}
- {"dt": "2023-11-14T17:33:47.271853", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '7'"}
- {"dt": "2023-11-14T17:33:51.255937", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-11-14T17:33:52.326349", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-11-14T17:33:52.373784", "lvl": "debug", "msg": "Returned 0 in 5 seconds"}
- {"dt": "2023-11-14T17:33:52.475811", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:05) [common]"}
- {"dt": "2023-11-14T17:33:52.476747", "lvl": "results", "msg": {"case": "pdu-reboot", "definition": "lava", "duration": "5.21", "extra": {"status": "success"}, "level": "2.4.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:33:52.478179", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:05) [common]"}
- {"dt": "2023-11-14T17:33:52.479129", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:19:51) [common]"}
- {"dt": "2023-11-14T17:33:52.479961", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2023-11-14T17:33:52.480825", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:20:00)"}
- {"dt": "2023-11-14T17:33:52.482977", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2023-11-14T17:33:52.483852", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2023-11-14T17:33:52.484636", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2023-11-14T17:33:58.997476", "lvl": "target", "msg": "\0"}
- {"dt": "2023-11-14T17:33:58.999029", "lvl": "target", "msg": ""}
- {"dt": "2023-11-14T17:33:59.000718", "lvl": "target", "msg": "U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)"}
- {"dt": "2023-11-14T17:33:59.001448", "lvl": "target", "msg": ""}
- {"dt": "2023-11-14T17:33:59.143541", "lvl": "target", "msg": "DRAM:  3.9 GiB"}
- {"dt": "2023-11-14T17:33:59.175614", "lvl": "target", "msg": "RPI 4 Model B (0xc03111)"}
- {"dt": "2023-11-14T17:33:59.212818", "lvl": "target", "msg": "MMC:   emmc2@7e340000: 0, mmcnr@7e300000: 1"}
- {"dt": "2023-11-14T17:33:59.278749", "lvl": "target", "msg": "Loading Environment from FAT... *** Warning - bad CRC, using default environment"}
- {"dt": "2023-11-14T17:33:59.279817", "lvl": "target", "msg": ""}
- {"dt": "2023-11-14T17:33:59.307425", "lvl": "target", "msg": "In:    serial"}
- {"dt": "2023-11-14T17:33:59.308518", "lvl": "target", "msg": "Out:   serial"}
- {"dt": "2023-11-14T17:33:59.309360", "lvl": "target", "msg": "Err:   serial"}
- {"dt": "2023-11-14T17:33:59.310611", "lvl": "target", "msg": "Net:   eth0: genet@7d580000"}
- {"dt": "2023-11-14T17:33:59.311513", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2023-11-14T17:33:59.312389", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2023-11-14T17:33:59.313782", "lvl": "input", "msg": "c"}
- {"dt": "2023-11-14T17:33:59.315255", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:00:07) [common]"}
- {"dt": "2023-11-14T17:33:59.316484", "lvl": "debug", "msg": "start: 2.4.3 bootloader-commands (timeout 00:19:44) [common]"}
- {"dt": "2023-11-14T17:33:59.317521", "lvl": "debug", "msg": "Setting prompt string to ['U-Boot>']"}
- {"dt": "2023-11-14T17:33:59.318490", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>'] (timeout 00:19:44)"}
- {"dt": "2023-11-14T17:33:59.342107", "lvl": "target", "msg": "Hit any key to stop autoboot:  2 \x03\b\b\b 0 "}
- {"dt": "2023-11-14T17:33:59.343489", "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-14T17:33:59.344584", "lvl": "input", "msg": "setenv autoload no\n"}
- {"dt": "2023-11-14T17:33:59.446285", "lvl": "target", "msg": "U-Boot> setenv autoload no"}
- {"dt": "2023-11-14T17:33:59.448090", "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:44)"}
- {"dt": "2023-11-14T17:33:59.458772", "lvl": "target", "msg": "setenv autoload no"}
- {"dt": "2023-11-14T17:33:59.459854", "lvl": "input", "msg": "setenv initrd_high 0xffffffff\n"}
- {"dt": "2023-11-14T17:33:59.562115", "lvl": "target", "msg": "U-Boot> setenv initrd_high 0xffffffff"}
- {"dt": "2023-11-14T17:33:59.563241", "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:44)"}
- {"dt": "2023-11-14T17:33:59.581652", "lvl": "target", "msg": "setenv initrd_high 0xffffffff"}
- {"dt": "2023-11-14T17:33:59.583090", "lvl": "input", "msg": "setenv fdt_high 0xffffffff\n"}
- {"dt": "2023-11-14T17:33:59.685201", "lvl": "target", "msg": "U-Boot> setenv fdt_high 0xffffffff"}
- {"dt": "2023-11-14T17:33:59.688873", "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:44)"}
- {"dt": "2023-11-14T17:33:59.693306", "lvl": "target", "msg": "setenv fdt_high 0xffffffff"}
- {"dt": "2023-11-14T17:33:59.695082", "lvl": "input", "msg": "dhcp\n"}
- {"dt": "2023-11-14T17:33:59.797124", "lvl": "target", "msg": "U-Boot> dhcp"}
- {"dt": "2023-11-14T17:33:59.798816", "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:44)"}
- {"dt": "2023-11-14T17:33:59.804983", "lvl": "target", "msg": "dhcp"}
- {"dt": "2023-11-14T17:34:03.068078", "lvl": "target", "msg": "genet@7d580000 Waiting for PHY auto negotiation to complete....... done"}
- {"dt": "2023-11-14T17:34:03.069219", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2023-11-14T17:34:03.322508", "lvl": "target", "msg": "BOOTP broadcast 2"}
- {"dt": "2023-11-14T17:34:03.818747", "lvl": "target", "msg": "BOOTP broadcast 3"}
- {"dt": "2023-11-14T17:34:05.462606", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (2384 ms)"}
- {"dt": "2023-11-14T17:34:05.463988", "lvl": "input", "msg": "setenv serverip 192.168.66.1\n"}
- {"dt": "2023-11-14T17:34:05.565818", "lvl": "target", "msg": "U-Boot> setenv serverip 192.168.66.1"}
- {"dt": "2023-11-14T17:34:05.566829", "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:38)"}
- {"dt": "2023-11-14T17:34:05.575621", "lvl": "target", "msg": "setenv serverip 192.168.66.1"}
- {"dt": "2023-11-14T17:34:05.577000", "lvl": "input", "msg": "tftp 0x00080000 33479/nbd-deploy-85hoc_z8/kernel/Image\n"}
- {"dt": "2023-11-14T17:34:05.678563", "lvl": "target", "msg": "U-Boot> tftp 0x00080000 33479/nbd-deploy-85hoc_z8/kernel/Image"}
- {"dt": "2023-11-14T17:34:05.680170", "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:38)"}
- {"dt": "2023-11-14T17:34:05.687467", "lvl": "target", "msg": "tftp 0x00080000 33479/nbd-deploy-85hoc_z8/kernel/Image"}
- {"dt": "2023-11-14T17:34:05.688330", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-11-14T17:34:05.710352", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-11-14T17:34:05.712263", "lvl": "target", "msg": "Filename '33479/nbd-deploy-85hoc_z8/kernel/Image'."}
- {"dt": "2023-11-14T17:34:05.714282", "lvl": "target", "msg": "Load address: 0x80000"}
- {"dt": "2023-11-14T17:34:18.767551", "lvl": "target", "msg": "Loading: *\b#################T #################################  23.1 MiB"}
- {"dt": "2023-11-14T17:34:18.768311", "lvl": "target", "msg": "\t 1.8 MiB/s"}
- {"dt": "2023-11-14T17:34:18.768805", "lvl": "target", "msg": "done"}
- {"dt": "2023-11-14T17:34:18.770899", "lvl": "target", "msg": "Bytes transferred = 24244736 (171f200 hex)"}
- {"dt": "2023-11-14T17:34:18.771852", "lvl": "input", "msg": "tftp 0x02700000 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz\n"}
- {"dt": "2023-11-14T17:34:18.873501", "lvl": "target", "msg": "U-Boot> tftp 0x02700000 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-14T17:34:18.874327", "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:25)"}
- {"dt": "2023-11-14T17:34:18.879674", "lvl": "target", "msg": "tftp 0x02700000 33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2023-11-14T17:34:18.909416", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-11-14T17:34:18.910527", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-11-14T17:34:18.911078", "lvl": "target", "msg": "Filename '33479/nbd-deploy-85hoc_z8/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz'."}
- {"dt": "2023-11-14T17:34:18.912708", "lvl": "target", "msg": "Load address: 0x2700000"}
- {"dt": "2023-11-14T17:34:19.615200", "lvl": "target", "msg": "Loading: *\b##################################################  2 MiB"}
- {"dt": "2023-11-14T17:34:19.615921", "lvl": "target", "msg": "\t 2.8 MiB/s"}
- {"dt": "2023-11-14T17:34:19.631365", "lvl": "target", "msg": "done"}
- {"dt": "2023-11-14T17:34:19.632041", "lvl": "target", "msg": "Bytes transferred = 2066870 (1f89b6 hex)"}
- {"dt": "2023-11-14T17:34:19.633142", "lvl": "input", "msg": "setenv initrd_size ${filesize}\n"}
- {"dt": "2023-11-14T17:34:19.734907", "lvl": "target", "msg": "U-Boot> setenv initrd_size ${filesize}"}
- {"dt": "2023-11-14T17:34:19.735747", "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:24)"}
- {"dt": "2023-11-14T17:34:19.743275", "lvl": "target", "msg": "setenv initrd_size ${filesize}"}
- {"dt": "2023-11-14T17:34:19.744329", "lvl": "input", "msg": "tftp 0x02400000 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb\n"}
- {"dt": "2023-11-14T17:34:19.845595", "lvl": "target", "msg": "U-Boot> tftp 0x02400000 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-14T17:34:19.846412", "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:24)"}
- {"dt": "2023-11-14T17:34:19.852281", "lvl": "target", "msg": "tftp 0x02400000 33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2023-11-14T17:34:19.890384", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2023-11-14T17:34:19.891101", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2023-11-14T17:34:19.891575", "lvl": "target", "msg": "Filename '33479/nbd-deploy-85hoc_z8/dtb/bcm2711-rpi-4-b+vc4.dtb'."}
- {"dt": "2023-11-14T17:34:19.892023", "lvl": "target", "msg": "Load address: 0x2400000"}
- {"dt": "2023-11-14T17:34:19.910919", "lvl": "target", "msg": "Loading: *\b##################################################  51.1 KiB"}
- {"dt": "2023-11-14T17:34:19.911579", "lvl": "target", "msg": "\t 1.9 MiB/s"}
- {"dt": "2023-11-14T17:34:19.912040", "lvl": "target", "msg": "done"}
- {"dt": "2023-11-14T17:34:19.914323", "lvl": "target", "msg": "Bytes transferred = 52323 (cc63 hex)"}
- {"dt": "2023-11-14T17:34:19.915311", "lvl": "input", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 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-14T17:34:20.016571", "lvl": "target", "msg": "U-Boot> setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 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-14T17:34:20.017401", "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:24)"}
- {"dt": "2023-11-14T17:34:20.024216", "lvl": "target", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 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-14T17:34:20.025225", "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-14T17:34:20.126491", "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-14T17:34:20.127301", "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-14T17:34:20.128095", "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:24)"}
- {"dt": "2023-11-14T17:34:20.139128", "lvl": "target", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2023-11-14T17:34:20.325061", "lvl": "target", "msg": "## Flattened Device Tree blob at 02400000"}
- {"dt": "2023-11-14T17:34:20.325771", "lvl": "target", "msg": "   Booting using the fdt blob at 0x2400000"}
- {"dt": "2023-11-14T17:34:20.328344", "lvl": "target", "msg": "   Loading Ramdisk to 3ad50000, end 3af489b6 ... OK"}
- {"dt": "2023-11-14T17:34:20.349804", "lvl": "target", "msg": "   Loading Device Tree to 000000003ad40000, end 000000003ad4ffff ... OK"}
- {"dt": "2023-11-14T17:34:20.350458", "lvl": "target", "msg": ""}
- {"dt": "2023-11-14T17:34:20.353114", "lvl": "target", "msg": "Starting kernel ..."}
- {"dt": "2023-11-14T17:34:20.353749", "lvl": "target", "msg": ""}
- {"dt": "2023-11-14T17:34:20.354748", "lvl": "debug", "msg": "end: 2.4.3 bootloader-commands (duration 00:00:21) [common]"}
- {"dt": "2023-11-14T17:34:20.355509", "lvl": "debug", "msg": "start: 2.4.4 auto-login-action (timeout 00:19:23) [common]"}
- {"dt": "2023-11-14T17:34:20.356102", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2023-11-14T17:34:20.356694", "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-14T17:34:20.357217", "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-14T17:34:22.189517", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]"}
- {"dt": "2023-11-14T17:34:22.192840", "lvl": "debug", "msg": "start: 2.4.4.1 login-action (timeout 00:19:22) [common]"}
- {"dt": "2023-11-14T17:34:22.195010", "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-14T17:34:22.197254", "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-14T17:34:22.199130", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2023-11-14T17:34:22.200776", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2023-11-14T17:34:22.201383", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2023-11-14T17:34:22.201927", "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-14T17:34:22.202958", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:19:22)"}
- {"dt": "2023-11-14T17:34:22.207510", "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-14T17:34:22.208238", "lvl": "target", "msg": "[    0.000000] Machine model: Raspberry Pi 4 Model B"}
- {"dt": "2023-11-14T17:34:22.208827", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2023-11-14T17:34:22.209362", "lvl": "target", "msg": "[    0.000000] Reserved memory: created CMA memory pool at 0x000000001c400000, size 316 MiB"}
- {"dt": "2023-11-14T17:34:22.232538", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool"}
- {"dt": "2023-11-14T17:34:22.233283", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2023-11-14T17:34:22.234312", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003fffffff]"}
- {"dt": "2023-11-14T17:34:22.235140", "lvl": "target", "msg": "[    0.000000]   DMA32    [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2023-11-14T17:34:22.235883", "lvl": "target", "msg": "[    0.000000]   Normal   empty"}
- {"dt": "2023-11-14T17:34:22.236674", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2023-11-14T17:34:22.237417", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2023-11-14T17:34:22.238272", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]"}
- {"dt": "2023-11-14T17:34:22.239062", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2023-11-14T17:34:22.276375", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]"}
- {"dt": "2023-11-14T17:34:22.278325", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 29 pages/cpu s77848 r8192 d32744 u118784"}
- {"dt": "2023-11-14T17:34:22.279767", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2023-11-14T17:34:22.281197", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v2"}
- {"dt": "2023-11-14T17:34:22.282590", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v3a"}
- {"dt": "2023-11-14T17:34:22.283926", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v4"}
- {"dt": "2023-11-14T17:34:22.285312", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-BHB"}
- {"dt": "2023-11-14T17:34:22.286874", "lvl": "target", "msg": "[    0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923"}
- {"dt": "2023-11-14T17:34:22.320233", "lvl": "target", "msg": "[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 996912"}
- {"dt": "2023-11-14T17:34:22.322548", "lvl": "target", "msg": "[    0.000000] Kernel command line: console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61999 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-14T17:34:22.325709", "lvl": "target", "msg": "[    0.000000] Unknown kernel command line parameters \\\"verbose earlyprintk ${extraargs} fstab=no\\\", will be passed to user space."}
- {"dt": "2023-11-14T17:34:22.364967", "lvl": "target", "msg": "[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.366547", "lvl": "target", "msg": "[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.368402", "lvl": "target", "msg": "[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off"}
- {"dt": "2023-11-14T17:34:22.370160", "lvl": "target", "msg": "[    0.000000] software IO TLB: mapped [mem 0x0000000036d40000-0x000000003ad40000] (64MB)"}
- {"dt": "2023-11-14T17:34:22.372168", "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-14T17:34:22.409046", "lvl": "target", "msg": "[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1"}
- {"dt": "2023-11-14T17:34:22.410920", "lvl": "target", "msg": "[    0.000000] ftrace: allocating 40745 entries in 160 pages"}
- {"dt": "2023-11-14T17:34:22.412692", "lvl": "target", "msg": "[    0.000000] ftrace: allocated 160 pages with 2 groups"}
- {"dt": "2023-11-14T17:34:22.414206", "lvl": "target", "msg": "[    0.000000] trace event string verifier disabled"}
- {"dt": "2023-11-14T17:34:22.415978", "lvl": "target", "msg": "[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2023-11-14T17:34:22.417563", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2023-11-14T17:34:22.419077", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4."}
- {"dt": "2023-11-14T17:34:22.420622", "lvl": "target", "msg": "[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2023-11-14T17:34:22.451747", "lvl": "target", "msg": "[    0.000000] \tRude variant of Tasks RCU enabled."}
- {"dt": "2023-11-14T17:34:22.454503", "lvl": "target", "msg": "[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2023-11-14T17:34:22.456448", "lvl": "target", "msg": "[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2023-11-14T17:34:22.457978", "lvl": "target", "msg": "[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4"}
- {"dt": "2023-11-14T17:34:22.459676", "lvl": "target", "msg": "[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2023-11-14T17:34:22.461291", "lvl": "target", "msg": "[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2023-11-14T17:34:22.462788", "lvl": "target", "msg": "[    0.000000] GIC: Using split EOI/Deactivate mode"}
- {"dt": "2023-11-14T17:34:22.495655", "lvl": "target", "msg": "[    0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 10)"}
- {"dt": "2023-11-14T17:34:22.497621", "lvl": "target", "msg": "[    0.000000] random: get_random_bytes called from start_kernel+0x514/0x708 with crng_init=0"}
- {"dt": "2023-11-14T17:34:22.498926", "lvl": "target", "msg": "[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys)."}
- {"dt": "2023-11-14T17:34:22.500103", "lvl": "target", "msg": "[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns"}
- {"dt": "2023-11-14T17:34:22.501340", "lvl": "target", "msg": "[    0.000000] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns"}
- {"dt": "2023-11-14T17:34:22.502736", "lvl": "target", "msg": "[    0.000252] Console: colour dummy device 80x25"}
- {"dt": "2023-11-14T17:34:22.540477", "lvl": "target", "msg": "[    0.000332] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)"}
- {"dt": "2023-11-14T17:34:22.542087", "lvl": "target", "msg": "[    0.000362] pid_max: default: 32768 minimum: 301"}
- {"dt": "2023-11-14T17:34:22.543584", "lvl": "target", "msg": "[    0.000496] LSM: Security Framework initializing"}
- {"dt": "2023-11-14T17:34:22.545390", "lvl": "target", "msg": "[    0.000746] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.546943", "lvl": "target", "msg": "[    0.000807] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.548518", "lvl": "target", "msg": "[    0.002003] cgroup: Disabling memory control group subsystem"}
- {"dt": "2023-11-14T17:34:22.583048", "lvl": "target", "msg": "[    0.004555] rcu: Hierarchical SRCU implementation."}
- {"dt": "2023-11-14T17:34:22.583706", "lvl": "target", "msg": "[    0.005580] EFI services will not be available."}
- {"dt": "2023-11-14T17:34:22.585191", "lvl": "target", "msg": "[    0.006097] smp: Bringing up secondary CPUs ..."}
- {"dt": "2023-11-14T17:34:22.586091", "lvl": "target", "msg": "[    0.007153] Detected PIPT I-cache on CPU1"}
- {"dt": "2023-11-14T17:34:22.586931", "lvl": "target", "msg": "[    0.007224] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]"}
- {"dt": "2023-11-14T17:34:22.587760", "lvl": "target", "msg": "[    0.008470] Detected PIPT I-cache on CPU2"}
- {"dt": "2023-11-14T17:34:22.588628", "lvl": "target", "msg": "[    0.008519] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]"}
- {"dt": "2023-11-14T17:34:22.589451", "lvl": "target", "msg": "[    0.009639] Detected PIPT I-cache on CPU3"}
- {"dt": "2023-11-14T17:34:22.590442", "lvl": "target", "msg": "[    0.009687] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]"}
- {"dt": "2023-11-14T17:34:22.627170", "lvl": "target", "msg": "[    0.009871] smp: Brought up 1 node, 4 CPUs"}
- {"dt": "2023-11-14T17:34:22.629470", "lvl": "target", "msg": "[    0.009916] SMP: Total of 4 processors activated."}
- {"dt": "2023-11-14T17:34:22.630888", "lvl": "target", "msg": "[    0.009932] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2023-11-14T17:34:22.632179", "lvl": "target", "msg": "[    0.009945] CPU features: detected: 32-bit EL1 Support"}
- {"dt": "2023-11-14T17:34:22.633438", "lvl": "target", "msg": "[    0.009961] CPU features: detected: CRC32 instructions"}
- {"dt": "2023-11-14T17:34:22.634642", "lvl": "target", "msg": "[    0.042709] CPU: All CPU(s) started at EL2"}
- {"dt": "2023-11-14T17:34:22.635928", "lvl": "target", "msg": "[    0.042793] alternatives: patching kernel code"}
- {"dt": "2023-11-14T17:34:22.637308", "lvl": "target", "msg": "[    0.044367] devtmpfs: initialized"}
- {"dt": "2023-11-14T17:34:22.638624", "lvl": "target", "msg": "[    0.054717] Enabled cp15_barrier support"}
- {"dt": "2023-11-14T17:34:22.640235", "lvl": "target", "msg": "[    0.054763] Enabled setend support"}
- {"dt": "2023-11-14T17:34:22.670845", "lvl": "target", "msg": "[    0.054786] KASLR disabled due to lack of seed"}
- {"dt": "2023-11-14T17:34:22.672099", "lvl": "target", "msg": "[    0.055116] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2023-11-14T17:34:22.673008", "lvl": "target", "msg": "[    0.055151] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.674021", "lvl": "target", "msg": "[    0.065522] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2023-11-14T17:34:22.674895", "lvl": "target", "msg": "[    0.066310] DMI not present or invalid."}
- {"dt": "2023-11-14T17:34:22.675725", "lvl": "target", "msg": "[    0.066910] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2023-11-14T17:34:22.676762", "lvl": "target", "msg": "[    0.070397] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations"}
- {"dt": "2023-11-14T17:34:22.715763", "lvl": "target", "msg": "[    0.070696] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations"}
- {"dt": "2023-11-14T17:34:22.717030", "lvl": "target", "msg": "[    0.071583] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations"}
- {"dt": "2023-11-14T17:34:22.718122", "lvl": "target", "msg": "[    0.071681] audit: initializing netlink subsys (disabled)"}
- {"dt": "2023-11-14T17:34:22.719345", "lvl": "target", "msg": "[    0.071965] audit: type=2000 audit(0.068:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2023-11-14T17:34:22.720560", "lvl": "target", "msg": "[    0.072499] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2023-11-14T17:34:22.721974", "lvl": "target", "msg": "[    0.072726] cpuidle: using governor menu"}
- {"dt": "2023-11-14T17:34:22.759141", "lvl": "target", "msg": "[    0.072954] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2023-11-14T17:34:22.762247", "lvl": "target", "msg": "[    0.073140] ASID allocator initialised with 65536 entries"}
- {"dt": "2023-11-14T17:34:22.764126", "lvl": "target", "msg": "[    0.073291] Serial: AMBA PL011 UART driver"}
- {"dt": "2023-11-14T17:34:22.765715", "lvl": "target", "msg": "[    0.084990] bcm2835-mbox fe00b880.mailbox: mailbox enabled"}
- {"dt": "2023-11-14T17:34:22.767201", "lvl": "target", "msg": "[    0.112332] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-01-22T17:23:15, variant start"}
- {"dt": "2023-11-14T17:34:22.768983", "lvl": "target", "msg": "[    0.116350] raspberrypi-firmware soc:firmware: Firmware hash is acb03c7d18aa08f25f6419d696d0cc39761d3e62"}
- {"dt": "2023-11-14T17:34:22.770944", "lvl": "target", "msg": "[    0.166918] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1"}
- {"dt": "2023-11-14T17:34:22.804938", "lvl": "target", "msg": "[    0.171200] vgaarb: loaded"}
- {"dt": "2023-11-14T17:34:22.805667", "lvl": "target", "msg": "[    0.171619] SCSI subsystem initialized"}
- {"dt": "2023-11-14T17:34:22.806235", "lvl": "target", "msg": "[    0.171828] usbcore: registered new interface driver usbfs"}
- {"dt": "2023-11-14T17:34:22.806789", "lvl": "target", "msg": "[    0.171885] usbcore: registered new interface driver hub"}
- {"dt": "2023-11-14T17:34:22.807339", "lvl": "target", "msg": "[    0.171953] usbcore: registered new device driver usb"}
- {"dt": "2023-11-14T17:34:22.807875", "lvl": "target", "msg": "[    0.172303] usb_phy_generic phy: supply vcc not found, using dummy regulator"}
- {"dt": "2023-11-14T17:34:22.808605", "lvl": "target", "msg": "[    0.172871] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2023-11-14T17:34:22.810436", "lvl": "target", "msg": "[    0.172890] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2023-11-14T17:34:22.847545", "lvl": "target", "msg": "[    0.172925] PTP clock support registered"}
- {"dt": "2023-11-14T17:34:22.849837", "lvl": "target", "msg": "[    0.173183] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2023-11-14T17:34:22.851112", "lvl": "target", "msg": "[    0.174389] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2023-11-14T17:34:22.852397", "lvl": "target", "msg": "[    0.262962] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2023-11-14T17:34:22.853712", "lvl": "target", "msg": "[    0.263084] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2023-11-14T17:34:22.855046", "lvl": "target", "msg": "[    0.263250] FS-Cache: Loaded"}
- {"dt": "2023-11-14T17:34:22.856400", "lvl": "target", "msg": "[    0.263477] CacheFiles: Loaded"}
- {"dt": "2023-11-14T17:34:22.857729", "lvl": "target", "msg": "[    0.274231] NET: Registered PF_INET protocol family"}
- {"dt": "2023-11-14T17:34:22.891507", "lvl": "target", "msg": "[    0.274729] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.894344", "lvl": "target", "msg": "[    0.278034] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.895944", "lvl": "target", "msg": "[    0.278095] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.897552", "lvl": "target", "msg": "[    0.278310] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.899054", "lvl": "target", "msg": "[    0.278865] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2023-11-14T17:34:22.900646", "lvl": "target", "msg": "[    0.279102] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.935638", "lvl": "target", "msg": "[    0.279170] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2023-11-14T17:34:22.938174", "lvl": "target", "msg": "[    0.279474] NET: Registered PF_UNIX/PF_LOCAL protocol family"}
- {"dt": "2023-11-14T17:34:22.939585", "lvl": "target", "msg": "[    0.280473] RPC: Registered named UNIX socket transport module."}
- {"dt": "2023-11-14T17:34:22.940991", "lvl": "target", "msg": "[    0.280497] RPC: Registered udp transport module."}
- {"dt": "2023-11-14T17:34:22.942307", "lvl": "target", "msg": "[    0.280511] RPC: Registered tcp transport module."}
- {"dt": "2023-11-14T17:34:22.943619", "lvl": "target", "msg": "[    0.280524] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2023-11-14T17:34:22.944988", "lvl": "target", "msg": "[    0.280547] PCI: CLS 0 bytes, default 64"}
- {"dt": "2023-11-14T17:34:22.946323", "lvl": "target", "msg": "[    0.281085] Trying to unpack rootfs image as initramfs..."}
- {"dt": "2023-11-14T17:34:22.979458", "lvl": "target", "msg": "[    0.281496] rootfs image is not initramfs (no cpio magic); looks like an initrd"}
- {"dt": "2023-11-14T17:34:22.981326", "lvl": "target", "msg": "[    0.288620] Freeing initrd memory: 2016K"}
- {"dt": "2023-11-14T17:34:22.982469", "lvl": "target", "msg": "[    0.290514] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available"}
- {"dt": "2023-11-14T17:34:22.983566", "lvl": "target", "msg": "[    0.290855] kvm [1]: IPA Size Limit: 44 bits"}
- {"dt": "2023-11-14T17:34:22.984696", "lvl": "target", "msg": "[    0.292099] kvm [1]: vgic interrupt IRQ9"}
- {"dt": "2023-11-14T17:34:22.985770", "lvl": "target", "msg": "[    0.292375] kvm [1]: Hyp mode initialized successfully"}
- {"dt": "2023-11-14T17:34:22.986831", "lvl": "target", "msg": "[    1.053355] Initialise system trusted keyrings"}
- {"dt": "2023-11-14T17:34:22.987882", "lvl": "target", "msg": "[    1.053722] workingset: timestamp_bits=46 max_order=20 bucket_order=0"}
- {"dt": "2023-11-14T17:34:22.989191", "lvl": "target", "msg": "[    1.060357] zbud: loaded"}
- {"dt": "2023-11-14T17:34:23.024539", "lvl": "target", "msg": "[    1.062144] FS-Cache: Netfs 'nfs' registered for caching"}
- {"dt": "2023-11-14T17:34:23.025256", "lvl": "target", "msg": "[    1.062813] NFS: Registering the id_resolver key type"}
- {"dt": "2023-11-14T17:34:23.025829", "lvl": "target", "msg": "[    1.062866] Key type id_resolver registered"}
- {"dt": "2023-11-14T17:34:23.026373", "lvl": "target", "msg": "[    1.062881] Key type id_legacy registered"}
- {"dt": "2023-11-14T17:34:23.026889", "lvl": "target", "msg": "[    1.062986] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2023-11-14T17:34:23.027406", "lvl": "target", "msg": "[    1.063005] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering..."}
- {"dt": "2023-11-14T17:34:23.029379", "lvl": "target", "msg": "[    1.064280] NET: Registered PF_ALG protocol family"}
- {"dt": "2023-11-14T17:34:23.030329", "lvl": "target", "msg": "[    1.064304] Key type asymmetric registered"}
- {"dt": "2023-11-14T17:34:23.067060", "lvl": "target", "msg": "[    1.064318] Asymmetric key parser 'x509' registered"}
- {"dt": "2023-11-14T17:34:23.068524", "lvl": "target", "msg": "[    1.064403] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 246)"}
- {"dt": "2023-11-14T17:34:23.069896", "lvl": "target", "msg": "[    1.064654] io scheduler mq-deadline registered"}
- {"dt": "2023-11-14T17:34:23.072533", "lvl": "target", "msg": "[    1.064674] io scheduler kyber registered"}
- {"dt": "2023-11-14T17:34:23.073847", "lvl": "target", "msg": "[    1.072554] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:"}
- {"dt": "2023-11-14T17:34:23.075034", "lvl": "target", "msg": "[    1.072604] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]"}
- {"dt": "2023-11-14T17:34:23.076259", "lvl": "target", "msg": "[    1.072693] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000"}
- {"dt": "2023-11-14T17:34:23.111352", "lvl": "target", "msg": "[    1.072776] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000"}
- {"dt": "2023-11-14T17:34:23.112538", "lvl": "target", "msg": "[    1.120489] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)"}
- {"dt": "2023-11-14T17:34:23.113718", "lvl": "target", "msg": "[    1.120878] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2023-11-14T17:34:23.114743", "lvl": "target", "msg": "[    1.120901] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2023-11-14T17:34:23.115915", "lvl": "target", "msg": "[    1.120922] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])"}
- {"dt": "2023-11-14T17:34:23.117165", "lvl": "target", "msg": "[    1.121009] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400"}
- {"dt": "2023-11-14T17:34:23.154772", "lvl": "target", "msg": "[    1.121257] pci 0000:00:00.0: PME# supported from D0 D3hot"}
- {"dt": "2023-11-14T17:34:23.156362", "lvl": "target", "msg": "[    1.124981] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring"}
- {"dt": "2023-11-14T17:34:23.159105", "lvl": "target", "msg": "[    1.125259] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330"}
- {"dt": "2023-11-14T17:34:23.160682", "lvl": "target", "msg": "[    1.125330] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]"}
- {"dt": "2023-11-14T17:34:23.162122", "lvl": "target", "msg": "[    1.125575] pci 0000:01:00.0: PME# supported from D0 D3cold"}
- {"dt": "2023-11-14T17:34:23.163503", "lvl": "target", "msg": "[    1.129156] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01"}
- {"dt": "2023-11-14T17:34:23.164865", "lvl": "target", "msg": "[    1.129204] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]"}
- {"dt": "2023-11-14T17:34:23.198095", "lvl": "target", "msg": "[    1.129230] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]"}
- {"dt": "2023-11-14T17:34:23.199488", "lvl": "target", "msg": "[    1.129273] pci 0000:00:00.0: PCI bridge to [bus 01]"}
- {"dt": "2023-11-14T17:34:23.201921", "lvl": "target", "msg": "[    1.129298] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]"}
- {"dt": "2023-11-14T17:34:23.203271", "lvl": "target", "msg": "[    1.135439] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled"}
- {"dt": "2023-11-14T17:34:23.204559", "lvl": "target", "msg": "[    1.138260] iproc-rng200 fe104000.rng: hwrng registered"}
- {"dt": "2023-11-14T17:34:23.205753", "lvl": "target", "msg": "[    1.138788] vc-mem: phys_addr:0x00000000 mem_base=0x00000000 mem_size:0x00000000(0 MiB)"}
- {"dt": "2023-11-14T17:34:23.242455", "lvl": "target", "msg": "[    1.140226] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000"}
- {"dt": "2023-11-14T17:34:23.244335", "lvl": "target", "msg": "[    1.152965] brd: module loaded"}
- {"dt": "2023-11-14T17:34:23.245888", "lvl": "target", "msg": "[    1.162566] loop: module loaded"}
- {"dt": "2023-11-14T17:34:23.247446", "lvl": "target", "msg": "[    1.193298] Loading iSCSI transport class v2.0-870."}
- {"dt": "2023-11-14T17:34:23.249554", "lvl": "target", "msg": "[    1.197949] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000"}
- {"dt": "2023-11-14T17:34:23.250305", "lvl": "target", "msg": "[    1.258548] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus"}
- {"dt": "2023-11-14T17:34:23.250969", "lvl": "target", "msg": "[    1.259629] usbcore: registered new interface driver r8152"}
- {"dt": "2023-11-14T17:34:23.251638", "lvl": "target", "msg": "[    1.259697] usbcore: registered new interface driver lan78xx"}
- {"dt": "2023-11-14T17:34:23.285706", "lvl": "target", "msg": "[    1.259714] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"}
- {"dt": "2023-11-14T17:34:23.286953", "lvl": "target", "msg": "[    1.259730] ehci-pci: EHCI PCI platform driver"}
- {"dt": "2023-11-14T17:34:23.289021", "lvl": "target", "msg": "[    1.259790] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"}
- {"dt": "2023-11-14T17:34:23.290498", "lvl": "target", "msg": "[    1.259827] ohci-pci: OHCI PCI platform driver"}
- {"dt": "2023-11-14T17:34:23.291633", "lvl": "target", "msg": "[    1.261382] pci 0000:00:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2023-11-14T17:34:23.292672", "lvl": "target", "msg": "[    1.261424] xhci_hcd 0000:01:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2023-11-14T17:34:23.293641", "lvl": "target", "msg": "[    1.261527] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2023-11-14T17:34:23.294786", "lvl": "target", "msg": "[    1.261562] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1"}
- {"dt": "2023-11-14T17:34:23.329615", "lvl": "target", "msg": "[    1.262279] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00003c0000000890"}
- {"dt": "2023-11-14T17:34:23.331395", "lvl": "target", "msg": "[    1.263247] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15"}
- {"dt": "2023-11-14T17:34:23.334568", "lvl": "target", "msg": "[    1.263273] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2023-11-14T17:34:23.336271", "lvl": "target", "msg": "[    1.263292] usb usb1: Product: xHCI Host Controller"}
- {"dt": "2023-11-14T17:34:23.337799", "lvl": "target", "msg": "[    1.263307] usb usb1: Manufacturer: Linux 5.15.34-v8 xhci-hcd"}
- {"dt": "2023-11-14T17:34:23.340429", "lvl": "target", "msg": "[    1.263323] usb usb1: SerialNumber: 0000:01:00.0"}
- {"dt": "2023-11-14T17:34:23.341138", "lvl": "target", "msg": "[    1.264050] hub 1-0:1.0: USB hub found"}
- {"dt": "2023-11-14T17:34:23.373158", "lvl": "target", "msg": "[    1.264129] hub 1-0:1.0: 1 port detected"}
- {"dt": "2023-11-14T17:34:23.374563", "lvl": "target", "msg": "[    1.264784] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2023-11-14T17:34:23.376964", "lvl": "target", "msg": "[    1.264811] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2"}
- {"dt": "2023-11-14T17:34:23.378539", "lvl": "target", "msg": "[    1.264850] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed"}
- {"dt": "2023-11-14T17:34:23.380325", "lvl": "target", "msg": "[    1.265225] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15"}
- {"dt": "2023-11-14T17:34:23.381228", "lvl": "target", "msg": "[    1.265248] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2023-11-14T17:34:23.382184", "lvl": "target", "msg": "[    1.265266] usb usb2: Product: xHCI Host Controller"}
- {"dt": "2023-11-14T17:34:23.416401", "lvl": "target", "msg": "[    1.265282] usb usb2: Manufacturer: Linux 5.15.34-v8 xhci-hcd"}
- {"dt": "2023-11-14T17:34:23.417920", "lvl": "target", "msg": "[    1.265298] usb usb2: SerialNumber: 0000:01:00.0"}
- {"dt": "2023-11-14T17:34:23.418669", "lvl": "target", "msg": "[    1.265979] hub 2-0:1.0: USB hub found"}
- {"dt": "2023-11-14T17:34:23.419328", "lvl": "target", "msg": "[    1.266047] hub 2-0:1.0: 4 ports detected"}
- {"dt": "2023-11-14T17:34:23.419979", "lvl": "target", "msg": "[    1.267672] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)"}
- {"dt": "2023-11-14T17:34:23.421311", "lvl": "target", "msg": "[    1.268544] usbcore: registered new interface driver uas"}
- {"dt": "2023-11-14T17:34:23.422472", "lvl": "target", "msg": "[    1.268649] usbcore: registered new interface driver usb-storage"}
- {"dt": "2023-11-14T17:34:23.423560", "lvl": "target", "msg": "[    1.268769] usbcore: registered new interface driver usbserial_generic"}
- {"dt": "2023-11-14T17:34:23.460109", "lvl": "target", "msg": "[    1.268806] usbserial: USB Serial support registered for generic"}
- {"dt": "2023-11-14T17:34:23.461240", "lvl": "target", "msg": "[    1.268869] usbcore: registered new interface driver cp210x"}
- {"dt": "2023-11-14T17:34:23.463246", "lvl": "target", "msg": "[    1.268912] usbserial: USB Serial support registered for cp210x"}
- {"dt": "2023-11-14T17:34:23.464383", "lvl": "target", "msg": "[    1.269150] mousedev: PS/2 mouse device common for all mice"}
- {"dt": "2023-11-14T17:34:23.465488", "lvl": "target", "msg": "[    1.269756] usbcore: registered new interface driver i2c-tiny-usb"}
- {"dt": "2023-11-14T17:34:23.466510", "lvl": "target", "msg": "[    1.274805] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2023-11-14T17:34:23.467518", "lvl": "target", "msg": "[    1.274829] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2023-11-14T17:34:23.468785", "lvl": "target", "msg": "[    1.275461] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2023-11-14T17:34:23.504834", "lvl": "target", "msg": "[    1.278904] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2023-11-14T17:34:23.506205", "lvl": "target", "msg": "[    1.279483] hid: raw HID events driver (C) Jiri Kosina"}
- {"dt": "2023-11-14T17:34:23.507438", "lvl": "target", "msg": "[    1.279819] usbcore: registered new interface driver usbhid"}
- {"dt": "2023-11-14T17:34:23.508765", "lvl": "target", "msg": "[    1.279837] usbhid: USB HID core driver"}
- {"dt": "2023-11-14T17:34:23.509968", "lvl": "target", "msg": "[    1.280152] ashmem: initialized"}
- {"dt": "2023-11-14T17:34:23.511148", "lvl": "target", "msg": "[    1.288362] usbcore: registered new interface driver snd-usb-audio"}
- {"dt": "2023-11-14T17:34:23.512383", "lvl": "target", "msg": "[    1.289350] Initializing XFRM netlink socket"}
- {"dt": "2023-11-14T17:34:23.513572", "lvl": "target", "msg": "[    1.289397] NET: Registered PF_PACKET protocol family"}
- {"dt": "2023-11-14T17:34:23.515359", "lvl": "target", "msg": "[    1.289522] Key type dns_resolver registered"}
- {"dt": "2023-11-14T17:34:23.548223", "lvl": "target", "msg": "[    1.290759] registered taskstats version 1"}
- {"dt": "2023-11-14T17:34:23.549114", "lvl": "target", "msg": "[    1.290798] Loading compiled-in X.509 certificates"}
- {"dt": "2023-11-14T17:34:23.549907", "lvl": "target", "msg": "[    1.291746] Key type ._fscrypt registered"}
- {"dt": "2023-11-14T17:34:23.550677", "lvl": "target", "msg": "[    1.291767] Key type .fscrypt registered"}
- {"dt": "2023-11-14T17:34:23.551438", "lvl": "target", "msg": "[    1.291780] Key type fscrypt-provisioning registered"}
- {"dt": "2023-11-14T17:34:23.552229", "lvl": "target", "msg": "[    1.303142] uart-pl011 fe201000.serial: there is not valid maps for state default"}
- {"dt": "2023-11-14T17:34:23.553012", "lvl": "target", "msg": "[    1.303423] uart-pl011 fe201000.serial: cts_event_workaround enabled"}
- {"dt": "2023-11-14T17:34:23.554590", "lvl": "target", "msg": "[    1.303596] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 19, base_baud = 0) is a PL011 rev2"}
- {"dt": "2023-11-14T17:34:23.591997", "lvl": "target", "msg": "[    1.311565] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default"}
- {"dt": "2023-11-14T17:34:23.593152", "lvl": "target", "msg": "[    1.312265] printk: console [ttyS0] disabled"}
- {"dt": "2023-11-14T17:34:23.594150", "lvl": "target", "msg": "[    1.312383] fe215040.serial: ttyS0 at MMIO 0xfe215040 (irq = 20, base_baud = 62500000) is a 16550"}
- {"dt": "2023-11-14T17:34:23.595122", "lvl": "target", "msg": "[    1.518430] usb 1-1: new high-speed USB device number 2 using xhci_hcd"}
- {"dt": "2023-11-14T17:34:23.596087", "lvl": "target", "msg": "[    1.531103] printk: console [ttyS0] enabled"}
- {"dt": "2023-11-14T17:34:23.598121", "lvl": "target", "msg": "[    1.684429] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.20"}
- {"dt": "2023-11-14T17:34:23.635406", "lvl": "target", "msg": "[    1.690187] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer"}
- {"dt": "2023-11-14T17:34:23.636154", "lvl": "target", "msg": "[    1.696692] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0"}
- {"dt": "2023-11-14T17:34:23.636789", "lvl": "target", "msg": "[    1.702914] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver"}
- {"dt": "2023-11-14T17:34:23.637330", "lvl": "target", "msg": "[    1.707313] usb 1-1: Product: USB2.0 Hub"}
- {"dt": "2023-11-14T17:34:23.637864", "lvl": "target", "msg": "[    1.713109] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0"}
- {"dt": "2023-11-14T17:34:23.639070", "lvl": "target", "msg": "[    1.717955] hub 1-1:1.0: USB hub found"}
- {"dt": "2023-11-14T17:34:23.639700", "lvl": "target", "msg": "[    1.720644] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated"}
- {"dt": "2023-11-14T17:34:23.640291", "lvl": "target", "msg": "[    1.727701] hub 1-1:1.0: 4 ports detected"}
- {"dt": "2023-11-14T17:34:23.640966", "lvl": "target", "msg": "[    1.760784] of_cfs_init"}
- {"dt": "2023-11-14T17:34:23.685707", "lvl": "target", "msg": "[    1.796763] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA"}
- {"dt": "2023-11-14T17:34:23.687259", "lvl": "target", "msg": "[    1.797395] of_cfs_init: OK"}
- {"dt": "2023-11-14T17:34:23.688775", "lvl": "target", "msg": "[    2.098432] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd"}
- {"dt": "2023-11-14T17:34:23.690164", "lvl": "target", "msg": "[    2.108928] random: fast init done"}
- {"dt": "2023-11-14T17:34:23.691506", "lvl": "target", "msg": "[    2.823824] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)"}
- {"dt": "2023-11-14T17:34:23.692942", "lvl": "target", "msg": "[    2.832654] bcmgenet fd580000.ethernet eth0: Link is Down"}
- {"dt": "2023-11-14T17:34:23.720293", "lvl": "target", "msg": "[    2.864578] mmc1: new high speed SDIO card at address 0001"}
- {"dt": "2023-11-14T17:34:23.799878", "lvl": "target", "msg": "[    2.923253] mmc0: new ultra high speed DDR50 SDHC card at address 59b4"}
- {"dt": "2023-11-14T17:34:23.801441", "lvl": "target", "msg": "[    2.924115] usb 1-1.3: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2023-11-14T17:34:23.802927", "lvl": "target", "msg": "[    2.930857] mmcblk0: mmc0:59b4 USDU1 7.51 GiB "}
- {"dt": "2023-11-14T17:34:23.804479", "lvl": "target", "msg": "[    2.938398] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2023-11-14T17:34:23.805958", "lvl": "target", "msg": "[    2.945840]  mmcblk0: p1 p2"}
- {"dt": "2023-11-14T17:34:23.807274", "lvl": "target", "msg": "[    2.950326] usb 1-1.3: Product: USB2.0 Hub             "}
- {"dt": "2023-11-14T17:34:23.809916", "lvl": "target", "msg": "[    2.950340] usb 1-1.3: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2023-11-14T17:34:23.819926", "lvl": "target", "msg": "[    2.953697] mmcblk0: mmc0:59b4 USDU1 7.51 GiB"}
- {"dt": "2023-11-14T17:34:23.820763", "lvl": "target", "msg": "[    2.960010] hub 1-1.3:1.0: USB hub found"}
- {"dt": "2023-11-14T17:34:23.823278", "lvl": "target", "msg": "[    2.972890] hub 1-1.3:1.0: 4 ports detected"}
- {"dt": "2023-11-14T17:34:24.139049", "lvl": "target", "msg": "[    3.282420] usb 1-1.3.1: new high-speed USB device number 4 using xhci_hcd"}
- {"dt": "2023-11-14T17:34:24.286792", "lvl": "target", "msg": "[    3.404114] usb 1-1.3.1: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2023-11-14T17:34:24.290178", "lvl": "target", "msg": "[    3.412802] usb 1-1.3.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2023-11-14T17:34:24.291797", "lvl": "target", "msg": "[    3.420415] usb 1-1.3.1: Product: USB2.0 Hub             "}
- {"dt": "2023-11-14T17:34:24.293439", "lvl": "target", "msg": "[    3.425913] usb 1-1.3.1: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2023-11-14T17:34:24.294961", "lvl": "target", "msg": "[    3.433276] hub 1-1.3.1:1.0: USB hub found"}
- {"dt": "2023-11-14T17:34:24.296765", "lvl": "target", "msg": "[    3.437706] hub 1-1.3.1:1.0: 4 ports detected"}
- {"dt": "2023-11-14T17:34:24.602918", "lvl": "target", "msg": "[    3.746419] usb 1-1.3.1.1: new high-speed USB device number 5 using xhci_hcd"}
- {"dt": "2023-11-14T17:34:24.755655", "lvl": "target", "msg": "[    3.878108] usb 1-1.3.1.1: New USB device found, idVendor=0bda, idProduct=2838, bcdDevice= 1.00"}
- {"dt": "2023-11-14T17:34:24.757608", "lvl": "target", "msg": "[    3.886968] usb 1-1.3.1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3"}
- {"dt": "2023-11-14T17:34:24.759220", "lvl": "target", "msg": "[    3.894771] usb 1-1.3.1.1: Product: RTL2838UHIDIR"}
- {"dt": "2023-11-14T17:34:24.760870", "lvl": "target", "msg": "[    3.899561] usb 1-1.3.1.1: Manufacturer: Realtek"}
- {"dt": "2023-11-14T17:34:24.763877", "lvl": "target", "msg": "[    3.904261] usb 1-1.3.1.1: SerialNumber: 00000001"}
- {"dt": "2023-11-14T17:34:27.769903", "lvl": "target", "msg": "[    6.910650] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx"}
- {"dt": "2023-11-14T17:34:27.837180", "lvl": "target", "msg": "[    6.942413] Sending DHCP requests ., OK"}
- {"dt": "2023-11-14T17:34:27.840665", "lvl": "target", "msg": "[    6.962366] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.241"}
- {"dt": "2023-11-14T17:34:27.842412", "lvl": "target", "msg": "[    6.970462] IP-Config: Complete:"}
- {"dt": "2023-11-14T17:34:27.844056", "lvl": "target", "msg": "[    6.973738]      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-14T17:34:27.845736", "lvl": "target", "msg": "[    6.984263]      host=192.168.66.241, domain=, nis-domain=(none)"}
- {"dt": "2023-11-14T17:34:27.847296", "lvl": "target", "msg": "[    6.990382]      bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath="}
- {"dt": "2023-11-14T17:34:27.848841", "lvl": "target", "msg": "[    6.990396]      nameserver0=10.1.1.1"}
- {"dt": "2023-11-14T17:34:27.857758", "lvl": "target", "msg": "[    7.002523] ALSA device list:"}
- {"dt": "2023-11-14T17:34:27.858388", "lvl": "target", "msg": "[    7.005547]   No soundcards found."}
- {"dt": "2023-11-14T17:34:27.861295", "lvl": "target", "msg": "[    7.009478] Waiting 7 sec before mounting root device..."}
- {"dt": "2023-11-14T17:34:34.896705", "lvl": "target", "msg": "[   14.046611] RAMDISK: gzip image found at block 0"}
- {"dt": "2023-11-14T17:34:35.239127", "lvl": "target", "msg": "[   14.359410] EXT4-fs (ram0): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none."}
- {"dt": "2023-11-14T17:34:35.240151", "lvl": "target", "msg": "[   14.368976] VFS: Mounted root (ext4 filesystem) on device 1:0."}
- {"dt": "2023-11-14T17:34:35.241203", "lvl": "target", "msg": "[   14.375129] devtmpfs: mounted"}
- {"dt": "2023-11-14T17:34:35.242853", "lvl": "target", "msg": "[   14.387585] Freeing unused kernel memory: 4096K"}
- {"dt": "2023-11-14T17:34:35.243523", "lvl": "target", "msg": "[   14.392411] Run /sbin/init as init process"}
- {"dt": "2023-11-14T17:34:35.291789", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2023-11-14T17:34:35.292846", "lvl": "target", "msg": "         ___   ________                _   __     __  __                __"}
- {"dt": "2023-11-14T17:34:35.293665", "lvl": "target", "msg": "        /   | / ____/ /               / | / /__  / /_/ /_  ____  ____  / /_"}
- {"dt": "2023-11-14T17:34:35.294369", "lvl": "target", "msg": "       / /| |/ / __/ /      ______   /  |/ / _ \\/ __/ __ \\/ __ \\/ __ \\/ __/"}
- {"dt": "2023-11-14T17:34:35.294955", "lvl": "target", "msg": "      / ___ / /_/ / /___   /_____/  / /|  /  __/ /_/ /_/ / /_/ / /_/ / /_"}
- {"dt": "2023-11-14T17:34:35.295674", "lvl": "target", "msg": "     /_/  |_\\____/_____/           /_/ |_/\\___/\\__/_.___/\\____/\\____/\\__/"}
- {"dt": "2023-11-14T17:34:35.339318", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2023-11-14T17:34:35.341199", "lvl": "target", "msg": "/sbin/init[1]: starting initrd script"}
- {"dt": "2023-11-14T17:34:35.342226", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: proc /proc"}
- {"dt": "2023-11-14T17:34:35.343039", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: sysfs /sys"}
- {"dt": "2023-11-14T17:34:35.343869", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devtmpfs /dev"}
- {"dt": "2023-11-14T17:34:35.344704", "lvl": "target", "msg": "/sbin/init[1]: /dev (devtmpfs) already mounted"}
- {"dt": "2023-11-14T17:34:35.345411", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devpts /dev/pts"}
- {"dt": "2023-11-14T17:34:35.346138", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /dev/shm"}
- {"dt": "2023-11-14T17:34:35.347156", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /tmp"}
- {"dt": "2023-11-14T17:34:35.357322", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /run"}
- {"dt": "2023-11-14T17:34:35.398459", "lvl": "target", "msg": "/sbin/init[1]: NBD parameters: device /dev/nbd0, server 192.168.66.1:61999"}
- {"dt": "2023-11-14T17:34:35.399609", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2023-11-14T17:34:35.400661", "lvl": "target", "msg": "nbd-client: can't connect to remote host (192.168.66.1): Connection refused"}
- {"dt": "2023-11-14T17:34:35.403424", "lvl": "target", "msg": "/sbin/init[1]: NBD client failed"}
- {"dt": "2023-11-14T17:34:35.405111", "lvl": "target", "msg": "/sbin/init[1]: Retrying (5 trie(s) left)..."}
- {"dt": "2023-11-14T17:34:38.391770", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2023-11-14T17:34:38.414545", "lvl": "target", "msg": "nbd-client: can't connect to remote host (192.168.66.1): Connection refused"}
- {"dt": "2023-11-14T17:34:38.415490", "lvl": "target", "msg": "/sbin/init[1]: NBD client failed"}
- {"dt": "2023-11-14T17:34:38.417813", "lvl": "target", "msg": "/sbin/init[1]: Retrying (4 trie(s) left)..."}
- {"dt": "2023-11-14T17:34:41.407158", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2023-11-14T17:34:41.438074", "lvl": "target", "msg": "nbd-client: can't connect to remote host (192.168.66.1): Connection refused"}
- {"dt": "2023-11-14T17:34:41.440610", "lvl": "target", "msg": "/sbin/init[1]: NBD client failed"}
- {"dt": "2023-11-14T17:34:41.442996", "lvl": "target", "msg": "/sbin/init[1]: Retrying (3 trie(s) left)..."}
- {"dt": "2023-11-14T17:34:44.451410", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2023-11-14T17:34:44.452234", "lvl": "target", "msg": "nbd-client: can't connect to remote host (192.168.66.1): Connection refused"}
- {"dt": "2023-11-14T17:34:44.453542", "lvl": "target", "msg": "/sbin/init[1]: NBD client failed"}
- {"dt": "2023-11-14T17:34:44.454238", "lvl": "target", "msg": "/sbin/init[1]: Retrying (2 trie(s) left)..."}
- {"dt": "2023-11-14T17:34:47.444545", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2023-11-14T17:34:47.469955", "lvl": "target", "msg": "nbd-client: can't connect to remote host (192.168.66.1): Connection refused"}
- {"dt": "2023-11-14T17:34:47.470739", "lvl": "target", "msg": "/sbin/init[1]: NBD client failed"}
- {"dt": "2023-11-14T17:34:47.472685", "lvl": "target", "msg": "/sbin/init[1]: Retrying (1 trie(s) left)..."}
- {"dt": "2023-11-14T17:34:50.494273", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2023-11-14T17:34:50.495027", "lvl": "target", "msg": "nbd-client: can't connect to remote host (192.168.66.1): Connection refused"}
- {"dt": "2023-11-14T17:34:50.496744", "lvl": "target", "msg": "/sbin/init[1]: NBD client failed"}
- {"dt": "2023-11-14T17:34:50.497545", "lvl": "target", "msg": "/[   29.632606] kvm: exiting hardware virtualization"}
- {"dt": "2023-11-14T17:34:50.498250", "lvl": "target", "msg": "sbin/init[1]: ERROR Unable to mount NBD device /dev/nbd0 using server 192.168.66.1:61999"}
- {"dt": "2023-11-14T17:34:50.498835", "lvl": "target", "msg": "/sbin/init[1]: Rebooting..."}
- {"dt": "2023-11-14T17:34:50.528623", "lvl": "target", "msg": "[   29.672504] bcmgenet fd580000.ethernet eth0: Link is Down"}
- {"dt": "2023-11-14T17:34:50.534733", "lvl": "target", "msg": "[   29.696858] reboot: Restarting system"}
- {"dt": "2023-11-14T17:34:56.913018", "lvl": "target", "msg": "\0"}
- {"dt": "2023-11-14T17:34:56.914491", "lvl": "target", "msg": ""}
- {"dt": "2023-11-14T17:34:56.928668", "lvl": "target", "msg": "U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)"}
- {"dt": "2023-11-14T17:34:56.929576", "lvl": "target", "msg": ""}
- {"dt": "2023-11-14T17:34:57.073989", "lvl": "target", "msg": "DRAM:  3.9 GiB"}
- {"dt": "2023-11-14T17:34:57.104833", "lvl": "target", "msg": "RPI 4 Model B (0xc03111)"}
- {"dt": "2023-11-14T17:34:57.142737", "lvl": "target", "msg": "MMC:   emmc2@7e340000: 0, mmcnr@7e300000: 1"}
- {"dt": "2023-11-14T17:34:57.208878", "lvl": "target", "msg": "Loading Environment from FAT... *** Warning - bad CRC, using default environment"}
- {"dt": "2023-11-14T17:34:57.210803", "lvl": "target", "msg": ""}
- {"dt": "2023-11-14T17:34:57.237559", "lvl": "target", "msg": "In:    serial"}
- {"dt": "2023-11-14T17:34:57.239440", "lvl": "target", "msg": "Out:   serial"}
- {"dt": "2023-11-14T17:34:57.241296", "lvl": "target", "msg": "Err:   serial"}
- {"dt": "2023-11-14T17:34:57.244667", "lvl": "target", "msg": "Net:   eth0: genet@7d580000"}
- {"dt": "2023-11-14T17:34:57.246463", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2023-11-14T17:34:57.247951", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2023-11-14T17:34:59.237793", "lvl": "target", "msg": "Hit any key to stop autoboot:  2 \b\b\b 1 \b\b\b 0 "}
- {"dt": "2023-11-14T17:34:59.269882", "lvl": "target", "msg": "switch to partitions #0, OK"}
- {"dt": "2023-11-14T17:34:59.271796", "lvl": "target", "msg": "mmc0 is current device"}
- {"dt": "2023-11-14T17:34:59.285702", "lvl": "target", "msg": "Scanning mmc 0:1..."}
- {"dt": "2023-11-14T17:34:59.682802", "lvl": "target", "msg": "Card did not respond to voltage select!"}
- {"dt": "2023-11-14T17:34:59.684766", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2023-11-14T17:34:59.688130", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2023-11-14T17:34:59.689182", "lvl": "target", "msg": "USB is stopped. Please issue 'usb start' first."}
- {"dt": "2023-11-14T17:34:59.689832", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2023-11-14T17:34:59.690443", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2023-11-14T17:35:00.966010", "lvl": "target", "msg": "genet@7d580000 Waiting for PHY auto negotiation to complete... done"}
- {"dt": "2023-11-14T17:35:00.968538", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2023-11-14T17:35:00.972026", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (3 ms)"}
- {"dt": "2023-11-14T17:35:00.973889", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:00.975630", "lvl": "target", "msg": "Cannot autoload with TFTPGET"}
- {"dt": "2023-11-14T17:35:00.977252", "lvl": "target", "msg": "missing environment variable: pxeuuid"}
- {"dt": "2023-11-14T17:35:00.978819", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:00.980643", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/01-dc-a6-32-54-fa-25"}
- {"dt": "2023-11-14T17:35:00.981100", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:00.981531", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:00.981957", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/C0A842F1"}
- {"dt": "2023-11-14T17:35:00.982380", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:00.982802", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:00.983264", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/C0A842F"}
- {"dt": "2023-11-14T17:35:01.008890", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.010783", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.011820", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/C0A842"}
- {"dt": "2023-11-14T17:35:01.012767", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.013624", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.014480", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/C0A84"}
- {"dt": "2023-11-14T17:35:01.015402", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.016333", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.017207", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/C0A8"}
- {"dt": "2023-11-14T17:35:01.018073", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.018917", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.019776", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/C0A"}
- {"dt": "2023-11-14T17:35:01.020733", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.021191", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.052744", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/C0"}
- {"dt": "2023-11-14T17:35:01.054597", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.055719", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.056864", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/C"}
- {"dt": "2023-11-14T17:35:01.057887", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.058883", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.059999", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/default-arm-bcm283x-rpi"}
- {"dt": "2023-11-14T17:35:01.061116", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.062167", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.063236", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/default-arm-bcm283x"}
- {"dt": "2023-11-14T17:35:01.064330", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.065094", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.107593", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/default-arm"}
- {"dt": "2023-11-14T17:35:01.109357", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.112017", "lvl": "target", "msg": "missing environment variable: bootfile"}
- {"dt": "2023-11-14T17:35:01.113167", "lvl": "target", "msg": "Retrieving file: pxelinux.cfg/default"}
- {"dt": "2023-11-14T17:35:01.114200", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.115256", "lvl": "target", "msg": "Config file not found"}
- {"dt": "2023-11-14T17:35:01.116568", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2023-11-14T17:35:01.117639", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2023-11-14T17:35:01.118670", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2023-11-14T17:35:01.119679", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (3 ms)"}
- {"dt": "2023-11-14T17:35:01.120770", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.121829", "lvl": "target", "msg": "Cannot autoload with TFTPGET"}
- {"dt": "2023-11-14T17:35:01.122943", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2023-11-14T17:35:01.124039", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (2 ms)"}
- {"dt": "2023-11-14T17:35:01.124903", "lvl": "target", "msg": "*** ERROR: `serverip' not set"}
- {"dt": "2023-11-14T17:35:01.125365", "lvl": "target", "msg": "Cannot autoload with TFTPGET"}
- {"dt": "2023-11-14T17:53:43.807411", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2023-11-14T17:53:43.809657", "lvl": "debug", "msg": "end: 2.4.4.1 login-action (duration 00:19:22) [common]"}
- {"dt": "2023-11-14T17:53:43.811502", "lvl": "results", "msg": {"case": "login-action", "definition": "lava", "duration": "1161.61", "extra": {"fail": "wait for prompt timed out"}, "level": "2.4.4.1", "namespace": "common", "result": "fail"}}
- {"dt": "2023-11-14T17:53:43.815101", "lvl": "error", "msg": "auto-login-action failed: 1 of 1 attempts. 'wait for prompt timed out'"}
- {"dt": "2023-11-14T17:53:43.816896", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2023-11-14T17:53:43.817662", "lvl": "debug", "msg": "end: 2.4.4 auto-login-action (duration 00:19:23) [common]"}
- {"dt": "2023-11-14T17:53:43.818498", "lvl": "results", "msg": {"case": "auto-login-action", "definition": "lava", "duration": "1163.46", "extra": {"fail": "wait for prompt timed out"}, "level": "2.4.4", "namespace": "common", "result": "fail"}}
- {"dt": "2023-11-14T17:53:43.821793", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2023-11-14T17:53:43.823750", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:19:57) [common]"}
- {"dt": "2023-11-14T17:53:43.825230", "lvl": "results", "msg": {"case": "uboot-commands", "definition": "lava", "duration": "1196.55", "extra": {"fail": "wait for prompt timed out"}, "level": "2.4", "namespace": "common", "result": "fail"}}
- {"dt": "2023-11-14T17:53:43.826863", "lvl": "error", "msg": "uboot-action failed: 1 of 1 attempts. 'wait for prompt timed out'"}
- {"dt": "2023-11-14T17:53:43.827978", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2023-11-14T17:53:43.828899", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:20:00) [common]"}
- {"dt": "2023-11-14T17:53:43.829840", "lvl": "results", "msg": {"case": "uboot-action", "definition": "lava", "duration": "1200.08", "extra": {"fail": "wait for prompt timed out"}, "level": "2", "namespace": "common", "result": "fail"}}
- {"dt": "2023-11-14T17:53:43.831812", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2023-11-14T17:53:43.832932", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/initrd"}
- {"dt": "2023-11-14T17:53:43.835867", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/kernel"}
- {"dt": "2023-11-14T17:53:43.842935", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/dtb"}
- {"dt": "2023-11-14T17:53:43.844368", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/33479/nbd-deploy-85hoc_z8/nbdroot"}
- {"dt": "2023-11-14T17:53:44.225758", "lvl": "debug", "msg": "start: 7.1 power-off (timeout 00:00:10) [common]"}
- {"dt": "2023-11-14T17:53:44.226895", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '7'"}
- {"dt": "2023-11-14T17:53:47.622321", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-11-14T17:53:47.658663", "lvl": "debug", "msg": "Returned 0 in 3 seconds"}
- {"dt": "2023-11-14T17:53:47.762649", "lvl": "debug", "msg": "end: 7.1 power-off (duration 00:00:04) [common]"}
- {"dt": "2023-11-14T17:53:47.765251", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "3.54", "extra": {"status": "success"}, "level": "7.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-11-14T17:53:47.769742", "lvl": "debug", "msg": "start: 7.2 read-feedback (timeout 00:29:56) [common]"}
- {"dt": "2023-11-14T17:53:47.773191", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2023-11-14T17:53:48.777648", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2023-11-14T17:53:48.779963", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2023-11-14T17:53:48.782187", "lvl": "target", "msg": "U-Boot> "}
- {"dt": "2023-11-14T17:53:48.885965", "lvl": "debug", "msg": "end: 7.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2023-11-14T17:53:48.888063", "lvl": "debug", "msg": "lava-xnbd cleanup"}
- {"dt": "2023-11-14T17:53:48.890018", "lvl": "debug", "msg": "clean NBD port 61999"}
- {"dt": "2023-11-14T17:53:52.120602", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/33479"}
- {"dt": "2023-11-14T17:53:52.210112", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/33479"}
- {"dt": "2023-11-14T17:53:52.211202", "lvl": "error", "msg": "JobError: Your job cannot terminate cleanly."}
- {"dt": "2023-11-14T17:53:52.211899", "lvl": "results", "msg": {"case": "job", "definition": "lava", "error_msg": "wait for prompt timed out", "error_type": "Job", "result": "fail"}}
