- {"dt": "2024-09-30T17:34:59.147014", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.10"}
- {"dt": "2024-09-30T17:34:59.149219", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-09-30T17:34:59.150572", "lvl": "info", "msg": "Start time: 2024-09-30 17:34:59.150517+00:00 (UTC)"}
- {"dt": "2024-09-30T17:34:59.152275", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30328/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz exists"}
- {"dt": "2024-09-30T17:34:59.435525", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30328/1/raspberrypi4/Image exists"}
- {"dt": "2024-09-30T17:34:59.651906", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30328/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb exists"}
- {"dt": "2024-09-30T17:34:59.868476", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30328/1/raspberrypi4/agl-ivi-demo-qt-raspberrypi4-64.ext4.xz exists"}
- {"dt": "2024-09-30T17:35:00.096729", "lvl": "info", "msg": "validate duration: 0.95"}
- {"dt": "2024-09-30T17:35:00.098014", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2024-09-30T17:35:00.099533", "lvl": "info", "msg": "start: 1 nbd-deploy (timeout 01:30:00) [common]"}
- {"dt": "2024-09-30T17:35:00.100459", "lvl": "info", "msg": "Making protocol call for nbd-deploy using lava-xnbd"}
- {"dt": "2024-09-30T17:35:00.101325", "lvl": "debug", "msg": "[nbd-deploy] Checking protocol data for lava-xnbd"}
- {"dt": "2024-09-30T17:35:00.102208", "lvl": "debug", "msg": "Get a port from pool"}
- {"dt": "2024-09-30T17:35:00.103617", "lvl": "debug", "msg": "Set_port 61994"}
- {"dt": "2024-09-30T17:35:00.104874", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 01:30:00) [common]"}
- {"dt": "2024-09-30T17:35:00.106011", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 01:30:00) [common]"}
- {"dt": "2024-09-30T17:35:00.107756", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30328/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-09-30T17:35:00.108729", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/36611/nbd-deploy-__9oaok5/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-09-30T17:35:00.109628", "lvl": "debug", "msg": "total size: 2065649 (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.110493", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-09-30T17:35:00.432088", "lvl": "debug", "msg": "progress   1\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.637110", "lvl": "debug", "msg": "progress   6\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.736057", "lvl": "debug", "msg": "progress  11\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.748317", "lvl": "debug", "msg": "progress  17\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.837526", "lvl": "debug", "msg": "progress  22\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.848568", "lvl": "debug", "msg": "progress  28\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.852837", "lvl": "debug", "msg": "progress  33\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.857131", "lvl": "debug", "msg": "progress  38\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.944713", "lvl": "debug", "msg": "progress  44\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.950787", "lvl": "debug", "msg": "progress  49\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.957434", "lvl": "debug", "msg": "progress  55\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.961827", "lvl": "debug", "msg": "progress  60\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.966015", "lvl": "debug", "msg": "progress  65\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.971350", "lvl": "debug", "msg": "progress  71\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.975550", "lvl": "debug", "msg": "progress  76\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:00.980850", "lvl": "debug", "msg": "progress  82\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:01.041368", "lvl": "debug", "msg": "progress  87\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:01.046403", "lvl": "debug", "msg": "progress  92\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:01.052753", "lvl": "debug", "msg": "progress  98\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:01.057045", "lvl": "info", "msg": "1\u202FMB downloaded in 0.95\u202Fs (2.08\u202FMB/s)"}
- {"dt": "2024-09-30T17:35:01.058288", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:35:01.058885", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.95", "extra": {"label": "initrd", "md5sum": "7d2202e4c37fcca41a1ba449b2d77718", "sha256sum": "702501404f59b32a47efd6a3fc34bb35be0daef704df153c9019ac92f14a6906", "sha512sum": "fade53c5e7f229d3ee1209c347362186e45235d20161ab2d91128a2612458c17e3a261156568df3c1b295e47f3605cee6b3e0eca7fae3cedddcb0c48f3f9dff8", "size": ! "2065649"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:35:01.060756", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:35:01.061869", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 01:29:59) [common]"}
- {"dt": "2024-09-30T17:35:01.062845", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 01:29:59) [common]"}
- {"dt": "2024-09-30T17:35:01.064304", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30328/1/raspberrypi4/Image"}
- {"dt": "2024-09-30T17:35:01.065214", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/36611/nbd-deploy-__9oaok5/kernel/Image"}
- {"dt": "2024-09-30T17:35:01.065970", "lvl": "debug", "msg": "total size: 24046080 (22\u202FMB)"}
- {"dt": "2024-09-30T17:35:01.066840", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-09-30T17:35:01.385739", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:01.910655", "lvl": "debug", "msg": "progress   5\u202F% (1\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.031320", "lvl": "debug", "msg": "progress  10\u202F% (2\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.115987", "lvl": "debug", "msg": "progress  15\u202F% (3\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.223540", "lvl": "debug", "msg": "progress  20\u202F% (4\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.268544", "lvl": "debug", "msg": "progress  25\u202F% (5\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.316426", "lvl": "debug", "msg": "progress  30\u202F% (6\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.364560", "lvl": "debug", "msg": "progress  35\u202F% (8\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.449869", "lvl": "debug", "msg": "progress  40\u202F% (9\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.498905", "lvl": "debug", "msg": "progress  45\u202F% (10\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.546745", "lvl": "debug", "msg": "progress  50\u202F% (11\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.712693", "lvl": "debug", "msg": "progress  55\u202F% (12\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.767722", "lvl": "debug", "msg": "progress  60\u202F% (13\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.810280", "lvl": "debug", "msg": "progress  65\u202F% (14\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.855273", "lvl": "debug", "msg": "progress  70\u202F% (16\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.947161", "lvl": "debug", "msg": "progress  75\u202F% (17\u202FMB)"}
- {"dt": "2024-09-30T17:35:02.990390", "lvl": "debug", "msg": "progress  80\u202F% (18\u202FMB)"}
- {"dt": "2024-09-30T17:35:03.234284", "lvl": "debug", "msg": "progress  85\u202F% (19\u202FMB)"}
- {"dt": "2024-09-30T17:35:03.475305", "lvl": "debug", "msg": "progress  90\u202F% (20\u202FMB)"}
- {"dt": "2024-09-30T17:35:03.531854", "lvl": "debug", "msg": "progress  95\u202F% (21\u202FMB)"}
- {"dt": "2024-09-30T17:35:03.588519", "lvl": "debug", "msg": "progress 100\u202F% (22\u202FMB)"}
- {"dt": "2024-09-30T17:35:03.590940", "lvl": "info", "msg": "22\u202FMB downloaded in 2.52\u202Fs (9.08\u202FMB/s)"}
- {"dt": "2024-09-30T17:35:03.592758", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:03) [common]"}
- {"dt": "2024-09-30T17:35:03.593976", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "2.53", "extra": {"label": "kernel", "md5sum": "b18f9dad403d55d0c61099a86719d57e", "sha256sum": "ace02884cec73a99a36be6eaf454f245a93e29d92857beac1fa35a95da93c8d4", "sha512sum": "46d790223aeb24bb73966d8391bb05c2b03f5b1c64c68e237f932266d21a1aeedcd3c52d5e6501c2cd08f44439211fe0bbbf07cf59854b0dcba11a40797245e7", "size": ! "24046080"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:35:03.596071", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:03) [common]"}
- {"dt": "2024-09-30T17:35:03.597353", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 01:29:57) [common]"}
- {"dt": "2024-09-30T17:35:03.598753", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 01:29:57) [common]"}
- {"dt": "2024-09-30T17:35:03.600078", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30328/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-09-30T17:35:03.600927", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/36611/nbd-deploy-__9oaok5/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-09-30T17:35:03.601720", "lvl": "debug", "msg": "total size: 52444 (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:03.602593", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-09-30T17:35:03.916075", "lvl": "debug", "msg": "progress  62\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:04.017201", "lvl": "debug", "msg": "progress 100\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:04.021014", "lvl": "info", "msg": "0\u202FMB downloaded in 0.42\u202Fs (0.12\u202FMB/s)"}
- {"dt": "2024-09-30T17:35:04.023089", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:35:04.024261", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.42", "extra": {"label": "dtb", "md5sum": "c0b21b6edb15dbb94ee1a3905c78641e", "sha256sum": "c01a0a575d13d9e95cf44098bfb752359daa6732ac3714750eb15fb2876b43d3", "sha512sum": "3faa7e2d588d1b48a12700c0639e60596f50b08909c8b6e5a4eb7d3878e2d573fe4a640a9505234ffddaae7e85c45fceca7986ced916f54ed967116e67586718", "size": ! "52444"}, "level": "1.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:35:04.027946", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:35:04.029458", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 01:29:56) [common]"}
- {"dt": "2024-09-30T17:35:04.031030", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 01:29:56) [common]"}
- {"dt": "2024-09-30T17:35:04.031980", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30328/1/raspberrypi4/agl-ivi-demo-qt-raspberrypi4-64.ext4.xz"}
- {"dt": "2024-09-30T17:35:04.032528", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/36611/nbd-deploy-__9oaok5/nbdroot/agl-ivi-demo-qt-raspberrypi4-64.ext4"}
- {"dt": "2024-09-30T17:35:04.032919", "lvl": "debug", "msg": "total size: 795627644 (758\u202FMB)"}
- {"dt": "2024-09-30T17:35:04.033330", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-09-30T17:35:04.353486", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-09-30T17:35:15.336729", "lvl": "debug", "msg": "progress   5\u202F% (37\u202FMB)"}
- {"dt": "2024-09-30T17:35:34.348913", "lvl": "debug", "msg": "progress  10\u202F% (75\u202FMB)"}
- {"dt": "2024-09-30T17:35:47.631977", "lvl": "debug", "msg": "progress  15\u202F% (113\u202FMB)"}
- {"dt": "2024-09-30T17:35:57.610310", "lvl": "debug", "msg": "progress  20\u202F% (151\u202FMB)"}
- {"dt": "2024-09-30T17:36:11.306047", "lvl": "debug", "msg": "progress  25\u202F% (189\u202FMB)"}
- {"dt": "2024-09-30T17:36:16.484474", "lvl": "debug", "msg": "progress  30\u202F% (227\u202FMB)"}
- {"dt": "2024-09-30T17:36:20.681188", "lvl": "debug", "msg": "progress  35\u202F% (265\u202FMB)"}
- {"dt": "2024-09-30T17:36:25.168587", "lvl": "debug", "msg": "progress  40\u202F% (303\u202FMB)"}
- {"dt": "2024-09-30T17:36:29.189677", "lvl": "debug", "msg": "progress  45\u202F% (341\u202FMB)"}
- {"dt": "2024-09-30T17:36:32.458166", "lvl": "debug", "msg": "progress  50\u202F% (379\u202FMB)"}
- {"dt": "2024-09-30T17:36:35.693881", "lvl": "debug", "msg": "progress  55\u202F% (417\u202FMB)"}
- {"dt": "2024-09-30T17:36:40.235043", "lvl": "debug", "msg": "progress  60\u202F% (455\u202FMB)"}
- {"dt": "2024-09-30T17:36:49.912149", "lvl": "debug", "msg": "progress  65\u202F% (493\u202FMB)"}
- {"dt": "2024-09-30T17:37:02.149388", "lvl": "debug", "msg": "progress  70\u202F% (531\u202FMB)"}
- {"dt": "2024-09-30T17:37:17.005859", "lvl": "debug", "msg": "progress  75\u202F% (569\u202FMB)"}
- {"dt": "2024-09-30T17:37:28.524652", "lvl": "debug", "msg": "progress  80\u202F% (607\u202FMB)"}
- {"dt": "2024-09-30T17:37:38.184865", "lvl": "debug", "msg": "progress  85\u202F% (644\u202FMB)"}
- {"dt": "2024-09-30T17:37:45.844567", "lvl": "debug", "msg": "progress  90\u202F% (682\u202FMB)"}
- {"dt": "2024-09-30T17:37:54.778280", "lvl": "debug", "msg": "progress  95\u202F% (720\u202FMB)"}
- {"dt": "2024-09-30T17:38:07.100432", "lvl": "debug", "msg": "progress 100\u202F% (758\u202FMB)"}
- {"dt": "2024-09-30T17:38:11.427130", "lvl": "info", "msg": "758\u202FMB downloaded in 187.39\u202Fs (4.05\u202FMB/s)"}
- {"dt": "2024-09-30T17:38:11.428470", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:03:07) [common]"}
- {"dt": "2024-09-30T17:38:11.429027", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "187.40", "extra": {"label": "nbdroot", "md5sum": "ce265575514e3487485c5cad1cb9b622", "sha256sum": "d441222ee6605e1087f5d384fa8ee250233c13730ea6e58d8aac7e63af5056e0", "sha512sum": "79063dca1ecd9359ce7c9d21e3468524aec55d7f9c38d1ab394cc76eca462cf842f9d97f783949f91d96dc9b276d548da8f410dc01ce6a8c6d06d802b8eeb8bb", "size": ! "795627644"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:11.430194", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:03:07) [common]"}
- {"dt": "2024-09-30T17:38:11.430743", "lvl": "debug", "msg": "start: 1.5 lava-overlay (timeout 01:26:49) [common]"}
- {"dt": "2024-09-30T17:38:11.433062", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb"}
- {"dt": "2024-09-30T17:38:11.434431", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin"}
- {"dt": "2024-09-30T17:38:11.435652", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/tests"}
- {"dt": "2024-09-30T17:38:11.436702", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/results"}
- {"dt": "2024-09-30T17:38:11.437658", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-add-keys"}
- {"dt": "2024-09-30T17:38:11.439094", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-add-sources"}
- {"dt": "2024-09-30T17:38:11.440592", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-background-process-start"}
- {"dt": "2024-09-30T17:38:11.442044", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-background-process-stop"}
- {"dt": "2024-09-30T17:38:11.443577", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-common-functions"}
- {"dt": "2024-09-30T17:38:11.445049", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-echo-ipv4"}
- {"dt": "2024-09-30T17:38:11.446475", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-install-packages"}
- {"dt": "2024-09-30T17:38:11.447936", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-installed-packages"}
- {"dt": "2024-09-30T17:38:11.449325", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-os-build"}
- {"dt": "2024-09-30T17:38:11.452913", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-probe-channel"}
- {"dt": "2024-09-30T17:38:11.454623", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-probe-ip"}
- {"dt": "2024-09-30T17:38:11.456893", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-target-ip"}
- {"dt": "2024-09-30T17:38:11.458230", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-target-mac"}
- {"dt": "2024-09-30T17:38:11.459397", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-target-storage"}
- {"dt": "2024-09-30T17:38:11.460508", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-test-case"}
- {"dt": "2024-09-30T17:38:11.461545", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-test-event"}
- {"dt": "2024-09-30T17:38:11.462556", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-test-feedback"}
- {"dt": "2024-09-30T17:38:11.463660", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-test-raise"}
- {"dt": "2024-09-30T17:38:11.464752", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-test-reference"}
- {"dt": "2024-09-30T17:38:11.465790", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-test-runner"}
- {"dt": "2024-09-30T17:38:11.467084", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-test-set"}
- {"dt": "2024-09-30T17:38:11.468219", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-test-shell"}
- {"dt": "2024-09-30T17:38:11.469278", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-install-packages (oe)"}
- {"dt": "2024-09-30T17:38:11.470912", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/bin/lava-installed-packages (oe)"}
- {"dt": "2024-09-30T17:38:11.472172", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/environment"}
- {"dt": "2024-09-30T17:38:11.473146", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2024-09-30T17:38:11.473693", "lvl": "debug", "msg": "- LAVA_JOB_ID=36611"}
- {"dt": "2024-09-30T17:38:11.474106", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.66.1"}
- {"dt": "2024-09-30T17:38:11.474837", "lvl": "debug", "msg": "start: 1.5.1 ssh-authorize (timeout 01:26:49) [common]"}
- {"dt": "2024-09-30T17:38:11.477000", "lvl": "debug", "msg": "end: 1.5.1 ssh-authorize (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:11.477728", "lvl": "debug", "msg": "start: 1.5.2 lava-vland-overlay (timeout 01:26:49) [common]"}
- {"dt": "2024-09-30T17:38:11.478181", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2024-09-30T17:38:11.478693", "lvl": "debug", "msg": "end: 1.5.2 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:11.479289", "lvl": "debug", "msg": "start: 1.5.3 lava-multinode-overlay (timeout 01:26:49) [common]"}
- {"dt": "2024-09-30T17:38:11.479733", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2024-09-30T17:38:11.480220", "lvl": "debug", "msg": "end: 1.5.3 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:11.480728", "lvl": "debug", "msg": "start: 1.5.4 test-definition (timeout 01:26:49) [common]"}
- {"dt": "2024-09-30T17:38:11.481240", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2024-09-30T17:38:11.481841", "lvl": "debug", "msg": "start: 1.5.4.1 git-repo-action (timeout 01:26:49) [common]"}
- {"dt": "2024-09-30T17:38:11.482336", "lvl": "debug", "msg": "Using /lava-36611 at stage 0"}
- {"dt": "2024-09-30T17:38:11.483127", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-09-30T17:38:11.487720", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/0/tests/0_network-veth'"}
- {"dt": "2024-09-30T17:38:12.092698", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/0/tests/0_network-veth/test-suites/short-smoke/network-veth.yaml"}
- {"dt": "2024-09-30T17:38:12.094903", "lvl": "debug", "msg": "uuid=36611_1.5.4.1 testdef=None"}
- {"dt": "2024-09-30T17:38:12.095739", "lvl": "debug", "msg": "end: 1.5.4.1 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:38:12.096250", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.61", "extra": {"commit": "1fe48c584e7e01b0e0f5509bf4bb678e0bf391c9", "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": "2024-09-30T17:38:12.097336", "lvl": "debug", "msg": "start: 1.5.4.2 test-overlay (timeout 01:26:48) [common]"}
- {"dt": "2024-09-30T17:38:12.101126", "lvl": "debug", "msg": "end: 1.5.4.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:12.101670", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "git", "name": "network-veth", "path": "test-suites/short-smoke/network-veth.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "36611_1.5.4.1"}, "level": "1.5.4.2", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:12.102853", "lvl": "debug", "msg": "start: 1.5.4.3 test-install-overlay (timeout 01:26:48) [common]"}
- {"dt": "2024-09-30T17:38:12.108278", "lvl": "debug", "msg": "end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:12.109010", "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": "36611_1.5.4.1", "uuid": "36611_1.5.4.1"}, "level": "1.5.4.3", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:12.110330", "lvl": "debug", "msg": "start: 1.5.4.4 test-runscript-overlay (timeout 01:26:48) [common]"}
- {"dt": "2024-09-30T17:38:12.115922", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/0/tests/0_network-veth test_uuid 36611_1.5.4.1"}
- {"dt": "2024-09-30T17:38:12.117281", "lvl": "debug", "msg": "end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:12.117860", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/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": "36611_1.5.4.1"}, "level": "1.5.4.4", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:12.119175", "lvl": "debug", "msg": "start: 1.5.4.5 git-repo-action (timeout 01:26:48) [common]"}
- {"dt": "2024-09-30T17:38:12.119667", "lvl": "debug", "msg": "Using /lava-36611 at stage 1"}
- {"dt": "2024-09-30T17:38:12.120355", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-09-30T17:38:12.120835", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/1_ci-busybox'"}
- {"dt": "2024-09-30T17:38:12.744093", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/1_ci-busybox"}
- {"dt": "2024-09-30T17:38:12.754425", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/1_ci-busybox/test-suites/short-smoke/busybox.yaml"}
- {"dt": "2024-09-30T17:38:12.756622", "lvl": "debug", "msg": "uuid=36611_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": "2024-09-30T17:38:12.757382", "lvl": "debug", "msg": "end: 1.5.4.5 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:38:12.757834", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.64", "extra": {"commit": "1fe48c584e7e01b0e0f5509bf4bb678e0bf391c9", "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": "2024-09-30T17:38:12.758886", "lvl": "debug", "msg": "start: 1.5.4.6 test-overlay (timeout 01:26:47) [common]"}
- {"dt": "2024-09-30T17:38:12.763634", "lvl": "debug", "msg": "end: 1.5.4.6 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:12.764191", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "git", "name": "ci-busybox", "path": "test-suites/short-smoke/busybox.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "36611_1.5.4.5"}, "level": "1.5.4.6", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:12.765366", "lvl": "debug", "msg": "start: 1.5.4.7 test-install-overlay (timeout 01:26:47) [common]"}
- {"dt": "2024-09-30T17:38:12.771787", "lvl": "debug", "msg": "end: 1.5.4.7 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:12.772374", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-busybox", "path": "test-suites/short-smoke/busybox.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "skipped test-install-overlay": "36611_1.5.4.5", "uuid": "36611_1.5.4.5"}, "level": "1.5.4.7", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:12.773610", "lvl": "debug", "msg": "start: 1.5.4.8 test-runscript-overlay (timeout 01:26:47) [common]"}
- {"dt": "2024-09-30T17:38:12.780361", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/1_ci-busybox test_uuid 36611_1.5.4.5"}
- {"dt": "2024-09-30T17:38:12.781796", "lvl": "debug", "msg": "end: 1.5.4.8 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:12.782446", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/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": "36611_1.5.4.5"}, "level": "1.5.4.8", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:12.784359", "lvl": "debug", "msg": "start: 1.5.4.9 git-repo-action (timeout 01:26:47) [common]"}
- {"dt": "2024-09-30T17:38:12.785004", "lvl": "debug", "msg": "Using /lava-36611 at stage 1"}
- {"dt": "2024-09-30T17:38:12.786287", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-09-30T17:38:12.787013", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/2_ci-smoke-tests-basic'"}
- {"dt": "2024-09-30T17:38:13.417517", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/2_ci-smoke-tests-basic"}
- {"dt": "2024-09-30T17:38:13.426237", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/2_ci-smoke-tests-basic/test-suites/short-smoke/smoke-tests-basic.yaml"}
- {"dt": "2024-09-30T17:38:13.428470", "lvl": "debug", "msg": "uuid=36611_1.5.4.9 testdef=None"}
- {"dt": "2024-09-30T17:38:13.429453", "lvl": "debug", "msg": "end: 1.5.4.9 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:38:13.430155", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.65", "extra": {"commit": "1fe48c584e7e01b0e0f5509bf4bb678e0bf391c9", "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": "2024-09-30T17:38:13.432090", "lvl": "debug", "msg": "start: 1.5.4.10 test-overlay (timeout 01:26:47) [common]"}
- {"dt": "2024-09-30T17:38:13.437389", "lvl": "debug", "msg": "end: 1.5.4.10 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:13.438199", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-smoke-tests-basic", "path": "test-suites/short-smoke/smoke-tests-basic.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "36611_1.5.4.9"}, "level": "1.5.4.10", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:13.439948", "lvl": "debug", "msg": "start: 1.5.4.11 test-install-overlay (timeout 01:26:47) [common]"}
- {"dt": "2024-09-30T17:38:13.446316", "lvl": "debug", "msg": "end: 1.5.4.11 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:13.447188", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-smoke-tests-basic", "path": "test-suites/short-smoke/smoke-tests-basic.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "skipped test-install-overlay": "36611_1.5.4.9", "uuid": "36611_1.5.4.9"}, "level": "1.5.4.11", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:13.448739", "lvl": "debug", "msg": "start: 1.5.4.12 test-runscript-overlay (timeout 01:26:47) [common]"}
- {"dt": "2024-09-30T17:38:13.456334", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/2_ci-smoke-tests-basic test_uuid 36611_1.5.4.9"}
- {"dt": "2024-09-30T17:38:13.458288", "lvl": "debug", "msg": "end: 1.5.4.12 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:13.463769", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/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": "36611_1.5.4.9"}, "level": "1.5.4.12", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:13.465301", "lvl": "debug", "msg": "start: 1.5.4.13 git-repo-action (timeout 01:26:47) [common]"}
- {"dt": "2024-09-30T17:38:13.466009", "lvl": "debug", "msg": "Using /lava-36611 at stage 1"}
- {"dt": "2024-09-30T17:38:13.466905", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-09-30T17:38:13.467731", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/3_ci-service-check'"}
- {"dt": "2024-09-30T17:38:14.177795", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/3_ci-service-check"}
- {"dt": "2024-09-30T17:38:14.186162", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/3_ci-service-check/test-suites/short-smoke/service-check.yaml"}
- {"dt": "2024-09-30T17:38:14.188300", "lvl": "debug", "msg": "uuid=36611_1.5.4.13 testdef=None"}
- {"dt": "2024-09-30T17:38:14.189035", "lvl": "debug", "msg": "end: 1.5.4.13 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:38:14.189489", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.72", "extra": {"commit": "1fe48c584e7e01b0e0f5509bf4bb678e0bf391c9", "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": "2024-09-30T17:38:14.190605", "lvl": "debug", "msg": "start: 1.5.4.14 test-overlay (timeout 01:26:46) [common]"}
- {"dt": "2024-09-30T17:38:14.194938", "lvl": "debug", "msg": "end: 1.5.4.14 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:14.195544", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "git", "name": "ci-service-check", "path": "test-suites/short-smoke/service-check.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "36611_1.5.4.13"}, "level": "1.5.4.14", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:14.196740", "lvl": "debug", "msg": "start: 1.5.4.15 test-install-overlay (timeout 01:26:46) [common]"}
- {"dt": "2024-09-30T17:38:14.203226", "lvl": "debug", "msg": "end: 1.5.4.15 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:14.203817", "lvl": "results", "msg": {"case": "test-install-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-service-check", "path": "test-suites/short-smoke/service-check.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "skipped test-install-overlay": "36611_1.5.4.13", "uuid": "36611_1.5.4.13"}, "level": "1.5.4.15", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:14.205074", "lvl": "debug", "msg": "start: 1.5.4.16 test-runscript-overlay (timeout 01:26:46) [common]"}
- {"dt": "2024-09-30T17:38:14.211221", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1/tests/3_ci-service-check test_uuid 36611_1.5.4.13"}
- {"dt": "2024-09-30T17:38:14.211857", "lvl": "debug", "msg": "BUILD_TAGS=''"}
- {"dt": "2024-09-30T17:38:14.212265", "lvl": "debug", "msg": "DEVICE_TAGS=''"}
- {"dt": "2024-09-30T17:38:14.213406", "lvl": "debug", "msg": "end: 1.5.4.16 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:14.213982", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/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": "36611_1.5.4.13"}, "level": "1.5.4.16", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:14.223781", "lvl": "debug", "msg": "start: 1.5.4.17 git-repo-action (timeout 01:26:46) [common]"}
- {"dt": "2024-09-30T17:38:14.224487", "lvl": "debug", "msg": "Using /lava-36611 at stage 2"}
- {"dt": "2024-09-30T17:38:14.225217", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-09-30T17:38:14.225710", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/2/tests/4_screenshooter'"}
- {"dt": "2024-09-30T17:38:14.873162", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/2/tests/4_screenshooter/test-suites/short-smoke/screenshooter.yaml"}
- {"dt": "2024-09-30T17:38:14.874888", "lvl": "debug", "msg": "uuid=36611_1.5.4.17 testdef=None"}
- {"dt": "2024-09-30T17:38:14.875918", "lvl": "debug", "msg": "end: 1.5.4.17 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:38:14.876388", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.65", "extra": {"commit": "1fe48c584e7e01b0e0f5509bf4bb678e0bf391c9", "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": "2024-09-30T17:38:14.877520", "lvl": "debug", "msg": "start: 1.5.4.18 test-overlay (timeout 01:26:45) [common]"}
- {"dt": "2024-09-30T17:38:14.881357", "lvl": "debug", "msg": "end: 1.5.4.18 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:14.881918", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "git", "name": "screenshooter", "path": "test-suites/short-smoke/screenshooter.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "36611_1.5.4.17"}, "level": "1.5.4.18", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:14.883323", "lvl": "debug", "msg": "start: 1.5.4.19 test-install-overlay (timeout 01:26:45) [common]"}
- {"dt": "2024-09-30T17:38:14.888655", "lvl": "debug", "msg": "end: 1.5.4.19 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:14.889243", "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": "36611_1.5.4.17", "uuid": "36611_1.5.4.17"}, "level": "1.5.4.19", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:14.890505", "lvl": "debug", "msg": "start: 1.5.4.20 test-runscript-overlay (timeout 01:26:45) [common]"}
- {"dt": "2024-09-30T17:38:14.907743", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/2/tests/4_screenshooter test_uuid 36611_1.5.4.17"}
- {"dt": "2024-09-30T17:38:14.909123", "lvl": "debug", "msg": "end: 1.5.4.20 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:14.909714", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.02", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/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": "36611_1.5.4.17"}, "level": "1.5.4.20", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:14.911011", "lvl": "debug", "msg": "start: 1.5.4.21 git-repo-action (timeout 01:26:45) [common]"}
- {"dt": "2024-09-30T17:38:14.911508", "lvl": "debug", "msg": "Using /lava-36611 at stage 3"}
- {"dt": "2024-09-30T17:38:14.912208", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-09-30T17:38:14.912694", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/3/tests/5_ci-dumpjournal'"}
- {"dt": "2024-09-30T17:38:15.543676", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/3/tests/5_ci-dumpjournal"}
- {"dt": "2024-09-30T17:38:15.552404", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/3/tests/5_ci-dumpjournal/test-suites/short-smoke/dumpjournal.yaml"}
- {"dt": "2024-09-30T17:38:15.554498", "lvl": "debug", "msg": "uuid=36611_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": "2024-09-30T17:38:15.555309", "lvl": "debug", "msg": "end: 1.5.4.21 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:38:15.555791", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.64", "extra": {"commit": "1fe48c584e7e01b0e0f5509bf4bb678e0bf391c9", "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": "2024-09-30T17:38:15.556872", "lvl": "debug", "msg": "start: 1.5.4.22 test-overlay (timeout 01:26:45) [common]"}
- {"dt": "2024-09-30T17:38:15.561477", "lvl": "debug", "msg": "end: 1.5.4.22 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:15.562041", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "git", "name": "ci-dumpjournal", "path": "test-suites/short-smoke/dumpjournal.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "36611_1.5.4.21"}, "level": "1.5.4.22", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:15.563721", "lvl": "debug", "msg": "start: 1.5.4.23 test-install-overlay (timeout 01:26:45) [common]"}
- {"dt": "2024-09-30T17:38:15.570229", "lvl": "debug", "msg": "end: 1.5.4.23 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:15.570832", "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": "36611_1.5.4.21", "uuid": "36611_1.5.4.21"}, "level": "1.5.4.23", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:15.572250", "lvl": "debug", "msg": "start: 1.5.4.24 test-runscript-overlay (timeout 01:26:45) [common]"}
- {"dt": "2024-09-30T17:38:15.578500", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/3/tests/5_ci-dumpjournal test_uuid 36611_1.5.4.21"}
- {"dt": "2024-09-30T17:38:15.579900", "lvl": "debug", "msg": "end: 1.5.4.24 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:15.580498", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/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": "36611_1.5.4.21"}, "level": "1.5.4.24", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:15.581594", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2024-09-30T17:38:15.582001", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/0 for stage 0"}
- {"dt": "2024-09-30T17:38:15.582726", "lvl": "debug", "msg": "- 0_network-veth"}
- {"dt": "2024-09-30T17:38:15.583482", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/1 for stage 1"}
- {"dt": "2024-09-30T17:38:15.584245", "lvl": "debug", "msg": "- 1_ci-busybox"}
- {"dt": "2024-09-30T17:38:15.584742", "lvl": "debug", "msg": "- 2_ci-smoke-tests-basic"}
- {"dt": "2024-09-30T17:38:15.585144", "lvl": "debug", "msg": "- 3_ci-service-check"}
- {"dt": "2024-09-30T17:38:15.585668", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/2 for stage 2"}
- {"dt": "2024-09-30T17:38:15.586369", "lvl": "debug", "msg": "- 4_screenshooter"}
- {"dt": "2024-09-30T17:38:15.587021", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/36611/lava-overlay-isvs6kvb/lava-36611/3 for stage 3"}
- {"dt": "2024-09-30T17:38:15.587766", "lvl": "debug", "msg": "- 5_ci-dumpjournal"}
- {"dt": "2024-09-30T17:38:15.588539", "lvl": "debug", "msg": "end: 1.5.4 test-definition (duration 00:00:04) [common]"}
- {"dt": "2024-09-30T17:38:15.589150", "lvl": "debug", "msg": "start: 1.5.5 compress-overlay (timeout 01:26:45) [common]"}
- {"dt": "2024-09-30T17:38:16.246730", "lvl": "debug", "msg": "end: 1.5.5 compress-overlay (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:38:16.247569", "lvl": "debug", "msg": "start: 1.5.6 persistent-nfs-overlay (timeout 01:26:44) [common]"}
- {"dt": "2024-09-30T17:38:16.248157", "lvl": "debug", "msg": "end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:16.248749", "lvl": "debug", "msg": "end: 1.5 lava-overlay (duration 00:00:05) [common]"}
- {"dt": "2024-09-30T17:38:16.249303", "lvl": "debug", "msg": "start: 1.6 prepare-kernel (timeout 01:26:44) [common]"}
- {"dt": "2024-09-30T17:38:16.249853", "lvl": "debug", "msg": "start: 1.6.1 uboot-prepare-kernel (timeout 01:26:44) [common]"}
- {"dt": "2024-09-30T17:38:16.250449", "lvl": "debug", "msg": "end: 1.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:16.251030", "lvl": "debug", "msg": "end: 1.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:16.251589", "lvl": "debug", "msg": "start: 1.7 xnbd-server-deploy (timeout 01:26:44) [common]"}
- {"dt": "2024-09-30T17:38:16.252033", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server"}
- {"dt": "2024-09-30T17:38:16.252460", "lvl": "debug", "msg": "NBD-IP: 192.168.66.1, NBD-PORT: 61994, NBD-ROOT: 36611/nbd-deploy-__9oaok5/nbdroot/agl-ivi-demo-qt-raspberrypi4-64.ext4"}
- {"dt": "2024-09-30T17:38:16.255135", "lvl": "debug", "msg": "nbd-server 61994 /var/lib/lava/dispatcher/tmp/36611/nbd-deploy-__9oaok5/nbdroot/agl-ivi-demo-qt-raspberrypi4-64.ext4"}
- {"dt": "2024-09-30T17:38:16.266887", "lvl": "debug", "msg": "output: "}
- {"dt": "2024-09-30T17:38:16.267658", "lvl": "debug", "msg": "output: ** (process:17579): WARNING **: 17:38:16.265: Specifying an export on the command line no longer uses the oldstyle protocol."}
- {"dt": "2024-09-30T17:38:16.268166", "lvl": "debug", "msg": "output: "}
- {"dt": "2024-09-30T17:38:16.268629", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server done"}
- {"dt": "2024-09-30T17:38:16.269406", "lvl": "debug", "msg": "end: 1.7 xnbd-server-deploy (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:16.270120", "lvl": "info", "msg": "end: 1 nbd-deploy (duration 00:03:16) [common]"}
- {"dt": "2024-09-30T17:38:16.270838", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:20:00) [common]"}
- {"dt": "2024-09-30T17:38:16.271656", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:20:00) [common]"}
- {"dt": "2024-09-30T17:38:16.272453", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:16.273211", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:20:00) [common]"}
- {"dt": "2024-09-30T17:38:16.274212", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2024-09-30T17:38:16.274832", "lvl": "debug", "msg": "- {BOOTX}: booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-09-30T17:38:16.275462", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x02400000"}
- {"dt": "2024-09-30T17:38:16.276024", "lvl": "debug", "msg": "- {DTB}: 36611/nbd-deploy-__9oaok5/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-09-30T17:38:16.276544", "lvl": "debug", "msg": "- {INITRD}: 36611/nbd-deploy-__9oaok5/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-09-30T17:38:16.277079", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x00080000"}
- {"dt": "2024-09-30T17:38:16.277650", "lvl": "debug", "msg": "- {KERNEL}: 36611/nbd-deploy-__9oaok5/kernel/Image"}
- {"dt": "2024-09-30T17:38:16.278238", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2024-09-30T17:38:16.278804", "lvl": "debug", "msg": "- {NBDSERVERIP}: 192.168.66.1"}
- {"dt": "2024-09-30T17:38:16.279404", "lvl": "debug", "msg": "- {NBDSERVERPORT}: 61994"}
- {"dt": "2024-09-30T17:38:16.279934", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2024-09-30T17:38:16.280530", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2024-09-30T17:38:16.281075", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x02700000"}
- {"dt": "2024-09-30T17:38:16.281597", "lvl": "debug", "msg": "- {RAMDISK}: 36611/nbd-deploy-__9oaok5/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-09-30T17:38:16.282214", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2024-09-30T17:38:16.282744", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2024-09-30T17:38:16.283410", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2024-09-30T17:38:16.283933", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2024-09-30T17:38:16.284395", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2024-09-30T17:38:16.284929", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2024-09-30T17:38:16.285377", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2024-09-30T17:38:16.285799", "lvl": "info", "msg": "- setenv initrd_high 0xffffffff"}
- {"dt": "2024-09-30T17:38:16.286264", "lvl": "info", "msg": "- setenv fdt_high 0xffffffff"}
- {"dt": "2024-09-30T17:38:16.286759", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2024-09-30T17:38:16.287278", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2024-09-30T17:38:16.287729", "lvl": "info", "msg": "- tftp 0x00080000 36611/nbd-deploy-__9oaok5/kernel/Image"}
- {"dt": "2024-09-30T17:38:16.288287", "lvl": "info", "msg": "- tftp 0x02700000 36611/nbd-deploy-__9oaok5/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-09-30T17:38:16.288815", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2024-09-30T17:38:16.289292", "lvl": "info", "msg": "- tftp 0x02400000 36611/nbd-deploy-__9oaok5/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-09-30T17:38:16.289748", "lvl": "info", "msg": "- setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61994 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'"}
- {"dt": "2024-09-30T17:38:16.290281", "lvl": "info", "msg": "- fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-09-30T17:38:16.291022", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-09-30T17:38:16.291683", "lvl": "results", "msg": {"case": "bootloader-overlay", "definition": "lava", "duration": "0.02", "extra": {"dtb_addr": "0x02400000", "kernel_addr": "0x00080000", "ramdisk_addr": "0x02700000", "tee_addr": "0x83000000"}, "level": "2.2", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:16.293150", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:20:00) [common]"}
- {"dt": "2024-09-30T17:38:16.294138", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63003'"}
- {"dt": "2024-09-30T17:38:19.971737", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2024-09-30T17:38:19.974068", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:04) [common]"}
- {"dt": "2024-09-30T17:38:19.975043", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:19:56) [common]"}
- {"dt": "2024-09-30T17:38:19.976016", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:19:56) [common]"}
- {"dt": "2024-09-30T17:38:19.976847", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:19:56) [common]"}
- {"dt": "2024-09-30T17:38:19.978436", "lvl": "debug", "msg": "Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '7'"}
- {"dt": "2024-09-30T17:38:23.737705", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2024-09-30T17:38:24.806244", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2024-09-30T17:38:24.854085", "lvl": "debug", "msg": "Returned 0 in 4 seconds"}
- {"dt": "2024-09-30T17:38:24.957866", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:05) [common]"}
- {"dt": "2024-09-30T17:38:24.960004", "lvl": "results", "msg": {"case": "pdu-reboot", "definition": "lava", "duration": "4.98", "extra": {"status": "success"}, "level": "2.4.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:38:24.963982", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:05) [common]"}
- {"dt": "2024-09-30T17:38:24.966207", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:19:51) [common]"}
- {"dt": "2024-09-30T17:38:24.968305", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2024-09-30T17:38:24.970104", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:20:00)"}
- {"dt": "2024-09-30T17:38:24.972390", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2024-09-30T17:38:24.972995", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2024-09-30T17:38:24.973455", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2024-09-30T17:38:31.492785", "lvl": "target", "msg": "\0"}
- {"dt": "2024-09-30T17:38:31.494170", "lvl": "target", "msg": ""}
- {"dt": "2024-09-30T17:38:31.509744", "lvl": "target", "msg": "U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)"}
- {"dt": "2024-09-30T17:38:31.510921", "lvl": "target", "msg": ""}
- {"dt": "2024-09-30T17:38:31.652586", "lvl": "target", "msg": "DRAM:  3.9 GiB"}
- {"dt": "2024-09-30T17:38:31.684492", "lvl": "target", "msg": "RPI 4 Model B (0xc03111)"}
- {"dt": "2024-09-30T17:38:31.722381", "lvl": "target", "msg": "MMC:   emmc2@7e340000: 0, mmcnr@7e300000: 1"}
- {"dt": "2024-09-30T17:38:31.789192", "lvl": "target", "msg": "Loading Environment from FAT... *** Warning - bad CRC, using default environment"}
- {"dt": "2024-09-30T17:38:31.790382", "lvl": "target", "msg": ""}
- {"dt": "2024-09-30T17:38:31.816858", "lvl": "target", "msg": "In:    serial"}
- {"dt": "2024-09-30T17:38:31.817562", "lvl": "target", "msg": "Out:   serial"}
- {"dt": "2024-09-30T17:38:31.818107", "lvl": "target", "msg": "Err:   serial"}
- {"dt": "2024-09-30T17:38:31.818622", "lvl": "target", "msg": "Net:   eth0: genet@7d580000"}
- {"dt": "2024-09-30T17:38:31.819165", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2024-09-30T17:38:31.819708", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2024-09-30T17:38:31.821107", "lvl": "input", "msg": "c"}
- {"dt": "2024-09-30T17:38:31.822294", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:00:07) [common]"}
- {"dt": "2024-09-30T17:38:31.823177", "lvl": "debug", "msg": "start: 2.4.3 bootloader-commands (timeout 00:19:44) [common]"}
- {"dt": "2024-09-30T17:38:31.823842", "lvl": "debug", "msg": "Setting prompt string to ['U-Boot>']"}
- {"dt": "2024-09-30T17:38:31.824438", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>'] (timeout 00:19:44)"}
- {"dt": "2024-09-30T17:38:31.835138", "lvl": "target", "msg": "Hit any key to stop autoboot:  2 \x03\b\b\b 0 "}
- {"dt": "2024-09-30T17:38:31.836428", "lvl": "debug", "msg": "Setting prompt string to ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image']"}
- {"dt": "2024-09-30T17:38:31.837258", "lvl": "input", "msg": "setenv autoload no\n"}
- {"dt": "2024-09-30T17:38:31.938274", "lvl": "target", "msg": "U-Boot> setenv autoload no"}
- {"dt": "2024-09-30T17:38:31.939419", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:44)"}
- {"dt": "2024-09-30T17:38:31.947007", "lvl": "target", "msg": "setenv autoload no"}
- {"dt": "2024-09-30T17:38:31.947976", "lvl": "input", "msg": "setenv initrd_high 0xffffffff\n"}
- {"dt": "2024-09-30T17:38:32.048946", "lvl": "target", "msg": "U-Boot> setenv initrd_high 0xffffffff"}
- {"dt": "2024-09-30T17:38:32.050365", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:44)"}
- {"dt": "2024-09-30T17:38:32.059866", "lvl": "target", "msg": "setenv initrd_high 0xffffffff"}
- {"dt": "2024-09-30T17:38:32.061042", "lvl": "input", "msg": "setenv fdt_high 0xffffffff\n"}
- {"dt": "2024-09-30T17:38:32.162129", "lvl": "target", "msg": "U-Boot> setenv fdt_high 0xffffffff"}
- {"dt": "2024-09-30T17:38:32.163399", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:44)"}
- {"dt": "2024-09-30T17:38:32.171578", "lvl": "target", "msg": "setenv fdt_high 0xffffffff"}
- {"dt": "2024-09-30T17:38:32.172775", "lvl": "input", "msg": "dhcp\n"}
- {"dt": "2024-09-30T17:38:32.273863", "lvl": "target", "msg": "U-Boot> dhcp"}
- {"dt": "2024-09-30T17:38:32.274811", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:44)"}
- {"dt": "2024-09-30T17:38:32.283276", "lvl": "target", "msg": "dhcp"}
- {"dt": "2024-09-30T17:38:35.495400", "lvl": "target", "msg": "genet@7d580000 Waiting for PHY auto negotiation to complete....... done"}
- {"dt": "2024-09-30T17:38:35.496486", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2024-09-30T17:38:35.751296", "lvl": "target", "msg": "BOOTP broadcast 2"}
- {"dt": "2024-09-30T17:38:36.245811", "lvl": "target", "msg": "BOOTP broadcast 3"}
- {"dt": "2024-09-30T17:38:36.789764", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (1287 ms)"}
- {"dt": "2024-09-30T17:38:36.791211", "lvl": "input", "msg": "setenv serverip 192.168.66.1\n"}
- {"dt": "2024-09-30T17:38:36.892749", "lvl": "target", "msg": "U-Boot> setenv serverip 192.168.66.1"}
- {"dt": "2024-09-30T17:38:36.893993", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:39)"}
- {"dt": "2024-09-30T17:38:36.901438", "lvl": "target", "msg": "setenv serverip 192.168.66.1"}
- {"dt": "2024-09-30T17:38:36.902352", "lvl": "input", "msg": "tftp 0x00080000 36611/nbd-deploy-__9oaok5/kernel/Image\n"}
- {"dt": "2024-09-30T17:38:37.003182", "lvl": "target", "msg": "U-Boot> tftp 0x00080000 36611/nbd-deploy-__9oaok5/kernel/Image"}
- {"dt": "2024-09-30T17:38:37.004300", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:39)"}
- {"dt": "2024-09-30T17:38:37.013354", "lvl": "target", "msg": "tftp 0x00080000 36611/nbd-deploy-__9oaok5/kernel/Image"}
- {"dt": "2024-09-30T17:38:37.014095", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2024-09-30T17:38:37.036325", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2024-09-30T17:38:37.038631", "lvl": "target", "msg": "Filename '36611/nbd-deploy-__9oaok5/kernel/Image'."}
- {"dt": "2024-09-30T17:38:37.039310", "lvl": "target", "msg": "Load address: 0x80000"}
- {"dt": "2024-09-30T17:38:59.018369", "lvl": "target", "msg": "Loading: *\bT #T #################################################  22.9 MiB"}
- {"dt": "2024-09-30T17:38:59.020015", "lvl": "target", "msg": "\t 1 MiB/s"}
- {"dt": "2024-09-30T17:38:59.021186", "lvl": "target", "msg": "done"}
- {"dt": "2024-09-30T17:38:59.023137", "lvl": "target", "msg": "Bytes transferred = 24046080 (16eea00 hex)"}
- {"dt": "2024-09-30T17:38:59.025083", "lvl": "input", "msg": "tftp 0x02700000 36611/nbd-deploy-__9oaok5/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz\n"}
- {"dt": "2024-09-30T17:38:59.127030", "lvl": "target", "msg": "U-Boot> tftp 0x02700000 36611/nbd-deploy-__9oaok5/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-09-30T17:38:59.128773", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:17)"}
- {"dt": "2024-09-30T17:38:59.133614", "lvl": "target", "msg": "tftp 0x02700000 36611/nbd-deploy-__9oaok5/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-09-30T17:38:59.175717", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2024-09-30T17:38:59.176755", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2024-09-30T17:38:59.177720", "lvl": "target", "msg": "Filename '36611/nbd-deploy-__9oaok5/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz'."}
- {"dt": "2024-09-30T17:38:59.178435", "lvl": "target", "msg": "Load address: 0x2700000"}
- {"dt": "2024-09-30T17:38:59.876031", "lvl": "target", "msg": "Loading: *\b##################################################  2 MiB"}
- {"dt": "2024-09-30T17:38:59.877593", "lvl": "target", "msg": "\t 2.8 MiB/s"}
- {"dt": "2024-09-30T17:38:59.878744", "lvl": "target", "msg": "done"}
- {"dt": "2024-09-30T17:38:59.880690", "lvl": "target", "msg": "Bytes transferred = 2065649 (1f84f1 hex)"}
- {"dt": "2024-09-30T17:38:59.882306", "lvl": "input", "msg": "setenv initrd_size ${filesize}\n"}
- {"dt": "2024-09-30T17:38:59.984077", "lvl": "target", "msg": "U-Boot> setenv initrd_size ${filesize}"}
- {"dt": "2024-09-30T17:38:59.986308", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:16)"}
- {"dt": "2024-09-30T17:38:59.990455", "lvl": "target", "msg": "setenv initrd_size ${filesize}"}
- {"dt": "2024-09-30T17:38:59.992444", "lvl": "input", "msg": "tftp 0x02400000 36611/nbd-deploy-__9oaok5/dtb/bcm2711-rpi-4-b+vc4.dtb\n"}
- {"dt": "2024-09-30T17:39:00.094734", "lvl": "target", "msg": "U-Boot>tftp 0x02400000 36611/nbd-deploy-__9oaok5/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-09-30T17:39:00.096534", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:16)"}
- {"dt": "2024-09-30T17:39:00.100899", "lvl": "target", "msg": " tftp 0x02400000 36611/nbd-deploy-__9oaok5/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-09-30T17:39:00.143426", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2024-09-30T17:39:00.144439", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2024-09-30T17:39:00.145400", "lvl": "target", "msg": "Filename '36611/nbd-deploy-__9oaok5/dtb/bcm2711-rpi-4-b+vc4.dtb'."}
- {"dt": "2024-09-30T17:39:00.146367", "lvl": "target", "msg": "Load address: 0x2400000"}
- {"dt": "2024-09-30T17:39:00.154682", "lvl": "target", "msg": "Loading: *\b##################################################  51.2 KiB"}
- {"dt": "2024-09-30T17:39:00.155369", "lvl": "target", "msg": "\t 2.6 MiB/s"}
- {"dt": "2024-09-30T17:39:00.156002", "lvl": "target", "msg": "done"}
- {"dt": "2024-09-30T17:39:00.157795", "lvl": "target", "msg": "Bytes transferred = 52444 (ccdc hex)"}
- {"dt": "2024-09-30T17:39:00.158823", "lvl": "input", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61994 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'\n"}
- {"dt": "2024-09-30T17:39:00.259814", "lvl": "target", "msg": "U-Boot> setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61994 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'"}
- {"dt": "2024-09-30T17:39:00.261940", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:16)"}
- {"dt": "2024-09-30T17:39:00.266754", "lvl": "target", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61994 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw'"}
- {"dt": "2024-09-30T17:39:00.269046", "lvl": "input", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000\n"}
- {"dt": "2024-09-30T17:39:00.371182", "lvl": "target", "msg": "U-Boot> fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-09-30T17:39:00.373292", "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": "2024-09-30T17:39:00.374889", "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:16)"}
- {"dt": "2024-09-30T17:39:00.382759", "lvl": "target", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-09-30T17:39:00.569307", "lvl": "target", "msg": "## Flattened Device Tree blob at 02400000"}
- {"dt": "2024-09-30T17:39:00.570520", "lvl": "target", "msg": "   Booting using the fdt blob at 0x2400000"}
- {"dt": "2024-09-30T17:39:00.572503", "lvl": "target", "msg": "   Loading Ramdisk to 3ad50000, end 3af484f1 ... OK"}
- {"dt": "2024-09-30T17:39:00.593829", "lvl": "target", "msg": "   Loading Device Tree to 000000003ad40000, end 000000003ad4ffff ... OK"}
- {"dt": "2024-09-30T17:39:00.595251", "lvl": "target", "msg": ""}
- {"dt": "2024-09-30T17:39:00.597020", "lvl": "target", "msg": "Starting kernel ..."}
- {"dt": "2024-09-30T17:39:00.598235", "lvl": "target", "msg": ""}
- {"dt": "2024-09-30T17:39:00.600415", "lvl": "debug", "msg": "end: 2.4.3 bootloader-commands (duration 00:00:29) [common]"}
- {"dt": "2024-09-30T17:39:00.602044", "lvl": "debug", "msg": "start: 2.4.4 auto-login-action (timeout 00:19:16) [common]"}
- {"dt": "2024-09-30T17:39:00.603428", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2024-09-30T17:39:00.604722", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image']"}
- {"dt": "2024-09-30T17:39:00.606039", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:20:00)"}
- {"dt": "2024-09-30T17:39:02.411347", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]"}
- {"dt": "2024-09-30T17:39:02.412738", "lvl": "target", "msg": "[    0.000000] Linux version 5.15.92-v8 (oe-user@oe-host) (aarch64-agl-linux-gcc (GCC) 11.4.0, GNU ld (GNU Binutils) 2.38.20220708) #1 SMP PREEMPT Mon Sep 30 13:38:28 UTC 2024"}
- {"dt": "2024-09-30T17:39:02.413508", "lvl": "target", "msg": "[    0.000000] Machine model: Raspberry Pi 4 Model B"}
- {"dt": "2024-09-30T17:39:02.414433", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2024-09-30T17:39:02.415316", "lvl": "target", "msg": "[    0.000000] Reserved memory: created CMA memory pool at 0x000000001c400000, size 316 MiB"}
- {"dt": "2024-09-30T17:39:02.417031", "lvl": "debug", "msg": "start: 2.4.4.1 login-action (timeout 00:19:14) [common]"}
- {"dt": "2024-09-30T17:39:02.418034", "lvl": "warning", "msg": "The string '/ #' does not look like a typical prompt and could match status messages instead. Please check the job log files and use a prompt string which matches the actual prompt string more closely."}
- {"dt": "2024-09-30T17:39:02.418903", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2024-09-30T17:39:02.419897", "lvl": "debug", "msg": "Setting prompt string to ['-\\\\[ cut here \\\\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing']"}
- {"dt": "2024-09-30T17:39:02.420746", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2024-09-30T17:39:02.421532", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2024-09-30T17:39:02.422325", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2024-09-30T17:39:02.423088", "lvl": "debug", "msg": ["-\\[ cut here \\]", "Unhandled fault", "BUG: KCSAN:", "BUG: KASAN:", "BUG: KFENCE:", "Oops(?: -|:)", "WARNING:", "(kernel BUG at|BUG:)", "invalid opcode:", "Kernel panic - not syncing", "root@raspberrypi4-64:~", "raspberrypi4-64:~#", "/ #", "login:", "Login incorrect"]}
- {"dt": "2024-09-30T17:39:02.424040", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:19:14)"}
- {"dt": "2024-09-30T17:39:02.456010", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool"}
- {"dt": "2024-09-30T17:39:02.457774", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2024-09-30T17:39:02.458839", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003fffffff]"}
- {"dt": "2024-09-30T17:39:02.460233", "lvl": "target", "msg": "[    0.000000]   DMA32    [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2024-09-30T17:39:02.461381", "lvl": "target", "msg": "[    0.000000]   Normal   empty"}
- {"dt": "2024-09-30T17:39:02.463070", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2024-09-30T17:39:02.464157", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2024-09-30T17:39:02.464945", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]"}
- {"dt": "2024-09-30T17:39:02.465597", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2024-09-30T17:39:02.499858", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]"}
- {"dt": "2024-09-30T17:39:02.500889", "lvl": "target", "msg": "[    0.000000] On node 0, zone DMA32: 19456 pages in unavailable ranges"}
- {"dt": "2024-09-30T17:39:02.502023", "lvl": "target", "msg": "[    0.000000] On node 0, zone DMA32: 16384 pages in unavailable ranges"}
- {"dt": "2024-09-30T17:39:02.503924", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 29 pages/cpu s78040 r8192 d32552 u118784"}
- {"dt": "2024-09-30T17:39:02.505217", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2024-09-30T17:39:02.505859", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v2"}
- {"dt": "2024-09-30T17:39:02.506366", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v3a"}
- {"dt": "2024-09-30T17:39:02.506842", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v4"}
- {"dt": "2024-09-30T17:39:02.543242", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-BHB"}
- {"dt": "2024-09-30T17:39:02.544777", "lvl": "target", "msg": "[    0.000000] CPU features: detected: ARM erratum 1742098"}
- {"dt": "2024-09-30T17:39:02.545646", "lvl": "target", "msg": "[    0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923"}
- {"dt": "2024-09-30T17:39:02.546411", "lvl": "target", "msg": "[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 996912"}
- {"dt": "2024-09-30T17:39:02.588179", "lvl": "target", "msg": "[    0.000000] Kernel command line: console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61994 root=/dev/ram0 ramdisk_size=16384 rootdelay=7   coherent_pool=1M 8250.nr_uarts=1 rw fstab=no systemd.mask=systemd-network-generator.service ip=dhcp verbose earlyprintk systemd.log_color=false ${extraargs} rw"}
- {"dt": "2024-09-30T17:39:02.591853", "lvl": "target", "msg": "[    0.000000] Unknown kernel command line parameters \\\"verbose earlyprintk ${extraargs} fstab=no\\\", will be passed to user space."}
- {"dt": "2024-09-30T17:39:02.593036", "lvl": "target", "msg": "[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2024-09-30T17:39:02.594011", "lvl": "target", "msg": "[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2024-09-30T17:39:02.594899", "lvl": "target", "msg": "[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off"}
- {"dt": "2024-09-30T17:39:02.630628", "lvl": "target", "msg": "[    0.000000] software IO TLB: mapped [mem 0x0000000036d40000-0x000000003ad40000] (64MB)"}
- {"dt": "2024-09-30T17:39:02.632270", "lvl": "target", "msg": "[    0.000000] Memory: 3554120K/4050944K available (12736K kernel code, 2042K rwdata, 4504K rodata, 4096K init, 1007K bss, 173240K reserved, 323584K cma-reserved)"}
- {"dt": "2024-09-30T17:39:02.633114", "lvl": "target", "msg": "[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1"}
- {"dt": "2024-09-30T17:39:02.633857", "lvl": "target", "msg": "[    0.000000] ftrace: allocating 40914 entries in 160 pages"}
- {"dt": "2024-09-30T17:39:02.634663", "lvl": "target", "msg": "[    0.000000] ftrace: allocated 160 pages with 2 groups"}
- {"dt": "2024-09-30T17:39:02.635480", "lvl": "target", "msg": "[    0.000000] trace event string verifier disabled"}
- {"dt": "2024-09-30T17:39:02.674538", "lvl": "target", "msg": "[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2024-09-30T17:39:02.675709", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2024-09-30T17:39:02.676573", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4."}
- {"dt": "2024-09-30T17:39:02.678225", "lvl": "target", "msg": "[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2024-09-30T17:39:02.679236", "lvl": "target", "msg": "[    0.000000] \tRude variant of Tasks RCU enabled."}
- {"dt": "2024-09-30T17:39:02.680028", "lvl": "target", "msg": "[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2024-09-30T17:39:02.680798", "lvl": "target", "msg": "[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2024-09-30T17:39:02.681727", "lvl": "target", "msg": "[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4"}
- {"dt": "2024-09-30T17:39:02.718203", "lvl": "target", "msg": "[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2024-09-30T17:39:02.719347", "lvl": "target", "msg": "[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2024-09-30T17:39:02.720068", "lvl": "target", "msg": "[    0.000000] GIC: Using split EOI/Deactivate mode"}
- {"dt": "2024-09-30T17:39:02.721591", "lvl": "target", "msg": "[    0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 10)"}
- {"dt": "2024-09-30T17:39:02.722427", "lvl": "target", "msg": "[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys)."}
- {"dt": "2024-09-30T17:39:02.723207", "lvl": "target", "msg": "[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns"}
- {"dt": "2024-09-30T17:39:02.762191", "lvl": "target", "msg": "[    0.000000] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns"}
- {"dt": "2024-09-30T17:39:02.763951", "lvl": "target", "msg": "[    0.000304] Console: colour dummy device 80x25"}
- {"dt": "2024-09-30T17:39:02.766136", "lvl": "target", "msg": "[    0.000382] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)"}
- {"dt": "2024-09-30T17:39:02.767104", "lvl": "target", "msg": "[    0.000410] pid_max: default: 32768 minimum: 301"}
- {"dt": "2024-09-30T17:39:02.767923", "lvl": "target", "msg": "[    0.000542] LSM: Security Framework initializing"}
- {"dt": "2024-09-30T17:39:02.768716", "lvl": "target", "msg": "[    0.000790] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-09-30T17:39:02.769611", "lvl": "target", "msg": "[    0.000851] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-09-30T17:39:02.806033", "lvl": "target", "msg": "[    0.002052] cgroup: Disabling memory control group subsystem"}
- {"dt": "2024-09-30T17:39:02.807483", "lvl": "target", "msg": "[    0.004853] rcu: Hierarchical SRCU implementation."}
- {"dt": "2024-09-30T17:39:02.810010", "lvl": "target", "msg": "[    0.005877] EFI services will not be available."}
- {"dt": "2024-09-30T17:39:02.811349", "lvl": "target", "msg": "[    0.006402] smp: Bringing up secondary CPUs ..."}
- {"dt": "2024-09-30T17:39:02.812588", "lvl": "target", "msg": "[    0.007482] Detected PIPT I-cache on CPU1"}
- {"dt": "2024-09-30T17:39:02.813784", "lvl": "target", "msg": "[    0.007557] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]"}
- {"dt": "2024-09-30T17:39:02.814949", "lvl": "target", "msg": "[    0.008840] Detected PIPT I-cache on CPU2"}
- {"dt": "2024-09-30T17:39:02.815590", "lvl": "target", "msg": "[    0.008891] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]"}
- {"dt": "2024-09-30T17:39:02.849951", "lvl": "target", "msg": "[    0.010044] Detected PIPT I-cache on CPU3"}
- {"dt": "2024-09-30T17:39:02.851241", "lvl": "target", "msg": "[    0.010092] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]"}
- {"dt": "2024-09-30T17:39:02.851993", "lvl": "target", "msg": "[    0.010272] smp: Brought up 1 node, 4 CPUs"}
- {"dt": "2024-09-30T17:39:02.853919", "lvl": "target", "msg": "[    0.010318] SMP: Total of 4 processors activated."}
- {"dt": "2024-09-30T17:39:02.854698", "lvl": "target", "msg": "[    0.010333] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2024-09-30T17:39:02.855372", "lvl": "target", "msg": "[    0.010346] CPU features: detected: 32-bit EL1 Support"}
- {"dt": "2024-09-30T17:39:02.855973", "lvl": "target", "msg": "[    0.010361] CPU features: detected: CRC32 instructions"}
- {"dt": "2024-09-30T17:39:02.856568", "lvl": "target", "msg": "[    0.043688] CPU: All CPU(s) started at EL2"}
- {"dt": "2024-09-30T17:39:02.857164", "lvl": "target", "msg": "[    0.043790] alternatives: patching kernel code"}
- {"dt": "2024-09-30T17:39:02.857756", "lvl": "target", "msg": "[    0.045200] devtmpfs: initialized"}
- {"dt": "2024-09-30T17:39:02.894309", "lvl": "target", "msg": "[    0.055334] Enabled cp15_barrier support"}
- {"dt": "2024-09-30T17:39:02.897026", "lvl": "target", "msg": "[    0.055377] Enabled setend support"}
- {"dt": "2024-09-30T17:39:02.898220", "lvl": "target", "msg": "[    0.055400] KASLR disabled due to lack of seed"}
- {"dt": "2024-09-30T17:39:02.899237", "lvl": "target", "msg": "[    0.055707] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2024-09-30T17:39:02.899926", "lvl": "target", "msg": "[    0.055742] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-09-30T17:39:02.900587", "lvl": "target", "msg": "[    0.063553] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2024-09-30T17:39:02.901249", "lvl": "target", "msg": "[    0.064371] DMI not present or invalid."}
- {"dt": "2024-09-30T17:39:02.901904", "lvl": "target", "msg": "[    0.065264] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2024-09-30T17:39:02.937660", "lvl": "target", "msg": "[    0.068730] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations"}
- {"dt": "2024-09-30T17:39:02.940738", "lvl": "target", "msg": "[    0.069027] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations"}
- {"dt": "2024-09-30T17:39:02.942113", "lvl": "target", "msg": "[    0.069910] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations"}
- {"dt": "2024-09-30T17:39:02.943464", "lvl": "target", "msg": "[    0.070001] audit: initializing netlink subsys (disabled)"}
- {"dt": "2024-09-30T17:39:02.944236", "lvl": "target", "msg": "[    0.070285] audit: type=2000 audit(0.068:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2024-09-30T17:39:02.945096", "lvl": "target", "msg": "[    0.070787] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2024-09-30T17:39:02.981238", "lvl": "target", "msg": "[    0.070993] cpuidle: using governor menu"}
- {"dt": "2024-09-30T17:39:02.982812", "lvl": "target", "msg": "[    0.071230] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2024-09-30T17:39:02.984051", "lvl": "target", "msg": "[    0.071414] ASID allocator initialised with 65536 entries"}
- {"dt": "2024-09-30T17:39:02.985266", "lvl": "target", "msg": "[    0.071571] Serial: AMBA PL011 UART driver"}
- {"dt": "2024-09-30T17:39:02.988311", "lvl": "target", "msg": "[    0.083404] bcm2835-mbox fe00b880.mailbox: mailbox enabled"}
- {"dt": "2024-09-30T17:39:02.989663", "lvl": "target", "msg": "[    0.108356] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-01-22T17:23:15, variant start"}
- {"dt": "2024-09-30T17:39:03.024952", "lvl": "target", "msg": "[    0.112375] raspberrypi-firmware soc:firmware: Firmware hash is acb03c7d18aa08f25f6419d696d0cc39761d3e62"}
- {"dt": "2024-09-30T17:39:03.026442", "lvl": "target", "msg": "[    0.163599] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1"}
- {"dt": "2024-09-30T17:39:03.027814", "lvl": "target", "msg": "[    0.167740] vgaarb: loaded"}
- {"dt": "2024-09-30T17:39:03.029126", "lvl": "target", "msg": "[    0.168202] SCSI subsystem initialized"}
- {"dt": "2024-09-30T17:39:03.032320", "lvl": "target", "msg": "[    0.168406] usbcore: registered new interface driver usbfs"}
- {"dt": "2024-09-30T17:39:03.033770", "lvl": "target", "msg": "[    0.168468] usbcore: registered new interface driver hub"}
- {"dt": "2024-09-30T17:39:03.035067", "lvl": "target", "msg": "[    0.168617] usbcore: registered new device driver usb"}
- {"dt": "2024-09-30T17:39:03.035734", "lvl": "target", "msg": "[    0.168967] usb_phy_generic phy: supply vcc not found, using dummy regulator"}
- {"dt": "2024-09-30T17:39:03.068574", "lvl": "target", "msg": "[    0.169160] usb_phy_generic phy: dummy supplies not allowed for exclusive requests"}
- {"dt": "2024-09-30T17:39:03.070073", "lvl": "target", "msg": "[    0.169470] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2024-09-30T17:39:03.073095", "lvl": "target", "msg": "[    0.169486] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2024-09-30T17:39:03.074316", "lvl": "target", "msg": "[    0.169511] PTP clock support registered"}
- {"dt": "2024-09-30T17:39:03.075371", "lvl": "target", "msg": "[    0.169755] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2024-09-30T17:39:03.075947", "lvl": "target", "msg": "[    0.170962] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2024-09-30T17:39:03.076524", "lvl": "target", "msg": "[    0.259494] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2024-09-30T17:39:03.077016", "lvl": "target", "msg": "[    0.259619] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2024-09-30T17:39:03.112806", "lvl": "target", "msg": "[    0.259781] FS-Cache: Loaded"}
- {"dt": "2024-09-30T17:39:03.114415", "lvl": "target", "msg": "[    0.259995] CacheFiles: Loaded"}
- {"dt": "2024-09-30T17:39:03.115830", "lvl": "target", "msg": "[    0.270300] NET: Registered PF_INET protocol family"}
- {"dt": "2024-09-30T17:39:03.117174", "lvl": "target", "msg": "[    0.270807] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)"}
- {"dt": "2024-09-30T17:39:03.118473", "lvl": "target", "msg": "[    0.274198] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2024-09-30T17:39:03.122341", "lvl": "target", "msg": "[    0.274254] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)"}
- {"dt": "2024-09-30T17:39:03.123498", "lvl": "target", "msg": "[    0.274282] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2024-09-30T17:39:03.156037", "lvl": "target", "msg": "[    0.274487] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)"}
- {"dt": "2024-09-30T17:39:03.159322", "lvl": "target", "msg": "[    0.275028] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2024-09-30T17:39:03.160518", "lvl": "target", "msg": "[    0.275244] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-09-30T17:39:03.161517", "lvl": "target", "msg": "[    0.275316] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-09-30T17:39:03.162549", "lvl": "target", "msg": "[    0.275615] NET: Registered PF_UNIX/PF_LOCAL protocol family"}
- {"dt": "2024-09-30T17:39:03.163687", "lvl": "target", "msg": "[    0.276545] RPC: Registered named UNIX socket transport module."}
- {"dt": "2024-09-30T17:39:03.164959", "lvl": "target", "msg": "[    0.276565] RPC: Registered udp transport module."}
- {"dt": "2024-09-30T17:39:03.199868", "lvl": "target", "msg": "[    0.276579] RPC: Registered tcp transport module."}
- {"dt": "2024-09-30T17:39:03.201066", "lvl": "target", "msg": "[    0.276592] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2024-09-30T17:39:03.202051", "lvl": "target", "msg": "[    0.276614] PCI: CLS 0 bytes, default 64"}
- {"dt": "2024-09-30T17:39:03.204951", "lvl": "target", "msg": "[    0.277179] Trying to unpack rootfs image as initramfs..."}
- {"dt": "2024-09-30T17:39:03.206179", "lvl": "target", "msg": "[    0.277576] rootfs image is not initramfs (no cpio magic); looks like an initrd"}
- {"dt": "2024-09-30T17:39:03.207329", "lvl": "target", "msg": "[    0.285088] Freeing initrd memory: 2016K"}
- {"dt": "2024-09-30T17:39:03.208417", "lvl": "target", "msg": "[    0.286855] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available"}
- {"dt": "2024-09-30T17:39:03.209475", "lvl": "target", "msg": "[    0.287235] kvm [1]: IPA Size Limit: 44 bits"}
- {"dt": "2024-09-30T17:39:03.243867", "lvl": "target", "msg": "[    0.288443] kvm [1]: vgic interrupt IRQ9"}
- {"dt": "2024-09-30T17:39:03.245141", "lvl": "target", "msg": "[    0.288720] kvm [1]: Hyp mode initialized successfully"}
- {"dt": "2024-09-30T17:39:03.246216", "lvl": "target", "msg": "[    1.050589] Initialise system trusted keyrings"}
- {"dt": "2024-09-30T17:39:03.247394", "lvl": "target", "msg": "[    1.051062] workingset: timestamp_bits=46 max_order=20 bucket_order=0"}
- {"dt": "2024-09-30T17:39:03.248550", "lvl": "target", "msg": "[    1.057587] zbud: loaded"}
- {"dt": "2024-09-30T17:39:03.249627", "lvl": "target", "msg": "[    1.059282] FS-Cache: Netfs 'nfs' registered for caching"}
- {"dt": "2024-09-30T17:39:03.250680", "lvl": "target", "msg": "[    1.059976] NFS: Registering the id_resolver key type"}
- {"dt": "2024-09-30T17:39:03.251529", "lvl": "target", "msg": "[    1.060027] Key type id_resolver registered"}
- {"dt": "2024-09-30T17:39:03.252802", "lvl": "target", "msg": "[    1.060041] Key type id_legacy registered"}
- {"dt": "2024-09-30T17:39:03.287470", "lvl": "target", "msg": "[    1.060163] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2024-09-30T17:39:03.290350", "lvl": "target", "msg": "[    1.060180] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering..."}
- {"dt": "2024-09-30T17:39:03.291456", "lvl": "target", "msg": "[    1.061443] NET: Registered PF_ALG protocol family"}
- {"dt": "2024-09-30T17:39:03.292469", "lvl": "target", "msg": "[    1.061465] Key type asymmetric registered"}
- {"dt": "2024-09-30T17:39:03.293450", "lvl": "target", "msg": "[    1.061479] Asymmetric key parser 'x509' registered"}
- {"dt": "2024-09-30T17:39:03.294426", "lvl": "target", "msg": "[    1.061559] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 246)"}
- {"dt": "2024-09-30T17:39:03.295484", "lvl": "target", "msg": "[    1.061812] io scheduler mq-deadline registered"}
- {"dt": "2024-09-30T17:39:03.296637", "lvl": "target", "msg": "[    1.061831] io scheduler kyber registered"}
- {"dt": "2024-09-30T17:39:03.331079", "lvl": "target", "msg": "[    1.069613] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:"}
- {"dt": "2024-09-30T17:39:03.331998", "lvl": "target", "msg": "[    1.069660] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]"}
- {"dt": "2024-09-30T17:39:03.334064", "lvl": "target", "msg": "[    1.069747] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000"}
- {"dt": "2024-09-30T17:39:03.334883", "lvl": "target", "msg": "[    1.069831] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000"}
- {"dt": "2024-09-30T17:39:03.335697", "lvl": "target", "msg": "[    1.117058] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)"}
- {"dt": "2024-09-30T17:39:03.374925", "lvl": "target", "msg": "[    1.117414] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2024-09-30T17:39:03.376275", "lvl": "target", "msg": "[    1.117437] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2024-09-30T17:39:03.377492", "lvl": "target", "msg": "[    1.117458] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])"}
- {"dt": "2024-09-30T17:39:03.380644", "lvl": "target", "msg": "[    1.117545] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400"}
- {"dt": "2024-09-30T17:39:03.381862", "lvl": "target", "msg": "[    1.117789] pci 0000:00:00.0: PME# supported from D0 D3hot"}
- {"dt": "2024-09-30T17:39:03.383038", "lvl": "target", "msg": "[    1.121286] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring"}
- {"dt": "2024-09-30T17:39:03.384145", "lvl": "target", "msg": "[    1.121566] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330"}
- {"dt": "2024-09-30T17:39:03.418894", "lvl": "target", "msg": "[    1.121636] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]"}
- {"dt": "2024-09-30T17:39:03.422861", "lvl": "target", "msg": "[    1.121880] pci 0000:01:00.0: PME# supported from D0 D3cold"}
- {"dt": "2024-09-30T17:39:03.424294", "lvl": "target", "msg": "[    1.125281] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01"}
- {"dt": "2024-09-30T17:39:03.425631", "lvl": "target", "msg": "[    1.125327] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]"}
- {"dt": "2024-09-30T17:39:03.427034", "lvl": "target", "msg": "[    1.125351] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]"}
- {"dt": "2024-09-30T17:39:03.428381", "lvl": "target", "msg": "[    1.125394] pci 0000:00:00.0: PCI bridge to [bus 01]"}
- {"dt": "2024-09-30T17:39:03.462783", "lvl": "target", "msg": "[    1.125418] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]"}
- {"dt": "2024-09-30T17:39:03.464348", "lvl": "target", "msg": "[    1.131387] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled"}
- {"dt": "2024-09-30T17:39:03.467627", "lvl": "target", "msg": "[    1.134098] iproc-rng200 fe104000.rng: hwrng registered"}
- {"dt": "2024-09-30T17:39:03.468905", "lvl": "target", "msg": "[    1.134561] vc-mem: phys_addr:0x00000000 mem_base=0x00000000 mem_size:0x00000000(0 MiB)"}
- {"dt": "2024-09-30T17:39:03.470057", "lvl": "target", "msg": "[    1.135979] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000"}
- {"dt": "2024-09-30T17:39:03.471293", "lvl": "target", "msg": "[    1.148619] brd: module loaded"}
- {"dt": "2024-09-30T17:39:03.472481", "lvl": "target", "msg": "[    1.158182] loop: module loaded"}
- {"dt": "2024-09-30T17:39:03.473658", "lvl": "target", "msg": "[    1.189229] Loading iSCSI transport class v2.0-870."}
- {"dt": "2024-09-30T17:39:03.506506", "lvl": "target", "msg": "[    1.193732] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000"}
- {"dt": "2024-09-30T17:39:03.509696", "lvl": "target", "msg": "[    1.251114] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus"}
- {"dt": "2024-09-30T17:39:03.510933", "lvl": "target", "msg": "[    1.252140] usbcore: registered new interface driver r8152"}
- {"dt": "2024-09-30T17:39:03.512085", "lvl": "target", "msg": "[    1.252221] usbcore: registered new interface driver lan78xx"}
- {"dt": "2024-09-30T17:39:03.513109", "lvl": "target", "msg": "[    1.252237] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"}
- {"dt": "2024-09-30T17:39:03.514126", "lvl": "target", "msg": "[    1.252252] ehci-pci: EHCI PCI platform driver"}
- {"dt": "2024-09-30T17:39:03.515196", "lvl": "target", "msg": "[    1.252312] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"}
- {"dt": "2024-09-30T17:39:03.516416", "lvl": "target", "msg": "[    1.252349] ohci-pci: OHCI PCI platform driver"}
- {"dt": "2024-09-30T17:39:03.550400", "lvl": "target", "msg": "[    1.253875] pci 0000:00:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2024-09-30T17:39:03.553646", "lvl": "target", "msg": "[    1.253916] xhci_hcd 0000:01:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2024-09-30T17:39:03.554842", "lvl": "target", "msg": "[    1.254022] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2024-09-30T17:39:03.556058", "lvl": "target", "msg": "[    1.254053] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1"}
- {"dt": "2024-09-30T17:39:03.557201", "lvl": "target", "msg": "[    1.254753] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0001e40000000890"}
- {"dt": "2024-09-30T17:39:03.558372", "lvl": "target", "msg": "[    1.255512] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2024-09-30T17:39:03.559681", "lvl": "target", "msg": "[    1.255538] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2"}
- {"dt": "2024-09-30T17:39:03.595394", "lvl": "target", "msg": "[    1.255566] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed"}
- {"dt": "2024-09-30T17:39:03.596297", "lvl": "target", "msg": "[    1.255926] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15"}
- {"dt": "2024-09-30T17:39:03.597037", "lvl": "target", "msg": "[    1.255950] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2024-09-30T17:39:03.597781", "lvl": "target", "msg": "[    1.255968] usb usb1: Product: xHCI Host Controller"}
- {"dt": "2024-09-30T17:39:03.598515", "lvl": "target", "msg": "[    1.255984] usb usb1: Manufacturer: Linux 5.15.92-v8 xhci-hcd"}
- {"dt": "2024-09-30T17:39:03.599285", "lvl": "target", "msg": "[    1.256000] usb usb1: SerialNumber: 0000:01:00.0"}
- {"dt": "2024-09-30T17:39:03.600154", "lvl": "target", "msg": "[    1.256704] hub 1-0:1.0: USB hub found"}
- {"dt": "2024-09-30T17:39:03.637551", "lvl": "target", "msg": "[    1.256782] hub 1-0:1.0: 1 port detected"}
- {"dt": "2024-09-30T17:39:03.638846", "lvl": "target", "msg": "[    1.257692] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15"}
- {"dt": "2024-09-30T17:39:03.640141", "lvl": "target", "msg": "[    1.257717] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2024-09-30T17:39:03.641277", "lvl": "target", "msg": "[    1.257736] usb usb2: Product: xHCI Host Controller"}
- {"dt": "2024-09-30T17:39:03.644457", "lvl": "target", "msg": "[    1.257752] usb usb2: Manufacturer: Linux 5.15.92-v8 xhci-hcd"}
- {"dt": "2024-09-30T17:39:03.645759", "lvl": "target", "msg": "[    1.257768] usb usb2: SerialNumber: 0000:01:00.0"}
- {"dt": "2024-09-30T17:39:03.646921", "lvl": "target", "msg": "[    1.258412] hub 2-0:1.0: USB hub found"}
- {"dt": "2024-09-30T17:39:03.648145", "lvl": "target", "msg": "[    1.258480] hub 2-0:1.0: 4 ports detected"}
- {"dt": "2024-09-30T17:39:03.681203", "lvl": "target", "msg": "[    1.260050] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)"}
- {"dt": "2024-09-30T17:39:03.681815", "lvl": "target", "msg": "[    1.260891] usbcore: registered new interface driver uas"}
- {"dt": "2024-09-30T17:39:03.683725", "lvl": "target", "msg": "[    1.260979] usbcore: registered new interface driver usb-storage"}
- {"dt": "2024-09-30T17:39:03.684897", "lvl": "target", "msg": "[    1.261102] usbcore: registered new interface driver usbserial_generic"}
- {"dt": "2024-09-30T17:39:03.685958", "lvl": "target", "msg": "[    1.261137] usbserial: USB Serial support registered for generic"}
- {"dt": "2024-09-30T17:39:03.686764", "lvl": "target", "msg": "[    1.261197] usbcore: registered new interface driver cp210x"}
- {"dt": "2024-09-30T17:39:03.687614", "lvl": "target", "msg": "[    1.261229] usbserial: USB Serial support registered for cp210x"}
- {"dt": "2024-09-30T17:39:03.725342", "lvl": "target", "msg": "[    1.261474] mousedev: PS/2 mouse device common for all mice"}
- {"dt": "2024-09-30T17:39:03.726818", "lvl": "target", "msg": "[    1.262045] usbcore: registered new interface driver i2c-tiny-usb"}
- {"dt": "2024-09-30T17:39:03.730230", "lvl": "target", "msg": "[    1.267311] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2024-09-30T17:39:03.731367", "lvl": "target", "msg": "[    1.267336] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2024-09-30T17:39:03.732001", "lvl": "target", "msg": "[    1.267932] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2024-09-30T17:39:03.732800", "lvl": "target", "msg": "[    1.270334] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2024-09-30T17:39:03.733509", "lvl": "target", "msg": "[    1.270576] hid: raw HID events driver (C) Jiri Kosina"}
- {"dt": "2024-09-30T17:39:03.734131", "lvl": "target", "msg": "[    1.270753] usbcore: registered new interface driver usbhid"}
- {"dt": "2024-09-30T17:39:03.734818", "lvl": "target", "msg": "[    1.270761] usbhid: USB HID core driver"}
- {"dt": "2024-09-30T17:39:03.769264", "lvl": "target", "msg": "[    1.270919] ashmem: initialized"}
- {"dt": "2024-09-30T17:39:03.772221", "lvl": "target", "msg": "[    1.275039] usbcore: registered new interface driver snd-usb-audio"}
- {"dt": "2024-09-30T17:39:03.773361", "lvl": "target", "msg": "[    1.275498] NET: Registered PF_PACKET protocol family"}
- {"dt": "2024-09-30T17:39:03.774413", "lvl": "target", "msg": "[    1.275575] Key type dns_resolver registered"}
- {"dt": "2024-09-30T17:39:03.775512", "lvl": "target", "msg": "[    1.276094] registered taskstats version 1"}
- {"dt": "2024-09-30T17:39:03.776572", "lvl": "target", "msg": "[    1.276113] Loading compiled-in X.509 certificates"}
- {"dt": "2024-09-30T17:39:03.777641", "lvl": "target", "msg": "[    1.276588] Key type .fscrypt registered"}
- {"dt": "2024-09-30T17:39:03.778712", "lvl": "target", "msg": "[    1.276597] Key type fscrypt-provisioning registered"}
- {"dt": "2024-09-30T17:39:03.812541", "lvl": "target", "msg": "[    1.282774] uart-pl011 fe201000.serial: there is not valid maps for state default"}
- {"dt": "2024-09-30T17:39:03.815130", "lvl": "target", "msg": "[    1.282916] uart-pl011 fe201000.serial: cts_event_workaround enabled"}
- {"dt": "2024-09-30T17:39:03.816129", "lvl": "target", "msg": "[    1.283038] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 19, base_baud = 0) is a PL011 rev2"}
- {"dt": "2024-09-30T17:39:03.817063", "lvl": "target", "msg": "[    1.289927] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default"}
- {"dt": "2024-09-30T17:39:03.818025", "lvl": "target", "msg": "[    1.290237] printk: console [ttyS0] disabled"}
- {"dt": "2024-09-30T17:39:03.819038", "lvl": "target", "msg": "[    1.290287] fe215040.serial: ttyS0 at MMIO 0xfe215040 (irq = 20, base_baud = 62500000) is a 16550"}
- {"dt": "2024-09-30T17:39:03.856374", "lvl": "target", "msg": "[    1.530961] usb 1-1: new high-speed USB device number 2 using xhci_hcd"}
- {"dt": "2024-09-30T17:39:03.858085", "lvl": "target", "msg": "[    1.533812] printk: console [ttyS0] enabled"}
- {"dt": "2024-09-30T17:39:03.861351", "lvl": "target", "msg": "[    1.688105] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.20"}
- {"dt": "2024-09-30T17:39:03.862579", "lvl": "target", "msg": "[    1.690539] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer"}
- {"dt": "2024-09-30T17:39:03.863741", "lvl": "target", "msg": "[    1.694752] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0"}
- {"dt": "2024-09-30T17:39:03.864839", "lvl": "target", "msg": "[    1.699530] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver"}
- {"dt": "2024-09-30T17:39:03.865766", "lvl": "target", "msg": "[    1.703921] usb 1-1: Product: USB2.0 Hub"}
- {"dt": "2024-09-30T17:39:03.866555", "lvl": "target", "msg": "[    1.704896] hub 1-1:1.0: USB hub found"}
- {"dt": "2024-09-30T17:39:03.900092", "lvl": "target", "msg": "[    1.708571] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0"}
- {"dt": "2024-09-30T17:39:03.904040", "lvl": "target", "msg": "[    1.714927] hub 1-1:1.0: 4 ports detected"}
- {"dt": "2024-09-30T17:39:03.905551", "lvl": "target", "msg": "[    1.718695] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated"}
- {"dt": "2024-09-30T17:39:03.906897", "lvl": "target", "msg": "[    1.746124] of_cfs_init"}
- {"dt": "2024-09-30T17:39:03.908295", "lvl": "target", "msg": "[    1.813070] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA"}
- {"dt": "2024-09-30T17:39:03.909673", "lvl": "target", "msg": "[    1.816684] of_cfs_init: OK"}
- {"dt": "2024-09-30T17:39:03.911057", "lvl": "target", "msg": "[    1.895101] mmc1: new high speed SDIO card at address 0001"}
- {"dt": "2024-09-30T17:39:03.911676", "lvl": "target", "msg": "[    1.897641] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)"}
- {"dt": "2024-09-30T17:39:03.937528", "lvl": "target", "msg": "[    1.922822] mmc0: new ultra high speed DDR50 SDHC card at address 59b4"}
- {"dt": "2024-09-30T17:39:03.938465", "lvl": "target", "msg": "[    1.924535] bcmgenet fd580000.ethernet eth0: Link is Down"}
- {"dt": "2024-09-30T17:39:03.939243", "lvl": "target", "msg": "[    1.929897] mmcblk0: mmc0:59b4 USDU1 7.51 GiB "}
- {"dt": "2024-09-30T17:39:03.940022", "lvl": "target", "msg": "[    2.042960] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd"}
- {"dt": "2024-09-30T17:39:03.940751", "lvl": "target", "msg": "[    2.843241]  mmcblk0: p1 p2"}
- {"dt": "2024-09-30T17:39:03.942758", "lvl": "target", "msg": "[    2.846346] mmcblk0: mmc0:59b4 USDU1 7.51 GiB"}
- {"dt": "2024-09-30T17:39:04.073871", "lvl": "target", "msg": "[    2.945574] usb 1-1.3: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2024-09-30T17:39:04.075420", "lvl": "target", "msg": "[    2.954080] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2024-09-30T17:39:04.076761", "lvl": "target", "msg": "[    2.961511] usb 1-1.3: Product: USB2.0 Hub             "}
- {"dt": "2024-09-30T17:39:04.078065", "lvl": "target", "msg": "[    2.966819] usb 1-1.3: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2024-09-30T17:39:04.079453", "lvl": "target", "msg": "[    2.973776] hub 1-1.3:1.0: USB hub found"}
- {"dt": "2024-09-30T17:39:04.081010", "lvl": "target", "msg": "[    2.977902] hub 1-1.3:1.0: 4 ports detected"}
- {"dt": "2024-09-30T17:39:04.387532", "lvl": "target", "msg": "[    3.286993] usb 1-1.3.1: new high-speed USB device number 4 using xhci_hcd"}
- {"dt": "2024-09-30T17:39:04.537494", "lvl": "target", "msg": "[    3.408691] usb 1-1.3.1: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2024-09-30T17:39:04.539287", "lvl": "target", "msg": "[    3.417383] usb 1-1.3.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2024-09-30T17:39:04.540791", "lvl": "target", "msg": "[    3.425000] usb 1-1.3.1: Product: USB2.0 Hub             "}
- {"dt": "2024-09-30T17:39:04.542182", "lvl": "target", "msg": "[    3.430500] usb 1-1.3.1: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2024-09-30T17:39:04.543664", "lvl": "target", "msg": "[    3.437843] hub 1-1.3.1:1.0: USB hub found"}
- {"dt": "2024-09-30T17:39:04.545352", "lvl": "target", "msg": "[    3.442292] hub 1-1.3.1:1.0: 4 ports detected"}
- {"dt": "2024-09-30T17:39:04.851975", "lvl": "target", "msg": "[    3.750994] usb 1-1.3.1.1: new high-speed USB device number 5 using xhci_hcd"}
- {"dt": "2024-09-30T17:39:05.005842", "lvl": "target", "msg": "[    3.882553] usb 1-1.3.1.1: New USB device found, idVendor=0bda, idProduct=2838, bcdDevice= 1.00"}
- {"dt": "2024-09-30T17:39:05.007661", "lvl": "target", "msg": "[    3.891420] usb 1-1.3.1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3"}
- {"dt": "2024-09-30T17:39:05.009515", "lvl": "target", "msg": "[    3.899229] usb 1-1.3.1.1: Product: RTL2838UHIDIR"}
- {"dt": "2024-09-30T17:39:05.010511", "lvl": "target", "msg": "[    3.904025] usb 1-1.3.1.1: Manufacturer: Realtek"}
- {"dt": "2024-09-30T17:39:05.011756", "lvl": "target", "msg": "[    3.908729] usb 1-1.3.1.1: SerialNumber: 00000001"}
- {"dt": "2024-09-30T17:39:07.114795", "lvl": "target", "msg": "[    6.015214] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx"}
- {"dt": "2024-09-30T17:39:07.181946", "lvl": "target", "msg": "[    6.042978] Sending DHCP requests ., OK"}
- {"dt": "2024-09-30T17:39:07.186516", "lvl": "target", "msg": "[    6.062976] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.241"}
- {"dt": "2024-09-30T17:39:07.188468", "lvl": "target", "msg": "[    6.071087] IP-Config: Complete:"}
- {"dt": "2024-09-30T17:39:07.190040", "lvl": "target", "msg": "[    6.074364]      device=eth0, hwaddr=dc:a6:32:54:fa:25, ipaddr=192.168.66.241, mask=255.255.255.0, gw=192.168.66.1"}
- {"dt": "2024-09-30T17:39:07.191492", "lvl": "target", "msg": "[    6.084893]      host=192.168.66.241, domain=, nis-domain=(none)"}
- {"dt": "2024-09-30T17:39:07.191916", "lvl": "target", "msg": "[    6.091007]      bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath="}
- {"dt": "2024-09-30T17:39:07.192431", "lvl": "target", "msg": "[    6.091020]      nameserver0=10.1.1.1"}
- {"dt": "2024-09-30T17:39:07.203530", "lvl": "target", "msg": "[    6.102808] ALSA device list:"}
- {"dt": "2024-09-30T17:39:07.204691", "lvl": "target", "msg": "[    6.105895]   No soundcards found."}
- {"dt": "2024-09-30T17:39:07.207749", "lvl": "target", "msg": "[    6.109785] Waiting 7 sec before mounting root device..."}
- {"dt": "2024-09-30T17:39:14.364311", "lvl": "target", "msg": "[   13.279176] RAMDISK: gzip image found at block 0"}
- {"dt": "2024-09-30T17:39:14.596833", "lvl": "target", "msg": "[   13.457191] EXT4-fs (ram0): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none."}
- {"dt": "2024-09-30T17:39:14.599235", "lvl": "target", "msg": "[   13.466776] VFS: Mounted root (ext4 filesystem) on device 1:0."}
- {"dt": "2024-09-30T17:39:14.600619", "lvl": "target", "msg": "[   13.472899] devtmpfs: mounted"}
- {"dt": "2024-09-30T17:39:14.601599", "lvl": "target", "msg": "[   13.480891] Freeing unused kernel memory: 4096K"}
- {"dt": "2024-09-30T17:39:14.602425", "lvl": "target", "msg": "[   13.485602] Run /sbin/init as init process"}
- {"dt": "2024-09-30T17:39:14.603265", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2024-09-30T17:39:14.604094", "lvl": "target", "msg": "         ___   ________                _   __     __  __                __"}
- {"dt": "2024-09-30T17:39:14.605112", "lvl": "target", "msg": "        /   | / ____/ /               / | / /__  / /_/ /_  ____  ____  / /_"}
- {"dt": "2024-09-30T17:39:14.640689", "lvl": "target", "msg": "       / /| |/ / __/ /      ______   /  |/ / _ \\/ __/ __ \\/ __ \\/ __ \\/ __/"}
- {"dt": "2024-09-30T17:39:14.641741", "lvl": "target", "msg": "      / ___ / /_/ / /___   /_____/  / /|  /  __/ /_/ /_/ / /_/ / /_/ / /_"}
- {"dt": "2024-09-30T17:39:14.644151", "lvl": "target", "msg": "     /_/  |_\\____/_____/           /_/ |_/\\___/\\__/_.___/\\____/\\____/\\__/"}
- {"dt": "2024-09-30T17:39:14.644762", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2024-09-30T17:39:14.645217", "lvl": "target", "msg": "/sbin/init[1]: starting initrd script"}
- {"dt": "2024-09-30T17:39:14.645638", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: proc /proc"}
- {"dt": "2024-09-30T17:39:14.646055", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: sysfs /sys"}
- {"dt": "2024-09-30T17:39:14.646561", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devtmpfs /dev"}
- {"dt": "2024-09-30T17:39:14.678151", "lvl": "target", "msg": "/sbin/init[1]: /dev (devtmpfs) already mounted"}
- {"dt": "2024-09-30T17:39:14.678805", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devpts /dev/pts"}
- {"dt": "2024-09-30T17:39:14.679316", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /dev/shm"}
- {"dt": "2024-09-30T17:39:14.679766", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /tmp"}
- {"dt": "2024-09-30T17:39:14.680184", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /run"}
- {"dt": "2024-09-30T17:39:14.682259", "lvl": "target", "msg": "/sbin/init[1]: NBD parameters: device /dev/nbd0, server 192.168.66.1:61994"}
- {"dt": "2024-09-30T17:39:14.682853", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2024-09-30T17:39:14.728531", "lvl": "target", "msg": "[   13.628115] nbd0: detected capacity change from 0 to 7137952"}
- {"dt": "2024-09-30T17:39:14.729182", "lvl": "target", "msg": "/sbin/init[1]: NBD client successfully started"}
- {"dt": "2024-09-30T17:39:15.294501", "lvl": "target", "msg": "[   14.159420] EXT4-fs (nbd0): recovery complete"}
- {"dt": "2024-09-30T17:39:15.295925", "lvl": "target", "msg": "[   14.164841] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none."}
- {"dt": "2024-09-30T17:39:15.297107", "lvl": "target", "msg": "/sbin/init[1]: Moving /dev to new rootfs"}
- {"dt": "2024-09-30T17:39:15.300260", "lvl": "target", "msg": "/sbin/init[1]: Moving /proc to new rootfs"}
- {"dt": "2024-09-30T17:39:15.301561", "lvl": "target", "msg": "/sbin/init[1]: Moving /sys to new rootfs"}
- {"dt": "2024-09-30T17:39:15.302716", "lvl": "target", "msg": "/sbin/init[1]: Moving /tmp to new rootfs"}
- {"dt": "2024-09-30T17:39:15.303924", "lvl": "target", "msg": "/sbin/init[1]: Moving /run to new rootfs"}
- {"dt": "2024-09-30T17:39:15.305041", "lvl": "target", "msg": "/sbin/init[1]: Switching to new rootfs"}
- {"dt": "2024-09-30T17:39:15.879471", "lvl": "target", "msg": "/sbin/init[1]: find_active_interface: first active interface is eth0"}
- {"dt": "2024-09-30T17:39:15.884700", "lvl": "target", "msg": "/sbin/init[1]: Adjusting Connman command line. Will be: 'connmand -r -n -I eth0'"}
- {"dt": "2024-09-30T17:39:15.962267", "lvl": "target", "msg": "/sbin/init[1]: Unmounting /tmp and /run"}
- {"dt": "2024-09-30T17:39:16.098707", "lvl": "target", "msg": "/sbin/init[1]: Exec'ing systemd"}
- {"dt": "2024-09-30T17:39:16.099541", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2024-09-30T17:39:16.101283", "lvl": "target", "msg": "      ___   ________       ____              __  _"}
- {"dt": "2024-09-30T17:39:16.102010", "lvl": "target", "msg": "     /   | / ____/ /      / __ )____  ____  / /_(_)___  ____ _"}
- {"dt": "2024-09-30T17:39:16.102669", "lvl": "target", "msg": "    / /| |/ / __/ /      / __  / __ \\/ __ \\/ __/ / __ \\/ __ `/"}
- {"dt": "2024-09-30T17:39:16.103387", "lvl": "target", "msg": "   / ___ / /_/ / /___   / /_/ / /_/ / /_/ / /_/ / / / / /_/ /   _     _     _"}
- {"dt": "2024-09-30T17:39:16.104074", "lvl": "target", "msg": "  /_/  |_\\____/_____/  /_____/\\____/\\____/\\__/_/_/ /_/\\__, /   (_)   (_)   (_)"}
- {"dt": "2024-09-30T17:39:16.116880", "lvl": "target", "msg": "_____________________________________________________/____/_____________________"}
- {"dt": "2024-09-30T17:39:16.655455", "lvl": "target", "msg": "[   15.554981] systemd[1]: System time before build time, advancing clock."}
- {"dt": "2024-09-30T17:39:16.799051", "lvl": "target", "msg": "[   15.671067] systemd[1]: systemd 250.5+ running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA -SMACK +SECCOMP -GCRYPT -GNUTLS -OPENSSL +ACL +BLKID -CURL -ELFUTILS -FIDO2 -IDN2 -IDN +IPTC +KMOD -LIBCRYPTSETUP +LIBFDISK -PCRE2 -PWQUALITY -P11KIT -QRENCODE -BZIP2 -LZ4 -XZ -ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=hybrid)"}
- {"dt": "2024-09-30T17:39:16.801100", "lvl": "target", "msg": "[   15.703786] systemd[1]: Detected architecture arm64."}
- {"dt": "2024-09-30T17:39:16.856041", "lvl": "target", "msg": "[   15.754997] random: crng init done"}
- {"dt": "2024-09-30T17:39:16.857279", "lvl": "target", "msg": ""}
- {"dt": "2024-09-30T17:39:16.860411", "lvl": "target", "msg": "Welcome to Automotive Grade Linux 17.1.3 (quillback)!"}
- {"dt": "2024-09-30T17:39:16.861386", "lvl": "target", "msg": ""}
- {"dt": "2024-09-30T17:39:16.874246", "lvl": "target", "msg": "[   15.780893] systemd[1]: Hostname set to <h3ulcb>."}
- {"dt": "2024-09-30T17:39:17.434116", "lvl": "target", "msg": "[   16.333754] systemd[1]: Binding to IPv6 address not available since kernel does not support IPv6."}
- {"dt": "2024-09-30T17:39:17.606230", "lvl": "target", "msg": "[   16.505364] systemd[1]: Queued start job for default target Graphical Interface."}
- {"dt": "2024-09-30T17:39:17.648315", "lvl": "target", "msg": "[   16.550388] systemd[1]: Created slice Slice /system/getty."}
- {"dt": "2024-09-30T17:39:17.651824", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/getty."}
- {"dt": "2024-09-30T17:39:17.672175", "lvl": "target", "msg": "[   16.572162] systemd[1]: Created slice Slice /system/modprobe."}
- {"dt": "2024-09-30T17:39:17.672907", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/modprobe."}
- {"dt": "2024-09-30T17:39:17.693141", "lvl": "target", "msg": "[   16.592843] systemd[1]: Created slice Slice /system/serial-getty."}
- {"dt": "2024-09-30T17:39:17.694555", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/serial-getty."}
- {"dt": "2024-09-30T17:39:17.718123", "lvl": "target", "msg": "[   16.617229] systemd[1]: Created slice Slice /system/wireplumber."}
- {"dt": "2024-09-30T17:39:17.719081", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/wireplumber."}
- {"dt": "2024-09-30T17:39:17.789923", "lvl": "target", "msg": "[   16.640755] systemd[1]: Created slice User and Session Slice."}
- {"dt": "2024-09-30T17:39:17.791421", "lvl": "target", "msg": "[  OK  ] Created slice User and Session Slice."}
- {"dt": "2024-09-30T17:39:17.793213", "lvl": "target", "msg": "[   16.659548] systemd[1]: Started Dispatch Password Requests to Console Directory Watch."}
- {"dt": "2024-09-30T17:39:17.794630", "lvl": "target", "msg": "[  OK  ] Started Dispatch Password Requests to Console Directory Watch."}
- {"dt": "2024-09-30T17:39:17.795999", "lvl": "target", "msg": "[   16.683463] systemd[1]: Started Forward Password Requests to Wall Directory Watch."}
- {"dt": "2024-09-30T17:39:17.797175", "lvl": "target", "msg": "[  OK  ] Started Forward Password Requests to Wall Directory Watch."}
- {"dt": "2024-09-30T17:39:17.824434", "lvl": "target", "msg": "[   16.707305] systemd[1]: Reached target Host and Network Name Lookups."}
- {"dt": "2024-09-30T17:39:17.825286", "lvl": "target", "msg": "[  OK  ] Reached target Host and Network Name Lookups."}
- {"dt": "2024-09-30T17:39:17.825922", "lvl": "target", "msg": "[   16.727126] systemd[1]: Reached target Path Units."}
- {"dt": "2024-09-30T17:39:17.827769", "lvl": "target", "msg": "[  OK  ] Reached target Path Units."}
- {"dt": "2024-09-30T17:39:17.844963", "lvl": "target", "msg": "[   16.747158] systemd[1]: Reached target Remote File Systems."}
- {"dt": "2024-09-30T17:39:17.848452", "lvl": "target", "msg": "[  OK  ] Reached target Remote File Systems."}
- {"dt": "2024-09-30T17:39:17.865708", "lvl": "target", "msg": "[   16.767132] systemd[1]: Reached target Slice Units."}
- {"dt": "2024-09-30T17:39:17.869058", "lvl": "target", "msg": "[  OK  ] Reached target Slice Units."}
- {"dt": "2024-09-30T17:39:17.883975", "lvl": "target", "msg": "[   16.787178] systemd[1]: Reached target Swaps."}
- {"dt": "2024-09-30T17:39:17.885161", "lvl": "target", "msg": "[  OK  ] Reached target Swaps."}
- {"dt": "2024-09-30T17:39:17.931044", "lvl": "target", "msg": "[   16.830394] systemd[1]: Listening on Process Core Dump Socket."}
- {"dt": "2024-09-30T17:39:17.931692", "lvl": "target", "msg": "[  OK  ] Listening on Process Core Dump Socket."}
- {"dt": "2024-09-30T17:39:17.954772", "lvl": "target", "msg": "[   16.851552] systemd[1]: Listening on initctl Compatibility Named Pipe."}
- {"dt": "2024-09-30T17:39:17.958057", "lvl": "target", "msg": "[  OK  ] Listening on initctl Compatibility Named Pipe."}
- {"dt": "2024-09-30T17:39:17.976066", "lvl": "target", "msg": "[   16.875846] systemd[1]: Listening on Journal Audit Socket."}
- {"dt": "2024-09-30T17:39:17.978435", "lvl": "target", "msg": "[  OK  ] Listening on Journal Audit Socket."}
- {"dt": "2024-09-30T17:39:18.011772", "lvl": "target", "msg": "[   16.895916] systemd[1]: Listening on Journal Socket (/dev/log)."}
- {"dt": "2024-09-30T17:39:18.012480", "lvl": "target", "msg": "[  OK  ] Listening on Journal Socket (/dev/log)."}
- {"dt": "2024-09-30T17:39:18.014744", "lvl": "target", "msg": "[   16.915984] systemd[1]: Listening on Journal Socket."}
- {"dt": "2024-09-30T17:39:18.015648", "lvl": "target", "msg": "[  OK  ] Listening on Journal Socket."}
- {"dt": "2024-09-30T17:39:18.039599", "lvl": "target", "msg": "[   16.936176] systemd[1]: Listening on Network Service Netlink Socket."}
- {"dt": "2024-09-30T17:39:18.040801", "lvl": "target", "msg": "[  OK  ] Listening on Network Service Netlink Socket."}
- {"dt": "2024-09-30T17:39:18.080521", "lvl": "target", "msg": "[   16.961549] systemd[1]: Listening on udev Control Socket."}
- {"dt": "2024-09-30T17:39:18.081150", "lvl": "target", "msg": "[  OK  ] Listening on udev Control Socket."}
- {"dt": "2024-09-30T17:39:18.082363", "lvl": "target", "msg": "[   16.979848] systemd[1]: Listening on udev Kernel Socket."}
- {"dt": "2024-09-30T17:39:18.083267", "lvl": "target", "msg": "[  OK  ] Listening on udev Kernel Socket."}
- {"dt": "2024-09-30T17:39:18.138467", "lvl": "target", "msg": "[   16.999848] systemd[1]: Listening on User Database Manager Socket."}
- {"dt": "2024-09-30T17:39:18.139521", "lvl": "target", "msg": "[  OK  ] Listening on User Database Manager Socket."}
- {"dt": "2024-09-30T17:39:18.141747", "lvl": "target", "msg": "[   17.019945] systemd[1]: Huge Pages File System was skipped because of a failed condition check (ConditionPathExists=/sys/kernel/mm/hugepages)."}
- {"dt": "2024-09-30T17:39:18.142367", "lvl": "target", "msg": "[   17.038339] systemd[1]: Mounting POSIX Message Queue File System..."}
- {"dt": "2024-09-30T17:39:18.142909", "lvl": "target", "msg": "         Mounting POSIX Message Queue File System..."}
- {"dt": "2024-09-30T17:39:18.163441", "lvl": "target", "msg": "[   17.062621] systemd[1]: Mounting Kernel Debug File System..."}
- {"dt": "2024-09-30T17:39:18.164397", "lvl": "target", "msg": "         Mounting Kernel Debug File System..."}
- {"dt": "2024-09-30T17:39:18.188054", "lvl": "target", "msg": "[   17.088261] systemd[1]: Mounting Kernel Trace File System..."}
- {"dt": "2024-09-30T17:39:18.189111", "lvl": "target", "msg": "         Mounting Kernel Trace File System..."}
- {"dt": "2024-09-30T17:39:18.219002", "lvl": "target", "msg": "[   17.117905] systemd[1]: Mounting Temporary Directory /tmp..."}
- {"dt": "2024-09-30T17:39:18.220309", "lvl": "target", "msg": "         Mounting Temporary Directory /tmp..."}
- {"dt": "2024-09-30T17:39:18.265353", "lvl": "target", "msg": "[   17.143834] systemd[1]: Create List of Static Device Nodes was skipped because of a failed condition check (ConditionFileNotEmpty=/lib/modules/5.15.92-v8/modules.devname)."}
- {"dt": "2024-09-30T17:39:18.266678", "lvl": "target", "msg": "[   17.164811] systemd[1]: Starting Load Kernel Module configfs..."}
- {"dt": "2024-09-30T17:39:18.268020", "lvl": "target", "msg": "         Starting Load Kernel Module configfs..."}
- {"dt": "2024-09-30T17:39:18.289937", "lvl": "target", "msg": "[   17.192331] systemd[1]: Starting Load Kernel Module drm..."}
- {"dt": "2024-09-30T17:39:18.292599", "lvl": "target", "msg": "         Starting Load Kernel Module drm..."}
- {"dt": "2024-09-30T17:39:18.314452", "lvl": "target", "msg": "[   17.216508] systemd[1]: Starting Load Kernel Module fuse..."}
- {"dt": "2024-09-30T17:39:18.317730", "lvl": "target", "msg": "         Starting Load Kernel Module fuse..."}
- {"dt": "2024-09-30T17:39:18.344624", "lvl": "target", "msg": "[   17.240597] systemd[1]: Starting Start psplash boot splash screen..."}
- {"dt": "2024-09-30T17:39:18.346002", "lvl": "target", "msg": "         Starting Start psplash boot splash screen..."}
- {"dt": "2024-09-30T17:39:18.375425", "lvl": "target", "msg": "[   17.271173] systemd[1]: Starting SELinux autorelabel service loading..."}
- {"dt": "2024-09-30T17:39:18.378751", "lvl": "target", "msg": "         Starting SELinux autorelabel service loading..."}
- {"dt": "2024-09-30T17:39:18.406037", "lvl": "target", "msg": "[   17.302690] systemd[1]: Starting SELinux init for /dev service loading..."}
- {"dt": "2024-09-30T17:39:18.409171", "lvl": "target", "msg": "         Starting SELinux init for /dev service loading..."}
- {"dt": "2024-09-30T17:39:18.456159", "lvl": "target", "msg": "[   17.350410] systemd[1]: Rebuild Hardware Database was skipped because of a failed condition check (ConditionNeedsUpdate=/etc)."}
- {"dt": "2024-09-30T17:39:18.479917", "lvl": "target", "msg": "[   17.381844] systemd[1]: Starting Journal Service..."}
- {"dt": "2024-09-30T17:39:18.483233", "lvl": "target", "msg": "         Starting Journal Service..."}
- {"dt": "2024-09-30T17:39:18.582061", "lvl": "target", "msg": "[   17.483409] systemd[1]: Starting Load Kernel Modules..."}
- {"dt": "2024-09-30T17:39:18.585420", "lvl": "target", "msg": "         Starting Load Kernel Modules..."}
- {"dt": "2024-09-30T17:39:18.635998", "lvl": "target", "msg": "[   17.503487] systemd[1]: Platform Persistent Storage Archival was skipped because of a failed condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore)."}
- {"dt": "2024-09-30T17:39:18.636832", "lvl": "target", "msg": "[   17.518240] systemd[1]: Create System Users was skipped because of a failed condition check (ConditionNeedsUpdate=/etc)."}
- {"dt": "2024-09-30T17:39:18.637557", "lvl": "target", "msg": "[   17.532954] systemd[1]: Starting Create Static Device Nodes in /dev..."}
- {"dt": "2024-09-30T17:39:18.639059", "lvl": "target", "msg": "         Starting Create Static Device Nodes in /dev..."}
- {"dt": "2024-09-30T17:39:18.658949", "lvl": "target", "msg": "[   17.558844] systemd[1]: Starting Coldplug All udev Devices..."}
- {"dt": "2024-09-30T17:39:18.659900", "lvl": "target", "msg": "         Starting Coldplug All udev Devices..."}
- {"dt": "2024-09-30T17:39:18.712510", "lvl": "target", "msg": "[   17.579238] systemd[1]: Bind mount volatile /var/cache was skipped because of a failed condition check (ConditionPathIsReadWrite=!/var/cache)."}
- {"dt": "2024-09-30T17:39:18.714007", "lvl": "target", "msg": "[   17.592479] systemd[1]: Bind mount volatile /var/lib was skipped because of a failed condition check (ConditionPathIsReadWrite=!/var/lib)."}
- {"dt": "2024-09-30T17:39:18.714526", "lvl": "target", "msg": "[   17.608716] systemd[1]: Starting Load/Save Random Seed..."}
- {"dt": "2024-09-30T17:39:18.714991", "lvl": "target", "msg": "         Starting Load/Save Random Seed..."}
- {"dt": "2024-09-30T17:39:18.772178", "lvl": "target", "msg": "[   17.627198] systemd[1]: Bind mount volatile /var/spool was skipped because of a failed condition check (ConditionPathIsReadWrite=!/var/spool)."}
- {"dt": "2024-09-30T17:39:18.773674", "lvl": "target", "msg": "[   17.640552] systemd[1]: Bind mount volatile /srv was skipped because of a failed condition check (ConditionPathIsReadWrite=!/srv)."}
- {"dt": "2024-09-30T17:39:18.774188", "lvl": "target", "msg": "[   17.659071] systemd[1]: Started Journal Service."}
- {"dt": "2024-09-30T17:39:18.774620", "lvl": "target", "msg": "[  OK  ] Started Journal Service."}
- {"dt": "2024-09-30T17:39:18.775969", "lvl": "target", "msg": "[   17.675583] audit: type=1130 audit(1724682492.127:2): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-journald comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2024-09-30T17:39:18.790746", "lvl": "target", "msg": "[  OK  ] Mounted POSIX Message Queue File System."}
- {"dt": "2024-09-30T17:39:18.805820", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Debug File System."}
- {"dt": "2024-09-30T17:39:18.822856", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Trace File System."}
- {"dt": "2024-09-30T17:39:18.837899", "lvl": "target", "msg": "[  OK  ] Mounted Temporary Directory /tmp."}
- {"dt": "2024-09-30T17:39:18.870611", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module configfs."}
- {"dt": "2024-09-30T17:39:18.916778", "lvl": "target", "msg": "[   17.787293] audit: type=1130 audit(1724682492.239:3): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@configfs comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2024-09-30T17:39:18.919297", "lvl": "target", "msg": "[   17.806508] audit: type=1131 audit(1724682492.239:4): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@configfs comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2024-09-30T17:39:18.919797", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module drm."}
- {"dt": "2024-09-30T17:39:18.970437", "lvl": "target", "msg": "[   17.839333] audit: type=1130 audit(1724682492.291:5): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@drm comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2024-09-30T17:39:18.971203", "lvl": "target", "msg": "[   17.858107] audit: type=1131 audit(1724682492.291:6): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@drm comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2024-09-30T17:39:18.973958", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module fuse."}
- {"dt": "2024-09-30T17:39:19.022947", "lvl": "target", "msg": "[   17.891442] audit: type=1130 audit(1724682492.343:7): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@fuse comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2024-09-30T17:39:19.023617", "lvl": "target", "msg": "[   17.910286] audit: type=1131 audit(1724682492.343:8): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@fuse comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2024-09-30T17:39:19.025692", "lvl": "target", "msg": "[FAILED] Failed to start Start psplash boot splash screen."}
- {"dt": "2024-09-30T17:39:19.040691", "lvl": "target", "msg": "See 'systemctl status psplash-start.service' for details."}
- {"dt": "2024-09-30T17:39:19.058836", "lvl": "target", "msg": "[DEPEND] Dependency failed for Start psplash\u2026emd progress communication helper."}
- {"dt": "2024-09-30T17:39:19.093011", "lvl": "target", "msg": "[   17.979877] audit: type=1130 audit(1724682492.431:9): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=psplash-start comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=failed'"}
- {"dt": "2024-09-30T17:39:19.094707", "lvl": "target", "msg": "[  OK  ] Finished SELinux autorelabel service loading."}
- {"dt": "2024-09-30T17:39:19.136848", "lvl": "target", "msg": "[   18.015317] audit: type=1130 audit(1724682492.467:10): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=selinux-autorelabel comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2024-09-30T17:39:19.137505", "lvl": "target", "msg": "[   18.034781] audit: type=1131 audit(1724682492.467:11): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=selinux-autorelabel comm=\\\"systemd\\\" exe=\\\"/usr/lib/systemd/systemd\\\" hostname=? addr=? terminal=? res=success'"}
- {"dt": "2024-09-30T17:39:19.154459", "lvl": "target", "msg": "[  OK  ] Finished SELinux init for /dev service loading."}
- {"dt": "2024-09-30T17:39:19.180715", "lvl": "target", "msg": "[FAILED] Failed to start Load Kernel Modules."}
- {"dt": "2024-09-30T17:39:19.183611", "lvl": "target", "msg": "See 'systemctl status systemd-modules-load.service' for details."}
- {"dt": "2024-09-30T17:39:19.199378", "lvl": "target", "msg": "[  OK  ] Finished Create Static Device Nodes in /dev."}
- {"dt": "2024-09-30T17:39:19.215201", "lvl": "target", "msg": "[  OK  ] Finished Load/Save Random Seed."}
- {"dt": "2024-09-30T17:39:19.231338", "lvl": "target", "msg": "[  OK  ] Reached target Local File Systems."}
- {"dt": "2024-09-30T17:39:19.247292", "lvl": "target", "msg": "         Mounting Kernel Configuration File System..."}
- {"dt": "2024-09-30T17:39:19.278233", "lvl": "target", "msg": "         Starting SELinux resolv.conf relabeling..."}
- {"dt": "2024-09-30T17:39:19.295052", "lvl": "target", "msg": "         Starting SELinux init service loading..."}
- {"dt": "2024-09-30T17:39:19.311041", "lvl": "target", "msg": "         Starting Flush Journal to Persistent Storage..."}
- {"dt": "2024-09-30T17:39:19.342281", "lvl": "target", "msg": "         Starting Apply Kernel Variables..."}
- {"dt": "2024-09-30T17:39:19.374155", "lvl": "target", "msg": "         Starting Rule-based Manager for Device Events and Files[   18.273526] systemd-journald[198]: Received client request to flush runtime journal."}
- {"dt": "2024-09-30T17:39:19.374845", "lvl": "target", "msg": "..."}
- {"dt": "2024-09-30T17:39:19.389940", "lvl": "target", "msg": "[  OK  ] Finished Coldplug All udev Devices."}
- {"dt": "2024-09-30T17:39:19.405799", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Configuration File System."}
- {"dt": "2024-09-30T17:39:19.421892", "lvl": "target", "msg": "[  OK  ] Finished SELinux resolv.conf relabeling."}
- {"dt": "2024-09-30T17:39:19.437821", "lvl": "target", "msg": "[  OK  ] Finished SELinux init service loading."}
- {"dt": "2024-09-30T17:39:19.469802", "lvl": "target", "msg": "[  OK  ] Finished Flush Journal to Persistent Storage."}
- {"dt": "2024-09-30T17:39:19.484950", "lvl": "target", "msg": "         Starting Create Volatile Files and Directories..."}
- {"dt": "2024-09-30T17:39:19.514879", "lvl": "target", "msg": "         Starting Wait for udev To Complete Device Initialization..."}
- {"dt": "2024-09-30T17:39:19.530688", "lvl": "target", "msg": "[  OK  ] Finished Apply Kernel Variables."}
- {"dt": "2024-09-30T17:39:19.562669", "lvl": "target", "msg": "[  OK  ] Finished Create Volatile Files and Directories."}
- {"dt": "2024-09-30T17:39:19.577952", "lvl": "target", "msg": "         Starting Security Auditing Service..."}
- {"dt": "2024-09-30T17:39:20.121517", "lvl": "target", "msg": "[  OK  ] Started Security Auditing Service."}
- {"dt": "2024-09-30T17:39:20.137182", "lvl": "target", "msg": "         Starting Record System Boot/Shutdown in UTMP..."}
- {"dt": "2024-09-30T17:39:20.219249", "lvl": "target", "msg": "[  OK  ] Finished Record System Boot/Shutdown in UTMP."}
- {"dt": "2024-09-30T17:39:20.879592", "lvl": "target", "msg": "[  OK  ] Started Rule-based Manager for Device Events and Files."}
- {"dt": "2024-09-30T17:39:21.662202", "lvl": "target", "msg": "[  OK  ] Finished Wait for udev To Complete Device Initialization."}
- {"dt": "2024-09-30T17:39:21.901002", "lvl": "target", "msg": "[  OK  ] Started Hardware RNG Entropy Gatherer Daemon."}
- {"dt": "2024-09-30T17:39:21.916969", "lvl": "target", "msg": "[  OK  ] Reached target System Initialization."}
- {"dt": "2024-09-30T17:39:21.933011", "lvl": "target", "msg": "[  OK  ] Started Daily Cleanup of Temporary Directories."}
- {"dt": "2024-09-30T17:39:21.949839", "lvl": "target", "msg": "[  OK  ] Reached target Timer Units."}
- {"dt": "2024-09-30T17:39:21.973196", "lvl": "target", "msg": "[  OK  ] Listening on agl-compositor, a Wayl\u2026ositor, as a systemd user service."}
- {"dt": "2024-09-30T17:39:22.001010", "lvl": "target", "msg": "[  OK  ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket."}
- {"dt": "2024-09-30T17:39:22.004304", "lvl": "target", "msg": "[  OK  ] Listening on D-Bus System Message Bus Socket."}
- {"dt": "2024-09-30T17:39:22.033064", "lvl": "target", "msg": "[  OK  ] Listening on GPS (Global Positioning System) Daemon Sockets."}
- {"dt": "2024-09-30T17:39:22.048183", "lvl": "target", "msg": "[  OK  ] Listening on mpd.socket."}
- {"dt": "2024-09-30T17:39:22.073642", "lvl": "target", "msg": "         Starting PipeWire Multimedia System Manager Socket..."}
- {"dt": "2024-09-30T17:39:22.092933", "lvl": "target", "msg": "         Starting PipeWire Multimedia System Socket..."}
- {"dt": "2024-09-30T17:39:22.107773", "lvl": "target", "msg": "         Starting sshd.socket..."}
- {"dt": "2024-09-30T17:39:22.130873", "lvl": "target", "msg": "[  OK  ] Listening on PipeWire Multimedia System Manager Socket."}
- {"dt": "2024-09-30T17:39:22.145673", "lvl": "target", "msg": "[  OK  ] Listening on PipeWire Multimedia System Socket."}
- {"dt": "2024-09-30T17:39:22.193618", "lvl": "target", "msg": "[  OK  ] Listening on sshd.socket."}
- {"dt": "2024-09-30T17:39:22.209545", "lvl": "target", "msg": "[  OK  ] Reached target Socket Units."}
- {"dt": "2024-09-30T17:39:22.225786", "lvl": "target", "msg": "[  OK  ] Reached target Basic System."}
- {"dt": "2024-09-30T17:39:22.258578", "lvl": "target", "msg": "         Starting CAN interface helper..."}
- {"dt": "2024-09-30T17:39:22.273713", "lvl": "target", "msg": "         Starting D-Bus System Message Bus..."}
- {"dt": "2024-09-30T17:39:22.289596", "lvl": "target", "msg": "         Starting IPv6 Packet Filtering Framework..."}
- {"dt": "2024-09-30T17:39:22.321835", "lvl": "target", "msg": "         Starting IPv4 Packet Filtering Framework..."}
- {"dt": "2024-09-30T17:39:22.337464", "lvl": "target", "msg": "         Starting Telephony service..."}
- {"dt": "2024-09-30T17:39:22.354426", "lvl": "target", "msg": "[  OK  ] Started PipeWire Multimedia Service."}
- {"dt": "2024-09-30T17:39:22.370416", "lvl": "target", "msg": "         Starting Authorization Manager..."}
- {"dt": "2024-09-30T17:39:22.402628", "lvl": "target", "msg": "         Starting User Login Management..."}
- {"dt": "2024-09-30T17:39:22.418516", "lvl": "target", "msg": "         Starting Disk Manager..."}
- {"dt": "2024-09-30T17:39:22.434343", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager."}
- {"dt": "2024-09-30T17:39:22.464249", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager (bluetooth)."}
- {"dt": "2024-09-30T17:39:22.479252", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager (policy)."}
- {"dt": "2024-09-30T17:39:22.512184", "lvl": "target", "msg": "         Starting OpenSSH Key Generation..."}
- {"dt": "2024-09-30T17:39:22.783632", "lvl": "target", "msg": "[  OK  ] Finished IPv4 Packet Filtering Framework."}
- {"dt": "2024-09-30T17:39:22.799422", "lvl": "target", "msg": "[  OK  ] Finished IPv6 Packet Filtering Framework."}
- {"dt": "2024-09-30T17:39:22.815114", "lvl": "target", "msg": "[  OK  ] Reached target Preparation for Network."}
- {"dt": "2024-09-30T17:39:22.831415", "lvl": "target", "msg": "         Starting Network Configuration..."}
- {"dt": "2024-09-30T17:39:22.879629", "lvl": "target", "msg": "[  OK  ] Finished OpenSSH Key Generation."}
- {"dt": "2024-09-30T17:39:23.805706", "lvl": "target", "msg": "[  OK  ] Finished CAN interface helper."}
- {"dt": "2024-09-30T17:39:24.157159", "lvl": "target", "msg": "[  OK  ] Started Network Configuration."}
- {"dt": "2024-09-30T17:39:24.477783", "lvl": "target", "msg": "[  OK  ] Started D-Bus System Message Bus."}
- {"dt": "2024-09-30T17:39:24.509734", "lvl": "target", "msg": "         Starting Connection service..."}
- {"dt": "2024-09-30T17:39:24.556893", "lvl": "target", "msg": "[  OK  ] Started Telephony service."}
- {"dt": "2024-09-30T17:39:24.573669", "lvl": "target", "msg": "[  OK  ] Started User Login Management."}
- {"dt": "2024-09-30T17:39:24.781201", "lvl": "target", "msg": "[  OK  ] Started Authorization Manager."}
- {"dt": "2024-09-30T17:39:25.898876", "lvl": "target", "msg": "[  OK  ] Started Connection service."}
- {"dt": "2024-09-30T17:39:25.915814", "lvl": "target", "msg": "[  OK  ] Reached target Network."}
- {"dt": "2024-09-30T17:39:25.930932", "lvl": "target", "msg": "[  OK  ] Started agl-service-radio.service."}
- {"dt": "2024-09-30T17:39:25.947825", "lvl": "target", "msg": "         Starting applaunchd.service..."}
- {"dt": "2024-09-30T17:39:25.963745", "lvl": "target", "msg": "         Starting Avahi mDNS/DNS-SD Stack..."}
- {"dt": "2024-09-30T17:39:26.042756", "lvl": "target", "msg": "[  OK  ] Started Eclipse KUKSA.val databroker."}
- {"dt": "2024-09-30T17:39:26.059197", "lvl": "target", "msg": "[  OK  ] Started agl-service-audiomixer.service."}
- {"dt": "2024-09-30T17:39:26.091537", "lvl": "target", "msg": "[  OK  ] Started agl-service-hvac.service."}
- {"dt": "2024-09-30T17:39:26.123533", "lvl": "target", "msg": "         Starting agl-vss-helper.service..."}
- {"dt": "2024-09-30T17:39:26.138738", "lvl": "target", "msg": "[  OK  ] Started Eclipse KUKSA.val DBC feeder."}
- {"dt": "2024-09-30T17:39:26.154875", "lvl": "target", "msg": "         Starting Permit User Sessions..."}
- {"dt": "2024-09-30T17:39:26.267460", "lvl": "target", "msg": "[  OK  ] Finished Permit User Sessions."}
- {"dt": "2024-09-30T17:39:26.299318", "lvl": "target", "msg": "         Starting AGL compositor..."}
- {"dt": "2024-09-30T17:39:26.314514", "lvl": "target", "msg": "[  OK  ] Started Getty on tty1."}
- {"dt": "2024-09-30T17:39:26.346667", "lvl": "target", "msg": "[  OK  ] Started Serial Getty on ttyS0."}
- {"dt": "2024-09-30T17:39:26.348132", "lvl": "target", "msg": "[  OK  ] Reached target Login Prompts."}
- {"dt": "2024-09-30T17:39:26.778755", "lvl": "target", "msg": "[  OK  ] Started Avahi mDNS/DNS-SD Stack."}
- {"dt": "2024-09-30T17:39:27.049867", "lvl": "target", "msg": "         Starting Hostname Service..."}
- {"dt": "2024-09-30T17:39:27.065863", "lvl": "target", "msg": "         Starting WPA supplicant..."}
- {"dt": "2024-09-30T17:39:27.529460", "lvl": "target", "msg": "         Starting User Database Manager..."}
- {"dt": "2024-09-30T17:39:27.593841", "lvl": "target", "msg": "[  OK  ] Started Hostname Service."}
- {"dt": "2024-09-30T17:39:27.848959", "lvl": "target", "msg": "[  OK  ] Started WPA supplicant."}
- {"dt": "2024-09-30T17:39:27.881643", "lvl": "target", "msg": "[  OK  ] Started User Database Manager."}
- {"dt": "2024-09-30T17:39:28.169245", "lvl": "target", "msg": "[  OK  ] Created slice User Slice of UID 1001."}
- {"dt": "2024-09-30T17:39:28.200298", "lvl": "target", "msg": "         Starting User Runtime Directory /run/user/1001..."}
- {"dt": "2024-09-30T17:39:28.281135", "lvl": "target", "msg": "[  OK  ] Finished User Runtime Directory /run/user/1001."}
- {"dt": "2024-09-30T17:39:28.328852", "lvl": "target", "msg": "         Starting User Manager for UID 1001..."}
- {"dt": "2024-09-30T17:39:28.679680", "lvl": "target", "msg": "[  OK  ] Started Disk Manager."}
- {"dt": "2024-09-30T17:39:28.711983", "lvl": "target", "msg": "[  OK  ] Started Automount Disk Manager."}
- {"dt": "2024-09-30T17:39:29.591510", "lvl": "target", "msg": "[  OK  ] Started User Manager for UID 1001."}
- {"dt": "2024-09-30T17:39:29.622641", "lvl": "target", "msg": "[  OK  ] Started Session c1 of User agl-driver."}
- {"dt": "2024-09-30T17:39:31.056808", "lvl": "target", "msg": "[FAILED] Failed to start AGL compositor."}
- {"dt": "2024-09-30T17:39:31.060706", "lvl": "target", "msg": "See 'systemctl status agl-compositor.service' for details."}
- {"dt": "2024-09-30T17:39:31.074898", "lvl": "target", "msg": "[DEPEND] Dependency failed for homescreen.service."}
- {"dt": "2024-09-30T17:39:31.091155", "lvl": "target", "msg": "[DEPEND] Dependency failed for launcher.service."}
- {"dt": "2024-09-30T17:39:33.105383", "lvl": "target", "msg": ""}
- {"dt": "2024-09-30T17:39:33.120365", "lvl": "target", "msg": "Automotive Grade Linux 17.1.3 h3ulcb ttyS0"}
- {"dt": "2024-09-30T17:39:33.121226", "lvl": "target", "msg": ""}
- {"dt": "2024-09-30T17:39:33.123461", "lvl": "debug", "msg": "Matched prompt #13: login:"}
- {"dt": "2024-09-30T17:39:33.124327", "lvl": "results", "msg": {"case": "kernel-messages", "definition": "lava", "duration": "30.70", "extra": {"extra": []}, "level": "2.4.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:39:33.125643", "lvl": "debug", "msg": "Sending username root"}
- {"dt": "2024-09-30T17:39:33.126257", "lvl": "input", "msg": "root\n"}
- {"dt": "2024-09-30T17:39:33.227241", "lvl": "target", "msg": "h3ulcb login: root"}
- {"dt": "2024-09-30T17:39:33.228059", "lvl": "debug", "msg": "Setting prompt string to ['root@raspberrypi4-64:~', 'raspberrypi4-64:~#', '/ #']"}
- {"dt": "2024-09-30T17:39:33.228775", "lvl": "debug", "msg": "login-action: Wait for prompt ['root@raspberrypi4-64:~', 'raspberrypi4-64:~#', '/ #', 'Login incorrect', 'Login timed out'] (timeout 00:18:43)"}
- {"dt": "2024-09-30T17:39:33.233219", "lvl": "target", "msg": "root"}
- {"dt": "2024-09-30T17:39:38.937132", "lvl": "target", "msg": "7[r[999;999H[6nroot@h3ulcb:~# [   37.855036] cam-dummy-reg: disabling"}
- {"dt": "2024-09-30T17:43:04.485092", "lvl": "target", "msg": "[  243.390807] block nbd0: Receive control failed (result -32)"}
- {"dt": "2024-09-30T17:43:04.488680", "lvl": "target", "msg": "[  243.396648] block nbd0: shutting down sockets"}
- {"dt": "2024-09-30T17:43:04.553760", "lvl": "target", "msg": "[  243.429253] blk_update_request: I/O error, dev nbd0, sector 3137232 op 0x0:(READ) flags 0x80700 phys_seg 4 prio class 0"}
- {"dt": "2024-09-30T17:43:04.554753", "lvl": "target", "msg": "[  243.440397] blk_update_request: I/O error, dev nbd0, sector 3137232 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:04.555305", "lvl": "target", "msg": "[  243.451656] blk_update_request: I/O error, dev nbd0, sector 3137232 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:04.557351", "lvl": "target", "msg": "[  243.462884] blk_update_request: I/O error, dev nbd0, sector 3137232 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:04.598749", "lvl": "target", "msg": "[  243.479188] blk_update_request: I/O error, dev nbd0, sector 3137232 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:04.599443", "lvl": "target", "msg": "[  243.489838] blk_update_request: I/O error, dev nbd0, sector 336696 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:04.599856", "lvl": "target", "msg": "[  243.500722] blk_update_request: I/O error, dev nbd0, sector 3137232 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:04.601939", "lvl": "target", "msg": "[  243.500781] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.644641", "lvl": "target", "msg": "[  243.523199] blk_update_request: I/O error, dev nbd0, sector 3137232 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:04.646570", "lvl": "target", "msg": "[  243.534571] blk_update_request: I/O error, dev nbd0, sector 351272 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:04.647100", "lvl": "target", "msg": "[  243.545515] blk_update_request: I/O error, dev nbd0, sector 3137232 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:04.647965", "lvl": "target", "msg": "[  243.545517] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #826: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.688403", "lvl": "target", "msg": "[  243.567715] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #57186: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.689496", "lvl": "target", "msg": "[  243.579469] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.690333", "lvl": "target", "msg": "[  243.591116] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.691893", "lvl": "target", "msg": "[  243.602607] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #56623: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.734445", "lvl": "target", "msg": "[  243.614307] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.736526", "lvl": "target", "msg": "[  243.623934] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #47895: comm python3: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.737777", "lvl": "target", "msg": "[  243.627208] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #20: comm systemd-udevd: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.739285", "lvl": "target", "msg": "[  243.636764] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #47895: comm python3: reading directory lblock 0"}
- {"dt": "2024-09-30T17:43:04.781490", "lvl": "target", "msg": "[  243.659903] EXT4-fs warning (device nbd0): dx_probe:818: inode #840: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:04.782125", "lvl": "target", "msg": "[  243.674810] EXT4-fs warning (device nbd0): dx_probe:818: inode #840: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:04.782523", "lvl": "target", "msg": "[  243.686499] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:04.826829", "lvl": "target", "msg": "[  243.698684] EXT4-fs warning (device nbd0): dx_probe:818: inode #840: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:04.828020", "lvl": "target", "msg": "[  243.710251] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:04.829441", "lvl": "target", "msg": "[  243.722346] EXT4-fs warning (device nbd0): dx_probe:818: inode #840: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:04.830459", "lvl": "target", "msg": "[  243.733910] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:04.869827", "lvl": "target", "msg": "[  243.745971] EXT4-fs warning (device nbd0): dx_probe:818: inode #840: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:04.871610", "lvl": "target", "msg": "[  243.757534] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:04.873848", "lvl": "target", "msg": "[  243.769593] EXT4-fs warning (device nbd0): dx_probe:818: inode #840: lblock 0: comm python3: error -5 reading directory block"}
- {"dt": "2024-09-30T17:43:05.306284", "lvl": "target", "msg": "[  244.182238] systemd-journald[198]: Data hash table of /run/log/journal/018026dec74c47b5b2d835fb346a07b9/system.journal has a fill level at 75.0 (10923 of 14563 items, 8388608 file size, 767 bytes per hash table item), suggesting rotation."}
- {"dt": "2024-09-30T17:43:05.309786", "lvl": "target", "msg": "[  244.203816] systemd-journald[198]: /run/log/journal/018026dec74c47b5b2d835fb346a07b9/system.journal: Journal header limits reached or header out-of-date, rotating."}
- {"dt": "2024-09-30T17:43:07.089670", "lvl": "target", "msg": "[  245.983275] Aborting journal on device nbd0-8."}
- {"dt": "2024-09-30T17:43:07.092371", "lvl": "target", "msg": "[  245.987949] Buffer I/O error on dev nbd0, logical block 393216, lost sync page write"}
- {"dt": "2024-09-30T17:43:07.094336", "lvl": "target", "msg": "[  245.995976] JBD2: Error -5 detected when updating journal superblock for nbd0-8."}
- {"dt": "2024-09-30T17:43:10.177742", "lvl": "target", "msg": "[  249.055150] print_req_error: 214 callbacks suppressed"}
- {"dt": "2024-09-30T17:43:10.179697", "lvl": "target", "msg": "[  249.055168] blk_update_request: I/O error, dev nbd0, sector 5247096 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:43:10.182463", "lvl": "target", "msg": "[  249.071070] EXT4-fs warning: 20 callbacks suppressed"}
- {"dt": "2024-09-30T17:43:10.184195", "lvl": "target", "msg": "[  249.071079] EXT4-fs warning (device nbd0): ext4_end_bio:344: I/O error 10 writing to inode 75904 starting block 655888)"}
- {"dt": "2024-09-30T17:43:10.186055", "lvl": "target", "msg": "[  249.087110] Buffer I/O error on device nbd0, logical block 655887"}
- {"dt": "2024-09-30T17:44:52.326900", "lvl": "target", "msg": "[  351.204533] blk_update_request: I/O error, dev nbd0, sector 336696 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.328835", "lvl": "target", "msg": "[  351.215415] EXT4-fs error: 136 callbacks suppressed"}
- {"dt": "2024-09-30T17:44:52.330594", "lvl": "target", "msg": "[  351.215432] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #20: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.332093", "lvl": "target", "msg": "[  351.231887] blk_update_request: I/O error, dev nbd0, sector 336696 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.333823", "lvl": "target", "msg": "[  351.242681] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.370521", "lvl": "target", "msg": "[  351.242687] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #20: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.373233", "lvl": "target", "msg": "[  351.253146] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.374886", "lvl": "target", "msg": "[  351.271976] blk_update_request: I/O error, dev nbd0, sector 3652120 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.376121", "lvl": "target", "msg": "[  351.282860] blk_update_request: I/O error, dev nbd0, sector 336696 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.413577", "lvl": "target", "msg": "[  351.282887] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #56623: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.414416", "lvl": "target", "msg": "[  351.293685] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:44:52.415855", "lvl": "target", "msg": "[  351.311241] blk_update_request: I/O error, dev nbd0, sector 3652120 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.416955", "lvl": "target", "msg": "[  351.311244] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #20: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.457760", "lvl": "target", "msg": "[  351.322156] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.459110", "lvl": "target", "msg": "[  351.322317] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #56623: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.461298", "lvl": "target", "msg": "[  351.355550] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.462741", "lvl": "target", "msg": "[  351.362985] blk_update_request: I/O error, dev nbd0, sector 3652120 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.464104", "lvl": "target", "msg": "[  351.373860] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:44:52.501911", "lvl": "target", "msg": "[  351.373859] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #56623: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.503792", "lvl": "target", "msg": "[  351.379825] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.507158", "lvl": "target", "msg": "[  351.401845] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.508825", "lvl": "target", "msg": "[  351.409279] blk_update_request: I/O error, dev nbd0, sector 3652120 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:44:52.510311", "lvl": "target", "msg": "[  351.420155] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:44:52.544884", "lvl": "target", "msg": "[  351.420153] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #56623: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.545971", "lvl": "target", "msg": "[  351.426113] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.547564", "lvl": "target", "msg": "[  351.445163] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:44:52.548582", "lvl": "target", "msg": "[  351.445162] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #56623: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.549719", "lvl": "target", "msg": "[  351.451119] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.589343", "lvl": "target", "msg": "[  351.470175] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:44:52.590836", "lvl": "target", "msg": "[  351.470175] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #56623: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.593465", "lvl": "target", "msg": "[  351.476127] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.594936", "lvl": "target", "msg": "[  351.495177] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:44:52.596351", "lvl": "target", "msg": "[  351.495178] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #56623: comm systemd-userwor: reading directory lblock 0"}
- {"dt": "2024-09-30T17:44:52.633042", "lvl": "target", "msg": "[  351.501134] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.634436", "lvl": "target", "msg": "[  351.520187] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:44:52.636794", "lvl": "target", "msg": "[  351.520788] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.638239", "lvl": "target", "msg": "[  351.526149] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.639789", "lvl": "target", "msg": "[  351.545807] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:44:52.677070", "lvl": "target", "msg": "[  351.545807] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.678882", "lvl": "target", "msg": "[  351.564065] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.680199", "lvl": "target", "msg": "[  351.576446] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.681539", "lvl": "target", "msg": "[  351.588774] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.721226", "lvl": "target", "msg": "[  351.601247] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.723555", "lvl": "target", "msg": "[  351.613738] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.725008", "lvl": "target", "msg": "[  351.626228] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.776348", "lvl": "target", "msg": "[  351.638759] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.778833", "lvl": "target", "msg": "[  351.638827] EXT4-fs warning (device nbd0): dx_probe:818: inode #5447: lblock 0: comm systemd-userwor: error -5 reading directory block"}
- {"dt": "2024-09-30T17:44:52.780617", "lvl": "target", "msg": "[  351.663994] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.782211", "lvl": "target", "msg": "[  351.671580] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:44:52.783907", "lvl": "target", "msg": "[  351.677710] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:44:52.785734", "lvl": "target", "msg": "[  351.685325] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:54:35.525527", "lvl": "target", "msg": "[  934.415187] print_req_error: 1205 callbacks suppressed"}
- {"dt": "2024-09-30T17:54:35.528526", "lvl": "target", "msg": "[  934.415202] blk_update_request: I/O error, dev nbd0, sector 351272 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:54:35.530153", "lvl": "target", "msg": "[  934.431284] EXT4-fs error: 480 callbacks suppressed"}
- {"dt": "2024-09-30T17:54:35.531775", "lvl": "target", "msg": "[  934.431291] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #826: comm (tmpfiles): reading directory lblock 0"}
- {"dt": "2024-09-30T17:54:35.533566", "lvl": "target", "msg": "[  934.447423] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:54:35.569564", "lvl": "target", "msg": "[  934.457896] buffer_io_error: 372 callbacks suppressed"}
- {"dt": "2024-09-30T17:54:35.571777", "lvl": "target", "msg": "[  934.457900] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:54:35.573011", "lvl": "target", "msg": "[  934.470597] blk_update_request: I/O error, dev nbd0, sector 351272 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:54:35.574143", "lvl": "target", "msg": "[  934.481518] EXT4-fs: 373 callbacks suppressed"}
- {"dt": "2024-09-30T17:54:35.575355", "lvl": "target", "msg": "[  934.481524] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:54:35.576142", "lvl": "target", "msg": "[  934.491911] EXT4-fs error (device nbd0): __ext4_find_entry:1663: inode #826: comm (tmpfiles): reading directory lblock 0"}
- {"dt": "2024-09-30T17:54:35.613756", "lvl": "target", "msg": "[  934.503015] blk_update_request: I/O error, dev nbd0, sector 0 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:54:35.614603", "lvl": "target", "msg": "[  934.513459] Buffer I/O error on dev nbd0, logical block 0, lost sync page write"}
- {"dt": "2024-09-30T17:54:35.615557", "lvl": "target", "msg": "[  934.520899] blk_update_request: I/O error, dev nbd0, sector 3927072 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:54:35.616582", "lvl": "target", "msg": "[  934.531769] EXT4-fs (nbd0): I/O error while writing superblock"}
- {"dt": "2024-09-30T17:54:35.617552", "lvl": "target", "msg": "[  934.537749] EXT4-fs warning: 333 callbacks suppressed"}
- {"dt": "2024-09-30T17:54:35.657540", "lvl": "target", "msg": "[  934.537755] EXT4-fs warning (device nbd0): dx_probe:818: inode #61204: lblock 0: comm (tmpfiles): error -5 reading directory block"}
- {"dt": "2024-09-30T17:54:35.659092", "lvl": "target", "msg": "[  934.555008] blk_update_request: I/O error, dev nbd0, sector 351296 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 0"}
- {"dt": "2024-09-30T17:54:35.660656", "lvl": "target", "msg": "[  934.565889] EXT4-fs warning (device nbd0): dx_probe:818: inode #840: lblock 0: comm (tmpfiles): error -5 reading directory block"}
- {"dt": "2024-09-30T17:58:16.373246", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-09-30T17:58:16.375406", "lvl": "debug", "msg": "end: 2.4.4.1 login-action (duration 00:19:14) [common]"}
- {"dt": "2024-09-30T17:58:16.377087", "lvl": "results", "msg": {"case": "login-action", "definition": "lava", "duration": "1153.96", "extra": {"fail": "wait for prompt timed out", "success": "No kernel warnings or errors detected."}, "level": "2.4.4.1", "namespace": "common", "result": "fail"}}
- {"dt": "2024-09-30T17:58:16.380547", "lvl": "error", "msg": "auto-login-action failed: 1 of 1 attempts. 'wait for prompt timed out'"}
- {"dt": "2024-09-30T17:58:16.382424", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-09-30T17:58:16.383731", "lvl": "debug", "msg": "end: 2.4.4 auto-login-action (duration 00:19:16) [common]"}
- {"dt": "2024-09-30T17:58:16.384340", "lvl": "results", "msg": {"case": "auto-login-action", "definition": "lava", "duration": "1155.78", "extra": {"fail": "wait for prompt timed out"}, "level": "2.4.4", "namespace": "common", "result": "fail"}}
- {"dt": "2024-09-30T17:58:16.388067", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-09-30T17:58:16.389960", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:19:56) [common]"}
- {"dt": "2024-09-30T17:58:16.391835", "lvl": "results", "msg": {"case": "uboot-commands", "definition": "lava", "duration": "1196.41", "extra": {"fail": "wait for prompt timed out"}, "level": "2.4", "namespace": "common", "result": "fail"}}
- {"dt": "2024-09-30T17:58:16.394899", "lvl": "error", "msg": "uboot-action failed: 1 of 1 attempts. 'wait for prompt timed out'"}
- {"dt": "2024-09-30T17:58:16.395882", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-09-30T17:58:16.396358", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:20:00) [common]"}
- {"dt": "2024-09-30T17:58:16.396818", "lvl": "results", "msg": {"case": "uboot-action", "definition": "lava", "duration": "1200.13", "extra": {"fail": "wait for prompt timed out"}, "level": "2", "namespace": "common", "result": "fail"}}
- {"dt": "2024-09-30T17:58:16.397895", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-09-30T17:58:16.398482", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/36611/nbd-deploy-__9oaok5/initrd"}
- {"dt": "2024-09-30T17:58:16.401992", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/36611/nbd-deploy-__9oaok5/kernel"}
- {"dt": "2024-09-30T17:58:16.408157", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/36611/nbd-deploy-__9oaok5/dtb"}
- {"dt": "2024-09-30T17:58:16.409455", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/36611/nbd-deploy-__9oaok5/nbdroot"}
- {"dt": "2024-09-30T17:58:16.678722", "lvl": "debug", "msg": "start: 7.1 power-off (timeout 00:00:10) [common]"}
- {"dt": "2024-09-30T17:58:16.679779", "lvl": "debug", "msg": "Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '7'"}
- {"dt": "2024-09-30T17:58:20.019821", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2024-09-30T17:58:20.061512", "lvl": "debug", "msg": "Returned 0 in 3 seconds"}
- {"dt": "2024-09-30T17:58:20.164759", "lvl": "debug", "msg": "end: 7.1 power-off (duration 00:00:03) [common]"}
- {"dt": "2024-09-30T17:58:20.166754", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "3.49", "extra": {"status": "success"}, "level": "7.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-09-30T17:58:20.170823", "lvl": "debug", "msg": "start: 7.2 read-feedback (timeout 00:29:57) [common]"}
- {"dt": "2024-09-30T17:58:20.175344", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2024-09-30T17:58:21.174613", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2024-09-30T17:58:21.176920", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2024-09-30T17:58:21.280377", "lvl": "debug", "msg": "end: 7.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2024-09-30T17:58:21.282327", "lvl": "debug", "msg": "lava-xnbd cleanup"}
- {"dt": "2024-09-30T17:58:21.284118", "lvl": "debug", "msg": "clean NBD port 61994"}
- {"dt": "2024-09-30T17:58:24.441030", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/36611"}
- {"dt": "2024-09-30T17:58:24.532196", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/36611"}
- {"dt": "2024-09-30T17:58:24.533194", "lvl": "error", "msg": "JobError: Your job cannot terminate cleanly."}
- {"dt": "2024-09-30T17:58:24.533714", "lvl": "results", "msg": {"case": "job", "definition": "lava", "error_msg": "wait for prompt timed out", "error_type": "Job", "result": "fail"}}
