- {"dt": "2023-12-15T01:39:30.956577", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.01"}
- {"dt": "2023-12-15T01:39:30.957914", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2023-12-15T01:39:30.958925", "lvl": "info", "msg": "Start time: 2023-12-15 01:39:30.958867+00:00 (UTC)"}
- {"dt": "2023-12-15T01:39:30.960207", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29533/1/h3ulcb-nogfx/initramfs-netboot-image-h3ulcb.ext4.gz exists"}
- {"dt": "2023-12-15T01:39:31.178935", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29533/1/h3ulcb-nogfx/Image exists"}
- {"dt": "2023-12-15T01:39:31.395433", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29533/1/h3ulcb-nogfx/r8a77951-ulcb.dtb exists"}
- {"dt": "2023-12-15T01:39:31.609215", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/29533/1/h3ulcb-nogfx/agl-demo-platform-h3ulcb.ext4.xz exists"}
- {"dt": "2023-12-15T01:39:31.839972", "lvl": "info", "msg": "validate duration: 0.88"}
- {"dt": "2023-12-15T01:39:31.840783", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2023-12-15T01:39:31.841945", "lvl": "info", "msg": "start: 1 nbd-deploy (timeout 01:30:00) [common]"}
- {"dt": "2023-12-15T01:39:31.842612", "lvl": "info", "msg": "Making protocol call for nbd-deploy using lava-xnbd"}
- {"dt": "2023-12-15T01:39:31.843295", "lvl": "debug", "msg": "[nbd-deploy] Checking protocol data for lava-xnbd"}
- {"dt": "2023-12-15T01:39:31.843936", "lvl": "debug", "msg": "Get a port from pool"}
- {"dt": "2023-12-15T01:39:31.844957", "lvl": "debug", "msg": "Set_port 61961"}
- {"dt": "2023-12-15T01:39:31.845858", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 01:30:00) [common]"}
- {"dt": "2023-12-15T01:39:31.846666", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 01:30:00) [common]"}
- {"dt": "2023-12-15T01:39:31.848032", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29533/1/h3ulcb-nogfx/initramfs-netboot-image-h3ulcb.ext4.gz"}
- {"dt": "2023-12-15T01:39:31.848751", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/34285/nbd-deploy-pxazkprr/initrd/initramfs-netboot-image-h3ulcb.ext4.gz"}
- {"dt": "2023-12-15T01:39:31.849367", "lvl": "debug", "msg": "total size: 2061324 (1MB)"}
- {"dt": "2023-12-15T01:39:31.849931", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-12-15T01:39:32.156065", "lvl": "debug", "msg": "progress   1% (0MB)"}
- {"dt": "2023-12-15T01:39:32.351000", "lvl": "debug", "msg": "progress   6% (0MB)"}
- {"dt": "2023-12-15T01:39:32.447731", "lvl": "debug", "msg": "progress  11% (0MB)"}
- {"dt": "2023-12-15T01:39:32.463473", "lvl": "debug", "msg": "progress  17% (0MB)"}
- {"dt": "2023-12-15T01:39:32.543633", "lvl": "debug", "msg": "progress  22% (0MB)"}
- {"dt": "2023-12-15T01:39:32.551666", "lvl": "debug", "msg": "progress  27% (0MB)"}
- {"dt": "2023-12-15T01:39:32.558792", "lvl": "debug", "msg": "progress  33% (0MB)"}
- {"dt": "2023-12-15T01:39:32.563273", "lvl": "debug", "msg": "progress  38% (0MB)"}
- {"dt": "2023-12-15T01:39:32.640724", "lvl": "debug", "msg": "progress  44% (0MB)"}
- {"dt": "2023-12-15T01:39:32.650547", "lvl": "debug", "msg": "progress  49% (0MB)"}
- {"dt": "2023-12-15T01:39:32.656929", "lvl": "debug", "msg": "progress  54% (1MB)"}
- {"dt": "2023-12-15T01:39:32.662567", "lvl": "debug", "msg": "progress  60% (1MB)"}
- {"dt": "2023-12-15T01:39:32.667355", "lvl": "debug", "msg": "progress  65% (1MB)"}
- {"dt": "2023-12-15T01:39:32.672969", "lvl": "debug", "msg": "progress  71% (1MB)"}
- {"dt": "2023-12-15T01:39:32.744713", "lvl": "debug", "msg": "progress  76% (1MB)"}
- {"dt": "2023-12-15T01:39:32.752525", "lvl": "debug", "msg": "progress  81% (1MB)"}
- {"dt": "2023-12-15T01:39:32.758403", "lvl": "debug", "msg": "progress  87% (1MB)"}
- {"dt": "2023-12-15T01:39:32.762832", "lvl": "debug", "msg": "progress  92% (1MB)"}
- {"dt": "2023-12-15T01:39:32.768463", "lvl": "debug", "msg": "progress  98% (1MB)"}
- {"dt": "2023-12-15T01:39:32.772064", "lvl": "info", "msg": "1MB downloaded in 0.92s (2.13MB/s)"}
- {"dt": "2023-12-15T01:39:32.773318", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:39:32.774012", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.93", "extra": {"label": "initrd", "md5sum": "ed41a0e3ebc53c3f45e3b8e9cea6152c", "sha256sum": "16129a2010c65a377affba1f5d5b9894dbf64ef0f0b8af84e8c5d03ef59dc5e7", "sha512sum": "2d3a8b0952a6bdf0fcf67a3de31d1e1bb3cb641ba65925ab2a9e7d4cb793fb43c02a58c21cc4fd82e4347e7ed6e225591a5b31e11a7d47b427c18772ef2d54bb", "size": ! "2061324"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:39:32.775801", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:39:32.776668", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 01:29:59) [common]"}
- {"dt": "2023-12-15T01:39:32.777537", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 01:29:59) [common]"}
- {"dt": "2023-12-15T01:39:32.778692", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29533/1/h3ulcb-nogfx/Image"}
- {"dt": "2023-12-15T01:39:32.780160", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/34285/nbd-deploy-pxazkprr/kernel/Image"}
- {"dt": "2023-12-15T01:39:32.780821", "lvl": "debug", "msg": "total size: 39207424 (37MB)"}
- {"dt": "2023-12-15T01:39:32.781375", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-12-15T01:39:33.180563", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-12-15T01:39:33.863762", "lvl": "debug", "msg": "progress   5% (1MB)"}
- {"dt": "2023-12-15T01:39:34.168809", "lvl": "debug", "msg": "progress  10% (3MB)"}
- {"dt": "2023-12-15T01:39:34.469598", "lvl": "debug", "msg": "progress  15% (5MB)"}
- {"dt": "2023-12-15T01:39:34.770283", "lvl": "debug", "msg": "progress  20% (7MB)"}
- {"dt": "2023-12-15T01:39:35.139566", "lvl": "debug", "msg": "progress  25% (9MB)"}
- {"dt": "2023-12-15T01:39:35.442829", "lvl": "debug", "msg": "progress  30% (11MB)"}
- {"dt": "2023-12-15T01:39:35.745491", "lvl": "debug", "msg": "progress  35% (13MB)"}
- {"dt": "2023-12-15T01:39:36.050125", "lvl": "debug", "msg": "progress  40% (14MB)"}
- {"dt": "2023-12-15T01:39:36.409881", "lvl": "debug", "msg": "progress  45% (16MB)"}
- {"dt": "2023-12-15T01:39:36.716032", "lvl": "debug", "msg": "progress  50% (18MB)"}
- {"dt": "2023-12-15T01:39:37.020539", "lvl": "debug", "msg": "progress  55% (20MB)"}
- {"dt": "2023-12-15T01:39:37.318882", "lvl": "debug", "msg": "progress  60% (22MB)"}
- {"dt": "2023-12-15T01:39:37.617782", "lvl": "debug", "msg": "progress  65% (24MB)"}
- {"dt": "2023-12-15T01:39:37.915757", "lvl": "debug", "msg": "progress  70% (26MB)"}
- {"dt": "2023-12-15T01:39:38.213339", "lvl": "debug", "msg": "progress  75% (28MB)"}
- {"dt": "2023-12-15T01:39:38.511617", "lvl": "debug", "msg": "progress  80% (29MB)"}
- {"dt": "2023-12-15T01:39:38.808923", "lvl": "debug", "msg": "progress  85% (31MB)"}
- {"dt": "2023-12-15T01:39:39.091092", "lvl": "debug", "msg": "progress  90% (33MB)"}
- {"dt": "2023-12-15T01:39:39.383106", "lvl": "debug", "msg": "progress  95% (35MB)"}
- {"dt": "2023-12-15T01:39:39.665641", "lvl": "debug", "msg": "progress 100% (37MB)"}
- {"dt": "2023-12-15T01:39:39.668710", "lvl": "info", "msg": "37MB downloaded in 6.89s (5.43MB/s)"}
- {"dt": "2023-12-15T01:39:39.669897", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:07) [common]"}
- {"dt": "2023-12-15T01:39:39.670492", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "6.89", "extra": {"label": "kernel", "md5sum": "67bfab12e96116ab670f028caec3573c", "sha256sum": "e30f14c64900849b17441f15e1578a685afa29566827ee43d2e0c94e58a73561", "sha512sum": "37d836f1471d791eb9e265b170ac123ce0548b1cb590a8511f2ce6476e17d2faa0df169055f6bd17cd10b942795f605950bc68d5169b3277cd4a24f11d672038", "size": ! "39207424"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:39:39.671973", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:07) [common]"}
- {"dt": "2023-12-15T01:39:39.672676", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 01:29:52) [common]"}
- {"dt": "2023-12-15T01:39:39.673316", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 01:29:52) [common]"}
- {"dt": "2023-12-15T01:39:39.674290", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29533/1/h3ulcb-nogfx/r8a77951-ulcb.dtb"}
- {"dt": "2023-12-15T01:39:39.674957", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/34285/nbd-deploy-pxazkprr/dtb/r8a77951-ulcb.dtb"}
- {"dt": "2023-12-15T01:39:39.677282", "lvl": "debug", "msg": "total size: 82960 (0MB)"}
- {"dt": "2023-12-15T01:39:39.677814", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2023-12-15T01:39:39.992860", "lvl": "debug", "msg": "progress  39% (0MB)"}
- {"dt": "2023-12-15T01:39:40.094120", "lvl": "debug", "msg": "progress  78% (0MB)"}
- {"dt": "2023-12-15T01:39:40.096610", "lvl": "debug", "msg": "progress 100% (0MB)"}
- {"dt": "2023-12-15T01:39:40.098113", "lvl": "info", "msg": "0MB downloaded in 0.42s (0.19MB/s)"}
- {"dt": "2023-12-15T01:39:40.101103", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:39:40.101937", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.43", "extra": {"label": "dtb", "md5sum": "b7b77a5bcd5ad3e5af64677b0833c507", "sha256sum": "7b589087974b9e9d0de191cb371345189ba4ef640b13944ea28ba49d078c1789", "sha512sum": "ebcb6657499258a45ce691359360493900603f1d08f640603ee9f5b4a642e5a3a35d29e4ba0c01a23c59eb57fb879b62bfa31433bb9d00bd0aefc03fc3adf229", "size": ! "82960"}, "level": "1.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:39:40.103488", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:39:40.104200", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 01:29:52) [common]"}
- {"dt": "2023-12-15T01:39:40.104848", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 01:29:52) [common]"}
- {"dt": "2023-12-15T01:39:40.105826", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/29533/1/h3ulcb-nogfx/agl-demo-platform-h3ulcb.ext4.xz"}
- {"dt": "2023-12-15T01:39:40.106513", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/34285/nbd-deploy-pxazkprr/nbdroot/agl-demo-platform-h3ulcb.ext4"}
- {"dt": "2023-12-15T01:39:40.107092", "lvl": "debug", "msg": "total size: 454051320 (433MB)"}
- {"dt": "2023-12-15T01:39:40.110245", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2023-12-15T01:39:40.438587", "lvl": "debug", "msg": "progress   0% (0MB)"}
- {"dt": "2023-12-15T01:39:46.720266", "lvl": "debug", "msg": "progress   5% (21MB)"}
- {"dt": "2023-12-15T01:39:51.406798", "lvl": "debug", "msg": "progress  10% (43MB)"}
- {"dt": "2023-12-15T01:39:56.420996", "lvl": "debug", "msg": "progress  15% (64MB)"}
- {"dt": "2023-12-15T01:40:04.471805", "lvl": "debug", "msg": "progress  20% (86MB)"}
- {"dt": "2023-12-15T01:40:12.855589", "lvl": "debug", "msg": "progress  25% (108MB)"}
- {"dt": "2023-12-15T01:40:21.679594", "lvl": "debug", "msg": "progress  30% (129MB)"}
- {"dt": "2023-12-15T01:40:32.022869", "lvl": "debug", "msg": "progress  35% (151MB)"}
- {"dt": "2023-12-15T01:40:40.221171", "lvl": "debug", "msg": "progress  40% (173MB)"}
- {"dt": "2023-12-15T01:40:46.569034", "lvl": "debug", "msg": "progress  45% (194MB)"}
- {"dt": "2023-12-15T01:40:51.891759", "lvl": "debug", "msg": "progress  50% (216MB)"}
- {"dt": "2023-12-15T01:40:58.259782", "lvl": "debug", "msg": "progress  55% (238MB)"}
- {"dt": "2023-12-15T01:41:05.142489", "lvl": "debug", "msg": "progress  60% (259MB)"}
- {"dt": "2023-12-15T01:41:12.047772", "lvl": "debug", "msg": "progress  65% (281MB)"}
- {"dt": "2023-12-15T01:41:19.871861", "lvl": "debug", "msg": "progress  70% (303MB)"}
- {"dt": "2023-12-15T01:41:25.415862", "lvl": "debug", "msg": "progress  75% (324MB)"}
- {"dt": "2023-12-15T01:41:30.707781", "lvl": "debug", "msg": "progress  80% (346MB)"}
- {"dt": "2023-12-15T01:41:35.840843", "lvl": "debug", "msg": "progress  85% (368MB)"}
- {"dt": "2023-12-15T01:41:41.107801", "lvl": "debug", "msg": "progress  90% (389MB)"}
- {"dt": "2023-12-15T01:41:46.307731", "lvl": "debug", "msg": "progress  95% (411MB)"}
- {"dt": "2023-12-15T01:41:56.789221", "lvl": "debug", "msg": "progress 100% (433MB)"}
- {"dt": "2023-12-15T01:42:01.464717", "lvl": "info", "msg": "433MB downloaded in 141.36s (3.06MB/s)"}
- {"dt": "2023-12-15T01:42:01.467443", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:02:21) [common]"}
- {"dt": "2023-12-15T01:42:01.469039", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "141.36", "extra": {"label": "nbdroot", "md5sum": "23ed9c352bbd25ed729aeadd2edb170b", "sha256sum": "1b30df17f888fbef2966f9aa5167e21d5d5f6fbb33737afd8b418f4c58108f3b", "sha512sum": "20aa4abcd7d1cfc01b2e14e951e7772e6be043b8361fecdb844d63a2fcfe9eb76fd12e6ad368b3eeca640a229d511f71a94cde0fd9617a9b9e0ecf9f3af58676", "size": ! "454051320"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:01.475231", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:02:21) [common]"}
- {"dt": "2023-12-15T01:42:01.480508", "lvl": "debug", "msg": "start: 1.5 lava-overlay (timeout 01:27:30) [common]"}
- {"dt": "2023-12-15T01:42:01.500641", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w"}
- {"dt": "2023-12-15T01:42:01.501990", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin"}
- {"dt": "2023-12-15T01:42:01.503108", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/tests"}
- {"dt": "2023-12-15T01:42:01.521004", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/results"}
- {"dt": "2023-12-15T01:42:01.522106", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-add-keys"}
- {"dt": "2023-12-15T01:42:01.540370", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-add-sources"}
- {"dt": "2023-12-15T01:42:01.541858", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-background-process-start"}
- {"dt": "2023-12-15T01:42:01.568886", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-background-process-stop"}
- {"dt": "2023-12-15T01:42:01.570474", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-common-functions"}
- {"dt": "2023-12-15T01:42:01.572225", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-echo-ipv4"}
- {"dt": "2023-12-15T01:42:01.573771", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-install-packages"}
- {"dt": "2023-12-15T01:42:01.583365", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-installed-packages"}
- {"dt": "2023-12-15T01:42:01.584915", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-os-build"}
- {"dt": "2023-12-15T01:42:01.586475", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-probe-channel"}
- {"dt": "2023-12-15T01:42:01.592328", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-probe-ip"}
- {"dt": "2023-12-15T01:42:01.596195", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-target-ip"}
- {"dt": "2023-12-15T01:42:01.597623", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-target-mac"}
- {"dt": "2023-12-15T01:42:01.600684", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-target-storage"}
- {"dt": "2023-12-15T01:42:01.602273", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-test-case"}
- {"dt": "2023-12-15T01:42:01.604299", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-test-event"}
- {"dt": "2023-12-15T01:42:01.605810", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-test-feedback"}
- {"dt": "2023-12-15T01:42:01.609081", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-test-raise"}
- {"dt": "2023-12-15T01:42:01.610551", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-test-reference"}
- {"dt": "2023-12-15T01:42:01.612567", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-test-runner"}
- {"dt": "2023-12-15T01:42:01.614068", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-test-set"}
- {"dt": "2023-12-15T01:42:01.616240", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-test-shell"}
- {"dt": "2023-12-15T01:42:01.617814", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-install-packages (oe)"}
- {"dt": "2023-12-15T01:42:01.621699", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/bin/lava-installed-packages (oe)"}
- {"dt": "2023-12-15T01:42:01.623254", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/environment"}
- {"dt": "2023-12-15T01:42:01.624515", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2023-12-15T01:42:01.625389", "lvl": "debug", "msg": "- LAVA_JOB_ID=34285"}
- {"dt": "2023-12-15T01:42:01.626163", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.66.1"}
- {"dt": "2023-12-15T01:42:01.630739", "lvl": "debug", "msg": "start: 1.5.1 ssh-authorize (timeout 01:27:30) [common]"}
- {"dt": "2023-12-15T01:42:01.636112", "lvl": "debug", "msg": "end: 1.5.1 ssh-authorize (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:01.641985", "lvl": "debug", "msg": "start: 1.5.2 lava-vland-overlay (timeout 01:27:30) [common]"}
- {"dt": "2023-12-15T01:42:01.643235", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2023-12-15T01:42:01.645213", "lvl": "debug", "msg": "end: 1.5.2 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:01.647126", "lvl": "debug", "msg": "start: 1.5.3 lava-multinode-overlay (timeout 01:27:30) [common]"}
- {"dt": "2023-12-15T01:42:01.648415", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2023-12-15T01:42:01.651060", "lvl": "debug", "msg": "end: 1.5.3 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:01.653293", "lvl": "debug", "msg": "start: 1.5.4 test-definition (timeout 01:27:30) [common]"}
- {"dt": "2023-12-15T01:42:01.654591", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2023-12-15T01:42:01.659970", "lvl": "debug", "msg": "start: 1.5.4.1 git-repo-action (timeout 01:27:30) [common]"}
- {"dt": "2023-12-15T01:42:01.660874", "lvl": "debug", "msg": "Using /lava-34285 at stage 0"}
- {"dt": "2023-12-15T01:42:01.662038", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-12-15T01:42:01.662939", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/0/tests/0_network-veth'"}
- {"dt": "2023-12-15T01:42:02.629052", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/0/tests/0_network-veth/test-suites/short-smoke/network-veth.yaml"}
- {"dt": "2023-12-15T01:42:02.633280", "lvl": "debug", "msg": "uuid=34285_1.5.4.1 testdef=None"}
- {"dt": "2023-12-15T01:42:02.634394", "lvl": "debug", "msg": "end: 1.5.4.1 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:42:02.635105", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.97", "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-12-15T01:42:02.636650", "lvl": "debug", "msg": "start: 1.5.4.2 test-overlay (timeout 01:27:29) [common]"}
- {"dt": "2023-12-15T01:42:02.642481", "lvl": "debug", "msg": "end: 1.5.4.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:02.643442", "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": "34285_1.5.4.1"}, "level": "1.5.4.2", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:02.645194", "lvl": "debug", "msg": "start: 1.5.4.3 test-install-overlay (timeout 01:27:29) [common]"}
- {"dt": "2023-12-15T01:42:02.652543", "lvl": "debug", "msg": "end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:02.653360", "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": "34285_1.5.4.1", "uuid": "34285_1.5.4.1"}, "level": "1.5.4.3", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:02.654931", "lvl": "debug", "msg": "start: 1.5.4.4 test-runscript-overlay (timeout 01:27:29) [common]"}
- {"dt": "2023-12-15T01:42:02.664143", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/0/tests/0_network-veth test_uuid 34285_1.5.4.1"}
- {"dt": "2023-12-15T01:42:02.665744", "lvl": "debug", "msg": "end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:02.666528", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/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": "34285_1.5.4.1"}, "level": "1.5.4.4", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:02.670314", "lvl": "debug", "msg": "start: 1.5.4.5 git-repo-action (timeout 01:27:29) [common]"}
- {"dt": "2023-12-15T01:42:02.671207", "lvl": "debug", "msg": "Using /lava-34285 at stage 1"}
- {"dt": "2023-12-15T01:42:02.672290", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-12-15T01:42:02.673051", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/1_ci-busybox'"}
- {"dt": "2023-12-15T01:42:03.702487", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/1_ci-busybox"}
- {"dt": "2023-12-15T01:42:03.737716", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/1_ci-busybox/test-suites/short-smoke/busybox.yaml"}
- {"dt": "2023-12-15T01:42:03.757334", "lvl": "debug", "msg": "uuid=34285_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-12-15T01:42:03.758507", "lvl": "debug", "msg": "end: 1.5.4.5 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:42:03.767502", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "1.09", "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-12-15T01:42:03.769165", "lvl": "debug", "msg": "start: 1.5.4.6 test-overlay (timeout 01:27:28) [common]"}
- {"dt": "2023-12-15T01:42:03.790862", "lvl": "debug", "msg": "end: 1.5.4.6 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:03.791682", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.02", "extra": {"from": "git", "name": "ci-busybox", "path": "test-suites/short-smoke/busybox.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "34285_1.5.4.5"}, "level": "1.5.4.6", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:03.797912", "lvl": "debug", "msg": "start: 1.5.4.7 test-install-overlay (timeout 01:27:28) [common]"}
- {"dt": "2023-12-15T01:42:03.819657", "lvl": "debug", "msg": "end: 1.5.4.7 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:03.820495", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.02", "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": "34285_1.5.4.5", "uuid": "34285_1.5.4.5"}, "level": "1.5.4.7", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:03.822040", "lvl": "debug", "msg": "start: 1.5.4.8 test-runscript-overlay (timeout 01:27:28) [common]"}
- {"dt": "2023-12-15T01:42:03.838124", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/1_ci-busybox test_uuid 34285_1.5.4.5"}
- {"dt": "2023-12-15T01:42:03.845265", "lvl": "debug", "msg": "end: 1.5.4.8 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:03.846045", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.02", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/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": "34285_1.5.4.5"}, "level": "1.5.4.8", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:03.848349", "lvl": "debug", "msg": "start: 1.5.4.9 git-repo-action (timeout 01:27:28) [common]"}
- {"dt": "2023-12-15T01:42:03.849107", "lvl": "debug", "msg": "Using /lava-34285 at stage 1"}
- {"dt": "2023-12-15T01:42:03.850073", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-12-15T01:42:03.850852", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/2_ci-smoke-tests-basic'"}
- {"dt": "2023-12-15T01:42:04.804330", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/2_ci-smoke-tests-basic"}
- {"dt": "2023-12-15T01:42:04.823964", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/2_ci-smoke-tests-basic/test-suites/short-smoke/smoke-tests-basic.yaml"}
- {"dt": "2023-12-15T01:42:04.829565", "lvl": "debug", "msg": "uuid=34285_1.5.4.9 testdef=None"}
- {"dt": "2023-12-15T01:42:04.830745", "lvl": "debug", "msg": "end: 1.5.4.9 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:42:04.836106", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.98", "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-12-15T01:42:04.838153", "lvl": "debug", "msg": "start: 1.5.4.10 test-overlay (timeout 01:27:27) [common]"}
- {"dt": "2023-12-15T01:42:04.856360", "lvl": "debug", "msg": "end: 1.5.4.10 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:04.857160", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.02", "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": "34285_1.5.4.9"}, "level": "1.5.4.10", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:04.858802", "lvl": "debug", "msg": "start: 1.5.4.11 test-install-overlay (timeout 01:27:27) [common]"}
- {"dt": "2023-12-15T01:42:04.876939", "lvl": "debug", "msg": "end: 1.5.4.11 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:04.877735", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.02", "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": "34285_1.5.4.9", "uuid": "34285_1.5.4.9"}, "level": "1.5.4.11", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:04.883535", "lvl": "debug", "msg": "start: 1.5.4.12 test-runscript-overlay (timeout 01:27:27) [common]"}
- {"dt": "2023-12-15T01:42:04.899441", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/2_ci-smoke-tests-basic test_uuid 34285_1.5.4.9"}
- {"dt": "2023-12-15T01:42:04.902404", "lvl": "debug", "msg": "end: 1.5.4.12 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:04.907351", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.02", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/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": "34285_1.5.4.9"}, "level": "1.5.4.12", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:04.909228", "lvl": "debug", "msg": "start: 1.5.4.13 git-repo-action (timeout 01:27:27) [common]"}
- {"dt": "2023-12-15T01:42:04.910016", "lvl": "debug", "msg": "Using /lava-34285 at stage 1"}
- {"dt": "2023-12-15T01:42:04.911112", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-12-15T01:42:04.920196", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/3_ci-service-check'"}
- {"dt": "2023-12-15T01:42:06.005203", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/3_ci-service-check"}
- {"dt": "2023-12-15T01:42:06.034168", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/3_ci-service-check/test-suites/short-smoke/service-check.yaml"}
- {"dt": "2023-12-15T01:42:06.042590", "lvl": "debug", "msg": "uuid=34285_1.5.4.13 testdef=None"}
- {"dt": "2023-12-15T01:42:06.049778", "lvl": "debug", "msg": "end: 1.5.4.13 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:42:06.050597", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "1.14", "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-12-15T01:42:06.052554", "lvl": "debug", "msg": "start: 1.5.4.14 test-overlay (timeout 01:27:26) [common]"}
- {"dt": "2023-12-15T01:42:06.068800", "lvl": "debug", "msg": "end: 1.5.4.14 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:06.069550", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.02", "extra": {"from": "git", "name": "ci-service-check", "path": "test-suites/short-smoke/service-check.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "34285_1.5.4.13"}, "level": "1.5.4.14", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:06.075329", "lvl": "debug", "msg": "start: 1.5.4.15 test-install-overlay (timeout 01:27:26) [common]"}
- {"dt": "2023-12-15T01:42:06.090676", "lvl": "debug", "msg": "end: 1.5.4.15 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:06.101393", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.02", "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": "34285_1.5.4.13", "uuid": "34285_1.5.4.13"}, "level": "1.5.4.15", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:06.103070", "lvl": "debug", "msg": "start: 1.5.4.16 test-runscript-overlay (timeout 01:27:26) [common]"}
- {"dt": "2023-12-15T01:42:06.121841", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1/tests/3_ci-service-check test_uuid 34285_1.5.4.13"}
- {"dt": "2023-12-15T01:42:06.122686", "lvl": "debug", "msg": "BUILD_TAGS=''"}
- {"dt": "2023-12-15T01:42:06.123389", "lvl": "debug", "msg": "DEVICE_TAGS='kingfisher can bluetooth wifi audio'"}
- {"dt": "2023-12-15T01:42:06.125333", "lvl": "debug", "msg": "end: 1.5.4.16 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:06.126089", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.02", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/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": "34285_1.5.4.13"}, "level": "1.5.4.16", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:06.137738", "lvl": "debug", "msg": "start: 1.5.4.17 git-repo-action (timeout 01:27:26) [common]"}
- {"dt": "2023-12-15T01:42:06.138563", "lvl": "debug", "msg": "Using /lava-34285 at stage 2"}
- {"dt": "2023-12-15T01:42:06.139766", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-12-15T01:42:06.141042", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/2/tests/4_screenshooter'"}
- {"dt": "2023-12-15T01:42:07.199113", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/2/tests/4_screenshooter/test-suites/short-smoke/screenshooter.yaml"}
- {"dt": "2023-12-15T01:42:07.204197", "lvl": "debug", "msg": "uuid=34285_1.5.4.17 testdef=None"}
- {"dt": "2023-12-15T01:42:07.205532", "lvl": "debug", "msg": "end: 1.5.4.17 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:42:07.206277", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "1.07", "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-12-15T01:42:07.208423", "lvl": "debug", "msg": "start: 1.5.4.18 test-overlay (timeout 01:27:25) [common]"}
- {"dt": "2023-12-15T01:42:07.213876", "lvl": "debug", "msg": "end: 1.5.4.18 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:07.214537", "lvl": "results", "msg": {"case": "test-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", "uuid": "34285_1.5.4.17"}, "level": "1.5.4.18", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:07.216552", "lvl": "debug", "msg": "start: 1.5.4.19 test-install-overlay (timeout 01:27:25) [common]"}
- {"dt": "2023-12-15T01:42:07.225618", "lvl": "debug", "msg": "end: 1.5.4.19 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:07.226404", "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": "34285_1.5.4.17", "uuid": "34285_1.5.4.17"}, "level": "1.5.4.19", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:07.228548", "lvl": "debug", "msg": "start: 1.5.4.20 test-runscript-overlay (timeout 01:27:25) [common]"}
- {"dt": "2023-12-15T01:42:07.236481", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/2/tests/4_screenshooter test_uuid 34285_1.5.4.17"}
- {"dt": "2023-12-15T01:42:07.238476", "lvl": "debug", "msg": "end: 1.5.4.20 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:07.239981", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/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": "34285_1.5.4.17"}, "level": "1.5.4.20", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:07.242052", "lvl": "debug", "msg": "start: 1.5.4.21 git-repo-action (timeout 01:27:25) [common]"}
- {"dt": "2023-12-15T01:42:07.243194", "lvl": "debug", "msg": "Using /lava-34285 at stage 3"}
- {"dt": "2023-12-15T01:42:07.244387", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2023-12-15T01:42:07.245219", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/3/tests/5_ci-dumpjournal'"}
- {"dt": "2023-12-15T01:42:08.090426", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/3/tests/5_ci-dumpjournal"}
- {"dt": "2023-12-15T01:42:08.129494", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/3/tests/5_ci-dumpjournal/test-suites/short-smoke/dumpjournal.yaml"}
- {"dt": "2023-12-15T01:42:08.134207", "lvl": "debug", "msg": "uuid=34285_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-12-15T01:42:08.138326", "lvl": "debug", "msg": "end: 1.5.4.21 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:42:08.139407", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.90", "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-12-15T01:42:08.141298", "lvl": "debug", "msg": "start: 1.5.4.22 test-overlay (timeout 01:27:24) [common]"}
- {"dt": "2023-12-15T01:42:08.153738", "lvl": "debug", "msg": "end: 1.5.4.22 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:08.154480", "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": "34285_1.5.4.21"}, "level": "1.5.4.22", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:08.158619", "lvl": "debug", "msg": "start: 1.5.4.23 test-install-overlay (timeout 01:27:24) [common]"}
- {"dt": "2023-12-15T01:42:08.171090", "lvl": "debug", "msg": "end: 1.5.4.23 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:08.171886", "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": "34285_1.5.4.21", "uuid": "34285_1.5.4.21"}, "level": "1.5.4.23", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:08.173943", "lvl": "debug", "msg": "start: 1.5.4.24 test-runscript-overlay (timeout 01:27:24) [common]"}
- {"dt": "2023-12-15T01:42:08.188810", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/3/tests/5_ci-dumpjournal test_uuid 34285_1.5.4.21"}
- {"dt": "2023-12-15T01:42:08.190471", "lvl": "debug", "msg": "end: 1.5.4.24 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:08.192754", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.02", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/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": "34285_1.5.4.21"}, "level": "1.5.4.24", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:08.194345", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2023-12-15T01:42:08.194953", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/0 for stage 0"}
- {"dt": "2023-12-15T01:42:08.196055", "lvl": "debug", "msg": "- 0_network-veth"}
- {"dt": "2023-12-15T01:42:08.197874", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/1 for stage 1"}
- {"dt": "2023-12-15T01:42:08.198920", "lvl": "debug", "msg": "- 1_ci-busybox"}
- {"dt": "2023-12-15T01:42:08.201306", "lvl": "debug", "msg": "- 2_ci-smoke-tests-basic"}
- {"dt": "2023-12-15T01:42:08.201962", "lvl": "debug", "msg": "- 3_ci-service-check"}
- {"dt": "2023-12-15T01:42:08.205109", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/2 for stage 2"}
- {"dt": "2023-12-15T01:42:08.206278", "lvl": "debug", "msg": "- 4_screenshooter"}
- {"dt": "2023-12-15T01:42:08.207131", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/34285/lava-overlay-i5ho233w/lava-34285/3 for stage 3"}
- {"dt": "2023-12-15T01:42:08.208685", "lvl": "debug", "msg": "- 5_ci-dumpjournal"}
- {"dt": "2023-12-15T01:42:08.210469", "lvl": "debug", "msg": "end: 1.5.4 test-definition (duration 00:00:07) [common]"}
- {"dt": "2023-12-15T01:42:08.211507", "lvl": "debug", "msg": "start: 1.5.5 compress-overlay (timeout 01:27:24) [common]"}
- {"dt": "2023-12-15T01:42:09.594887", "lvl": "debug", "msg": "end: 1.5.5 compress-overlay (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:42:09.596269", "lvl": "debug", "msg": "start: 1.5.6 persistent-nfs-overlay (timeout 01:27:22) [common]"}
- {"dt": "2023-12-15T01:42:09.598000", "lvl": "debug", "msg": "end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:09.598931", "lvl": "debug", "msg": "end: 1.5 lava-overlay (duration 00:00:08) [common]"}
- {"dt": "2023-12-15T01:42:09.600890", "lvl": "debug", "msg": "start: 1.6 prepare-kernel (timeout 01:27:22) [common]"}
- {"dt": "2023-12-15T01:42:09.601842", "lvl": "debug", "msg": "start: 1.6.1 uboot-prepare-kernel (timeout 01:27:22) [common]"}
- {"dt": "2023-12-15T01:42:09.602728", "lvl": "debug", "msg": "end: 1.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:09.604888", "lvl": "debug", "msg": "end: 1.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:09.605876", "lvl": "debug", "msg": "start: 1.7 xnbd-server-deploy (timeout 01:27:22) [common]"}
- {"dt": "2023-12-15T01:42:09.606623", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server"}
- {"dt": "2023-12-15T01:42:09.608023", "lvl": "debug", "msg": "NBD-IP: 192.168.66.1, NBD-PORT: 61961, NBD-ROOT: 34285/nbd-deploy-pxazkprr/nbdroot/agl-demo-platform-h3ulcb.ext4"}
- {"dt": "2023-12-15T01:42:09.613240", "lvl": "debug", "msg": "nbd-server 61961 /var/lib/lava/dispatcher/tmp/34285/nbd-deploy-pxazkprr/nbdroot/agl-demo-platform-h3ulcb.ext4"}
- {"dt": "2023-12-15T01:42:09.639810", "lvl": "debug", "msg": "output: "}
- {"dt": "2023-12-15T01:42:09.641678", "lvl": "debug", "msg": "output: ** (process:11055): WARNING **: 01:42:09.633: Specifying an export on the command line no longer uses the oldstyle protocol."}
- {"dt": "2023-12-15T01:42:09.642514", "lvl": "debug", "msg": "output: "}
- {"dt": "2023-12-15T01:42:09.643329", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server done"}
- {"dt": "2023-12-15T01:42:09.644406", "lvl": "debug", "msg": "end: 1.7 xnbd-server-deploy (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:09.645455", "lvl": "info", "msg": "end: 1 nbd-deploy (duration 00:02:38) [common]"}
- {"dt": "2023-12-15T01:42:09.646381", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:20:00) [common]"}
- {"dt": "2023-12-15T01:42:09.655497", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:20:00) [common]"}
- {"dt": "2023-12-15T01:42:09.656563", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:09.657480", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:20:00) [common]"}
- {"dt": "2023-12-15T01:42:09.658881", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2023-12-15T01:42:09.659743", "lvl": "debug", "msg": "- {BOOTX}: booti 0x68080000 0x4a000000:${initrd_size} 0x68000000"}
- {"dt": "2023-12-15T01:42:09.660326", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x68000000"}
- {"dt": "2023-12-15T01:42:09.661010", "lvl": "debug", "msg": "- {DTB}: 34285/nbd-deploy-pxazkprr/dtb/r8a77951-ulcb.dtb"}
- {"dt": "2023-12-15T01:42:09.661598", "lvl": "debug", "msg": "- {INITRD}: 34285/nbd-deploy-pxazkprr/initrd/initramfs-netboot-image-h3ulcb.ext4.gz"}
- {"dt": "2023-12-15T01:42:09.662167", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x68080000"}
- {"dt": "2023-12-15T01:42:09.662693", "lvl": "debug", "msg": "- {KERNEL}: 34285/nbd-deploy-pxazkprr/kernel/Image"}
- {"dt": "2023-12-15T01:42:09.670210", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2023-12-15T01:42:09.670980", "lvl": "debug", "msg": "- {NBDSERVERIP}: 192.168.66.1"}
- {"dt": "2023-12-15T01:42:09.671676", "lvl": "debug", "msg": "- {NBDSERVERPORT}: 61961"}
- {"dt": "2023-12-15T01:42:09.672263", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2023-12-15T01:42:09.672927", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2023-12-15T01:42:09.673507", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x4a000000"}
- {"dt": "2023-12-15T01:42:09.674019", "lvl": "debug", "msg": "- {RAMDISK}: 34285/nbd-deploy-pxazkprr/initrd/initramfs-netboot-image-h3ulcb.ext4.gz"}
- {"dt": "2023-12-15T01:42:09.674536", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2023-12-15T01:42:09.675016", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2023-12-15T01:42:09.679927", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2023-12-15T01:42:09.680643", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2023-12-15T01:42:09.681198", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2023-12-15T01:42:09.681800", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2023-12-15T01:42:09.682387", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2023-12-15T01:42:09.682912", "lvl": "info", "msg": "- setenv initrd_high 0xffffffff"}
- {"dt": "2023-12-15T01:42:09.688501", "lvl": "info", "msg": "- setenv fdt_high 0xffffffff"}
- {"dt": "2023-12-15T01:42:09.689225", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2023-12-15T01:42:09.689807", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2023-12-15T01:42:09.690390", "lvl": "info", "msg": "- tftp 0x68080000 34285/nbd-deploy-pxazkprr/kernel/Image"}
- {"dt": "2023-12-15T01:42:09.690904", "lvl": "info", "msg": "- tftp 0x4a000000 34285/nbd-deploy-pxazkprr/initrd/initramfs-netboot-image-h3ulcb.ext4.gz"}
- {"dt": "2023-12-15T01:42:09.695820", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2023-12-15T01:42:09.696550", "lvl": "info", "msg": "- tftp 0x68000000 34285/nbd-deploy-pxazkprr/dtb/r8a77951-ulcb.dtb"}
- {"dt": "2023-12-15T01:42:09.697152", "lvl": "info", "msg": "- setenv bootargs 'console=ttySC0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61961 root=/dev/ram0 ramdisk_size=16384 rootdelay=7  systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'"}
- {"dt": "2023-12-15T01:42:09.697773", "lvl": "info", "msg": "- booti 0x68080000 0x4a000000:${initrd_size} 0x68000000"}
- {"dt": "2023-12-15T01:42:09.698524", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2023-12-15T01:42:09.707274", "lvl": "results", "msg": {"case": "bootloader-overlay", "definition": "lava", "duration": "0.04", "extra": {"dtb_addr": "0x68000000", "kernel_addr": "0x68080000", "ramdisk_addr": "0x4a000000", "tee_addr": "0x83000000"}, "level": "2.2", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:09.709087", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:20:00) [common]"}
- {"dt": "2023-12-15T01:42:09.709825", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63001'"}
- {"dt": "2023-12-15T01:42:16.055758", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2023-12-15T01:42:16.057991", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:06) [common]"}
- {"dt": "2023-12-15T01:42:16.058982", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:19:54) [common]"}
- {"dt": "2023-12-15T01:42:16.065508", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:19:54) [common]"}
- {"dt": "2023-12-15T01:42:16.066466", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:19:54) [common]"}
- {"dt": "2023-12-15T01:42:16.069988", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '2'"}
- {"dt": "2023-12-15T01:42:21.359936", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-12-15T01:42:22.450403", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-12-15T01:42:22.540591", "lvl": "debug", "msg": "Returned 0 in 6 seconds"}
- {"dt": "2023-12-15T01:42:22.642939", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:07) [common]"}
- {"dt": "2023-12-15T01:42:22.644167", "lvl": "results", "msg": {"case": "pdu-reboot", "definition": "lava", "duration": "6.58", "extra": {"status": "success"}, "level": "2.4.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:22.659789", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:07) [common]"}
- {"dt": "2023-12-15T01:42:22.660741", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:19:47) [common]"}
- {"dt": "2023-12-15T01:42:22.661472", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2023-12-15T01:42:22.662136", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:20:00)"}
- {"dt": "2023-12-15T01:42:22.672320", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2023-12-15T01:42:22.673098", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2023-12-15T01:42:22.673631", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2023-12-15T01:42:22.674110", "lvl": "target", "msg": "NOTICE:  BL2: R-Car Gen3 Initi\uFFFD\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:22.674630", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:22.687057", "lvl": "target", "msg": "NOTICE:  BL2\uFFFD\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:22.687927", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:22.770840", "lvl": "target", "msg": "NOTICE:  BL2: Board is Starter Kit Pre\uFFFD\0NOTICE:  BL2: R-Car Gen3 Initial Pr\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:22.771705", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:22.812194", "lvl": "target", "msg": "NOTICE\uFFFD\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:22.813548", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:22.866837", "lvl": "target", "msg": "NOTICE:  BL2: Board is St\uFFFD\0\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:22.867714", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:22.916904", "lvl": "target", "msg": "NOTICE:  BL2: Board is \uFFFD\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:22.917762", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:22.924428", "lvl": "target", "msg": "NOTICE:  BL2: Board is Starter Kit Premier Rev.2.0"}
- {"dt": "2023-12-15T01:42:22.974155", "lvl": "target", "msg": "NOTICE:  BL\0\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:22.974978", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:22.979715", "lvl": "target", "msg": "NOTICE:  BL2: Board is Starter Kit Premier Rev.2.0"}
- {"dt": "2023-12-15T01:42:23.024561", "lvl": "target", "msg": "NOTICE:\uFFFD\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:23.025394", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:23.026079", "lvl": "target", "msg": "NOTICE:  BL2: Board is Starter Kit Premier Rev.2.0"}
- {"dt": "2023-12-15T01:42:23.030273", "lvl": "target", "msg": "NOTICE:  BL2: Boot device is HyperFlash(80MHz)"}
- {"dt": "2023-12-15T01:42:23.083786", "lvl": "target", "msg": "NOTICE:  BL2:\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:23.084688", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:23.085457", "lvl": "target", "msg": "NOTICE:  BL2: Board is Starter Kit Premier Rev.2.0"}
- {"dt": "2023-12-15T01:42:23.086112", "lvl": "target", "msg": "NOTICE:  BL2: Boot device is HyperFlash(80MHz)"}
- {"dt": "2023-12-15T01:42:23.086779", "lvl": "target", "msg": "NOTICE:  BL2: LCM state is CM"}
- {"dt": "2023-12-15T01:42:23.100061", "lvl": "target", "msg": "NOTICE:  AVS setting succeeded. DVFS_SetVID=0x53"}
- {"dt": "2023-12-15T01:42:23.155618", "lvl": "target", "msg": "NO\uFFFD\0NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3"}
- {"dt": "2023-12-15T01:42:23.156415", "lvl": "target", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0"}
- {"dt": "2023-12-15T01:42:23.157102", "lvl": "target", "msg": "NOTICE:  BL2: Board is Starter Kit Premier Rev.2.0"}
- {"dt": "2023-12-15T01:42:23.157764", "lvl": "target", "msg": "NOTICE:  BL2: Boot device is HyperFlash(80MHz)"}
- {"dt": "2023-12-15T01:42:23.158297", "lvl": "target", "msg": "NOTICE:  BL2: LCM state is CM"}
- {"dt": "2023-12-15T01:42:23.158796", "lvl": "target", "msg": "NOTICE:  AVS setting succeeded. DVFS_SetVID=0x53"}
- {"dt": "2023-12-15T01:42:23.163526", "lvl": "target", "msg": "NOTICE:  BL2: DDR3200(rev.0.42)"}
- {"dt": "2023-12-15T01:42:23.166400", "lvl": "target", "msg": "NOTICE:  BL2: [COLD_BOOT]"}
- {"dt": "2023-12-15T01:42:23.199591", "lvl": "target", "msg": "NOTICE:  BL2: DRAM Split is 4ch(DDR f)"}
- {"dt": "2023-12-15T01:42:23.200407", "lvl": "target", "msg": "NOTICE:  BL2: QoS is default setting(rev.0.11)"}
- {"dt": "2023-12-15T01:42:23.201099", "lvl": "target", "msg": "NOTICE:  BL2: DRAM refresh interval 1.95 usec"}
- {"dt": "2023-12-15T01:42:23.204325", "lvl": "target", "msg": "NOTICE:  BL2: Periodic Write DQ Training"}
- {"dt": "2023-12-15T01:42:23.205073", "lvl": "target", "msg": "NOTICE:  BL2: CH0: 400000000 - 43fffffff, 1 GiB"}
- {"dt": "2023-12-15T01:42:23.205619", "lvl": "target", "msg": "NOTICE:  BL2: CH1: 500000000 - 53fffffff, 1 GiB"}
- {"dt": "2023-12-15T01:42:23.206121", "lvl": "target", "msg": "NOTICE:  BL2: CH2: 600000000 - 63fffffff, 1 GiB"}
- {"dt": "2023-12-15T01:42:23.206698", "lvl": "target", "msg": "NOTICE:  BL2: CH3: 700000000 - 73fffffff, 1 GiB"}
- {"dt": "2023-12-15T01:42:23.213661", "lvl": "target", "msg": "NOTICE:  BL2: FDT at 0xe6326f70"}
- {"dt": "2023-12-15T01:42:23.214369", "lvl": "target", "msg": "NOTICE:  BL2: v2.5(release):268df1d86"}
- {"dt": "2023-12-15T01:42:23.219976", "lvl": "target", "msg": "NOTICE:  BL2: Built : 17:33:20, Jan 30 2023"}
- {"dt": "2023-12-15T01:42:23.241599", "lvl": "target", "msg": "NOTICE:  BL2: Normal boot"}
- {"dt": "2023-12-15T01:42:23.242388", "lvl": "target", "msg": "NOTICE:  BL2: dst=0xe6326800 src=0x8180000 len=512(0x200)"}
- {"dt": "2023-12-15T01:42:23.242974", "lvl": "target", "msg": "NOTICE:  BL2: dst=0x43f00000 src=0x8180400 len=6144(0x1800)"}
- {"dt": "2023-12-15T01:42:23.243617", "lvl": "target", "msg": "NOTICE:  rcar_file_len: len: 0x0003e000"}
- {"dt": "2023-12-15T01:42:23.244248", "lvl": "target", "msg": "NOTICE:  BL2: dst=0x44000000 src=0x81c0000 len=253952(0x3e000)"}
- {"dt": "2023-12-15T01:42:23.249094", "lvl": "target", "msg": "NOTICE:  rcar_file_len: len: 0x00200000"}
- {"dt": "2023-12-15T01:42:23.252008", "lvl": "target", "msg": "NOTICE:  BL2: dst=0x44100000 src=0x8200000 len=2097152(0x200000)"}
- {"dt": "2023-12-15T01:42:23.281176", "lvl": "target", "msg": "NOTICE:  rcar_file_len: len: 0x00100000"}
- {"dt": "2023-12-15T01:42:23.281964", "lvl": "target", "msg": "NOTICE:  BL2: dst=0x50000000 src=0x8640000 len=1048576(0x100000)"}
- {"dt": "2023-12-15T01:42:23.285151", "lvl": "target", "msg": "NOTICE:  BL2: Booting BL31"}
- {"dt": "2023-12-15T01:42:23.612425", "lvl": "target", "msg": ""}
- {"dt": "2023-12-15T01:42:23.613222", "lvl": "target", "msg": ""}
- {"dt": "2023-12-15T01:42:23.613876", "lvl": "target", "msg": "U-Boot 2020.10 (Jan 30 2023 - 17:33:20 +0000)"}
- {"dt": "2023-12-15T01:42:23.614418", "lvl": "target", "msg": ""}
- {"dt": "2023-12-15T01:42:23.614946", "lvl": "target", "msg": "CPU: Renesas Electronics R8A7795 rev 3.0"}
- {"dt": "2023-12-15T01:42:23.622411", "lvl": "target", "msg": "Model: Renesas H3ULCB board based on r8a77950"}
- {"dt": "2023-12-15T01:42:23.807193", "lvl": "target", "msg": "DRAM:  3.9 GiB"}
- {"dt": "2023-12-15T01:42:23.837001", "lvl": "target", "msg": "RAM Configuration:"}
- {"dt": "2023-12-15T01:42:23.837822", "lvl": "target", "msg": "Bank #0: 0x048000000 - 0x07fffffff, 896 MiB"}
- {"dt": "2023-12-15T01:42:23.838467", "lvl": "target", "msg": "Bank #1: 0x500000000 - 0x53fffffff, 1 GiB"}
- {"dt": "2023-12-15T01:42:23.842740", "lvl": "target", "msg": "Bank #2: 0x600000000 - 0x63fffffff, 1 GiB"}
- {"dt": "2023-12-15T01:42:23.846581", "lvl": "target", "msg": "Bank #3: 0x700000000 - 0x73fffffff, 1 GiB"}
- {"dt": "2023-12-15T01:42:23.847275", "lvl": "target", "msg": ""}
- {"dt": "2023-12-15T01:42:23.873297", "lvl": "target", "msg": "MMC:   sd@ee100000: 0, sd@ee140000: 1"}
- {"dt": "2023-12-15T01:42:24.051475", "lvl": "target", "msg": "Loading Environment from MMC... OK"}
- {"dt": "2023-12-15T01:42:24.052326", "lvl": "target", "msg": "In:    serial@e6e88000"}
- {"dt": "2023-12-15T01:42:24.052885", "lvl": "target", "msg": "Out:   serial@e6e88000"}
- {"dt": "2023-12-15T01:42:24.057741", "lvl": "target", "msg": "Err:   serial@e6e88000"}
- {"dt": "2023-12-15T01:42:24.101651", "lvl": "target", "msg": "Net:   eth0: ethernet@e6800000"}
- {"dt": "2023-12-15T01:42:24.119052", "lvl": "input", "msg": "\n"}
- {"dt": "2023-12-15T01:42:24.170848", "lvl": "target", "msg": "Hit any key to stop autoboot:  3 "}
- {"dt": "2023-12-15T01:42:24.175290", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:00:02) [common]"}
- {"dt": "2023-12-15T01:42:24.176367", "lvl": "debug", "msg": "start: 2.4.3 bootloader-commands (timeout 00:19:45) [common]"}
- {"dt": "2023-12-15T01:42:24.177139", "lvl": "debug", "msg": "Setting prompt string to ['=>']"}
- {"dt": "2023-12-15T01:42:24.177817", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>'] (timeout 00:19:45)"}
- {"dt": "2023-12-15T01:42:24.198440", "lvl": "target", "msg": "\b\b\b 0 "}
- {"dt": "2023-12-15T01:42:24.200089", "lvl": "debug", "msg": "Setting prompt string to ['=>', '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-12-15T01:42:24.200913", "lvl": "input", "msg": "setenv autoload no\n"}
- {"dt": "2023-12-15T01:42:24.306921", "lvl": "target", "msg": "=> setenv autoload no"}
- {"dt": "2023-12-15T01:42:24.307865", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:45)"}
- {"dt": "2023-12-15T01:42:24.326783", "lvl": "target", "msg": "setenv autoload no"}
- {"dt": "2023-12-15T01:42:24.328179", "lvl": "input", "msg": "setenv initrd_high 0xffffffff\n"}
- {"dt": "2023-12-15T01:42:24.430540", "lvl": "target", "msg": "=> setenv initrd_high 0xffffffff"}
- {"dt": "2023-12-15T01:42:24.431507", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:45)"}
- {"dt": "2023-12-15T01:42:24.439563", "lvl": "target", "msg": "setenv initrd_high 0xffffffff"}
- {"dt": "2023-12-15T01:42:24.440868", "lvl": "input", "msg": "setenv fdt_high 0xffffffff\n"}
- {"dt": "2023-12-15T01:42:24.543348", "lvl": "target", "msg": "=> setenv fdt_high 0xffffffff"}
- {"dt": "2023-12-15T01:42:24.544286", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:45)"}
- {"dt": "2023-12-15T01:42:24.567089", "lvl": "target", "msg": "setenv fdt_high 0xffffffff"}
- {"dt": "2023-12-15T01:42:24.569647", "lvl": "input", "msg": "dhcp\n"}
- {"dt": "2023-12-15T01:42:24.671332", "lvl": "target", "msg": "=> dhcp"}
- {"dt": "2023-12-15T01:42:24.672653", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:45)"}
- {"dt": "2023-12-15T01:42:24.677673", "lvl": "target", "msg": "dhcp"}
- {"dt": "2023-12-15T01:42:27.973169", "lvl": "target", "msg": "ethernet@e6800000 Waiting for PHY auto negotiation to complete....... done"}
- {"dt": "2023-12-15T01:42:27.989154", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2023-12-15T01:42:28.229104", "lvl": "target", "msg": "BOOTP broadcast 2"}
- {"dt": "2023-12-15T01:42:28.739086", "lvl": "target", "msg": "BOOTP broadcast 3"}
- {"dt": "2023-12-15T01:42:29.010705", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.19 (1033 ms)"}
- {"dt": "2023-12-15T01:42:29.016502", "lvl": "input", "msg": "setenv serverip 192.168.66.1\n"}
- {"dt": "2023-12-15T01:42:29.121425", "lvl": "target", "msg": "=> setenv serverip 192.168.66.1"}
- {"dt": "2023-12-15T01:42:29.124731", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', '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:41)"}
- {"dt": "2023-12-15T01:42:29.141397", "lvl": "target", "msg": "setenv serverip 192.168.66.1"}
- {"dt": "2023-12-15T01:42:29.142641", "lvl": "input", "msg": "tftp 0x68080000 34285/nbd-deploy-pxazkprr/kernel/Image\n"}
- {"dt": "2023-12-15T01:42:29.247304", "lvl": "target", "msg": "=> tftp 0x68080000 34285/nbd-deploy-pxazkprr/kernel/Image"}
- {"dt": "2023-12-15T01:42:29.248239", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:40)"}
- {"dt": "2023-12-15T01:42:29.287773", "lvl": "target", "msg": "tftp 0x68080000 34285/nbd-deploy-pxazkprr/kernel/Image"}
- {"dt": "2023-12-15T01:42:29.288549", "lvl": "target", "msg": "Using ethernet@e6800000 device"}
- {"dt": "2023-12-15T01:42:29.289131", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.19"}
- {"dt": "2023-12-15T01:42:29.295518", "lvl": "target", "msg": "Filename '34285/nbd-deploy-pxazkprr/kernel/Image'."}
- {"dt": "2023-12-15T01:42:29.296297", "lvl": "target", "msg": "Load address: 0x68080000"}
- {"dt": "2023-12-15T01:42:29.815057", "lvl": "target", "msg": "Loading: *\b#################################################################"}
- {"dt": "2023-12-15T01:42:30.357619", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:30.884102", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:31.427829", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:31.955608", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:32.498212", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:33.023903", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:33.520126", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:34.030149", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:34.557961", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:35.036009", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:35.514938", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:36.012870", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:36.473677", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:36.952806", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:37.431096", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:37.910785", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:38.389785", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:38.868081", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:39.364380", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:39.843283", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:40.323099", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:40.833250", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:41.344547", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:41.839343", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:42.366982", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:42.892442", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:43.436994", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:43.979599", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:44.537657", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:45.096741", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:45.625065", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:46.102554", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:46.582687", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:47.077673", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:47.555819", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:48.018635", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:48.497795", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:48.993979", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:49.457529", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:49.921263", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:49.979984", "lvl": "target", "msg": "\t ######"}
- {"dt": "2023-12-15T01:42:49.980762", "lvl": "target", "msg": "\t 1.8 MiB/s"}
- {"dt": "2023-12-15T01:42:49.981293", "lvl": "target", "msg": "done"}
- {"dt": "2023-12-15T01:42:49.982989", "lvl": "target", "msg": "Bytes transferred = 39207424 (2564200 hex)"}
- {"dt": "2023-12-15T01:42:49.984416", "lvl": "input", "msg": "tftp 0x4a000000 34285/nbd-deploy-pxazkprr/initrd/initramfs-netboot-image-h3ulcb.ext4.gz\n"}
- {"dt": "2023-12-15T01:42:50.086041", "lvl": "target", "msg": "=> tftp 0x4a000000 34285/nbd-deploy-pxazkprr/initrd/initramfs-netboot-image-h3ulcb.ext4.gz"}
- {"dt": "2023-12-15T01:42:50.087002", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', '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:20)"}
- {"dt": "2023-12-15T01:42:50.091903", "lvl": "target", "msg": "tftp 0x4a000000 34285/nbd-deploy-pxazkprr/initrd/initramfs-netboot-image-h3ulcb.ext4.gz"}
- {"dt": "2023-12-15T01:42:50.124186", "lvl": "target", "msg": "Using ethernet@e6800000 device"}
- {"dt": "2023-12-15T01:42:50.124963", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.19"}
- {"dt": "2023-12-15T01:42:50.125510", "lvl": "target", "msg": "Filename '34285/nbd-deploy-pxazkprr/initrd/initramfs-netboot-image-h3ulcb.ext4.gz'."}
- {"dt": "2023-12-15T01:42:50.127393", "lvl": "target", "msg": "Load address: 0x4a000000"}
- {"dt": "2023-12-15T01:42:50.589647", "lvl": "target", "msg": "Loading: *\b#################################################################"}
- {"dt": "2023-12-15T01:42:51.069248", "lvl": "target", "msg": "\t #################################################################"}
- {"dt": "2023-12-15T01:42:51.155202", "lvl": "target", "msg": "\t ###########"}
- {"dt": "2023-12-15T01:42:51.155953", "lvl": "target", "msg": "\t 1.9 MiB/s"}
- {"dt": "2023-12-15T01:42:51.156417", "lvl": "target", "msg": "done"}
- {"dt": "2023-12-15T01:42:51.156849", "lvl": "target", "msg": "Bytes transferred = 2061324 (1f740c hex)"}
- {"dt": "2023-12-15T01:42:51.158784", "lvl": "input", "msg": "setenv initrd_size ${filesize}\n"}
- {"dt": "2023-12-15T01:42:51.260446", "lvl": "target", "msg": "=> setenv initrd_size ${filesize}"}
- {"dt": "2023-12-15T01:42:51.261789", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', '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:18)"}
- {"dt": "2023-12-15T01:42:51.269214", "lvl": "target", "msg": "setenv initrd_size ${filesize}"}
- {"dt": "2023-12-15T01:42:51.270487", "lvl": "input", "msg": "tftp 0x68000000 34285/nbd-deploy-pxazkprr/dtb/r8a77951-ulcb.dtb\n"}
- {"dt": "2023-12-15T01:42:51.372117", "lvl": "target", "msg": "=> tftp 0x68000000 34285/nbd-deploy-pxazkprr/dtb/r8a77951-ulcb.dtb"}
- {"dt": "2023-12-15T01:42:51.373300", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', '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:18)"}
- {"dt": "2023-12-15T01:42:51.378061", "lvl": "target", "msg": "tftp 0x68000000 34285/nbd-deploy-pxazkprr/dtb/r8a77951-ulcb.dtb"}
- {"dt": "2023-12-15T01:42:51.409210", "lvl": "target", "msg": "Using ethernet@e6800000 device"}
- {"dt": "2023-12-15T01:42:51.410792", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.19"}
- {"dt": "2023-12-15T01:42:51.411840", "lvl": "target", "msg": "Filename '34285/nbd-deploy-pxazkprr/dtb/r8a77951-ulcb.dtb'."}
- {"dt": "2023-12-15T01:42:51.413377", "lvl": "target", "msg": "Load address: 0x68000000"}
- {"dt": "2023-12-15T01:42:51.443201", "lvl": "target", "msg": "Loading: *\b######"}
- {"dt": "2023-12-15T01:42:51.459115", "lvl": "target", "msg": "\t 1.7 MiB/s"}
- {"dt": "2023-12-15T01:42:51.459834", "lvl": "target", "msg": "done"}
- {"dt": "2023-12-15T01:42:51.460304", "lvl": "target", "msg": "Bytes transferred = 82960 (14410 hex)"}
- {"dt": "2023-12-15T01:42:51.461442", "lvl": "input", "msg": "setenv bootargs 'console=ttySC0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61961 root=/dev/ram0 ramdisk_size=16384 rootdelay=7  systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'\n"}
- {"dt": "2023-12-15T01:42:51.562835", "lvl": "target", "msg": "=> setenv bootargs 'console=ttySC0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61961 root=/dev/ram0 ramdisk_size=16384 rootdelay=7  systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'"}
- {"dt": "2023-12-15T01:42:51.563980", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['=>', '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:18)"}
- {"dt": "2023-12-15T01:42:51.579958", "lvl": "target", "msg": "setenv bootargs 'console=ttySC0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61961 root=/dev/ram0 ramdisk_size=16384 rootdelay=7  systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'"}
- {"dt": "2023-12-15T01:42:51.581073", "lvl": "input", "msg": "booti 0x68080000 0x4a000000:${initrd_size} 0x68000000\n"}
- {"dt": "2023-12-15T01:42:51.682411", "lvl": "target", "msg": "=> booti 0x68080000 0x4a000000:${initrd_size} 0x68000000"}
- {"dt": "2023-12-15T01:42:51.683333", "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-12-15T01:42:51.684023", "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:18)"}
- {"dt": "2023-12-15T01:42:51.691872", "lvl": "target", "msg": "booti 0x68080000 0x4a000000:${initrd_size} 0x68000000"}
- {"dt": "2023-12-15T01:42:51.707871", "lvl": "target", "msg": "Moving Image from 0x68080000 to 0x68200000, end=6a800000"}
- {"dt": "2023-12-15T01:42:51.803961", "lvl": "target", "msg": "## Flattened Device Tree blob at 68000000"}
- {"dt": "2023-12-15T01:42:51.854974", "lvl": "target", "msg": "   Booting using the fdt blob at 0x68000000"}
- {"dt": "2023-12-15T01:42:51.855669", "lvl": "target", "msg": "   Loading Ramdisk to 7fe08000, end 7ffff40c ... OK"}
- {"dt": "2023-12-15T01:42:51.856140", "lvl": "target", "msg": "   Loading Device Tree to 0000000053fe8000, end 0000000053fff40f ... \\\"Synchronous Abort\\\" handler, esr 0x96000042"}
- {"dt": "2023-12-15T01:42:51.856585", "lvl": "target", "msg": "elr: 000000002016db9c lr : 000000002016dbfc (reloc)"}
- {"dt": "2023-12-15T01:42:51.857022", "lvl": "target", "msg": "elr: 0000000050069b9c lr : 0000000050069bfc"}
- {"dt": "2023-12-15T01:42:51.857455", "lvl": "target", "msg": "x0 : 0000000053fe8000 x1 : 0000000068000000"}
- {"dt": "2023-12-15T01:42:51.857889", "lvl": "target", "msg": "x2 : 0000000000014410 x3 : 0000000000000000"}
- {"dt": "2023-12-15T01:42:51.858375", "lvl": "target", "msg": "x4 : 10440100edfe0dd0 x5 : 0000000053fe8000"}
- {"dt": "2023-12-15T01:42:51.859211", "lvl": "target", "msg": "x6 : 0000000053fe8000 x7 : 000000007beeed80"}
- {"dt": "2023-12-15T01:42:51.899668", "lvl": "target", "msg": "x8 : 000000007beeed48 x9 : 0000000000000008"}
- {"dt": "2023-12-15T01:42:51.900383", "lvl": "target", "msg": "x10: 0000000053fff40f x11: 0000000053fff40f"}
- {"dt": "2023-12-15T01:42:51.900852", "lvl": "target", "msg": "x12: 0000000048000000 x13: fffffffffffff000"}
- {"dt": "2023-12-15T01:42:51.901283", "lvl": "target", "msg": "x14: 0000000053fe8000 x15: 0000000000000021"}
- {"dt": "2023-12-15T01:42:51.901712", "lvl": "target", "msg": "x16: 0000000050038720 x17: 0000000000000000"}
- {"dt": "2023-12-15T01:42:51.902186", "lvl": "target", "msg": "x18: 000000007befbdb0 x19: 0000000053fe8000"}
- {"dt": "2023-12-15T01:42:51.902627", "lvl": "target", "msg": "x20: 0000000068000000 x21: 0000000000017410"}
- {"dt": "2023-12-15T01:42:51.903455", "lvl": "target", "msg": "x22: 0000000010440100 x23: 0000000000000010"}
- {"dt": "2023-12-15T01:42:51.904011", "lvl": "target", "msg": "x24: 00000000500e3980 x25: 000000007beeedf8"}
- {"dt": "2023-12-15T01:42:51.904457", "lvl": "target", "msg": "x26: 0000000000000000 x27: 0000000050002e3c"}
- {"dt": "2023-12-15T01:42:51.904883", "lvl": "target", "msg": "x28: 000000007bf04d70 x29: 000000007beeed10"}
- {"dt": "2023-12-15T01:42:51.905308", "lvl": "target", "msg": ""}
- {"dt": "2023-12-15T01:42:51.916789", "lvl": "target", "msg": "Code: eb03005f 540001e1 d65f03c0 f8636824 (f8236804) "}
- {"dt": "2023-12-15T01:42:51.917382", "lvl": "target", "msg": "Resetting CPU ..."}
- {"dt": "2023-12-15T01:42:51.917840", "lvl": "target", "msg": ""}
- {"dt": "2023-12-15T01:42:51.918769", "lvl": "exception", "msg": "matched a bootloader error message: 'Resetting CPU' (1)"}
- {"dt": "2023-12-15T01:42:51.919433", "lvl": "debug", "msg": "end: 2.4.3 bootloader-commands (duration 00:00:28) [common]"}
- {"dt": "2023-12-15T01:42:51.919960", "lvl": "results", "msg": {"case": "bootloader-commands", "definition": "lava", "duration": "27.74", "extra": {"fail": "matched a bootloader error message: 'Resetting CPU' (1)"}, "level": "2.4.3", "namespace": "common", "result": "fail"}}
- {"dt": "2023-12-15T01:42:51.920986", "lvl": "exception", "msg": "matched a bootloader error message: 'Resetting CPU' (1)"}
- {"dt": "2023-12-15T01:42:51.921533", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:00:36) [common]"}
- {"dt": "2023-12-15T01:42:51.922142", "lvl": "results", "msg": {"case": "uboot-commands", "definition": "lava", "duration": "35.86", "extra": {"fail": "matched a bootloader error message: 'Resetting CPU' (1)"}, "level": "2.4", "namespace": "common", "result": "fail"}}
- {"dt": "2023-12-15T01:42:51.923179", "lvl": "error", "msg": "uboot-action failed: 1 of 1 attempts. 'matched a bootloader error message: 'Resetting CPU' (1)'"}
- {"dt": "2023-12-15T01:42:51.923849", "lvl": "exception", "msg": "matched a bootloader error message: 'Resetting CPU' (1)"}
- {"dt": "2023-12-15T01:42:51.924391", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:00:42) [common]"}
- {"dt": "2023-12-15T01:42:51.924915", "lvl": "results", "msg": {"case": "uboot-action", "definition": "lava", "duration": "42.28", "extra": {"fail": "matched a bootloader error message: 'Resetting CPU' (1)"}, "level": "2", "namespace": "common", "result": "fail"}}
- {"dt": "2023-12-15T01:42:51.926125", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2023-12-15T01:42:51.926821", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/34285/nbd-deploy-pxazkprr/initrd"}
- {"dt": "2023-12-15T01:42:51.928759", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/34285/nbd-deploy-pxazkprr/kernel"}
- {"dt": "2023-12-15T01:42:51.940186", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/34285/nbd-deploy-pxazkprr/dtb"}
- {"dt": "2023-12-15T01:42:51.941726", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/34285/nbd-deploy-pxazkprr/nbdroot"}
- {"dt": "2023-12-15T01:42:51.944432", "lvl": "debug", "msg": "start: 7.1 power-off (timeout 00:00:10) [common]"}
- {"dt": "2023-12-15T01:42:51.945579", "lvl": "debug", "msg": "Calling: 'nice' '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '2'"}
- {"dt": "2023-12-15T01:42:55.466263", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2023-12-15T01:42:55.502285", "lvl": "debug", "msg": "Returned 0 in 3 seconds"}
- {"dt": "2023-12-15T01:42:55.605401", "lvl": "debug", "msg": "end: 7.1 power-off (duration 00:00:04) [common]"}
- {"dt": "2023-12-15T01:42:55.607576", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "3.66", "extra": {"status": "success"}, "level": "7.1", "namespace": "common", "result": "pass"}}
- {"dt": "2023-12-15T01:42:55.611674", "lvl": "debug", "msg": "start: 7.2 read-feedback (timeout 00:29:56) [common]"}
- {"dt": "2023-12-15T01:42:55.615060", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2023-12-15T01:42:55.616167", "lvl": "feedback", "msg": "resetting ...", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.616809", "lvl": "feedback", "msg": "NOTICE:  BL2: R-Car Gen3 Initial Program Loader(CA57) Rev.3.0.3", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.617349", "lvl": "feedback", "msg": "NOTICE:  BL2: PRR is R-Car H3 Ver.3.0", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.617857", "lvl": "feedback", "msg": "NOTICE:  BL2: Board is Starter Kit Premier Rev.2.0", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.618369", "lvl": "feedback", "msg": "NOTICE:  BL2: Boot device is HyperFlash(80MHz)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.618876", "lvl": "feedback", "msg": "NOTICE:  BL2: LCM state is CM", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.619419", "lvl": "feedback", "msg": "NOTICE:  AVS setting succeeded. DVFS_SetVID=0x53", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.619919", "lvl": "feedback", "msg": "NOTICE:  BL2: DDR3200(rev.0.42)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.620428", "lvl": "feedback", "msg": "NOTICE:  BL2: [COLD_BOOT]", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.620918", "lvl": "feedback", "msg": "NOTICE:  BL2: DRAM Split is 4ch(DDR f)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.621428", "lvl": "feedback", "msg": "NOTICE:  BL2: QoS is default setting(rev.0.11)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.621918", "lvl": "feedback", "msg": "NOTICE:  BL2: DRAM refresh interval 1.95 usec", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.622409", "lvl": "feedback", "msg": "NOTICE:  BL2: Periodic Write DQ Training", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.622897", "lvl": "feedback", "msg": "NOTICE:  BL2: CH0: 400000000 - 43fffffff, 1 GiB", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.623429", "lvl": "feedback", "msg": "NOTICE:  BL2: CH1: 500000000 - 53fffffff, 1 GiB", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.623924", "lvl": "feedback", "msg": "NOTICE:  BL2: CH2: 600000000 - 63fffffff, 1 GiB", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.624431", "lvl": "feedback", "msg": "NOTICE:  BL2: CH3: 700000000 - 73fffffff, 1 GiB", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.624923", "lvl": "feedback", "msg": "NOTICE:  BL2: FDT at 0xe6326f70", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.625409", "lvl": "feedback", "msg": "NOTICE:  BL2: v2.5(release):268df1d86", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.625891", "lvl": "feedback", "msg": "NOTICE:  BL2: Built : 17:33:20, Jan 30 2023", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.626376", "lvl": "feedback", "msg": "NOTICE:  BL2: Normal boot", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.626858", "lvl": "feedback", "msg": "NOTICE:  BL2: dst=0xe6326800 src=0x8180000 len=512(0x200)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.627390", "lvl": "feedback", "msg": "NOTICE:  BL2: dst=0x43f00000 src=0x8180400 len=6144(0x1800)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.627886", "lvl": "feedback", "msg": "NOTICE:  rcar_file_len: len: 0x0003e000", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.628380", "lvl": "feedback", "msg": "NOTICE:  BL2: dst=0x44000000 src=0x81c0000 len=253952(0x3e000)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.628873", "lvl": "feedback", "msg": "NOTICE:  rcar_file_len: len: 0x00200000", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.629363", "lvl": "feedback", "msg": "NOTICE:  BL2: dst=0x44100000 src=0x8200000 len=2097152(0x200000)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.629862", "lvl": "feedback", "msg": "NOTICE:  rcar_file_len: len: 0x00100000", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.630363", "lvl": "feedback", "msg": "NOTICE:  BL2: dst=0x50000000 src=0x8640000 len=1048576(0x100000)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.630859", "lvl": "feedback", "msg": "NOTICE:  BL2: Booting BL31", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.631401", "lvl": "feedback", "msg": "", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.631893", "lvl": "feedback", "msg": "", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.632387", "lvl": "feedback", "msg": "U-Boot 2020.10 (Jan 30 2023 - 17:33:20 +0000)", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.632870", "lvl": "feedback", "msg": "", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.633352", "lvl": "feedback", "msg": "CPU: Renesas Electronics R8A7795 rev 3.0", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.633840", "lvl": "feedback", "msg": "Model: Renesas H3ULCB board based on r8a77950", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.634320", "lvl": "feedback", "msg": "DRAM:  3.9 GiB", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.634796", "lvl": "feedback", "msg": "RAM Configuration:", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.635384", "lvl": "feedback", "msg": "Bank #0: 0x048000000 - 0x07fffffff, 896 MiB", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.635884", "lvl": "feedback", "msg": "Bank #1: 0x500000000 - 0x53fffffff, 1 GiB", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.636373", "lvl": "feedback", "msg": "Bank #2: 0x600000000 - 0x63fffffff, 1 GiB", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.636854", "lvl": "feedback", "msg": "Bank #3: 0x700000000 - 0x73fffffff, 1 GiB", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.637333", "lvl": "feedback", "msg": "", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.637816", "lvl": "feedback", "msg": "MMC:   sd@ee100000: 0, sd@ee140000: 1", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.638298", "lvl": "feedback", "msg": "Loading Environment from MMC... OK", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.638780", "lvl": "feedback", "msg": "In:    serial@e6e88000", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.639306", "lvl": "feedback", "msg": "Out:   serial@e6e88000", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.639792", "lvl": "feedback", "msg": "Err:   serial@e6e88000", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.640272", "lvl": "feedback", "msg": "Net:   eth0: ethernet@e6800000", "ns": "common"}
- {"dt": "2023-12-15T01:42:55.641083", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2023-12-15T01:42:56.615896", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2023-12-15T01:42:56.618229", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2023-12-15T01:42:56.620399", "lvl": "target", "msg": "Hit any key to stop autoboot:  3 \b\b\b 2 \b\b\b 1 \0"}
- {"dt": "2023-12-15T01:42:56.723990", "lvl": "debug", "msg": "end: 7.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2023-12-15T01:42:56.725992", "lvl": "debug", "msg": "lava-xnbd cleanup"}
- {"dt": "2023-12-15T01:42:56.727786", "lvl": "debug", "msg": "clean NBD port 61961"}
- {"dt": "2023-12-15T01:43:00.278272", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/34285"}
- {"dt": "2023-12-15T01:43:00.382537", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/34285"}
- {"dt": "2023-12-15T01:43:00.383811", "lvl": "error", "msg": "InfrastructureError: The Infrastructure is not working correctly. Please report this error to LAVA admins."}
- {"dt": "2023-12-15T01:43:00.384580", "lvl": "results", "msg": {"case": "job", "definition": "lava", "error_msg": "matched a bootloader error message: 'Resetting CPU' (1)", "error_type": "Infrastructure", "result": "fail"}}
