- {"dt": "2024-08-15T23:45:12.176542", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.10"}
- {"dt": "2024-08-15T23:45:12.180374", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-08-15T23:45:12.181929", "lvl": "info", "msg": "Start time: 2024-08-15 23:45:12.181869+00:00 (UTC)"}
- {"dt": "2024-08-15T23:45:12.183578", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30173/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz exists"}
- {"dt": "2024-08-15T23:45:12.409349", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30173/1/raspberrypi4/Image exists"}
- {"dt": "2024-08-15T23:45:12.624746", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30173/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb exists"}
- {"dt": "2024-08-15T23:45:12.841222", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30173/1/raspberrypi4/agl-ivi-demo-qt-raspberrypi4-64.ext4.xz exists"}
- {"dt": "2024-08-15T23:45:13.073358", "lvl": "info", "msg": "validate duration: 0.89"}
- {"dt": "2024-08-15T23:45:13.074670", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2024-08-15T23:45:13.076285", "lvl": "info", "msg": "start: 1 nbd-deploy (timeout 01:30:00) [common]"}
- {"dt": "2024-08-15T23:45:13.077287", "lvl": "info", "msg": "Making protocol call for nbd-deploy using lava-xnbd"}
- {"dt": "2024-08-15T23:45:13.078169", "lvl": "debug", "msg": "[nbd-deploy] Checking protocol data for lava-xnbd"}
- {"dt": "2024-08-15T23:45:13.079022", "lvl": "debug", "msg": "Get a port from pool"}
- {"dt": "2024-08-15T23:45:13.081599", "lvl": "debug", "msg": "Set_port 61980"}
- {"dt": "2024-08-15T23:45:13.082737", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 01:30:00) [common]"}
- {"dt": "2024-08-15T23:45:13.083865", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 01:30:00) [common]"}
- {"dt": "2024-08-15T23:45:13.085680", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30173/1/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T23:45:13.086732", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/35933/nbd-deploy-2hwyeya7/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T23:45:13.087701", "lvl": "debug", "msg": "total size: 2153469 (2\u202FMB)"}
- {"dt": "2024-08-15T23:45:13.088658", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-08-15T23:45:13.404660", "lvl": "debug", "msg": "progress   1\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:13.607980", "lvl": "debug", "msg": "progress   6\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:13.713405", "lvl": "debug", "msg": "progress  12\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:13.721414", "lvl": "debug", "msg": "progress  18\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:13.813616", "lvl": "debug", "msg": "progress  24\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:13.911578", "lvl": "debug", "msg": "progress  30\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:13.917786", "lvl": "debug", "msg": "progress  36\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.009705", "lvl": "debug", "msg": "progress  41\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.015684", "lvl": "debug", "msg": "progress  47\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.021795", "lvl": "debug", "msg": "progress  53\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.028732", "lvl": "debug", "msg": "progress  59\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.035057", "lvl": "debug", "msg": "progress  65\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.041027", "lvl": "debug", "msg": "progress  71\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.046285", "lvl": "debug", "msg": "progress  76\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.110452", "lvl": "debug", "msg": "progress  82\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.119051", "lvl": "debug", "msg": "progress  88\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.126256", "lvl": "debug", "msg": "progress  94\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.132658", "lvl": "debug", "msg": "progress 100\u202F% (2\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.134619", "lvl": "info", "msg": "2\u202FMB downloaded in 1.05\u202Fs (1.96\u202FMB/s)"}
- {"dt": "2024-08-15T23:45:14.136081", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T23:45:14.137163", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "1.05", "extra": {"label": "initrd", "md5sum": "71f52d5effa77b95bd7dad63afe06c98", "sha256sum": "bc40d0b6b1332fba575b672e9ebba774529c77453cf6c711cbd4c23a889ec799", "sha512sum": "31dc8e1cd4a50d3fff62148e9e59e193451cd24be5cc808119fea9d8b596dae2dc35e0d14fa79a3a290e661b70942ee073fd052d6f6b205b8267ead0148a2330", "size": ! "2153469"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:45:14.139122", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T23:45:14.140285", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 01:29:59) [common]"}
- {"dt": "2024-08-15T23:45:14.141552", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 01:29:59) [common]"}
- {"dt": "2024-08-15T23:45:14.142992", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30173/1/raspberrypi4/Image"}
- {"dt": "2024-08-15T23:45:14.143897", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/35933/nbd-deploy-2hwyeya7/kernel/Image"}
- {"dt": "2024-08-15T23:45:14.144732", "lvl": "debug", "msg": "total size: 28535296 (27\u202FMB)"}
- {"dt": "2024-08-15T23:45:14.145565", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-08-15T23:45:14.462206", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:15.072076", "lvl": "debug", "msg": "progress   5\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T23:45:15.199339", "lvl": "debug", "msg": "progress  10\u202F% (2\u202FMB)"}
- {"dt": "2024-08-15T23:45:15.318581", "lvl": "debug", "msg": "progress  15\u202F% (4\u202FMB)"}
- {"dt": "2024-08-15T23:45:15.531962", "lvl": "debug", "msg": "progress  20\u202F% (5\u202FMB)"}
- {"dt": "2024-08-15T23:45:15.710364", "lvl": "debug", "msg": "progress  25\u202F% (6\u202FMB)"}
- {"dt": "2024-08-15T23:45:15.903061", "lvl": "debug", "msg": "progress  30\u202F% (8\u202FMB)"}
- {"dt": "2024-08-15T23:45:16.098944", "lvl": "debug", "msg": "progress  35\u202F% (9\u202FMB)"}
- {"dt": "2024-08-15T23:45:16.296797", "lvl": "debug", "msg": "progress  40\u202F% (10\u202FMB)"}
- {"dt": "2024-08-15T23:45:16.482640", "lvl": "debug", "msg": "progress  45\u202F% (12\u202FMB)"}
- {"dt": "2024-08-15T23:45:16.628179", "lvl": "debug", "msg": "progress  50\u202F% (13\u202FMB)"}
- {"dt": "2024-08-15T23:45:16.913762", "lvl": "debug", "msg": "progress  55\u202F% (14\u202FMB)"}
- {"dt": "2024-08-15T23:45:17.137125", "lvl": "debug", "msg": "progress  60\u202F% (16\u202FMB)"}
- {"dt": "2024-08-15T23:45:17.415789", "lvl": "debug", "msg": "progress  65\u202F% (17\u202FMB)"}
- {"dt": "2024-08-15T23:45:17.741936", "lvl": "debug", "msg": "progress  70\u202F% (19\u202FMB)"}
- {"dt": "2024-08-15T23:45:18.051991", "lvl": "debug", "msg": "progress  75\u202F% (20\u202FMB)"}
- {"dt": "2024-08-15T23:45:18.360206", "lvl": "debug", "msg": "progress  80\u202F% (21\u202FMB)"}
- {"dt": "2024-08-15T23:45:18.677356", "lvl": "debug", "msg": "progress  85\u202F% (23\u202FMB)"}
- {"dt": "2024-08-15T23:45:18.984146", "lvl": "debug", "msg": "progress  90\u202F% (24\u202FMB)"}
- {"dt": "2024-08-15T23:45:19.372647", "lvl": "debug", "msg": "progress  95\u202F% (25\u202FMB)"}
- {"dt": "2024-08-15T23:45:19.781109", "lvl": "debug", "msg": "progress 100\u202F% (27\u202FMB)"}
- {"dt": "2024-08-15T23:45:19.783534", "lvl": "info", "msg": "27\u202FMB downloaded in 5.64\u202Fs (4.83\u202FMB/s)"}
- {"dt": "2024-08-15T23:45:19.787165", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:06) [common]"}
- {"dt": "2024-08-15T23:45:19.792122", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "5.65", "extra": {"label": "kernel", "md5sum": "6fb1fd92b04099c5272721d44179c1c3", "sha256sum": "38f20e78efb94b69b140c2e12915b6c3e743383ff8bd2c831b4c9f04d88f79da", "sha512sum": "523b97e16d642ea1a81965251c0fe69cb01bdf60896a9f3e4a764f1c6b34e6f2fd0392544bb57cc2e75e39bc4a91526854cfaee44b21190199203fe0fb0cbe30", "size": ! "28535296"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:45:19.794647", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:06) [common]"}
- {"dt": "2024-08-15T23:45:19.797850", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 01:29:53) [common]"}
- {"dt": "2024-08-15T23:45:19.799453", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 01:29:53) [common]"}
- {"dt": "2024-08-15T23:45:19.805998", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30173/1/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T23:45:19.807048", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/35933/nbd-deploy-2hwyeya7/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T23:45:19.807920", "lvl": "debug", "msg": "total size: 54759 (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:19.808864", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-08-15T23:45:20.126342", "lvl": "debug", "msg": "progress  59\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:20.225184", "lvl": "debug", "msg": "progress 100\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:20.227359", "lvl": "info", "msg": "0\u202FMB downloaded in 0.42\u202Fs (0.12\u202FMB/s)"}
- {"dt": "2024-08-15T23:45:20.228528", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:45:20.229196", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.43", "extra": {"label": "dtb", "md5sum": "8148061872e529fe20707e8f5c677261", "sha256sum": "1adf34a5564e59d473c570c15f579e4d5e76eaa4075cc7de3b0ff791eb331780", "sha512sum": "9ff04a457be78d59fcedbfd99fb68d45d2902d85c59dd81de3de83d150135ac59f9023d063fef0c4a2f2aafbb67378d80c9d21f49ad6a3ebd92993535f10e125", "size": ! "54759"}, "level": "1.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:45:20.231186", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:45:20.231929", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 01:29:53) [common]"}
- {"dt": "2024-08-15T23:45:20.233891", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 01:29:53) [common]"}
- {"dt": "2024-08-15T23:45:20.238691", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30173/1/raspberrypi4/agl-ivi-demo-qt-raspberrypi4-64.ext4.xz"}
- {"dt": "2024-08-15T23:45:20.240276", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/35933/nbd-deploy-2hwyeya7/nbdroot/agl-ivi-demo-qt-raspberrypi4-64.ext4"}
- {"dt": "2024-08-15T23:45:20.241236", "lvl": "debug", "msg": "total size: 494349128 (471\u202FMB)"}
- {"dt": "2024-08-15T23:45:20.242086", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-08-15T23:45:20.563976", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T23:45:52.446387", "lvl": "debug", "msg": "progress   5\u202F% (23\u202FMB)"}
- {"dt": "2024-08-15T23:46:03.737548", "lvl": "debug", "msg": "progress  10\u202F% (47\u202FMB)"}
- {"dt": "2024-08-15T23:46:11.127348", "lvl": "debug", "msg": "progress  15\u202F% (70\u202FMB)"}
- {"dt": "2024-08-15T23:46:17.568874", "lvl": "debug", "msg": "progress  20\u202F% (94\u202FMB)"}
- {"dt": "2024-08-15T23:46:23.446018", "lvl": "debug", "msg": "progress  25\u202F% (117\u202FMB)"}
- {"dt": "2024-08-15T23:46:29.128524", "lvl": "debug", "msg": "progress  30\u202F% (141\u202FMB)"}
- {"dt": "2024-08-15T23:46:35.284213", "lvl": "debug", "msg": "progress  35\u202F% (165\u202FMB)"}
- {"dt": "2024-08-15T23:46:42.413664", "lvl": "debug", "msg": "progress  40\u202F% (188\u202FMB)"}
- {"dt": "2024-08-15T23:46:48.341626", "lvl": "debug", "msg": "progress  45\u202F% (212\u202FMB)"}
- {"dt": "2024-08-15T23:46:56.224894", "lvl": "debug", "msg": "progress  50\u202F% (235\u202FMB)"}
- {"dt": "2024-08-15T23:47:04.070375", "lvl": "debug", "msg": "progress  55\u202F% (259\u202FMB)"}
- {"dt": "2024-08-15T23:47:11.298683", "lvl": "debug", "msg": "progress  60\u202F% (282\u202FMB)"}
- {"dt": "2024-08-15T23:47:17.501774", "lvl": "debug", "msg": "progress  65\u202F% (306\u202FMB)"}
- {"dt": "2024-08-15T23:47:23.931058", "lvl": "debug", "msg": "progress  70\u202F% (330\u202FMB)"}
- {"dt": "2024-08-15T23:47:32.776835", "lvl": "debug", "msg": "progress  75\u202F% (353\u202FMB)"}
- {"dt": "2024-08-15T23:47:39.732054", "lvl": "debug", "msg": "progress  80\u202F% (377\u202FMB)"}
- {"dt": "2024-08-15T23:47:45.345006", "lvl": "debug", "msg": "progress  85\u202F% (400\u202FMB)"}
- {"dt": "2024-08-15T23:47:51.403826", "lvl": "debug", "msg": "progress  90\u202F% (424\u202FMB)"}
- {"dt": "2024-08-15T23:47:57.036419", "lvl": "debug", "msg": "progress  95\u202F% (447\u202FMB)"}
- {"dt": "2024-08-15T23:48:10.459393", "lvl": "debug", "msg": "progress 100\u202F% (471\u202FMB)"}
- {"dt": "2024-08-15T23:48:14.133966", "lvl": "info", "msg": "471\u202FMB downloaded in 173.89\u202Fs (2.71\u202FMB/s)"}
- {"dt": "2024-08-15T23:48:14.135077", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:02:54) [common]"}
- {"dt": "2024-08-15T23:48:14.135691", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "173.90", "extra": {"label": "nbdroot", "md5sum": "d4fa79695c1fb12546583ca37ae5bd9e", "sha256sum": "c42a5b5a18e6c4d8a9846c7662fb1f140719a9b4637457bcb0daaf5afb2bb85c", "sha512sum": "f2ce3e2c18c264c0a3a2cb336b49bcdb83a0cee15cb03caae752cac906d57b1a9c515d24ea1aaff2bcc795a3a8324d1c522c5badf566b2d76cc38e7db1fc12fb", "size": ! "494349128"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:14.137026", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:02:54) [common]"}
- {"dt": "2024-08-15T23:48:14.137731", "lvl": "debug", "msg": "start: 1.5 lava-overlay (timeout 01:26:59) [common]"}
- {"dt": "2024-08-15T23:48:14.138932", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j"}
- {"dt": "2024-08-15T23:48:14.140050", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin"}
- {"dt": "2024-08-15T23:48:14.141018", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/tests"}
- {"dt": "2024-08-15T23:48:14.141919", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/results"}
- {"dt": "2024-08-15T23:48:14.142802", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-add-keys"}
- {"dt": "2024-08-15T23:48:14.144008", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-add-sources"}
- {"dt": "2024-08-15T23:48:14.145339", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-background-process-start"}
- {"dt": "2024-08-15T23:48:14.146572", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-background-process-stop"}
- {"dt": "2024-08-15T23:48:14.147867", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-common-functions"}
- {"dt": "2024-08-15T23:48:14.149477", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-echo-ipv4"}
- {"dt": "2024-08-15T23:48:14.150804", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-install-packages"}
- {"dt": "2024-08-15T23:48:14.152061", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-installed-packages"}
- {"dt": "2024-08-15T23:48:14.153384", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-os-build"}
- {"dt": "2024-08-15T23:48:14.154630", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-probe-channel"}
- {"dt": "2024-08-15T23:48:14.155831", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-probe-ip"}
- {"dt": "2024-08-15T23:48:14.157098", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-target-ip"}
- {"dt": "2024-08-15T23:48:14.158301", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-target-mac"}
- {"dt": "2024-08-15T23:48:14.159517", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-target-storage"}
- {"dt": "2024-08-15T23:48:14.160893", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-test-case"}
- {"dt": "2024-08-15T23:48:14.162140", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-test-event"}
- {"dt": "2024-08-15T23:48:14.163342", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-test-feedback"}
- {"dt": "2024-08-15T23:48:14.164986", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-test-raise"}
- {"dt": "2024-08-15T23:48:14.166382", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-test-reference"}
- {"dt": "2024-08-15T23:48:14.167639", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-test-runner"}
- {"dt": "2024-08-15T23:48:14.168922", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-test-set"}
- {"dt": "2024-08-15T23:48:14.170119", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-test-shell"}
- {"dt": "2024-08-15T23:48:14.171309", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-install-packages (oe)"}
- {"dt": "2024-08-15T23:48:14.172745", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/bin/lava-installed-packages (oe)"}
- {"dt": "2024-08-15T23:48:14.173969", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/environment"}
- {"dt": "2024-08-15T23:48:14.175014", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2024-08-15T23:48:14.175628", "lvl": "debug", "msg": "- LAVA_JOB_ID=35933"}
- {"dt": "2024-08-15T23:48:14.176203", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.66.1"}
- {"dt": "2024-08-15T23:48:14.177210", "lvl": "debug", "msg": "start: 1.5.1 ssh-authorize (timeout 01:26:59) [common]"}
- {"dt": "2024-08-15T23:48:14.179491", "lvl": "debug", "msg": "end: 1.5.1 ssh-authorize (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:14.180402", "lvl": "debug", "msg": "start: 1.5.2 lava-vland-overlay (timeout 01:26:59) [common]"}
- {"dt": "2024-08-15T23:48:14.181055", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2024-08-15T23:48:14.181690", "lvl": "debug", "msg": "end: 1.5.2 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:14.182341", "lvl": "debug", "msg": "start: 1.5.3 lava-multinode-overlay (timeout 01:26:59) [common]"}
- {"dt": "2024-08-15T23:48:14.182850", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2024-08-15T23:48:14.183426", "lvl": "debug", "msg": "end: 1.5.3 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:14.184021", "lvl": "debug", "msg": "start: 1.5.4 test-definition (timeout 01:26:59) [common]"}
- {"dt": "2024-08-15T23:48:14.184676", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2024-08-15T23:48:14.185398", "lvl": "debug", "msg": "start: 1.5.4.1 git-repo-action (timeout 01:26:59) [common]"}
- {"dt": "2024-08-15T23:48:14.185986", "lvl": "debug", "msg": "Using /lava-35933 at stage 0"}
- {"dt": "2024-08-15T23:48:14.186819", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T23:48:14.187385", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/0/tests/0_network-veth'"}
- {"dt": "2024-08-15T23:48:15.320134", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/0/tests/0_network-veth/test-suites/short-smoke/network-veth.yaml"}
- {"dt": "2024-08-15T23:48:15.322786", "lvl": "debug", "msg": "uuid=35933_1.5.4.1 testdef=None"}
- {"dt": "2024-08-15T23:48:15.323717", "lvl": "debug", "msg": "end: 1.5.4.1 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T23:48:15.324560", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "1.14", "extra": {"commit": "24eb3fb3eac80295290a0e5c6fc310fea9a46677", "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-08-15T23:48:15.326396", "lvl": "debug", "msg": "start: 1.5.4.2 test-overlay (timeout 01:26:58) [common]"}
- {"dt": "2024-08-15T23:48:15.334166", "lvl": "debug", "msg": "end: 1.5.4.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:15.334884", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "network-veth", "path": "test-suites/short-smoke/network-veth.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "35933_1.5.4.1"}, "level": "1.5.4.2", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:15.336362", "lvl": "debug", "msg": "start: 1.5.4.3 test-install-overlay (timeout 01:26:58) [common]"}
- {"dt": "2024-08-15T23:48:15.343801", "lvl": "debug", "msg": "end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:15.344627", "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": "35933_1.5.4.1", "uuid": "35933_1.5.4.1"}, "level": "1.5.4.3", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:15.346788", "lvl": "debug", "msg": "start: 1.5.4.4 test-runscript-overlay (timeout 01:26:58) [common]"}
- {"dt": "2024-08-15T23:48:15.354585", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/0/tests/0_network-veth test_uuid 35933_1.5.4.1"}
- {"dt": "2024-08-15T23:48:15.356375", "lvl": "debug", "msg": "end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:15.357193", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/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": "35933_1.5.4.1"}, "level": "1.5.4.4", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:15.359039", "lvl": "debug", "msg": "start: 1.5.4.5 git-repo-action (timeout 01:26:58) [common]"}
- {"dt": "2024-08-15T23:48:15.359831", "lvl": "debug", "msg": "Using /lava-35933 at stage 1"}
- {"dt": "2024-08-15T23:48:15.361235", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T23:48:15.362076", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/1_ci-busybox'"}
- {"dt": "2024-08-15T23:48:16.381503", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/1_ci-busybox"}
- {"dt": "2024-08-15T23:48:16.391465", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/1_ci-busybox/test-suites/short-smoke/busybox.yaml"}
- {"dt": "2024-08-15T23:48:16.393801", "lvl": "debug", "msg": "uuid=35933_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-08-15T23:48:16.394676", "lvl": "debug", "msg": "end: 1.5.4.5 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T23:48:16.395265", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "1.04", "extra": {"commit": "24eb3fb3eac80295290a0e5c6fc310fea9a46677", "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-08-15T23:48:16.396492", "lvl": "debug", "msg": "start: 1.5.4.6 test-overlay (timeout 01:26:57) [common]"}
- {"dt": "2024-08-15T23:48:16.401610", "lvl": "debug", "msg": "end: 1.5.4.6 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:16.402200", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-busybox", "path": "test-suites/short-smoke/busybox.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "35933_1.5.4.5"}, "level": "1.5.4.6", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:16.403462", "lvl": "debug", "msg": "start: 1.5.4.7 test-install-overlay (timeout 01:26:57) [common]"}
- {"dt": "2024-08-15T23:48:16.410493", "lvl": "debug", "msg": "end: 1.5.4.7 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:16.411108", "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": "35933_1.5.4.5", "uuid": "35933_1.5.4.5"}, "level": "1.5.4.7", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:16.412948", "lvl": "debug", "msg": "start: 1.5.4.8 test-runscript-overlay (timeout 01:26:57) [common]"}
- {"dt": "2024-08-15T23:48:16.419884", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/1_ci-busybox test_uuid 35933_1.5.4.5"}
- {"dt": "2024-08-15T23:48:16.421316", "lvl": "debug", "msg": "end: 1.5.4.8 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:16.421958", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/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": "35933_1.5.4.5"}, "level": "1.5.4.8", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:16.423318", "lvl": "debug", "msg": "start: 1.5.4.9 git-repo-action (timeout 01:26:57) [common]"}
- {"dt": "2024-08-15T23:48:16.423842", "lvl": "debug", "msg": "Using /lava-35933 at stage 1"}
- {"dt": "2024-08-15T23:48:16.424641", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T23:48:16.425223", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/2_ci-smoke-tests-basic'"}
- {"dt": "2024-08-15T23:48:17.495557", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/2_ci-smoke-tests-basic"}
- {"dt": "2024-08-15T23:48:17.510191", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/2_ci-smoke-tests-basic/test-suites/short-smoke/smoke-tests-basic.yaml"}
- {"dt": "2024-08-15T23:48:17.514222", "lvl": "debug", "msg": "uuid=35933_1.5.4.9 testdef=None"}
- {"dt": "2024-08-15T23:48:17.515954", "lvl": "debug", "msg": "end: 1.5.4.9 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T23:48:17.517872", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "1.09", "extra": {"commit": "24eb3fb3eac80295290a0e5c6fc310fea9a46677", "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-08-15T23:48:17.520544", "lvl": "debug", "msg": "start: 1.5.4.10 test-overlay (timeout 01:26:56) [common]"}
- {"dt": "2024-08-15T23:48:17.530302", "lvl": "debug", "msg": "end: 1.5.4.10 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:17.531923", "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": "35933_1.5.4.9"}, "level": "1.5.4.10", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:17.534973", "lvl": "debug", "msg": "start: 1.5.4.11 test-install-overlay (timeout 01:26:56) [common]"}
- {"dt": "2024-08-15T23:48:17.546439", "lvl": "debug", "msg": "end: 1.5.4.11 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:17.548046", "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": "35933_1.5.4.9", "uuid": "35933_1.5.4.9"}, "level": "1.5.4.11", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:17.551480", "lvl": "debug", "msg": "start: 1.5.4.12 test-runscript-overlay (timeout 01:26:56) [common]"}
- {"dt": "2024-08-15T23:48:17.563380", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/2_ci-smoke-tests-basic test_uuid 35933_1.5.4.9"}
- {"dt": "2024-08-15T23:48:17.567490", "lvl": "debug", "msg": "end: 1.5.4.12 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:17.569634", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.02", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/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": "35933_1.5.4.9"}, "level": "1.5.4.12", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:17.572899", "lvl": "debug", "msg": "start: 1.5.4.13 git-repo-action (timeout 01:26:56) [common]"}
- {"dt": "2024-08-15T23:48:17.574510", "lvl": "debug", "msg": "Using /lava-35933 at stage 1"}
- {"dt": "2024-08-15T23:48:17.576405", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T23:48:17.578425", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/3_ci-service-check'"}
- {"dt": "2024-08-15T23:48:18.646855", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/3_ci-service-check"}
- {"dt": "2024-08-15T23:48:18.659507", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/3_ci-service-check/test-suites/short-smoke/service-check.yaml"}
- {"dt": "2024-08-15T23:48:18.663470", "lvl": "debug", "msg": "uuid=35933_1.5.4.13 testdef=None"}
- {"dt": "2024-08-15T23:48:18.664869", "lvl": "debug", "msg": "end: 1.5.4.13 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T23:48:18.666250", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "1.09", "extra": {"commit": "24eb3fb3eac80295290a0e5c6fc310fea9a46677", "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-08-15T23:48:18.668928", "lvl": "debug", "msg": "start: 1.5.4.14 test-overlay (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T23:48:18.676872", "lvl": "debug", "msg": "end: 1.5.4.14 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:18.678586", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.01", "extra": {"from": "git", "name": "ci-service-check", "path": "test-suites/short-smoke/service-check.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "35933_1.5.4.13"}, "level": "1.5.4.14", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:18.681033", "lvl": "debug", "msg": "start: 1.5.4.15 test-install-overlay (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T23:48:18.693482", "lvl": "debug", "msg": "end: 1.5.4.15 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:18.695023", "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": "35933_1.5.4.13", "uuid": "35933_1.5.4.13"}, "level": "1.5.4.15", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:18.697579", "lvl": "debug", "msg": "start: 1.5.4.16 test-runscript-overlay (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T23:48:18.708368", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1/tests/3_ci-service-check test_uuid 35933_1.5.4.13"}
- {"dt": "2024-08-15T23:48:18.709757", "lvl": "debug", "msg": "BUILD_TAGS=''"}
- {"dt": "2024-08-15T23:48:18.711123", "lvl": "debug", "msg": "DEVICE_TAGS=''"}
- {"dt": "2024-08-15T23:48:18.713804", "lvl": "debug", "msg": "end: 1.5.4.16 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:18.715276", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.02", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/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": "35933_1.5.4.13"}, "level": "1.5.4.16", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:18.717999", "lvl": "debug", "msg": "start: 1.5.4.17 git-repo-action (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T23:48:18.719129", "lvl": "debug", "msg": "Using /lava-35933 at stage 2"}
- {"dt": "2024-08-15T23:48:18.721034", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T23:48:18.722443", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/2/tests/4_screenshooter'"}
- {"dt": "2024-08-15T23:48:19.855659", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/2/tests/4_screenshooter/test-suites/short-smoke/screenshooter.yaml"}
- {"dt": "2024-08-15T23:48:19.857476", "lvl": "debug", "msg": "uuid=35933_1.5.4.17 testdef=None"}
- {"dt": "2024-08-15T23:48:19.858255", "lvl": "debug", "msg": "end: 1.5.4.17 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T23:48:19.858795", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "1.14", "extra": {"commit": "24eb3fb3eac80295290a0e5c6fc310fea9a46677", "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-08-15T23:48:19.859970", "lvl": "debug", "msg": "start: 1.5.4.18 test-overlay (timeout 01:26:53) [common]"}
- {"dt": "2024-08-15T23:48:19.864471", "lvl": "debug", "msg": "end: 1.5.4.18 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:19.865074", "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": "35933_1.5.4.17"}, "level": "1.5.4.18", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:19.866439", "lvl": "debug", "msg": "start: 1.5.4.19 test-install-overlay (timeout 01:26:53) [common]"}
- {"dt": "2024-08-15T23:48:19.872060", "lvl": "debug", "msg": "end: 1.5.4.19 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:19.872750", "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": "35933_1.5.4.17", "uuid": "35933_1.5.4.17"}, "level": "1.5.4.19", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:19.874175", "lvl": "debug", "msg": "start: 1.5.4.20 test-runscript-overlay (timeout 01:26:53) [common]"}
- {"dt": "2024-08-15T23:48:19.879780", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/2/tests/4_screenshooter test_uuid 35933_1.5.4.17"}
- {"dt": "2024-08-15T23:48:19.881220", "lvl": "debug", "msg": "end: 1.5.4.20 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:19.881845", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/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": "35933_1.5.4.17"}, "level": "1.5.4.20", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:19.883282", "lvl": "debug", "msg": "start: 1.5.4.21 git-repo-action (timeout 01:26:53) [common]"}
- {"dt": "2024-08-15T23:48:19.883895", "lvl": "debug", "msg": "Using /lava-35933 at stage 3"}
- {"dt": "2024-08-15T23:48:19.884842", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T23:48:19.885451", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/3/tests/5_ci-dumpjournal'"}
- {"dt": "2024-08-15T23:48:20.674004", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/3/tests/5_ci-dumpjournal"}
- {"dt": "2024-08-15T23:48:20.683587", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/3/tests/5_ci-dumpjournal/test-suites/short-smoke/dumpjournal.yaml"}
- {"dt": "2024-08-15T23:48:20.685715", "lvl": "debug", "msg": "uuid=35933_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-08-15T23:48:20.686466", "lvl": "debug", "msg": "end: 1.5.4.21 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T23:48:20.686932", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.80", "extra": {"commit": "24eb3fb3eac80295290a0e5c6fc310fea9a46677", "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-08-15T23:48:20.688007", "lvl": "debug", "msg": "start: 1.5.4.22 test-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T23:48:20.692879", "lvl": "debug", "msg": "end: 1.5.4.22 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:20.693434", "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": "35933_1.5.4.21"}, "level": "1.5.4.22", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:20.695159", "lvl": "debug", "msg": "start: 1.5.4.23 test-install-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T23:48:20.701806", "lvl": "debug", "msg": "end: 1.5.4.23 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:20.702402", "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": "35933_1.5.4.21", "uuid": "35933_1.5.4.21"}, "level": "1.5.4.23", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:20.703668", "lvl": "debug", "msg": "start: 1.5.4.24 test-runscript-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T23:48:20.711035", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/3/tests/5_ci-dumpjournal test_uuid 35933_1.5.4.21"}
- {"dt": "2024-08-15T23:48:20.712436", "lvl": "debug", "msg": "end: 1.5.4.24 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:20.713028", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/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": "35933_1.5.4.21"}, "level": "1.5.4.24", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:20.714131", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2024-08-15T23:48:20.714537", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/0 for stage 0"}
- {"dt": "2024-08-15T23:48:20.715256", "lvl": "debug", "msg": "- 0_network-veth"}
- {"dt": "2024-08-15T23:48:20.715922", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/1 for stage 1"}
- {"dt": "2024-08-15T23:48:20.716722", "lvl": "debug", "msg": "- 1_ci-busybox"}
- {"dt": "2024-08-15T23:48:20.717239", "lvl": "debug", "msg": "- 2_ci-smoke-tests-basic"}
- {"dt": "2024-08-15T23:48:20.717641", "lvl": "debug", "msg": "- 3_ci-service-check"}
- {"dt": "2024-08-15T23:48:20.718165", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/2 for stage 2"}
- {"dt": "2024-08-15T23:48:20.718871", "lvl": "debug", "msg": "- 4_screenshooter"}
- {"dt": "2024-08-15T23:48:20.719463", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/35933/lava-overlay-vqj1xs9j/lava-35933/3 for stage 3"}
- {"dt": "2024-08-15T23:48:20.720169", "lvl": "debug", "msg": "- 5_ci-dumpjournal"}
- {"dt": "2024-08-15T23:48:20.721012", "lvl": "debug", "msg": "end: 1.5.4 test-definition (duration 00:00:07) [common]"}
- {"dt": "2024-08-15T23:48:20.721634", "lvl": "debug", "msg": "start: 1.5.5 compress-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T23:48:21.421683", "lvl": "debug", "msg": "end: 1.5.5 compress-overlay (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T23:48:21.422480", "lvl": "debug", "msg": "start: 1.5.6 persistent-nfs-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T23:48:21.423046", "lvl": "debug", "msg": "end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:21.423599", "lvl": "debug", "msg": "end: 1.5 lava-overlay (duration 00:00:07) [common]"}
- {"dt": "2024-08-15T23:48:21.424141", "lvl": "debug", "msg": "start: 1.6 prepare-kernel (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T23:48:21.424762", "lvl": "debug", "msg": "start: 1.6.1 uboot-prepare-kernel (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T23:48:21.425375", "lvl": "debug", "msg": "end: 1.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:21.425907", "lvl": "debug", "msg": "end: 1.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:21.426425", "lvl": "debug", "msg": "start: 1.7 xnbd-server-deploy (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T23:48:21.426845", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server"}
- {"dt": "2024-08-15T23:48:21.427259", "lvl": "debug", "msg": "NBD-IP: 192.168.66.1, NBD-PORT: 61980, NBD-ROOT: 35933/nbd-deploy-2hwyeya7/nbdroot/agl-ivi-demo-qt-raspberrypi4-64.ext4"}
- {"dt": "2024-08-15T23:48:21.430312", "lvl": "debug", "msg": "nbd-server 61980 /var/lib/lava/dispatcher/tmp/35933/nbd-deploy-2hwyeya7/nbdroot/agl-ivi-demo-qt-raspberrypi4-64.ext4"}
- {"dt": "2024-08-15T23:48:21.449618", "lvl": "debug", "msg": "output: "}
- {"dt": "2024-08-15T23:48:21.450295", "lvl": "debug", "msg": "output: ** (process:2621): WARNING **: 23:48:21.448: Specifying an export on the command line no longer uses the oldstyle protocol."}
- {"dt": "2024-08-15T23:48:21.450774", "lvl": "debug", "msg": "output: "}
- {"dt": "2024-08-15T23:48:21.451295", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server done"}
- {"dt": "2024-08-15T23:48:21.454292", "lvl": "debug", "msg": "end: 1.7 xnbd-server-deploy (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:21.455195", "lvl": "info", "msg": "end: 1 nbd-deploy (duration 00:03:08) [common]"}
- {"dt": "2024-08-15T23:48:21.455865", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:20:00) [common]"}
- {"dt": "2024-08-15T23:48:21.456623", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:20:00) [common]"}
- {"dt": "2024-08-15T23:48:21.457660", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:21.458394", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:20:00) [common]"}
- {"dt": "2024-08-15T23:48:21.459362", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2024-08-15T23:48:21.459968", "lvl": "debug", "msg": "- {BOOTX}: booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-08-15T23:48:21.461359", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x02400000"}
- {"dt": "2024-08-15T23:48:21.461923", "lvl": "debug", "msg": "- {DTB}: 35933/nbd-deploy-2hwyeya7/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T23:48:21.462417", "lvl": "debug", "msg": "- {INITRD}: 35933/nbd-deploy-2hwyeya7/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T23:48:21.462842", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x00080000"}
- {"dt": "2024-08-15T23:48:21.463289", "lvl": "debug", "msg": "- {KERNEL}: 35933/nbd-deploy-2hwyeya7/kernel/Image"}
- {"dt": "2024-08-15T23:48:21.463725", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2024-08-15T23:48:21.464976", "lvl": "debug", "msg": "- {NBDSERVERIP}: 192.168.66.1"}
- {"dt": "2024-08-15T23:48:21.465742", "lvl": "debug", "msg": "- {NBDSERVERPORT}: 61980"}
- {"dt": "2024-08-15T23:48:21.466450", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2024-08-15T23:48:21.467101", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2024-08-15T23:48:21.467525", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x02700000"}
- {"dt": "2024-08-15T23:48:21.468167", "lvl": "debug", "msg": "- {RAMDISK}: 35933/nbd-deploy-2hwyeya7/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T23:48:21.468876", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2024-08-15T23:48:21.469329", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2024-08-15T23:48:21.469968", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2024-08-15T23:48:21.472242", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2024-08-15T23:48:21.473027", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2024-08-15T23:48:21.473694", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2024-08-15T23:48:21.474352", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2024-08-15T23:48:21.474821", "lvl": "info", "msg": "- setenv initrd_high 0xffffffff"}
- {"dt": "2024-08-15T23:48:21.475455", "lvl": "info", "msg": "- setenv fdt_high 0xffffffff"}
- {"dt": "2024-08-15T23:48:21.476151", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2024-08-15T23:48:21.476854", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2024-08-15T23:48:21.477682", "lvl": "info", "msg": "- tftp 0x00080000 35933/nbd-deploy-2hwyeya7/kernel/Image"}
- {"dt": "2024-08-15T23:48:21.478395", "lvl": "info", "msg": "- tftp 0x02700000 35933/nbd-deploy-2hwyeya7/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T23:48:21.478825", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2024-08-15T23:48:21.479465", "lvl": "info", "msg": "- tftp 0x02400000 35933/nbd-deploy-2hwyeya7/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T23:48:21.480089", "lvl": "info", "msg": "- setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61980 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-08-15T23:48:21.480839", "lvl": "info", "msg": "- fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-08-15T23:48:21.481644", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T23:48:21.482385", "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-08-15T23:48:21.484007", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:20:00) [common]"}
- {"dt": "2024-08-15T23:48:21.484880", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63003'"}
- {"dt": "2024-08-15T23:48:25.576906", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2024-08-15T23:48:25.578859", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:04) [common]"}
- {"dt": "2024-08-15T23:48:25.579835", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:19:56) [common]"}
- {"dt": "2024-08-15T23:48:25.580641", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:19:56) [common]"}
- {"dt": "2024-08-15T23:48:25.581361", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:19:56) [common]"}
- {"dt": "2024-08-15T23:48:25.582547", "lvl": "debug", "msg": "Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '7'"}
- {"dt": "2024-08-15T23:48:29.083455", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2024-08-15T23:48:30.151835", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2024-08-15T23:48:30.193711", "lvl": "debug", "msg": "Returned 0 in 4 seconds"}
- {"dt": "2024-08-15T23:48:30.295394", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:05) [common]"}
- {"dt": "2024-08-15T23:48:30.296181", "lvl": "results", "msg": {"case": "pdu-reboot", "definition": "lava", "duration": "4.71", "extra": {"status": "success"}, "level": "2.4.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:48:30.297867", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:05) [common]"}
- {"dt": "2024-08-15T23:48:30.298624", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:19:51) [common]"}
- {"dt": "2024-08-15T23:48:30.299446", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2024-08-15T23:48:30.299994", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:20:00)"}
- {"dt": "2024-08-15T23:48:30.301721", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2024-08-15T23:48:30.302537", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2024-08-15T23:48:30.302986", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2024-08-15T23:48:36.859187", "lvl": "target", "msg": "\0"}
- {"dt": "2024-08-15T23:48:36.860740", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T23:48:36.862831", "lvl": "target", "msg": "U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)"}
- {"dt": "2024-08-15T23:48:36.864402", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T23:48:37.004966", "lvl": "target", "msg": "DRAM:  3.9 GiB"}
- {"dt": "2024-08-15T23:48:37.037565", "lvl": "target", "msg": "RPI 4 Model B (0xc03111)"}
- {"dt": "2024-08-15T23:48:37.073765", "lvl": "target", "msg": "MMC:   emmc2@7e340000: 0, mmcnr@7e300000: 1"}
- {"dt": "2024-08-15T23:48:37.140655", "lvl": "target", "msg": "Loading Environment from FAT... *** Warning - bad CRC, using default environment"}
- {"dt": "2024-08-15T23:48:37.141560", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T23:48:37.168825", "lvl": "target", "msg": "In:    serial"}
- {"dt": "2024-08-15T23:48:37.169969", "lvl": "target", "msg": "Out:   serial"}
- {"dt": "2024-08-15T23:48:37.170904", "lvl": "target", "msg": "Err:   serial"}
- {"dt": "2024-08-15T23:48:37.171864", "lvl": "target", "msg": "Net:   eth0: genet@7d580000"}
- {"dt": "2024-08-15T23:48:37.172893", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2024-08-15T23:48:37.173687", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2024-08-15T23:48:37.175190", "lvl": "input", "msg": "c"}
- {"dt": "2024-08-15T23:48:37.175966", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:00:07) [common]"}
- {"dt": "2024-08-15T23:48:37.176728", "lvl": "debug", "msg": "start: 2.4.3 bootloader-commands (timeout 00:19:44) [common]"}
- {"dt": "2024-08-15T23:48:37.177289", "lvl": "debug", "msg": "Setting prompt string to ['U-Boot>']"}
- {"dt": "2024-08-15T23:48:37.177774", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>'] (timeout 00:19:44)"}
- {"dt": "2024-08-15T23:48:37.228843", "lvl": "target", "msg": "Hit any key to stop autoboot:  2 \x03\b\b\b 0 "}
- {"dt": "2024-08-15T23:48:37.230746", "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-08-15T23:48:37.232100", "lvl": "input", "msg": "setenv autoload no\n"}
- {"dt": "2024-08-15T23:48:37.333917", "lvl": "target", "msg": "U-Boot> setenv autoload no"}
- {"dt": "2024-08-15T23:48:37.335979", "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-08-15T23:48:37.346554", "lvl": "target", "msg": "setenv autoload no"}
- {"dt": "2024-08-15T23:48:37.347433", "lvl": "input", "msg": "setenv initrd_high 0xffffffff\n"}
- {"dt": "2024-08-15T23:48:37.448383", "lvl": "target", "msg": "U-Boot> setenv initrd_high 0xffffffff"}
- {"dt": "2024-08-15T23:48:37.450773", "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-08-15T23:48:37.458331", "lvl": "target", "msg": "setenv initrd_high 0xffffffff"}
- {"dt": "2024-08-15T23:48:37.459469", "lvl": "input", "msg": "setenv fdt_high 0xffffffff\n"}
- {"dt": "2024-08-15T23:48:37.560573", "lvl": "target", "msg": "U-Boot> setenv fdt_high 0xffffffff"}
- {"dt": "2024-08-15T23:48:37.562575", "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-08-15T23:48:37.570316", "lvl": "target", "msg": "setenv fdt_high 0xffffffff"}
- {"dt": "2024-08-15T23:48:37.571359", "lvl": "input", "msg": "dhcp\n"}
- {"dt": "2024-08-15T23:48:37.672416", "lvl": "target", "msg": "U-Boot> dhcp"}
- {"dt": "2024-08-15T23:48:37.673729", "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-08-15T23:48:37.698813", "lvl": "target", "msg": "dhcp"}
- {"dt": "2024-08-15T23:48:40.847700", "lvl": "target", "msg": "genet@7d580000 Waiting for PHY auto negotiation to complete....... done"}
- {"dt": "2024-08-15T23:48:40.849360", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2024-08-15T23:48:41.087527", "lvl": "target", "msg": "BOOTP broadcast 2"}
- {"dt": "2024-08-15T23:48:41.597635", "lvl": "target", "msg": "BOOTP broadcast 3"}
- {"dt": "2024-08-15T23:48:42.135946", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (1283 ms)"}
- {"dt": "2024-08-15T23:48:42.136912", "lvl": "input", "msg": "setenv serverip 192.168.66.1\n"}
- {"dt": "2024-08-15T23:48:42.237754", "lvl": "target", "msg": "U-Boot> setenv serverip 192.168.66.1"}
- {"dt": "2024-08-15T23:48:42.238587", "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-08-15T23:48:42.246753", "lvl": "target", "msg": "setenv serverip 192.168.66.1"}
- {"dt": "2024-08-15T23:48:42.247616", "lvl": "input", "msg": "tftp 0x00080000 35933/nbd-deploy-2hwyeya7/kernel/Image\n"}
- {"dt": "2024-08-15T23:48:42.348387", "lvl": "target", "msg": "U-Boot> tftp 0x00080000 35933/nbd-deploy-2hwyeya7/kernel/Image"}
- {"dt": "2024-08-15T23:48:42.349358", "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-08-15T23:48:42.376648", "lvl": "target", "msg": "tftp 0x00080000 35933/nbd-deploy-2hwyeya7/kernel/Image"}
- {"dt": "2024-08-15T23:48:42.377290", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2024-08-15T23:48:42.377683", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2024-08-15T23:48:42.379884", "lvl": "target", "msg": "Filename '35933/nbd-deploy-2hwyeya7/kernel/Image'."}
- {"dt": "2024-08-15T23:48:42.380539", "lvl": "target", "msg": "Load address: 0x80000"}
- {"dt": "2024-08-15T23:49:25.002683", "lvl": "target", "msg": "Loading: *\bT #T #################################################  27.2 MiB"}
- {"dt": "2024-08-15T23:49:25.003793", "lvl": "target", "msg": "\t 653.3 KiB/s"}
- {"dt": "2024-08-15T23:49:25.004932", "lvl": "target", "msg": "done"}
- {"dt": "2024-08-15T23:49:25.006831", "lvl": "target", "msg": "Bytes transferred = 28535296 (1b36a00 hex)"}
- {"dt": "2024-08-15T23:49:25.008199", "lvl": "input", "msg": "tftp 0x02700000 35933/nbd-deploy-2hwyeya7/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz\n"}
- {"dt": "2024-08-15T23:49:25.109685", "lvl": "target", "msg": "U-Boot> tftp 0x02700000 35933/nbd-deploy-2hwyeya7/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T23:49:25.110534", "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:18:56)"}
- {"dt": "2024-08-15T23:49:25.116392", "lvl": "target", "msg": "tftp 0x02700000 35933/nbd-deploy-2hwyeya7/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T23:49:25.156771", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2024-08-15T23:49:25.157781", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2024-08-15T23:49:25.158240", "lvl": "target", "msg": "Filename '35933/nbd-deploy-2hwyeya7/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz'."}
- {"dt": "2024-08-15T23:49:25.158624", "lvl": "target", "msg": "Load address: 0x2700000"}
- {"dt": "2024-08-15T23:49:28.061487", "lvl": "target", "msg": "Loading: *\b##################################################  2.1 MiB"}
- {"dt": "2024-08-15T23:49:28.062256", "lvl": "target", "msg": "\t 721.7 KiB/s"}
- {"dt": "2024-08-15T23:49:28.062858", "lvl": "target", "msg": "done"}
- {"dt": "2024-08-15T23:49:28.064757", "lvl": "target", "msg": "Bytes transferred = 2153469 (20dbfd hex)"}
- {"dt": "2024-08-15T23:49:28.066075", "lvl": "input", "msg": "setenv initrd_size ${filesize}\n"}
- {"dt": "2024-08-15T23:49:28.167371", "lvl": "target", "msg": "U-Boot> setenv initrd_size ${filesize}"}
- {"dt": "2024-08-15T23:49:28.169004", "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:18:53)"}
- {"dt": "2024-08-15T23:49:28.175767", "lvl": "target", "msg": "setenv initrd_size ${filesize}"}
- {"dt": "2024-08-15T23:49:28.177412", "lvl": "input", "msg": "tftp 0x02400000 35933/nbd-deploy-2hwyeya7/dtb/bcm2711-rpi-4-b+vc4.dtb\n"}
- {"dt": "2024-08-15T23:49:28.278984", "lvl": "target", "msg": "U-Boot> tftp 0x02400000 35933/nbd-deploy-2hwyeya7/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T23:49:28.279976", "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:18:53)"}
- {"dt": "2024-08-15T23:49:28.285410", "lvl": "target", "msg": "tftp 0x02400000 35933/nbd-deploy-2hwyeya7/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T23:49:28.328966", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2024-08-15T23:49:28.329972", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2024-08-15T23:49:28.330770", "lvl": "target", "msg": "Filename '35933/nbd-deploy-2hwyeya7/dtb/bcm2711-rpi-4-b+vc4.dtb'."}
- {"dt": "2024-08-15T23:49:28.331544", "lvl": "target", "msg": "Load address: 0x2400000"}
- {"dt": "2024-08-15T23:49:28.341482", "lvl": "target", "msg": "Loading: *\b##################################################  53.5 KiB"}
- {"dt": "2024-08-15T23:49:28.342463", "lvl": "target", "msg": "\t 2.3 MiB/s"}
- {"dt": "2024-08-15T23:49:28.343256", "lvl": "target", "msg": "done"}
- {"dt": "2024-08-15T23:49:28.344886", "lvl": "target", "msg": "Bytes transferred = 54759 (d5e7 hex)"}
- {"dt": "2024-08-15T23:49:28.346292", "lvl": "input", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61980 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-08-15T23:49:28.447477", "lvl": "target", "msg": "U-Boot> setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61980 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-08-15T23:49:28.449101", "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:18:53)"}
- {"dt": "2024-08-15T23:49:28.454171", "lvl": "target", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61980 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-08-15T23:49:28.455444", "lvl": "input", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000\n"}
- {"dt": "2024-08-15T23:49:28.557510", "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-08-15T23:49:28.558621", "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-08-15T23:49:28.559437", "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:18:53)"}
- {"dt": "2024-08-15T23:49:28.569114", "lvl": "target", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-08-15T23:49:28.569837", "lvl": "target", "msg": "libfdt fdt_path_offset() returned FDT_ERR_BADPATH"}
- {"dt": "2024-08-15T23:49:28.788655", "lvl": "target", "msg": "## Flattened Device Tree blob at 02400000"}
- {"dt": "2024-08-15T23:49:28.789321", "lvl": "target", "msg": "   Booting using the fdt blob at 0x2400000"}
- {"dt": "2024-08-15T23:49:28.792246", "lvl": "target", "msg": "   Loading Ramdisk to 3ad3b000, end 3af48bfd ... OK"}
- {"dt": "2024-08-15T23:49:28.812816", "lvl": "target", "msg": "   Loading Device Tree to 000000003ad2a000, end 000000003ad3afff ... OK"}
- {"dt": "2024-08-15T23:49:28.813638", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T23:49:28.814297", "lvl": "target", "msg": "Starting kernel ..."}
- {"dt": "2024-08-15T23:49:28.814925", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T23:49:28.816162", "lvl": "debug", "msg": "end: 2.4.3 bootloader-commands (duration 00:00:52) [common]"}
- {"dt": "2024-08-15T23:49:28.817244", "lvl": "debug", "msg": "start: 2.4.4 auto-login-action (timeout 00:18:53) [common]"}
- {"dt": "2024-08-15T23:49:28.818010", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2024-08-15T23:49:28.818775", "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-08-15T23:49:28.819527", "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-08-15T23:49:30.877153", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]"}
- {"dt": "2024-08-15T23:49:30.878511", "lvl": "debug", "msg": "start: 2.4.4.1 login-action (timeout 00:18:51) [common]"}
- {"dt": "2024-08-15T23:49:30.879309", "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-08-15T23:49:30.879944", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2024-08-15T23:49:30.880617", "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-08-15T23:49:30.881334", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2024-08-15T23:49:30.881991", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2024-08-15T23:49:30.882621", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2024-08-15T23:49:30.883209", "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-08-15T23:49:30.884454", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:18:51)"}
- {"dt": "2024-08-15T23:49:30.888229", "lvl": "target", "msg": "[    0.000000] Linux version 6.6.22-v8 (oe-user@oe-host) (aarch64-agl-linux-gcc (GCC) 13.3.0, GNU ld (GNU Binutils) 2.42.0.20240716) #1 SMP PREEMPT Wed Jul 24 10:01:18 UTC 2024"}
- {"dt": "2024-08-15T23:49:30.888915", "lvl": "target", "msg": "[    0.000000] KASLR disabled due to lack of seed"}
- {"dt": "2024-08-15T23:49:30.889589", "lvl": "target", "msg": "[    0.000000] Machine model: Raspberry Pi 4 Model B"}
- {"dt": "2024-08-15T23:49:30.890122", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2024-08-15T23:49:30.890609", "lvl": "target", "msg": "[    0.000000] Reserved memory: created CMA memory pool at 0x0000000010400000, size 508 MiB"}
- {"dt": "2024-08-15T23:49:30.921078", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool"}
- {"dt": "2024-08-15T23:49:30.921835", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: 0x0000000010400000..0x000000002fffffff (520192 KiB) map reusable linux,cma"}
- {"dt": "2024-08-15T23:49:30.922572", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2024-08-15T23:49:30.923184", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003fffffff]"}
- {"dt": "2024-08-15T23:49:30.923745", "lvl": "target", "msg": "[    0.000000]   DMA32    [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2024-08-15T23:49:30.924295", "lvl": "target", "msg": "[    0.000000]   Normal   empty"}
- {"dt": "2024-08-15T23:49:30.924953", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2024-08-15T23:49:30.925689", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2024-08-15T23:49:30.964504", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]"}
- {"dt": "2024-08-15T23:49:30.965784", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2024-08-15T23:49:30.966469", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]"}
- {"dt": "2024-08-15T23:49:30.967107", "lvl": "target", "msg": "[    0.000000] On node 0, zone DMA32: 19456 pages in unavailable ranges"}
- {"dt": "2024-08-15T23:49:30.967756", "lvl": "target", "msg": "[    0.000000] On node 0, zone DMA32: 16384 pages in unavailable ranges"}
- {"dt": "2024-08-15T23:49:30.968466", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 31 pages/cpu s86632 r8192 d32152 u126976"}
- {"dt": "2024-08-15T23:49:30.969337", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2024-08-15T23:49:31.008524", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v2"}
- {"dt": "2024-08-15T23:49:31.011139", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v3a"}
- {"dt": "2024-08-15T23:49:31.012746", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v4"}
- {"dt": "2024-08-15T23:49:31.014075", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-BHB"}
- {"dt": "2024-08-15T23:49:31.015541", "lvl": "target", "msg": "[    0.000000] CPU features: detected: ARM erratum 1742098"}
- {"dt": "2024-08-15T23:49:31.016681", "lvl": "target", "msg": "[    0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923"}
- {"dt": "2024-08-15T23:49:31.017750", "lvl": "target", "msg": "[    0.000000] alternatives: applying boot alternatives"}
- {"dt": "2024-08-15T23:49:31.053234", "lvl": "target", "msg": "[    0.000000] Kernel command line: console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61980 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-08-15T23:49:31.055033", "lvl": "target", "msg": "[    0.000000] Unknown kernel command line parameters \\\"verbose earlyprintk ${extraargs} fstab=no\\\", will be passed to user space."}
- {"dt": "2024-08-15T23:49:31.056793", "lvl": "target", "msg": "[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.096469", "lvl": "target", "msg": "[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.098778", "lvl": "target", "msg": "[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 996912"}
- {"dt": "2024-08-15T23:49:31.099959", "lvl": "target", "msg": "[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off"}
- {"dt": "2024-08-15T23:49:31.101002", "lvl": "target", "msg": "[    0.000000] software IO TLB: area num 4."}
- {"dt": "2024-08-15T23:49:31.101945", "lvl": "target", "msg": "[    0.000000] software IO TLB: mapped [mem 0x0000000036d2a000-0x000000003ad2a000] (64MB)"}
- {"dt": "2024-08-15T23:49:31.102952", "lvl": "target", "msg": "[    0.000000] Memory: 3352824K/4050944K available (15104K kernel code, 2266K rwdata, 4992K rodata, 5376K init, 1117K bss, 177928K reserved, 520192K cma-reserved)"}
- {"dt": "2024-08-15T23:49:31.139404", "lvl": "target", "msg": "[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1"}
- {"dt": "2024-08-15T23:49:31.141628", "lvl": "target", "msg": "[    0.000000] ftrace: allocating 49049 entries in 192 pages"}
- {"dt": "2024-08-15T23:49:31.142609", "lvl": "target", "msg": "[    0.000000] ftrace: allocated 192 pages with 2 groups"}
- {"dt": "2024-08-15T23:49:31.143443", "lvl": "target", "msg": "[    0.000000] trace event string verifier disabled"}
- {"dt": "2024-08-15T23:49:31.144282", "lvl": "target", "msg": "[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2024-08-15T23:49:31.145179", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2024-08-15T23:49:31.146039", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4."}
- {"dt": "2024-08-15T23:49:31.147050", "lvl": "target", "msg": "[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2024-08-15T23:49:31.183828", "lvl": "target", "msg": "[    0.000000] \tRude variant of Tasks RCU enabled."}
- {"dt": "2024-08-15T23:49:31.186449", "lvl": "target", "msg": "[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2024-08-15T23:49:31.187815", "lvl": "target", "msg": "[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2024-08-15T23:49:31.189057", "lvl": "target", "msg": "[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4"}
- {"dt": "2024-08-15T23:49:31.190062", "lvl": "target", "msg": "[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2024-08-15T23:49:31.191405", "lvl": "target", "msg": "[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2024-08-15T23:49:31.192576", "lvl": "target", "msg": "[    0.000000] GIC: Using split EOI/Deactivate mode"}
- {"dt": "2024-08-15T23:49:31.193873", "lvl": "target", "msg": "[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention."}
- {"dt": "2024-08-15T23:49:31.228845", "lvl": "target", "msg": "[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys)."}
- {"dt": "2024-08-15T23:49:31.230590", "lvl": "target", "msg": "[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns"}
- {"dt": "2024-08-15T23:49:31.231625", "lvl": "target", "msg": "[    0.000001] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns"}
- {"dt": "2024-08-15T23:49:31.232712", "lvl": "target", "msg": "[    0.000325] Console: colour dummy device 80x25"}
- {"dt": "2024-08-15T23:49:31.233742", "lvl": "target", "msg": "[    0.000376] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)"}
- {"dt": "2024-08-15T23:49:31.271238", "lvl": "target", "msg": "[    0.000393] pid_max: default: 32768 minimum: 301"}
- {"dt": "2024-08-15T23:49:31.273904", "lvl": "target", "msg": "[    0.000468] LSM: initializing lsm=capability,integrity"}
- {"dt": "2024-08-15T23:49:31.275164", "lvl": "target", "msg": "[    0.000670] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.276579", "lvl": "target", "msg": "[    0.000714] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.277454", "lvl": "target", "msg": "[    0.001598] cgroup: Disabling memory control group subsystem"}
- {"dt": "2024-08-15T23:49:31.278129", "lvl": "target", "msg": "[    0.003252] RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1."}
- {"dt": "2024-08-15T23:49:31.279003", "lvl": "target", "msg": "[    0.003379] RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1."}
- {"dt": "2024-08-15T23:49:31.314490", "lvl": "target", "msg": "[    0.003488] RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1."}
- {"dt": "2024-08-15T23:49:31.315993", "lvl": "target", "msg": "[    0.003766] rcu: Hierarchical SRCU implementation."}
- {"dt": "2024-08-15T23:49:31.318614", "lvl": "target", "msg": "[    0.003773] rcu: \tMax phase no-delay instances is 1000."}
- {"dt": "2024-08-15T23:49:31.319930", "lvl": "target", "msg": "[    0.005675] EFI services will not be available."}
- {"dt": "2024-08-15T23:49:31.321336", "lvl": "target", "msg": "[    0.006023] smp: Bringing up secondary CPUs ..."}
- {"dt": "2024-08-15T23:49:31.322545", "lvl": "target", "msg": "[    0.006678] Detected PIPT I-cache on CPU1"}
- {"dt": "2024-08-15T23:49:31.323685", "lvl": "target", "msg": "[    0.006798] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]"}
- {"dt": "2024-08-15T23:49:31.324853", "lvl": "target", "msg": "[    0.007513] Detected PIPT I-cache on CPU2"}
- {"dt": "2024-08-15T23:49:31.358165", "lvl": "target", "msg": "[    0.007601] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]"}
- {"dt": "2024-08-15T23:49:31.360919", "lvl": "target", "msg": "[    0.008347] Detected PIPT I-cache on CPU3"}
- {"dt": "2024-08-15T23:49:31.362241", "lvl": "target", "msg": "[    0.008439] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]"}
- {"dt": "2024-08-15T23:49:31.363400", "lvl": "target", "msg": "[    0.008539] smp: Brought up 1 node, 4 CPUs"}
- {"dt": "2024-08-15T23:49:31.364681", "lvl": "target", "msg": "[    0.008549] SMP: Total of 4 processors activated."}
- {"dt": "2024-08-15T23:49:31.365391", "lvl": "target", "msg": "[    0.008557] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2024-08-15T23:49:31.366140", "lvl": "target", "msg": "[    0.008562] CPU features: detected: 32-bit EL1 Support"}
- {"dt": "2024-08-15T23:49:31.366838", "lvl": "target", "msg": "[    0.008570] CPU features: detected: CRC32 instructions"}
- {"dt": "2024-08-15T23:49:31.367653", "lvl": "target", "msg": "[    0.008673] CPU: All CPU(s) started at EL2"}
- {"dt": "2024-08-15T23:49:31.402502", "lvl": "target", "msg": "[    0.008700] alternatives: applying system-wide alternatives"}
- {"dt": "2024-08-15T23:49:31.405452", "lvl": "target", "msg": "[    0.011000] devtmpfs: initialized"}
- {"dt": "2024-08-15T23:49:31.406709", "lvl": "target", "msg": "[    0.020645] Enabled cp15_barrier support"}
- {"dt": "2024-08-15T23:49:31.407952", "lvl": "target", "msg": "[    0.020670] Enabled setend support"}
- {"dt": "2024-08-15T23:49:31.409008", "lvl": "target", "msg": "[    0.020973] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2024-08-15T23:49:31.409721", "lvl": "target", "msg": "[    0.020993] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.410368", "lvl": "target", "msg": "[    0.033240] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2024-08-15T23:49:31.411150", "lvl": "target", "msg": "[    0.033740] DMI not present or invalid."}
- {"dt": "2024-08-15T23:49:31.445997", "lvl": "target", "msg": "[    0.034473] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2024-08-15T23:49:31.447890", "lvl": "target", "msg": "[    0.036374] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations"}
- {"dt": "2024-08-15T23:49:31.448647", "lvl": "target", "msg": "[    0.036632] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations"}
- {"dt": "2024-08-15T23:49:31.449247", "lvl": "target", "msg": "[    0.037047] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations"}
- {"dt": "2024-08-15T23:49:31.449816", "lvl": "target", "msg": "[    0.037109] audit: initializing netlink subsys (disabled)"}
- {"dt": "2024-08-15T23:49:31.450572", "lvl": "target", "msg": "[    0.037290] audit: type=2000 audit(0.036:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2024-08-15T23:49:31.489529", "lvl": "target", "msg": "[    0.037807] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2024-08-15T23:49:31.491515", "lvl": "target", "msg": "[    0.037858] cpuidle: using governor menu"}
- {"dt": "2024-08-15T23:49:31.492484", "lvl": "target", "msg": "[    0.038103] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2024-08-15T23:49:31.493340", "lvl": "target", "msg": "[    0.038209] ASID allocator initialised with 65536 entries"}
- {"dt": "2024-08-15T23:49:31.494178", "lvl": "target", "msg": "[    0.039115] Serial: AMBA PL011 UART driver"}
- {"dt": "2024-08-15T23:49:31.495033", "lvl": "target", "msg": "[    0.045738] bcm2835-mbox fe00b880.mailbox: mailbox enabled"}
- {"dt": "2024-08-15T23:49:31.495819", "lvl": "target", "msg": "[    0.056154] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-01-22T17:23:15, variant start"}
- {"dt": "2024-08-15T23:49:31.533341", "lvl": "target", "msg": "[    0.060151] raspberrypi-firmware soc:firmware: Firmware hash is acb03c7d18aa08f25f6419d696d0cc39761d3e62"}
- {"dt": "2024-08-15T23:49:31.534097", "lvl": "target", "msg": "[    0.070101] Modules: 25504 pages in range for non-PLT usage"}
- {"dt": "2024-08-15T23:49:31.534641", "lvl": "target", "msg": "[    0.070112] Modules: 517024 pages in range for PLT usage"}
- {"dt": "2024-08-15T23:49:31.535974", "lvl": "target", "msg": "[    0.077138] bcm2835-dma fe007000.dma-controller: DMA legacy API manager, dmachans=0x1"}
- {"dt": "2024-08-15T23:49:31.536678", "lvl": "target", "msg": "[    0.078849] iommu: Default domain type: Translated"}
- {"dt": "2024-08-15T23:49:31.537380", "lvl": "target", "msg": "[    0.078858] iommu: DMA domain TLB invalidation policy: strict mode"}
- {"dt": "2024-08-15T23:49:31.538186", "lvl": "target", "msg": "[    0.079238] SCSI subsystem initialized"}
- {"dt": "2024-08-15T23:49:31.538878", "lvl": "target", "msg": "[    0.079407] usbcore: registered new interface driver usbfs"}
- {"dt": "2024-08-15T23:49:31.576927", "lvl": "target", "msg": "[    0.079442] usbcore: registered new interface driver hub"}
- {"dt": "2024-08-15T23:49:31.578778", "lvl": "target", "msg": "[    0.079485] usbcore: registered new device driver usb"}
- {"dt": "2024-08-15T23:49:31.579490", "lvl": "target", "msg": "[    0.079921] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2024-08-15T23:49:31.580076", "lvl": "target", "msg": "[    0.079928] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2024-08-15T23:49:31.580708", "lvl": "target", "msg": "[    0.079948] PTP clock support registered"}
- {"dt": "2024-08-15T23:49:31.581329", "lvl": "target", "msg": "[    0.080206] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2024-08-15T23:49:31.581973", "lvl": "target", "msg": "[    0.081152] vgaarb: loaded"}
- {"dt": "2024-08-15T23:49:31.582774", "lvl": "target", "msg": "[    0.081610] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2024-08-15T23:49:31.620627", "lvl": "target", "msg": "[    0.082002] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2024-08-15T23:49:31.622484", "lvl": "target", "msg": "[    0.082044] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2024-08-15T23:49:31.623132", "lvl": "target", "msg": "[    0.082150] FS-Cache: Loaded"}
- {"dt": "2024-08-15T23:49:31.623687", "lvl": "target", "msg": "[    0.084258] CacheFiles: Loaded"}
- {"dt": "2024-08-15T23:49:31.624208", "lvl": "target", "msg": "[    0.092709] NET: Registered PF_INET protocol family"}
- {"dt": "2024-08-15T23:49:31.624836", "lvl": "target", "msg": "[    0.093131] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.625466", "lvl": "target", "msg": "[    0.097658] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.664671", "lvl": "target", "msg": "[    0.097714] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.665529", "lvl": "target", "msg": "[    0.097733] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.667376", "lvl": "target", "msg": "[    0.097965] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.668095", "lvl": "target", "msg": "[    0.099047] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2024-08-15T23:49:31.668828", "lvl": "target", "msg": "[    0.099375] MPTCP token hash table entries: 4096 (order: 4, 98304 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.669459", "lvl": "target", "msg": "[    0.099558] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.708145", "lvl": "target", "msg": "[    0.099608] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T23:49:31.710033", "lvl": "target", "msg": "[    0.099863] NET: Registered PF_UNIX/PF_LOCAL protocol family"}
- {"dt": "2024-08-15T23:49:31.710720", "lvl": "target", "msg": "[    0.100450] RPC: Registered named UNIX socket transport module."}
- {"dt": "2024-08-15T23:49:31.711290", "lvl": "target", "msg": "[    0.100460] RPC: Registered udp transport module."}
- {"dt": "2024-08-15T23:49:31.711823", "lvl": "target", "msg": "[    0.100465] RPC: Registered tcp transport module."}
- {"dt": "2024-08-15T23:49:31.712414", "lvl": "target", "msg": "[    0.100471] RPC: Registered tcp-with-tls transport module."}
- {"dt": "2024-08-15T23:49:31.712991", "lvl": "target", "msg": "[    0.100476] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2024-08-15T23:49:31.713663", "lvl": "target", "msg": "[    0.100494] PCI: CLS 0 bytes, default 64"}
- {"dt": "2024-08-15T23:49:31.751861", "lvl": "target", "msg": "[    0.101073] Trying to unpack rootfs image as initramfs..."}
- {"dt": "2024-08-15T23:49:31.753987", "lvl": "target", "msg": "[    0.101433] rootfs image is not initramfs (no cpio magic); looks like an initrd"}
- {"dt": "2024-08-15T23:49:31.754859", "lvl": "target", "msg": "[    0.101866] kvm [1]: IPA Size Limit: 44 bits"}
- {"dt": "2024-08-15T23:49:31.755630", "lvl": "target", "msg": "[    0.103338] kvm [1]: vgic interrupt IRQ9"}
- {"dt": "2024-08-15T23:49:31.756474", "lvl": "target", "msg": "[    0.103404] kvm [1]: Hyp mode initialized successfully"}
- {"dt": "2024-08-15T23:49:31.757324", "lvl": "target", "msg": "[    0.106667] Freeing initrd memory: 2100K"}
- {"dt": "2024-08-15T23:49:31.758083", "lvl": "target", "msg": "[    1.102726] Initialise system trusted keyrings"}
- {"dt": "2024-08-15T23:49:31.758871", "lvl": "target", "msg": "[    1.103030] workingset: timestamp_bits=46 max_order=20 bucket_order=0"}
- {"dt": "2024-08-15T23:49:31.759538", "lvl": "target", "msg": "[    1.103100] zbud: loaded"}
- {"dt": "2024-08-15T23:49:31.795838", "lvl": "target", "msg": "[    1.103812] NFS: Registering the id_resolver key type"}
- {"dt": "2024-08-15T23:49:31.796720", "lvl": "target", "msg": "[    1.103861] Key type id_resolver registered"}
- {"dt": "2024-08-15T23:49:31.797428", "lvl": "target", "msg": "[    1.103867] Key type id_legacy registered"}
- {"dt": "2024-08-15T23:49:31.799179", "lvl": "target", "msg": "[    1.103890] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2024-08-15T23:49:31.799919", "lvl": "target", "msg": "[    1.103897] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering..."}
- {"dt": "2024-08-15T23:49:31.800709", "lvl": "target", "msg": "[    1.104632] NET: Registered PF_ALG protocol family"}
- {"dt": "2024-08-15T23:49:31.801378", "lvl": "target", "msg": "[    1.104645] Key type asymmetric registered"}
- {"dt": "2024-08-15T23:49:31.802021", "lvl": "target", "msg": "[    1.104652] Asymmetric key parser 'x509' registered"}
- {"dt": "2024-08-15T23:49:31.839681", "lvl": "target", "msg": "[    1.104704] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)"}
- {"dt": "2024-08-15T23:49:31.840380", "lvl": "target", "msg": "[    1.104875] io scheduler mq-deadline registered"}
- {"dt": "2024-08-15T23:49:31.841833", "lvl": "target", "msg": "[    1.104884] io scheduler kyber registered"}
- {"dt": "2024-08-15T23:49:31.842405", "lvl": "target", "msg": "[    1.104922] io scheduler bfq registered"}
- {"dt": "2024-08-15T23:49:31.842847", "lvl": "target", "msg": "[    1.105761] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 23)"}
- {"dt": "2024-08-15T23:49:31.843270", "lvl": "target", "msg": "[    1.110698] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:"}
- {"dt": "2024-08-15T23:49:31.843681", "lvl": "target", "msg": "[    1.110725] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]"}
- {"dt": "2024-08-15T23:49:31.883464", "lvl": "target", "msg": "[    1.110766] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000"}
- {"dt": "2024-08-15T23:49:31.885822", "lvl": "target", "msg": "[    1.110802] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000"}
- {"dt": "2024-08-15T23:49:31.886815", "lvl": "target", "msg": "[    1.111808] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2024-08-15T23:49:31.887611", "lvl": "target", "msg": "[    1.111821] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2024-08-15T23:49:31.888233", "lvl": "target", "msg": "[    1.111835] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])"}
- {"dt": "2024-08-15T23:49:31.889088", "lvl": "target", "msg": "[    1.111876] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400"}
- {"dt": "2024-08-15T23:49:31.927326", "lvl": "target", "msg": "[    1.111962] pci 0000:00:00.0: PME# supported from D0 D3hot"}
- {"dt": "2024-08-15T23:49:31.931291", "lvl": "target", "msg": "[    1.115417] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring"}
- {"dt": "2024-08-15T23:49:31.932716", "lvl": "target", "msg": "[    1.115552] pci_bus 0000:01: supply vpcie3v3 not found, using dummy regulator"}
- {"dt": "2024-08-15T23:49:31.933926", "lvl": "target", "msg": "[    1.115676] pci_bus 0000:01: supply vpcie3v3aux not found, using dummy regulator"}
- {"dt": "2024-08-15T23:49:31.935178", "lvl": "target", "msg": "[    1.115729] pci_bus 0000:01: supply vpcie12v not found, using dummy regulator"}
- {"dt": "2024-08-15T23:49:31.937314", "lvl": "target", "msg": "[    1.223689] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)"}
- {"dt": "2024-08-15T23:49:31.970936", "lvl": "target", "msg": "[    1.223745] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330"}
- {"dt": "2024-08-15T23:49:31.971944", "lvl": "target", "msg": "[    1.223782] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]"}
- {"dt": "2024-08-15T23:49:31.974202", "lvl": "target", "msg": "[    1.223912] pci 0000:01:00.0: PME# supported from D0 D3cold"}
- {"dt": "2024-08-15T23:49:31.975438", "lvl": "target", "msg": "[    1.224277] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01"}
- {"dt": "2024-08-15T23:49:31.976816", "lvl": "target", "msg": "[    1.224310] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]"}
- {"dt": "2024-08-15T23:49:31.977869", "lvl": "target", "msg": "[    1.224326] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]"}
- {"dt": "2024-08-15T23:49:31.979308", "lvl": "target", "msg": "[    1.224349] pci 0000:00:00.0: PCI bridge to [bus 01]"}
- {"dt": "2024-08-15T23:49:32.014660", "lvl": "target", "msg": "[    1.224360] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]"}
- {"dt": "2024-08-15T23:49:32.016173", "lvl": "target", "msg": "[    1.224594] pcieport 0000:00:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2024-08-15T23:49:32.018414", "lvl": "target", "msg": "[    1.224733] pcieport 0000:00:00.0: PME: Signaling with IRQ 27"}
- {"dt": "2024-08-15T23:49:32.021446", "lvl": "target", "msg": "[    1.225020] pcieport 0000:00:00.0: AER: enabled with IRQ 27"}
- {"dt": "2024-08-15T23:49:32.022185", "lvl": "target", "msg": "[    1.228921] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled"}
- {"dt": "2024-08-15T23:49:32.022779", "lvl": "target", "msg": "[    1.230925] iproc-rng200 fe104000.rng: hwrng registered"}
- {"dt": "2024-08-15T23:49:32.023361", "lvl": "target", "msg": "[    1.231166] vc-mem: phys_addr:0x00000000 mem_base=0x00000000 mem_size:0x00000000(0 MiB)"}
- {"dt": "2024-08-15T23:49:32.023997", "lvl": "target", "msg": "[    1.231346] random: crng init done"}
- {"dt": "2024-08-15T23:49:32.059088", "lvl": "target", "msg": "[    1.236056] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:32.059763", "lvl": "target", "msg": "[    1.236078] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:32.060290", "lvl": "target", "msg": "[    1.236412] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:32.061059", "lvl": "target", "msg": "[    1.246440] brd: module loaded"}
- {"dt": "2024-08-15T23:49:32.061926", "lvl": "target", "msg": "[    1.252521] loop: module loaded"}
- {"dt": "2024-08-15T23:49:32.062501", "lvl": "target", "msg": "[    1.273115] Loading iSCSI transport class v2.0-870."}
- {"dt": "2024-08-15T23:49:32.063084", "lvl": "target", "msg": "[    1.276982] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000"}
- {"dt": "2024-08-15T23:49:32.102010", "lvl": "target", "msg": "[    1.469682] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus"}
- {"dt": "2024-08-15T23:49:32.103848", "lvl": "target", "msg": "[    1.470653] usbcore: registered new device driver r8152-cfgselector"}
- {"dt": "2024-08-15T23:49:32.104638", "lvl": "target", "msg": "[    1.470694] usbcore: registered new interface driver r8152"}
- {"dt": "2024-08-15T23:49:32.105472", "lvl": "target", "msg": "[    1.470734] usbcore: registered new interface driver lan78xx"}
- {"dt": "2024-08-15T23:49:32.106166", "lvl": "target", "msg": "[    1.472043] xhci_hcd 0000:01:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2024-08-15T23:49:32.106872", "lvl": "target", "msg": "[    1.472101] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2024-08-15T23:49:32.107579", "lvl": "target", "msg": "[    1.472126] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1"}
- {"dt": "2024-08-15T23:49:32.145828", "lvl": "target", "msg": "[    1.473838] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0700240000000890"}
- {"dt": "2024-08-15T23:49:32.146694", "lvl": "target", "msg": "[    1.474350] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2024-08-15T23:49:32.148450", "lvl": "target", "msg": "[    1.474367] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2"}
- {"dt": "2024-08-15T23:49:32.149317", "lvl": "target", "msg": "[    1.474384] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed"}
- {"dt": "2024-08-15T23:49:32.150058", "lvl": "target", "msg": "[    1.474588] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06"}
- {"dt": "2024-08-15T23:49:32.150615", "lvl": "target", "msg": "[    1.474603] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2024-08-15T23:49:32.151386", "lvl": "target", "msg": "[    1.474612] usb usb1: Product: xHCI Host Controller"}
- {"dt": "2024-08-15T23:49:32.189919", "lvl": "target", "msg": "[    1.474621] usb usb1: Manufacturer: Linux 6.6.22-v8 xhci-hcd"}
- {"dt": "2024-08-15T23:49:32.191704", "lvl": "target", "msg": "[    1.474629] usb usb1: SerialNumber: 0000:01:00.0"}
- {"dt": "2024-08-15T23:49:32.192363", "lvl": "target", "msg": "[    1.475198] hub 1-0:1.0: USB hub found"}
- {"dt": "2024-08-15T23:49:32.192940", "lvl": "target", "msg": "[    1.475241] hub 1-0:1.0: 1 port detected"}
- {"dt": "2024-08-15T23:49:32.193726", "lvl": "target", "msg": "[    1.475795] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.06"}
- {"dt": "2024-08-15T23:49:32.194549", "lvl": "target", "msg": "[    1.475810] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2024-08-15T23:49:32.195364", "lvl": "target", "msg": "[    1.475820] usb usb2: Product: xHCI Host Controller"}
- {"dt": "2024-08-15T23:49:32.196378", "lvl": "target", "msg": "[    1.475828] usb usb2: Manufacturer: Linux 6.6.22-v8 xhci-hcd"}
- {"dt": "2024-08-15T23:49:32.233318", "lvl": "target", "msg": "[    1.475836] usb usb2: SerialNumber: 0000:01:00.0"}
- {"dt": "2024-08-15T23:49:32.234122", "lvl": "target", "msg": "[    1.476301] hub 2-0:1.0: USB hub found"}
- {"dt": "2024-08-15T23:49:32.235672", "lvl": "target", "msg": "[    1.476342] hub 2-0:1.0: 4 ports detected"}
- {"dt": "2024-08-15T23:49:32.236367", "lvl": "target", "msg": "[    1.477227] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)"}
- {"dt": "2024-08-15T23:49:32.237051", "lvl": "target", "msg": "[    1.477997] usbcore: registered new interface driver uas"}
- {"dt": "2024-08-15T23:49:32.237744", "lvl": "target", "msg": "[    1.478052] usbcore: registered new interface driver usb-storage"}
- {"dt": "2024-08-15T23:49:32.238318", "lvl": "target", "msg": "[    1.478136] usbcore: registered new interface driver usbserial_generic"}
- {"dt": "2024-08-15T23:49:32.238965", "lvl": "target", "msg": "[    1.478168] usbserial: USB Serial support registered for generic"}
- {"dt": "2024-08-15T23:49:32.277158", "lvl": "target", "msg": "[    1.478203] usbcore: registered new interface driver cp210x"}
- {"dt": "2024-08-15T23:49:32.278975", "lvl": "target", "msg": "[    1.478228] usbserial: USB Serial support registered for cp210x"}
- {"dt": "2024-08-15T23:49:32.279670", "lvl": "target", "msg": "[    1.478663] mousedev: PS/2 mouse device common for all mice"}
- {"dt": "2024-08-15T23:49:32.280247", "lvl": "target", "msg": "[    1.479165] usbcore: registered new interface driver i2c-tiny-usb"}
- {"dt": "2024-08-15T23:49:32.280988", "lvl": "target", "msg": "[    1.482284] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2024-08-15T23:49:32.281689", "lvl": "target", "msg": "[    1.482295] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2024-08-15T23:49:32.282386", "lvl": "target", "msg": "[    1.482516] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2024-08-15T23:49:32.321029", "lvl": "target", "msg": "[    1.486242] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2024-08-15T23:49:32.323348", "lvl": "target", "msg": "[    1.486412] hid: raw HID events driver (C) Jiri Kosina"}
- {"dt": "2024-08-15T23:49:32.324344", "lvl": "target", "msg": "[    1.486550] usbcore: registered new interface driver usbhid"}
- {"dt": "2024-08-15T23:49:32.325034", "lvl": "target", "msg": "[    1.486554] usbhid: USB HID core driver"}
- {"dt": "2024-08-15T23:49:32.325618", "lvl": "target", "msg": "[    1.489980] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available"}
- {"dt": "2024-08-15T23:49:32.326169", "lvl": "target", "msg": "[    1.490379] usbcore: registered new interface driver snd-usb-audio"}
- {"dt": "2024-08-15T23:49:32.326735", "lvl": "target", "msg": "[    1.490785] NET: Registered PF_PACKET protocol family"}
- {"dt": "2024-08-15T23:49:32.327295", "lvl": "target", "msg": "[    1.490842] Key type dns_resolver registered"}
- {"dt": "2024-08-15T23:49:32.327998", "lvl": "target", "msg": "[    1.502597] registered taskstats version 1"}
- {"dt": "2024-08-15T23:49:32.364581", "lvl": "target", "msg": "[    1.502723] Loading compiled-in X.509 certificates"}
- {"dt": "2024-08-15T23:49:32.365568", "lvl": "target", "msg": "[    1.506431] Key type .fscrypt registered"}
- {"dt": "2024-08-15T23:49:32.367723", "lvl": "target", "msg": "[    1.506440] Key type fscrypt-provisioning registered"}
- {"dt": "2024-08-15T23:49:32.368663", "lvl": "target", "msg": "[    1.509934] uart-pl011 fe201000.serial: there is not valid maps for state default"}
- {"dt": "2024-08-15T23:49:32.369705", "lvl": "target", "msg": "[    1.510145] uart-pl011 fe201000.serial: cts_event_workaround enabled"}
- {"dt": "2024-08-15T23:49:32.370287", "lvl": "target", "msg": "[    1.510322] fe201000.serial: ttyAMA1 at MMIO 0xfe201000 (irq = 37, base_baud = 0) is a PL011 rev2"}
- {"dt": "2024-08-15T23:49:32.370875", "lvl": "target", "msg": "[    1.510429] serial serial0: tty port ttyAMA1 registered"}
- {"dt": "2024-08-15T23:49:32.409699", "lvl": "target", "msg": "[    1.511557] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default"}
- {"dt": "2024-08-15T23:49:32.410544", "lvl": "target", "msg": "[    1.511811] printk: console [ttyS0] disabled"}
- {"dt": "2024-08-15T23:49:32.412370", "lvl": "target", "msg": "[    1.512013] fe215040.serial: ttyS0 at MMIO 0xfe215040 (irq = 38, base_baud = 62500000) is a 16550"}
- {"dt": "2024-08-15T23:49:32.413202", "lvl": "target", "msg": "[    1.512214] printk: console [ttyS0] enabled"}
- {"dt": "2024-08-15T23:49:32.413802", "lvl": "target", "msg": "[    3.068702] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:32.414376", "lvl": "target", "msg": "[    3.077283] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:32.448096", "lvl": "target", "msg": "[    3.084313] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:32.450302", "lvl": "target", "msg": "[    3.090736] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer"}
- {"dt": "2024-08-15T23:49:32.451097", "lvl": "target", "msg": "[    3.097316] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver"}
- {"dt": "2024-08-15T23:49:32.451770", "lvl": "target", "msg": "[    3.105050] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0"}
- {"dt": "2024-08-15T23:49:32.452600", "lvl": "target", "msg": "[    3.111149] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated"}
- {"dt": "2024-08-15T23:49:32.513084", "lvl": "target", "msg": "[    3.143622] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:32.514367", "lvl": "target", "msg": "[    3.152247] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:32.514996", "lvl": "target", "msg": "[    3.159329] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:32.515633", "lvl": "target", "msg": "[    3.168570] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:32.516083", "lvl": "target", "msg": "[    3.177155] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:32.516711", "lvl": "target", "msg": "[    3.184162] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:32.559688", "lvl": "target", "msg": "[    3.189796] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA"}
- {"dt": "2024-08-15T23:49:32.560650", "lvl": "target", "msg": "[    3.190836] of_cfs_init"}
- {"dt": "2024-08-15T23:49:32.561539", "lvl": "target", "msg": "[    3.198303] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:32.562377", "lvl": "target", "msg": "[    3.199648] usb 1-1: new high-speed USB device number 2 using xhci_hcd"}
- {"dt": "2024-08-15T23:49:32.563245", "lvl": "target", "msg": "[    3.200232] of_cfs_init: OK"}
- {"dt": "2024-08-15T23:49:32.564086", "lvl": "target", "msg": "[    3.208198] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:32.565086", "lvl": "target", "msg": "[    3.224877] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:32.579819", "lvl": "target", "msg": "[    3.232843] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)"}
- {"dt": "2024-08-15T23:49:32.583138", "lvl": "target", "msg": "[    3.242156] bcmgenet fd580000.ethernet eth0: Link is Down"}
- {"dt": "2024-08-15T23:49:32.613855", "lvl": "target", "msg": "[    3.271900] mmc1: new high speed SDIO card at address 0001"}
- {"dt": "2024-08-15T23:49:32.684749", "lvl": "target", "msg": "[    3.305998] mmc0: new ultra high speed DDR50 SDHC card at address 59b4"}
- {"dt": "2024-08-15T23:49:32.685595", "lvl": "target", "msg": "[    3.313080] mmcblk0: mmc0:59b4 USDU1 7.51 GiB"}
- {"dt": "2024-08-15T23:49:32.687486", "lvl": "target", "msg": "[    3.319021]  mmcblk0: p1 p2"}
- {"dt": "2024-08-15T23:49:32.688295", "lvl": "target", "msg": "[    3.322087] mmcblk0: mmc0:59b4 USDU1 7.51 GiB"}
- {"dt": "2024-08-15T23:49:32.688961", "lvl": "target", "msg": "[    3.327538] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:32.689525", "lvl": "target", "msg": "[    3.336114] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:32.690193", "lvl": "target", "msg": "[    3.343140] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:32.741689", "lvl": "target", "msg": "[    3.366778] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.20"}
- {"dt": "2024-08-15T23:49:32.744030", "lvl": "target", "msg": "[    3.375087] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0"}
- {"dt": "2024-08-15T23:49:32.745062", "lvl": "target", "msg": "[    3.382331] usb 1-1: Product: USB2.0 Hub"}
- {"dt": "2024-08-15T23:49:32.745870", "lvl": "target", "msg": "[    3.387529] hub 1-1:1.0: USB hub found"}
- {"dt": "2024-08-15T23:49:32.746605", "lvl": "target", "msg": "[    3.391479] hub 1-1:1.0: 4 ports detected"}
- {"dt": "2024-08-15T23:49:32.747286", "lvl": "target", "msg": "[    3.404190] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:32.748192", "lvl": "target", "msg": "[    3.412795] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:32.781812", "lvl": "target", "msg": "[    3.419814] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:32.783506", "lvl": "target", "msg": "[    3.427984] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:32.784112", "lvl": "target", "msg": "[    3.436580] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:32.788905", "lvl": "target", "msg": "[    3.443584] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:33.034620", "lvl": "target", "msg": "[    3.689635] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd"}
- {"dt": "2024-08-15T23:49:33.171249", "lvl": "target", "msg": "[    3.795084] usb 1-1.3: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2024-08-15T23:49:33.174270", "lvl": "target", "msg": "[    3.803589] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2024-08-15T23:49:33.175899", "lvl": "target", "msg": "[    3.811019] usb 1-1.3: Product: USB2.0 Hub             "}
- {"dt": "2024-08-15T23:49:33.177461", "lvl": "target", "msg": "[    3.816334] usb 1-1.3: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2024-08-15T23:49:33.178481", "lvl": "target", "msg": "[    3.823459] hub 1-1.3:1.0: USB hub found"}
- {"dt": "2024-08-15T23:49:33.179271", "lvl": "target", "msg": "[    3.827672] hub 1-1.3:1.0: 4 ports detected"}
- {"dt": "2024-08-15T23:49:33.180138", "lvl": "target", "msg": "[    3.841587] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:33.198839", "lvl": "target", "msg": "[    3.850208] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:33.202057", "lvl": "target", "msg": "[    3.858627] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:33.482767", "lvl": "target", "msg": "[    4.137634] usb 1-1.3.1: new high-speed USB device number 4 using xhci_hcd"}
- {"dt": "2024-08-15T23:49:33.634815", "lvl": "target", "msg": "[    4.259086] usb 1-1.3.1: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2024-08-15T23:49:33.636501", "lvl": "target", "msg": "[    4.267756] usb 1-1.3.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2024-08-15T23:49:33.637399", "lvl": "target", "msg": "[    4.275364] usb 1-1.3.1: Product: USB2.0 Hub             "}
- {"dt": "2024-08-15T23:49:33.637920", "lvl": "target", "msg": "[    4.280853] usb 1-1.3.1: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2024-08-15T23:49:33.638348", "lvl": "target", "msg": "[    4.288140] hub 1-1.3.1:1.0: USB hub found"}
- {"dt": "2024-08-15T23:49:33.638755", "lvl": "target", "msg": "[    4.292516] hub 1-1.3.1:1.0: 4 ports detected"}
- {"dt": "2024-08-15T23:49:33.661363", "lvl": "target", "msg": "[    4.306459] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:33.662257", "lvl": "target", "msg": "[    4.315046] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:33.664721", "lvl": "target", "msg": "[    4.322140] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:33.946278", "lvl": "target", "msg": "[    4.601638] usb 1-1.3.1.1: new high-speed USB device number 5 using xhci_hcd"}
- {"dt": "2024-08-15T23:49:34.097887", "lvl": "target", "msg": "[    4.733176] usb 1-1.3.1.1: New USB device found, idVendor=0bda, idProduct=2838, bcdDevice= 1.00"}
- {"dt": "2024-08-15T23:49:34.100129", "lvl": "target", "msg": "[    4.742040] usb 1-1.3.1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3"}
- {"dt": "2024-08-15T23:49:34.100899", "lvl": "target", "msg": "[    4.749840] usb 1-1.3.1.1: Product: RTL2838UHIDIR"}
- {"dt": "2024-08-15T23:49:34.101635", "lvl": "target", "msg": "[    4.754627] usb 1-1.3.1.1: Manufacturer: Realtek"}
- {"dt": "2024-08-15T23:49:34.102606", "lvl": "target", "msg": "[    4.759323] usb 1-1.3.1.1: SerialNumber: 00000001"}
- {"dt": "2024-08-15T23:49:34.129744", "lvl": "target", "msg": "[    4.774402] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:34.131608", "lvl": "target", "msg": "[    4.783001] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:34.133709", "lvl": "target", "msg": "[    4.790156] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:36.670736", "lvl": "target", "msg": "[    7.326047] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx"}
- {"dt": "2024-08-15T23:49:36.735400", "lvl": "target", "msg": "[    7.353625] Sending DHCP requests ., OK"}
- {"dt": "2024-08-15T23:49:36.738033", "lvl": "target", "msg": "[    7.373554] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.241"}
- {"dt": "2024-08-15T23:49:36.739265", "lvl": "target", "msg": "[    7.381623] IP-Config: Complete:"}
- {"dt": "2024-08-15T23:49:36.740445", "lvl": "target", "msg": "[    7.384894]      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-08-15T23:49:36.741531", "lvl": "target", "msg": "[    7.395413]      host=192.168.66.241, domain=, nis-domain=(none)"}
- {"dt": "2024-08-15T23:49:36.742275", "lvl": "target", "msg": "[    7.401517]      bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath="}
- {"dt": "2024-08-15T23:49:36.742992", "lvl": "target", "msg": "[    7.401526]      nameserver0=10.1.1.1"}
- {"dt": "2024-08-15T23:49:36.762591", "lvl": "target", "msg": "[    7.412621] clk: Disabling unused clocks"}
- {"dt": "2024-08-15T23:49:36.763489", "lvl": "target", "msg": "[    7.416813] ALSA device list:"}
- {"dt": "2024-08-15T23:49:36.764250", "lvl": "target", "msg": "[    7.419856]   No soundcards found."}
- {"dt": "2024-08-15T23:49:36.766300", "lvl": "target", "msg": "[    7.423474] Waiting 7 sec before mounting root device..."}
- {"dt": "2024-08-15T23:49:43.892574", "lvl": "target", "msg": "[   14.557735] RAMDISK: gzip image found at block 0"}
- {"dt": "2024-08-15T23:49:44.095131", "lvl": "target", "msg": "[   14.710754] EXT4-fs (ram0): mounted filesystem e7a2763b-7897-4e83-a291-36788025f074 r/w with ordered data mode. Quota mode: none."}
- {"dt": "2024-08-15T23:49:44.096909", "lvl": "target", "msg": "[   14.722651] VFS: Mounted root (ext4 filesystem) on device 1:0."}
- {"dt": "2024-08-15T23:49:44.097574", "lvl": "target", "msg": "[   14.728632] devtmpfs: mounted"}
- {"dt": "2024-08-15T23:49:44.098321", "lvl": "target", "msg": "[   14.736857] Freeing unused kernel memory: 5376K"}
- {"dt": "2024-08-15T23:49:44.098980", "lvl": "target", "msg": "[   14.745717] Run /sbin/init as init process"}
- {"dt": "2024-08-15T23:49:44.099559", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2024-08-15T23:49:44.100239", "lvl": "target", "msg": "         ___   ________                _   __     __  __                __"}
- {"dt": "2024-08-15T23:49:44.138796", "lvl": "target", "msg": "        /   | / ____/ /               / | / /__  / /_/ /_  ____  ____  / /_"}
- {"dt": "2024-08-15T23:49:44.140604", "lvl": "target", "msg": "       / /| |/ / __/ /      ______   /  |/ / _ \\/ __/ __ \\/ __ \\/ __ \\/ __/"}
- {"dt": "2024-08-15T23:49:44.141332", "lvl": "target", "msg": "      / ___ / /_/ / /___   /_____/  / /|  /  __/ /_/ /_/ / /_/ / /_/ / /_"}
- {"dt": "2024-08-15T23:49:44.141956", "lvl": "target", "msg": "     /_/  |_\\____/_____/           /_/ |_/\\___/\\__/_.___/\\____/\\____/\\__/"}
- {"dt": "2024-08-15T23:49:44.142568", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2024-08-15T23:49:44.143210", "lvl": "target", "msg": "/sbin/init[1]: starting initrd script"}
- {"dt": "2024-08-15T23:49:44.143810", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: proc /proc"}
- {"dt": "2024-08-15T23:49:44.144562", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: sysfs /sys"}
- {"dt": "2024-08-15T23:49:44.183149", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devtmpfs /dev"}
- {"dt": "2024-08-15T23:49:44.183994", "lvl": "target", "msg": "/sbin/init[1]: /dev (devtmpfs) already mounted"}
- {"dt": "2024-08-15T23:49:44.184786", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devpts /dev/pts"}
- {"dt": "2024-08-15T23:49:44.185453", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /dev/shm"}
- {"dt": "2024-08-15T23:49:44.186110", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /tmp"}
- {"dt": "2024-08-15T23:49:44.186759", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /run"}
- {"dt": "2024-08-15T23:49:44.188550", "lvl": "target", "msg": "/sbin/init[1]: NBD parameters: device /dev/nbd0, server 192.168.66.1:61980"}
- {"dt": "2024-08-15T23:49:44.189445", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2024-08-15T23:49:44.239418", "lvl": "target", "msg": "[   14.894604] nbd0: detected capacity change from 0 to 8938544"}
- {"dt": "2024-08-15T23:49:44.240169", "lvl": "target", "msg": "/sbin/init[1]: NBD client successfully started"}
- {"dt": "2024-08-15T23:49:45.964811", "lvl": "target", "msg": "[   16.589301] EXT4-fs (nbd0): recovery complete"}
- {"dt": "2024-08-15T23:49:45.966089", "lvl": "target", "msg": "[   16.595585] EXT4-fs (nbd0): mounted filesystem eae6b6f4-a305-4a4d-8abb-a424501f4cd1 r/w with ordered data mode. Quota mode: none."}
- {"dt": "2024-08-15T23:49:45.968044", "lvl": "target", "msg": "/sbin/init[1]: Moving /dev to new rootfs"}
- {"dt": "2024-08-15T23:49:45.972111", "lvl": "target", "msg": "/sbin/init[1]: Moving /proc to new rootfs"}
- {"dt": "2024-08-15T23:49:45.973501", "lvl": "target", "msg": "/sbin/init[1]: Moving /sys to new rootfs"}
- {"dt": "2024-08-15T23:49:45.975489", "lvl": "target", "msg": "/sbin/init[1]: Moving /tmp to new rootfs"}
- {"dt": "2024-08-15T23:49:45.977137", "lvl": "target", "msg": "/sbin/init[1]: Moving /run to new rootfs"}
- {"dt": "2024-08-15T23:49:45.978661", "lvl": "target", "msg": "/sbin/init[1]: Switching to new rootfs"}
- {"dt": "2024-08-15T23:49:46.525346", "lvl": "target", "msg": "/sbin/init[1]: find_active_interface: first active interface is eth0"}
- {"dt": "2024-08-15T23:49:46.529623", "lvl": "target", "msg": "/sbin/init[1]: Adjusting Connman command line. Will be: 'connmand -r -n -I eth0,enp2s0,enp3s0,end0,enp0s2,enp0s1 '"}
- {"dt": "2024-08-15T23:49:46.631147", "lvl": "target", "msg": "mkdir: cannot create directory '/etc/systemd/system/systemd-network-generator.service.d/': File exists"}
- {"dt": "2024-08-15T23:49:46.694925", "lvl": "target", "msg": "/sbin/init[1]: Unmounting /tmp and /run"}
- {"dt": "2024-08-15T23:49:46.887327", "lvl": "target", "msg": "/sbin/init[1]: Exec'ing systemd"}
- {"dt": "2024-08-15T23:49:46.889312", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2024-08-15T23:49:46.891400", "lvl": "target", "msg": "      ___   ________       ____              __  _"}
- {"dt": "2024-08-15T23:49:46.892040", "lvl": "target", "msg": "     /   | / ____/ /      / __ )____  ____  / /_(_)___  ____ _"}
- {"dt": "2024-08-15T23:49:46.893499", "lvl": "target", "msg": "    / /| |/ / __/ /      / __  / __ \\/ __ \\/ __/ / __ \\/ __ `/"}
- {"dt": "2024-08-15T23:49:46.893996", "lvl": "target", "msg": "   / ___ / /_/ / /___   / /_/ / /_/ / /_/ / /_/ / / / / /_/ /   _     _     _"}
- {"dt": "2024-08-15T23:49:46.894381", "lvl": "target", "msg": "  /_/  |_\\____/_____/  /_____/\\____/\\____/\\__/_/_/ /_/\\__, /   (_)   (_)   (_)"}
- {"dt": "2024-08-15T23:49:46.905510", "lvl": "target", "msg": "_____________________________________________________/____/_____________________"}
- {"dt": "2024-08-15T23:49:46.991415", "lvl": "target", "msg": "[   17.632332] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:49:46.992922", "lvl": "target", "msg": "[   17.640978] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:49:46.993388", "lvl": "target", "msg": "[   17.648159] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:49:46.994721", "lvl": "target", "msg": "[   17.654835] platform gpu: deferred probe pending"}
- {"dt": "2024-08-15T23:49:48.174551", "lvl": "target", "msg": "[   18.830107] systemd[1]: System time before build time, advancing clock."}
- {"dt": "2024-08-15T23:49:48.437313", "lvl": "target", "msg": "[   19.066447] systemd[1]: systemd 255.4^ 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 -TPM2 -BZIP2 -LZ4 -XZ -ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)"}
- {"dt": "2024-08-15T23:49:48.440364", "lvl": "target", "msg": "[   19.098813] systemd[1]: Detected architecture arm64."}
- {"dt": "2024-08-15T23:49:48.470628", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T23:49:48.486610", "lvl": "target", "msg": "Welcome to Automotive Grade Linux 18.90.0 (salmon)!"}
- {"dt": "2024-08-15T23:49:48.487411", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T23:49:48.501871", "lvl": "target", "msg": "[   19.170775] systemd[1]: Hostname set to <h3ulcb>."}
- {"dt": "2024-08-15T23:49:50.685921", "lvl": "target", "msg": "[   21.341454] systemd[1]: Binding to IPv6 address not available since kernel does not support IPv6."}
- {"dt": "2024-08-15T23:49:50.765672", "lvl": "target", "msg": "[   21.423777] systemd[1]: Queued start job for default target Graphical Interface."}
- {"dt": "2024-08-15T23:49:50.802731", "lvl": "target", "msg": "[   21.460933] systemd[1]: Created slice Slice /system/getty."}
- {"dt": "2024-08-15T23:49:50.806790", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/getty."}
- {"dt": "2024-08-15T23:49:50.884650", "lvl": "target", "msg": "[   21.483105] systemd[1]: Created slice Slice /system/modprobe."}
- {"dt": "2024-08-15T23:49:50.885627", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/modprobe."}
- {"dt": "2024-08-15T23:49:50.887927", "lvl": "target", "msg": "[   21.503021] systemd[1]: Created slice Slice /system/serial-getty."}
- {"dt": "2024-08-15T23:49:50.888941", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/serial-getty."}
- {"dt": "2024-08-15T23:49:50.890365", "lvl": "target", "msg": "[   21.523026] systemd[1]: Created slice Slice /system/wireplumber."}
- {"dt": "2024-08-15T23:49:50.891280", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/wireplumber."}
- {"dt": "2024-08-15T23:49:50.892110", "lvl": "target", "msg": "[   21.542535] systemd[1]: Created slice User and Session Slice."}
- {"dt": "2024-08-15T23:49:50.893162", "lvl": "target", "msg": "[  OK  ] Created slice User and Session Slice."}
- {"dt": "2024-08-15T23:49:50.957251", "lvl": "target", "msg": "[   21.562018] systemd[1]: Started Dispatch Password Requests to Console Directory Watch."}
- {"dt": "2024-08-15T23:49:50.957906", "lvl": "target", "msg": "[  OK  ] Started Dispatch Password Requests to Console Directory Watch."}
- {"dt": "2024-08-15T23:49:50.958449", "lvl": "target", "msg": "[   21.585947] systemd[1]: Started Forward Password Requests to Wall Directory Watch."}
- {"dt": "2024-08-15T23:49:50.958913", "lvl": "target", "msg": "[  OK  ] Started Forward Password Requests to Wall Directory Watch."}
- {"dt": "2024-08-15T23:49:50.959338", "lvl": "target", "msg": "[   21.609882] systemd[1]: Reached target Host and Network Name Lookups."}
- {"dt": "2024-08-15T23:49:50.959939", "lvl": "target", "msg": "[  OK  ] Reached target Host and Network Name Lookups."}
- {"dt": "2024-08-15T23:49:50.960602", "lvl": "target", "msg": "[   21.629746] systemd[1]: Reached target Path Units."}
- {"dt": "2024-08-15T23:49:51.024458", "lvl": "target", "msg": "[  OK  ] Reached target Path Units."}
- {"dt": "2024-08-15T23:49:51.025708", "lvl": "target", "msg": "[   21.645783] systemd[1]: Reached target Remote File Systems."}
- {"dt": "2024-08-15T23:49:51.026968", "lvl": "target", "msg": "[  OK  ] Reached target Remote File Systems."}
- {"dt": "2024-08-15T23:49:51.029776", "lvl": "target", "msg": "[   21.665747] systemd[1]: Reached target Slice Units."}
- {"dt": "2024-08-15T23:49:51.030690", "lvl": "target", "msg": "[  OK  ] Reached target Slice Units."}
- {"dt": "2024-08-15T23:49:51.031843", "lvl": "target", "msg": "[   21.681790] systemd[1]: Reached target Swaps."}
- {"dt": "2024-08-15T23:49:51.033096", "lvl": "target", "msg": "[  OK  ] Reached target Swaps."}
- {"dt": "2024-08-15T23:49:51.077488", "lvl": "target", "msg": "[   21.710925] systemd[1]: Listening on Process Core Dump Socket."}
- {"dt": "2024-08-15T23:49:51.078506", "lvl": "target", "msg": "[  OK  ] Listening on Process Core Dump Socket."}
- {"dt": "2024-08-15T23:49:51.079433", "lvl": "target", "msg": "[   21.730069] systemd[1]: Listening on initctl Compatibility Named Pipe."}
- {"dt": "2024-08-15T23:49:51.080275", "lvl": "target", "msg": "[  OK  ] Listening on initctl Compatibility Named Pipe."}
- {"dt": "2024-08-15T23:49:51.134558", "lvl": "target", "msg": "[   21.754865] systemd[1]: Listening on Journal Audit Socket."}
- {"dt": "2024-08-15T23:49:51.136008", "lvl": "target", "msg": "[  OK  ] Listening on Journal Audit Socket."}
- {"dt": "2024-08-15T23:49:51.139317", "lvl": "target", "msg": "[   21.774355] systemd[1]: Listening on Journal Socket (/dev/log)."}
- {"dt": "2024-08-15T23:49:51.139990", "lvl": "target", "msg": "[  OK  ] Listening on Journal Socket (/dev/log)."}
- {"dt": "2024-08-15T23:49:51.140607", "lvl": "target", "msg": "[   21.794363] systemd[1]: Listening on Journal Socket."}
- {"dt": "2024-08-15T23:49:51.141166", "lvl": "target", "msg": "[  OK  ] Listening on Journal Socket."}
- {"dt": "2024-08-15T23:49:51.176257", "lvl": "target", "msg": "[   21.814487] systemd[1]: Listening on Network Service Netlink Socket."}
- {"dt": "2024-08-15T23:49:51.177015", "lvl": "target", "msg": "[  OK  ] Listening on Network Service Netlink Socket."}
- {"dt": "2024-08-15T23:49:51.177761", "lvl": "target", "msg": "[   21.834453] systemd[1]: Listening on udev Control Socket."}
- {"dt": "2024-08-15T23:49:51.179227", "lvl": "target", "msg": "[  OK  ] Listening on udev Control Socket."}
- {"dt": "2024-08-15T23:49:51.196294", "lvl": "target", "msg": "[   21.854204] systemd[1]: Listening on udev Kernel Socket."}
- {"dt": "2024-08-15T23:49:51.199419", "lvl": "target", "msg": "[  OK  ] Listening on udev Kernel Socket."}
- {"dt": "2024-08-15T23:49:51.242414", "lvl": "target", "msg": "[   21.874245] systemd[1]: Listening on User Database Manager Socket."}
- {"dt": "2024-08-15T23:49:51.243192", "lvl": "target", "msg": "[  OK  ] Listening on User Database Manager Socket."}
- {"dt": "2024-08-15T23:49:51.243930", "lvl": "target", "msg": "[   21.894279] systemd[1]: Huge Pages File System was skipped because of an unmet condition check (ConditionPathExists=/sys/kernel/mm/hugepages)."}
- {"dt": "2024-08-15T23:49:51.279088", "lvl": "target", "msg": "[   21.933917] systemd[1]: Mounting POSIX Message Queue File System..."}
- {"dt": "2024-08-15T23:49:51.282193", "lvl": "target", "msg": "         Mounting POSIX Message Queue File System..."}
- {"dt": "2024-08-15T23:49:51.321129", "lvl": "target", "msg": "[   21.955918] systemd[1]: Mounting Kernel Debug File System..."}
- {"dt": "2024-08-15T23:49:51.321960", "lvl": "target", "msg": "         Mounting Kernel Debug File System..."}
- {"dt": "2024-08-15T23:49:51.322626", "lvl": "target", "msg": "[   21.975616] systemd[1]: Mounting Kernel Trace File System..."}
- {"dt": "2024-08-15T23:49:51.325398", "lvl": "target", "msg": "         Mounting Kernel Trace File System..."}
- {"dt": "2024-08-15T23:49:51.370148", "lvl": "target", "msg": "[   22.003255] systemd[1]: Mounting Temporary Directory /tmp..."}
- {"dt": "2024-08-15T23:49:51.371394", "lvl": "target", "msg": "         Mounting Temporary Directory /tmp..."}
- {"dt": "2024-08-15T23:49:51.374586", "lvl": "target", "msg": "[   22.021990] systemd[1]: Create List of Static Device Nodes was skipped because of an unmet condition check (ConditionFileNotEmpty=/lib/modules/6.6.22-v8/modules.devname)."}
- {"dt": "2024-08-15T23:49:51.390939", "lvl": "target", "msg": "[   22.047523] systemd[1]: Starting Load Kernel Module configfs..."}
- {"dt": "2024-08-15T23:49:51.396235", "lvl": "target", "msg": "         Starting Load Kernel Module configfs..."}
- {"dt": "2024-08-15T23:49:51.414013", "lvl": "target", "msg": "[   22.072368] systemd[1]: Starting Load Kernel Module drm..."}
- {"dt": "2024-08-15T23:49:51.419146", "lvl": "target", "msg": "         Starting Load Kernel Module drm..."}
- {"dt": "2024-08-15T23:49:51.438040", "lvl": "target", "msg": "[   22.096375] systemd[1]: Starting Load Kernel Module fuse..."}
- {"dt": "2024-08-15T23:49:51.443526", "lvl": "target", "msg": "         Starting Load Kernel Module fuse..."}
- {"dt": "2024-08-15T23:49:51.467780", "lvl": "target", "msg": "[   22.120340] systemd[1]: Starting Start psplash boot splash screen..."}
- {"dt": "2024-08-15T23:49:51.471027", "lvl": "target", "msg": "         Starting Start psplash boot splash screen..."}
- {"dt": "2024-08-15T23:49:51.510802", "lvl": "target", "msg": "[   22.143863] (psplash)[194]: psplash-start.service: Referenced but unset environment variable evaluates to an empty string: PSPLASH_ARGS"}
- {"dt": "2024-08-15T23:49:51.512341", "lvl": "target", "msg": "[   22.144052] systemd[1]: Starting SELinux autorelabel service loading..."}
- {"dt": "2024-08-15T23:49:51.512823", "lvl": "target", "msg": "         Starting SELinux autore[   22.165440] systemd[1]: Starting SELinux init for /dev service loading..."}
- {"dt": "2024-08-15T23:49:51.513226", "lvl": "target", "msg": "label service loading..."}
- {"dt": "2024-08-15T23:49:51.529520", "lvl": "target", "msg": "         Starting SELinux init for /dev service loading..."}
- {"dt": "2024-08-15T23:49:51.585703", "lvl": "target", "msg": "[   22.226917] systemd[1]: Rebuild Hardware Database was skipped because of an unmet condition check (ConditionNeedsUpdate=/etc)."}
- {"dt": "2024-08-15T23:49:51.586339", "lvl": "target", "msg": "[   22.245007] systemd[1]: Starting Journal Service..."}
- {"dt": "2024-08-15T23:49:51.589006", "lvl": "target", "msg": "         Starting Journal Service..."}
- {"dt": "2024-08-15T23:49:51.718330", "lvl": "target", "msg": "[   22.374023] systemd[1]: Starting Load Kernel Modules..."}
- {"dt": "2024-08-15T23:49:51.721605", "lvl": "target", "msg": "         Starting Load Kernel Modules..."}
- {"dt": "2024-08-15T23:49:51.748815", "lvl": "target", "msg": "[   22.400610] systemd[1]: Starting Create Static Device Nodes in /dev gracefully..."}
- {"dt": "2024-08-15T23:49:51.751183", "lvl": "target", "msg": "         Starting Create Static Device Nodes in /dev gracefully..."}
- {"dt": "2024-08-15T23:49:51.802513", "lvl": "target", "msg": "[   22.429287] systemd[1]: Starting Coldplug All udev Devices..."}
- {"dt": "2024-08-15T23:49:51.803273", "lvl": "target", "msg": "         Starting Coldplug All udev Devices..."}
- {"dt": "2024-08-15T23:49:51.804577", "lvl": "target", "msg": "[   22.444688] systemd-journald[197]: Collecting audit messages is enabled."}
- {"dt": "2024-08-15T23:49:51.805045", "lvl": "target", "msg": "[   22.451790] systemd[1]: Bind mount volatile /var/cache was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/var/cache)."}
- {"dt": "2024-08-15T23:49:51.806819", "lvl": "target", "msg": "[   22.465125] systemd[1]: Bind mount volatile /var/lib was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/var/lib)."}
- {"dt": "2024-08-15T23:49:51.824010", "lvl": "target", "msg": "[   22.480167] systemd[1]: Starting Load/Save OS Random Seed..."}
- {"dt": "2024-08-15T23:49:51.826712", "lvl": "target", "msg": "         Starting Load/Save OS Random Seed..."}
- {"dt": "2024-08-15T23:49:51.871620", "lvl": "target", "msg": "[   22.501886] systemd[1]: Bind mount volatile /var/spool was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/var/spool)."}
- {"dt": "2024-08-15T23:49:51.873826", "lvl": "target", "msg": "[   22.515251] systemd[1]: Bind mount volatile /srv was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/srv)."}
- {"dt": "2024-08-15T23:49:51.875607", "lvl": "target", "msg": "[   22.532232] systemd[1]: Started Journal Service."}
- {"dt": "2024-08-15T23:49:51.876448", "lvl": "target", "msg": "[  OK  ] Started Journal Service."}
- {"dt": "2024-08-15T23:49:51.927382", "lvl": "target", "msg": "[   22.554064] audit: type=1130 audit(1721815281.719: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-08-15T23:49:51.928119", "lvl": "target", "msg": "[  OK  ] Mounted POSIX Message Queue File System."}
- {"dt": "2024-08-15T23:49:51.928674", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Debug File System."}
- {"dt": "2024-08-15T23:49:51.944937", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Trace File System."}
- {"dt": "2024-08-15T23:49:51.961537", "lvl": "target", "msg": "[  OK  ] Mounted Temporary Directory /tmp."}
- {"dt": "2024-08-15T23:49:51.976690", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module configfs."}
- {"dt": "2024-08-15T23:49:52.030537", "lvl": "target", "msg": "[   22.654088] audit: type=1130 audit(1721815281.819: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-08-15T23:49:52.031927", "lvl": "target", "msg": "[   22.673375] audit: type=1131 audit(1721815281.819: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-08-15T23:49:52.033890", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module drm."}
- {"dt": "2024-08-15T23:49:52.089328", "lvl": "target", "msg": "[   22.712919] audit: type=1130 audit(1721815281.875: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-08-15T23:49:52.089936", "lvl": "target", "msg": "[   22.732237] audit: type=1131 audit(1721815281.875: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-08-15T23:49:52.092126", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module fuse."}
- {"dt": "2024-08-15T23:49:52.144593", "lvl": "target", "msg": "[   22.766064] audit: type=1130 audit(1721815281.931: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-08-15T23:49:52.145429", "lvl": "target", "msg": "[   22.785047] audit: type=1131 audit(1721815281.931: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-08-15T23:49:52.147164", "lvl": "target", "msg": "[FAILED] Failed to start Start psplash boot splash screen."}
- {"dt": "2024-08-15T23:49:52.161927", "lvl": "target", "msg": "See 'systemctl status psplash-start.service' for details."}
- {"dt": "2024-08-15T23:49:52.187221", "lvl": "target", "msg": "[DEPEND] Dependency failed for Start psplash\u2026emd progress communication helper."}
- {"dt": "2024-08-15T23:49:52.222267", "lvl": "target", "msg": "[   22.862105] audit: type=1130 audit(1721815282.027: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-08-15T23:49:52.223450", "lvl": "target", "msg": "[  OK  ] Finished SELinux autorelabel service loading."}
- {"dt": "2024-08-15T23:49:52.276220", "lvl": "target", "msg": "[   22.897795] audit: type=1130 audit(1721815282.063: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-08-15T23:49:52.279046", "lvl": "target", "msg": "[   22.917387] audit: type=1131 audit(1721815282.063: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-08-15T23:49:52.280240", "lvl": "target", "msg": "[  OK  ] Finished SELinux init for /dev service loading."}
- {"dt": "2024-08-15T23:49:52.294082", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Modules."}
- {"dt": "2024-08-15T23:49:52.320160", "lvl": "target", "msg": "[  OK  ] Finished Create Static Device Nodes in /dev gracefully."}
- {"dt": "2024-08-15T23:49:52.321227", "lvl": "target", "msg": "[  OK  ] Finished Coldplug All udev Devices."}
- {"dt": "2024-08-15T23:49:52.335520", "lvl": "target", "msg": "[  OK  ] Finished Load/Save OS Random Seed."}
- {"dt": "2024-08-15T23:49:52.399669", "lvl": "target", "msg": "         Mounting Kernel Configuration File System..."}
- {"dt": "2024-08-15T23:49:52.430999", "lvl": "target", "msg": "         Starting Flush Journal to Persistent Storage..."}
- {"dt": "2024-08-15T23:49:52.447611", "lvl": "target", "msg": "         Starting Apply Kernel Variables..."}
- {"dt": "2024-08-15T23:49:52.471809", "lvl": "target", "msg": "[   23.123141] systemd-journald[197]: Received client request to flush runtime journal."}
- {"dt": "2024-08-15T23:49:52.474964", "lvl": "target", "msg": "         Starting Create Static Device Nodes in /dev..."}
- {"dt": "2024-08-15T23:49:52.506582", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Configuration File System."}
- {"dt": "2024-08-15T23:49:52.526599", "lvl": "target", "msg": "[  OK  ] Finished Flush Journal to Persistent Storage."}
- {"dt": "2024-08-15T23:49:52.530244", "lvl": "target", "msg": "[  OK  ] Finished Create Static Device Nodes in /dev."}
- {"dt": "2024-08-15T23:49:52.544860", "lvl": "target", "msg": "[  OK  ] Finished Apply Kernel Variables."}
- {"dt": "2024-08-15T23:49:52.568528", "lvl": "target", "msg": "[  OK  ] Reached target Preparation for Local File Systems."}
- {"dt": "2024-08-15T23:49:52.572166", "lvl": "target", "msg": "[  OK  ] Reached target Local File Systems."}
- {"dt": "2024-08-15T23:49:52.602909", "lvl": "target", "msg": "         Starting SELinux resolv.conf relabeling..."}
- {"dt": "2024-08-15T23:49:52.635415", "lvl": "target", "msg": "         Starting SELinux init service loading..."}
- {"dt": "2024-08-15T23:49:52.651003", "lvl": "target", "msg": "         Starting Create Volatile Files and Directories..."}
- {"dt": "2024-08-15T23:49:52.667665", "lvl": "target", "msg": "         Starting Rule-based Manager for Device Events and Files..."}
- {"dt": "2024-08-15T23:49:52.682596", "lvl": "target", "msg": "[  OK  ] Finished SELinux resolv.conf relabeling."}
- {"dt": "2024-08-15T23:49:52.698815", "lvl": "target", "msg": "[  OK  ] Finished SELinux init service loading."}
- {"dt": "2024-08-15T23:49:52.731738", "lvl": "target", "msg": "[  OK  ] Finished Create Volatile Files and Directories."}
- {"dt": "2024-08-15T23:49:52.778967", "lvl": "target", "msg": "         Starting Load Audit Rules..."}
- {"dt": "2024-08-15T23:49:53.049854", "lvl": "target", "msg": "[  OK  ] Finished Load Audit Rules."}
- {"dt": "2024-08-15T23:49:53.098052", "lvl": "target", "msg": "         Starting Security Audit Logging Service..."}
- {"dt": "2024-08-15T23:49:53.127525", "lvl": "target", "msg": "[  OK  ] Started Rule-based Manager for Device Events and Files."}
- {"dt": "2024-08-15T23:49:53.190307", "lvl": "target", "msg": "[  OK  ] Started Security Audit Logging Service."}
- {"dt": "2024-08-15T23:49:53.324928", "lvl": "target", "msg": "[   23.979800] bcmgenet fd580000.ethernet end0: renamed from eth0 (while UP)"}
- {"dt": "2024-08-15T23:49:53.341029", "lvl": "target", "msg": "         Starting Record System Boot/Shutdown in UTMP..."}
- {"dt": "2024-08-15T23:49:53.404462", "lvl": "target", "msg": "[  OK  ] Finished Record System Boot/Shutdown in UTMP."}
- {"dt": "2024-08-15T23:49:53.420463", "lvl": "target", "msg": "[  OK  ] Reached target System Initialization."}
- {"dt": "2024-08-15T23:49:53.435718", "lvl": "target", "msg": "[  OK  ] Started Daily Cleanup of Temporary Directories."}
- {"dt": "2024-08-15T23:49:53.451520", "lvl": "target", "msg": "[  OK  ] Reached target Timer Units."}
- {"dt": "2024-08-15T23:49:53.480164", "lvl": "target", "msg": "[  OK  ] Listening on agl-compositor, a Wayl\u2026ositor, as a systemd user service."}
- {"dt": "2024-08-15T23:49:53.508108", "lvl": "target", "msg": "[  OK  ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket."}
- {"dt": "2024-08-15T23:49:53.511432", "lvl": "target", "msg": "[  OK  ] Listening on D-Bus System Message Bus Socket."}
- {"dt": "2024-08-15T23:49:53.551747", "lvl": "target", "msg": "[  OK  ] Listening on GPS (Global Positioning System) Daemon Sockets."}
- {"dt": "2024-08-15T23:49:53.584423", "lvl": "target", "msg": "[  OK  ] Listening on mpd.socket."}
- {"dt": "2024-08-15T23:49:53.615477", "lvl": "target", "msg": "         Starting PipeWire Multimedia System Manager Socket..."}
- {"dt": "2024-08-15T23:49:53.631044", "lvl": "target", "msg": "         Starting PipeWire Multimedia System Socket..."}
- {"dt": "2024-08-15T23:49:53.663016", "lvl": "target", "msg": "         Starting sshd.socket..."}
- {"dt": "2024-08-15T23:49:53.684140", "lvl": "target", "msg": "[  OK  ] Listening on PipeWire Multimedia System Manager Socket."}
- {"dt": "2024-08-15T23:49:53.700998", "lvl": "target", "msg": "[  OK  ] Listening on PipeWire Multimedia System Socket."}
- {"dt": "2024-08-15T23:49:53.780159", "lvl": "target", "msg": "[  OK  ] Listening on sshd.socket."}
- {"dt": "2024-08-15T23:49:53.892945", "lvl": "target", "msg": "[  OK  ] Reached target Socket Units."}
- {"dt": "2024-08-15T23:49:53.908707", "lvl": "target", "msg": "[  OK  ] Reached target Basic System."}
- {"dt": "2024-08-15T23:49:53.955840", "lvl": "target", "msg": "         Starting CAN interface helper..."}
- {"dt": "2024-08-15T23:49:53.972716", "lvl": "target", "msg": "         Starting D-Bus System Message Bus..."}
- {"dt": "2024-08-15T23:49:53.988202", "lvl": "target", "msg": "         Starting IPv6 Packet Filtering Framework..."}
- {"dt": "2024-08-15T23:49:54.019896", "lvl": "target", "msg": "         Starting IPv4 Packet Filtering Framework..."}
- {"dt": "2024-08-15T23:49:54.021142", "lvl": "target", "msg": "         Starting Telephony service..."}
- {"dt": "2024-08-15T23:49:54.052660", "lvl": "target", "msg": "[  OK  ] Started PipeWire Multimedia Service."}
- {"dt": "2024-08-15T23:49:54.068762", "lvl": "target", "msg": "         Starting Authorization Manager..."}
- {"dt": "2024-08-15T23:49:54.100597", "lvl": "target", "msg": "         Starting User Login Management..."}
- {"dt": "2024-08-15T23:49:54.116001", "lvl": "target", "msg": "         Starting Virtual Console Setup..."}
- {"dt": "2024-08-15T23:49:54.132893", "lvl": "target", "msg": "         Starting Disk Manager..."}
- {"dt": "2024-08-15T23:49:54.147608", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager."}
- {"dt": "2024-08-15T23:49:54.176021", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager (bluetooth)."}
- {"dt": "2024-08-15T23:49:54.190644", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager (policy)."}
- {"dt": "2024-08-15T23:49:54.207250", "lvl": "target", "msg": "         Starting OpenSSH Key Generation..."}
- {"dt": "2024-08-15T23:49:54.239538", "lvl": "target", "msg": "         Starting User Database Manager..."}
- {"dt": "2024-08-15T23:49:54.286016", "lvl": "target", "msg": "[  OK  ] Finished IPv6 Packet Filtering Framework."}
- {"dt": "2024-08-15T23:49:54.288047", "lvl": "target", "msg": "[  OK  ] Finished IPv4 Packet Filtering Framework."}
- {"dt": "2024-08-15T23:49:54.288930", "lvl": "target", "msg": "[  OK  ] Reached target Preparation for Network."}
- {"dt": "2024-08-15T23:49:54.289812", "lvl": "target", "msg": "         Starting Network Configuration..."}
- {"dt": "2024-08-15T23:49:54.401290", "lvl": "target", "msg": "[  OK  ] Started User Database Manager."}
- {"dt": "2024-08-15T23:49:54.516488", "lvl": "target", "msg": "[  OK  ] Started User Login Management."}
- {"dt": "2024-08-15T23:49:54.960719", "lvl": "target", "msg": "[  OK  ] Finished CAN interface helper."}
- {"dt": "2024-08-15T23:49:56.062437", "lvl": "target", "msg": "[  OK  ] Finished Virtual Console Setup."}
- {"dt": "2024-08-15T23:49:56.110015", "lvl": "target", "msg": "[  OK  ] Started Network Configuration."}
- {"dt": "2024-08-15T23:49:56.365697", "lvl": "target", "msg": "[  OK  ] Finished OpenSSH Key Generation."}
- {"dt": "2024-08-15T23:49:56.510401", "lvl": "target", "msg": "[  OK  ] Started D-Bus System Message Bus."}
- {"dt": "2024-08-15T23:49:56.558473", "lvl": "target", "msg": "         Starting Connection service..."}
- {"dt": "2024-08-15T23:49:56.573728", "lvl": "target", "msg": "[  OK  ] Started Telephony service."}
- {"dt": "2024-08-15T23:49:56.811484", "lvl": "target", "msg": "[   27.466951] pipewire[312]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set"}
- {"dt": "2024-08-15T23:49:58.120501", "lvl": "target", "msg": "[  OK  ] Started Connection service."}
- {"dt": "2024-08-15T23:49:58.136352", "lvl": "target", "msg": "[  OK  ] Reached target Network."}
- {"dt": "2024-08-15T23:49:58.168503", "lvl": "target", "msg": "[  OK  ] Started agl-service-radio.service."}
- {"dt": "2024-08-15T23:49:58.200109", "lvl": "target", "msg": "         Starting Avahi mDNS/DNS-SD Stack..."}
- {"dt": "2024-08-15T23:49:58.248360", "lvl": "target", "msg": "[  OK  ] Started Eclipse KUKSA.val databroker."}
- {"dt": "2024-08-15T23:49:58.265740", "lvl": "target", "msg": "[  OK  ] Started agl-service-audiomixer.service."}
- {"dt": "2024-08-15T23:49:58.297482", "lvl": "target", "msg": "[  OK  ] Started agl-service-hvac.service."}
- {"dt": "2024-08-15T23:49:58.313319", "lvl": "target", "msg": "         Starting agl-vss-helper.service..."}
- {"dt": "2024-08-15T23:49:58.345201", "lvl": "target", "msg": "[  OK  ] Started Eclipse KUKSA.val DBC feeder."}
- {"dt": "2024-08-15T23:49:58.361153", "lvl": "target", "msg": "         Starting Permit User Sessions..."}
- {"dt": "2024-08-15T23:49:58.504083", "lvl": "target", "msg": "[  OK  ] Finished Permit User Sessions."}
- {"dt": "2024-08-15T23:49:58.552992", "lvl": "target", "msg": "         Starting AGL compositor..."}
- {"dt": "2024-08-15T23:49:58.568860", "lvl": "target", "msg": "[  OK  ] Started Getty on tty1."}
- {"dt": "2024-08-15T23:49:58.584578", "lvl": "target", "msg": "[  OK  ] Started Serial Getty on ttyS0."}
- {"dt": "2024-08-15T23:49:58.600773", "lvl": "target", "msg": "[  OK  ] Reached target Login Prompts."}
- {"dt": "2024-08-15T23:49:58.888398", "lvl": "target", "msg": "         Starting Hostname Service..."}
- {"dt": "2024-08-15T23:49:58.903626", "lvl": "target", "msg": "         Starting WPA supplicant..."}
- {"dt": "2024-08-15T23:49:59.063809", "lvl": "target", "msg": "[  OK  ] Started Avahi mDNS/DNS-SD Stack."}
- {"dt": "2024-08-15T23:49:59.175321", "lvl": "target", "msg": "[  OK  ] Started Hostname Service."}
- {"dt": "2024-08-15T23:50:00.949064", "lvl": "target", "msg": "[  OK  ] Started WPA supplicant."}
- {"dt": "2024-08-15T23:50:01.012758", "lvl": "target", "msg": "[  OK  ] Created slice User Slice of UID 1001."}
- {"dt": "2024-08-15T23:50:01.044769", "lvl": "target", "msg": "         Starting User Runtime Directory /run/user/1001..."}
- {"dt": "2024-08-15T23:50:01.157618", "lvl": "target", "msg": "[  OK  ] Finished User Runtime Directory /run/user/1001."}
- {"dt": "2024-08-15T23:50:01.205597", "lvl": "target", "msg": "         Starting User Manager for UID 1001..."}
- {"dt": "2024-08-15T23:50:01.572356", "lvl": "target", "msg": "[  OK  ] Started Authorization Manager."}
- {"dt": "2024-08-15T23:50:01.605035", "lvl": "target", "msg": "         Starting applaunchd.service..."}
- {"dt": "2024-08-15T23:50:01.845901", "lvl": "target", "msg": "[  OK  ] Started Disk Manager."}
- {"dt": "2024-08-15T23:50:01.876352", "lvl": "target", "msg": "[  OK  ] Started Automount Disk Manager."}
- {"dt": "2024-08-15T23:50:02.515130", "lvl": "target", "msg": "[  OK  ] Started User Manager for UID 1001."}
- {"dt": "2024-08-15T23:50:02.547521", "lvl": "target", "msg": "[  OK  ] Started Session c1 of User agl-driver."}
- {"dt": "2024-08-15T23:50:04.732634", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T23:50:04.734395", "lvl": "target", "msg": "Automotive Grade Linux 18.90.0 h3ulcb ttyS0"}
- {"dt": "2024-08-15T23:50:04.736507", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T23:50:04.741767", "lvl": "debug", "msg": "Matched prompt #13: login:"}
- {"dt": "2024-08-15T23:50:04.743252", "lvl": "results", "msg": {"case": "kernel-messages", "definition": "lava", "duration": "33.86", "extra": {"extra": []}, "level": "2.4.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T23:50:04.745703", "lvl": "debug", "msg": "Sending username root"}
- {"dt": "2024-08-15T23:50:04.747013", "lvl": "input", "msg": "root\n"}
- {"dt": "2024-08-15T23:50:04.849139", "lvl": "target", "msg": "h3ulcb login: root"}
- {"dt": "2024-08-15T23:50:04.853160", "lvl": "debug", "msg": "Setting prompt string to ['root@raspberrypi4-64:~', 'raspberrypi4-64:~#', '/ #']"}
- {"dt": "2024-08-15T23:50:04.855307", "lvl": "debug", "msg": "login-action: Wait for prompt ['root@raspberrypi4-64:~', 'raspberrypi4-64:~#', '/ #', 'Login incorrect', 'Login timed out'] (timeout 00:18:17)"}
- {"dt": "2024-08-15T23:50:04.859570", "lvl": "target", "msg": "root"}
- {"dt": "2024-08-15T23:50:05.833398", "lvl": "target", "msg": "[   36.478173] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:50:05.835969", "lvl": "target", "msg": "[   36.487026] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:50:05.838917", "lvl": "target", "msg": "[   36.495158] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:50:06.395385", "lvl": "target", "msg": "[   37.029672] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T23:50:06.396105", "lvl": "target", "msg": "[   37.038363] block nbd0: Receive control failed (result -32)"}
- {"dt": "2024-08-15T23:50:06.396753", "lvl": "target", "msg": "[   37.038458] block nbd0: shutting down sockets"}
- {"dt": "2024-08-15T23:50:06.397286", "lvl": "target", "msg": "[   37.048723] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T23:50:06.397767", "lvl": "target", "msg": "[   37.048868] I/O error, dev nbd0, sector 3797952 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:06.438813", "lvl": "target", "msg": "[   37.049614] I/O error, dev nbd0, sector 3797968 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:06.441490", "lvl": "target", "msg": "[   37.049638] I/O error, dev nbd0, sector 1503016 op 0x0:(READ) flags 0x80700 phys_seg 28 prio class 2"}
- {"dt": "2024-08-15T23:50:06.446305", "lvl": "target", "msg": "[   37.049652] I/O error, dev nbd0, sector 1571280 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:06.449303", "lvl": "target", "msg": "[   37.050076] I/O error, dev nbd0, sector 1571280 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:06.450275", "lvl": "target", "msg": "[   37.050108] I/O error, dev nbd0, sector 1571280 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:06.482994", "lvl": "target", "msg": "[   37.050152] I/O error, dev nbd0, sector 1571280 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:06.484422", "lvl": "target", "msg": "[   37.050183] I/O error, dev nbd0, sector 1571280 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:06.486213", "lvl": "target", "msg": "[   37.055674] I/O error, dev nbd0, sector 4907720 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:06.487189", "lvl": "target", "msg": "[   37.059192] I/O error, dev nbd0, sector 4908248 op 0x0:(READ) flags 0x80700 phys_seg 4 prio class 2"}
- {"dt": "2024-08-15T23:50:06.488491", "lvl": "target", "msg": "[   37.059317] Core dump to |/usr/lib/systemd/systemd-coredump pipe failed"}
- {"dt": "2024-08-15T23:50:06.489589", "lvl": "target", "msg": "[   37.060810] EXT4-fs (nbd0): shut down requested (2)"}
- {"dt": "2024-08-15T23:50:06.526833", "lvl": "target", "msg": "[   37.060829] Aborting journal on device nbd0-8."}
- {"dt": "2024-08-15T23:50:06.527530", "lvl": "target", "msg": "[   37.061051] Buffer I/O error on dev nbd0, logical block 557056, lost sync page write"}
- {"dt": "2024-08-15T23:50:06.528101", "lvl": "target", "msg": "[   37.061078] JBD2: I/O error when updating journal superblock for nbd0-8."}
- {"dt": "2024-08-15T23:50:06.528719", "lvl": "target", "msg": "[   37.065403] Core dump to |/usr/lib/systemd/systemd-coredump pipe failed"}
- {"dt": "2024-08-15T23:50:06.529261", "lvl": "target", "msg": "[   37.086735] Buffer I/O error on dev nbd0, logical block 613135, lost async page write"}
- {"dt": "2024-08-15T23:50:06.529781", "lvl": "target", "msg": "[   37.091207] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T23:50:06.570515", "lvl": "target", "msg": "[   37.093278] EXT4-fs warning (device nbd0): ext4_dx_find_entry:1795: inode #5556: lblock 10: comm applaunchd: error -5 reading directory block"}
- {"dt": "2024-08-15T23:50:06.571216", "lvl": "target", "msg": "[   37.119506] Buffer I/O error on dev nbd0, logical block 613217, lost async page write"}
- {"dt": "2024-08-15T23:50:06.571784", "lvl": "target", "msg": "[   37.119546] Buffer I/O error on dev nbd0, logical block 613343, lost async page write"}
- {"dt": "2024-08-15T23:50:06.572290", "lvl": "target", "msg": "[   37.119558] Buffer I/O error on dev nbd0, logical block 744357, lost async page write"}
- {"dt": "2024-08-15T23:50:06.572899", "lvl": "target", "msg": "[   37.119570] Buffer I/O error on dev nbd0, logical block 744487, lost async page write"}
- {"dt": "2024-08-15T23:50:06.614054", "lvl": "target", "msg": "[   37.119580] Buffer I/O error on dev nbd0, logical block 744488, lost async page write"}
- {"dt": "2024-08-15T23:50:06.614780", "lvl": "target", "msg": "[   37.119589] Buffer I/O error on dev nbd0, logical block 744970, lost async page write"}
- {"dt": "2024-08-15T23:50:06.615352", "lvl": "target", "msg": "[   37.119597] Buffer I/O error on dev nbd0, logical block 744971, lost async page write"}
- {"dt": "2024-08-15T23:50:06.616272", "lvl": "target", "msg": "[   37.119606] Buffer I/O error on dev nbd0, logical block 744972, lost async page write"}
- {"dt": "2024-08-15T23:50:06.616972", "lvl": "target", "msg": "[   37.129475] EXT4-fs warning (device nbd0): dx_probe:822: inode #61074: lblock 0: comm systemd: error -5 reading directory block"}
- {"dt": "2024-08-15T23:50:06.659040", "lvl": "target", "msg": "[   37.138238] EXT4-fs warning (device nbd0): ext4_dx_find_entry:1795: inode #5556: lblock 4: comm applaunchd: error -5 reading directory block"}
- {"dt": "2024-08-15T23:50:06.659735", "lvl": "target", "msg": "[   37.299295] EXT4-fs warning (device nbd0): ext4_dx_find_entry:1795: inode #5556: lblock 2: comm applaunchd: error -5 reading directory block"}
- {"dt": "2024-08-15T23:50:06.660437", "lvl": "target", "msg": "[   37.312388] EXT4-fs warning (device nbd0): ext4_dx_find_entry:1795: inode #5556: lblock 2: comm applaunchd: error -5 reading directory block"}
- {"dt": "2024-08-15T23:50:06.676721", "lvl": "target", "msg": "[   37.325792] EXT4-fs warning (device nbd0): ext4_dx_find_entry:1795: inode #5556: lblock 2: comm applaunchd: error -5 reading directory block"}
- {"dt": "2024-08-15T23:50:06.757255", "lvl": "target", "msg": "Cannot fi[FAILED] Failed to start agl-service-hvac.service."}
- {"dt": "2024-08-15T23:50:06.789436", "lvl": "target", "msg": "See 'systemctl status agl-service-hvac.service' for details."}
- {"dt": "2024-08-15T23:50:06.804639", "lvl": "target", "msg": "[FAILED] Failed to start agl-vss-helper.service."}
- {"dt": "2024-08-15T23:50:06.820444", "lvl": "target", "msg": "See 'systemctl status agl-vss-helper.service' for details."}
- {"dt": "2024-08-15T23:50:06.836563", "lvl": "target", "msg": "[FAILED] Failed to start CAN interface helper."}
- {"dt": "2024-08-15T23:50:06.852405", "lvl": "target", "msg": "See 'systemctl status can-dev-helper.service' for details."}
- {"dt": "2024-08-15T23:50:06.885293", "lvl": "target", "msg": "[DEPEND] Dependency failed for Eclipse KUKSA.val DBC feeder."}
- {"dt": "2024-08-15T23:50:06.916878", "lvl": "target", "msg": "[   37.573258] Core dump to |/usr/lib/systemd/systemd-coredump pipe failed"}
- {"dt": "2024-08-15T23:50:06.932538", "lvl": "target", "msg": "[FAILED] Failed to start agl-service-audiomixer.service."}
- {"dt": "2024-08-15T23:50:06.964085", "lvl": "target", "msg": "See 'systemctl status agl-service-audiomixer.service' for details."}
- {"dt": "2024-08-15T23:50:06.980416", "lvl": "target", "msg": "[FAILED] Failed to start agl-service-hvac.service."}
- {"dt": "2024-08-15T23:50:07.005943", "lvl": "target", "msg": "See 'systemctl status agl-service-hvac.service' for details."}
- {"dt": "2024-08-15T23:50:07.033072", "lvl": "target", "msg": "[FAILED] Failed to start agl-vss-helper.service."}
- {"dt": "2024-08-15T23:50:07.035499", "lvl": "target", "msg": "See 'systemctl status agl-vss-helper.service' for details."}
- {"dt": "2024-08-15T23:50:07.050075", "lvl": "target", "msg": "[FAILED] Failed to start Serial Getty on ttyS0."}
- {"dt": "2024-08-15T23:50:07.065154", "lvl": "target", "msg": "See 'systemctl status serial-getty@ttyS0.service' for details."}
- {"dt": "2024-08-15T23:50:07.147786", "lvl": "target", "msg": "[FAILED] Failed to start agl-service-audiomixer.service."}
- {"dt": "2024-08-15T23:50:07.149435", "lvl": "target", "msg": "[   37.795983] Core dump to |/usr/lib/systemd/systemd-coredump pipe failed"}
- {"dt": "2024-08-15T23:50:07.150999", "lvl": "target", "msg": "See 'systemctl status agl-service-audiomixer.service' for details."}
- {"dt": "2024-08-15T23:50:07.165989", "lvl": "target", "msg": "[FAILED] Failed to start agl-service-hvac.service."}
- {"dt": "2024-08-15T23:50:07.188841", "lvl": "target", "msg": "See 'systemctl status agl-service-hvac.service' for details."}
- {"dt": "2024-08-15T23:50:07.204938", "lvl": "target", "msg": "[FAILED] Failed to start agl-service-radio.service."}
- {"dt": "2024-08-15T23:50:07.221885", "lvl": "target", "msg": "See 'systemctl status agl-service-radio.service' for details."}
- {"dt": "2024-08-15T23:50:07.239152", "lvl": "target", "msg": "[FAILED] Failed to start agl-vss-helper.service."}
- {"dt": "2024-08-15T23:50:07.268858", "lvl": "target", "msg": "See 'systemctl status agl-vss-helper.service' for details."}
- {"dt": "2024-08-15T23:50:07.285743", "lvl": "target", "msg": "[FAILED] Failed to start Serial Getty on ttyS0."}
- {"dt": "2024-08-15T23:50:07.302142", "lvl": "target", "msg": "See 'systemctl status serial-getty@ttyS0.service' for details."}
- {"dt": "2024-08-15T23:50:07.317932", "lvl": "target", "msg": "[FAILED] Failed to start applaunchd.service."}
- {"dt": "2024-08-15T23:50:07.335004", "lvl": "target", "msg": "See 'systemctl status applaunchd.service' for details."}
- {"dt": "2024-08-15T23:50:07.381391", "lvl": "target", "msg": "[FAILED] Failed to start agl-service-audiomixer.service."}
- {"dt": "2024-08-15T23:50:07.406498", "lvl": "target", "msg": "See 'systemctl status agl-service-audiomixer.service' for details."}
- {"dt": "2024-08-15T23:50:07.421474", "lvl": "target", "msg": "[FAILED] Failed to start agl-service-hvac.service."}
- {"dt": "2024-08-15T23:50:07.446419", "lvl": "target", "msg": "See 'systemctl status agl-service-hvac.service' for details."}
- {"dt": "2024-08-15T23:50:07.474236", "lvl": "target", "msg": "[FAILED] Failed to start agl-service-radio.service."}
- {"dt": "2024-08-15T23:50:07.477538", "lvl": "target", "msg": "See 'systemctl status agl-service-radio.service' for details."}
- {"dt": "2024-08-15T23:50:07.493348", "lvl": "target", "msg": "[FAILED] Failed to start agl-vss-helper.service."}
- {"dt": "2024-08-15T23:50:07.509196", "lvl": "target", "msg": "See 'systemctl status agl-vss-helper.service' for details."}
- {"dt": "2024-08-15T23:50:07.524432", "lvl": "target", "msg": "[  OK  ] Reached target Multi-User System."}
- {"dt": "2024-08-15T23:50:07.541253", "lvl": "target", "msg": "[  OK  ] Reached target Graphical Interface."}
- {"dt": "2024-08-15T23:50:07.585167", "lvl": "target", "msg": "[FAILED] Failed to start Serial Getty on ttyS0."}
- {"dt": "2024-08-15T23:50:07.588548", "lvl": "target", "msg": "See 'systemctl status serial-getty@ttyS0.service' for details."}
- {"dt": "2024-08-15T23:50:07.603283", "lvl": "target", "msg": "[FAILED] Failed to start Record Runlevel Change in UTMP."}
- {"dt": "2024-08-15T23:50:07.630309", "lvl": "target", "msg": "See 'systemctl status systemd-update-utmp-runlevel.service' for details."}
- {"dt": "2024-08-15T23:50:14.504525", "lvl": "target", "msg": "[   45.136153] blk_print_req_error: 2689 callbacks suppressed"}
- {"dt": "2024-08-15T23:50:14.506521", "lvl": "target", "msg": "[   45.136169] I/O error, dev nbd0, sector 342208 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:14.508204", "lvl": "target", "msg": "[   45.154618] I/O error, dev nbd0, sector 370720 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:14.509547", "lvl": "target", "msg": "[   45.163720] I/O error, dev nbd0, sector 342208 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:14.510850", "lvl": "target", "msg": "[   45.163984] I/O error, dev nbd0, sector 4864 op 0x0:(READ) flags 0x80700 phys_seg 18 prio class 2"}
- {"dt": "2024-08-15T23:50:14.548659", "lvl": "target", "msg": "[   45.174269] I/O error, dev nbd0, sector 342208 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:14.550256", "lvl": "target", "msg": "[   45.181832] I/O error, dev nbd0, sector 5008 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:14.551217", "lvl": "target", "msg": "[   45.191784] I/O error, dev nbd0, sector 342208 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:14.552869", "lvl": "target", "msg": "[   45.199697] I/O error, dev nbd0, sector 5016 op 0x0:(READ) flags 0x80700 phys_seg 14 prio class 2"}
- {"dt": "2024-08-15T23:50:14.553769", "lvl": "target", "msg": "[   45.209769] I/O error, dev nbd0, sector 342208 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:14.571948", "lvl": "target", "msg": "[   45.218067] I/O error, dev nbd0, sector 4864 op 0x0:(READ) flags 0x80700 phys_seg 8 prio class 2"}
- {"dt": "2024-08-15T23:50:29.236968", "lvl": "target", "msg": "[   59.878809] blk_print_req_error: 63 callbacks suppressed"}
- {"dt": "2024-08-15T23:50:29.237850", "lvl": "target", "msg": "[   59.878827] I/O error, dev nbd0, sector 5834536 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:29.239865", "lvl": "target", "msg": "[   59.893584] I/O error, dev nbd0, sector 5834536 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:29.315752", "lvl": "target", "msg": "[   59.950569] I/O error, dev nbd0, sector 4864 op 0x0:(READ) flags 0x80700 phys_seg 16 prio class 2"}
- {"dt": "2024-08-15T23:50:29.316621", "lvl": "target", "msg": "[   59.959655] I/O error, dev nbd0, sector 4992 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:29.317169", "lvl": "target", "msg": "[   59.968517] I/O error, dev nbd0, sector 5000 op 0x0:(READ) flags 0x80700 phys_seg 16 prio class 2"}
- {"dt": "2024-08-15T23:50:29.317605", "lvl": "target", "msg": "[   59.977906] I/O error, dev nbd0, sector 370816 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:29.358986", "lvl": "target", "msg": "[   59.987200] I/O error, dev nbd0, sector 4915976 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:29.360222", "lvl": "target", "msg": "[   59.996705] I/O error, dev nbd0, sector 4864 op 0x0:(READ) flags 0x80700 phys_seg 8 prio class 2"}
- {"dt": "2024-08-15T23:50:29.360963", "lvl": "target", "msg": "[   60.005664] I/O error, dev nbd0, sector 4928 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:50:29.363176", "lvl": "target", "msg": "[   60.014519] I/O error, dev nbd0, sector 4936 op 0x0:(READ) flags 0x80700 phys_seg 24 prio class 2"}
- {"dt": "2024-08-15T23:52:14.715936", "lvl": "target", "msg": "[  165.389078] blk_print_req_error: 2 callbacks suppressed"}
- {"dt": "2024-08-15T23:52:14.747361", "lvl": "target", "msg": "[  165.389092] I/O error, dev nbd0, sector 342208 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-15T23:52:14.750677", "lvl": "target", "msg": "[  165.404658] I/O error, dev nbd0, sector 342208 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2"}
- {"dt": "2024-08-16T00:08:21.558522", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-08-16T00:08:21.560545", "lvl": "debug", "msg": "end: 2.4.4.1 login-action (duration 00:18:51) [common]"}
- {"dt": "2024-08-16T00:08:21.562256", "lvl": "results", "msg": {"case": "login-action", "definition": "lava", "duration": "1130.68", "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-08-16T00:08:21.565713", "lvl": "error", "msg": "auto-login-action failed: 1 of 1 attempts. 'wait for prompt timed out'"}
- {"dt": "2024-08-16T00:08:21.567573", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-08-16T00:08:21.569027", "lvl": "debug", "msg": "end: 2.4.4 auto-login-action (duration 00:18:53) [common]"}
- {"dt": "2024-08-16T00:08:21.569655", "lvl": "results", "msg": {"case": "auto-login-action", "definition": "lava", "duration": "1132.75", "extra": {"fail": "wait for prompt timed out"}, "level": "2.4.4", "namespace": "common", "result": "fail"}}
- {"dt": "2024-08-16T00:08:21.570862", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-08-16T00:08:21.571559", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:19:56) [common]"}
- {"dt": "2024-08-16T00:08:21.572111", "lvl": "results", "msg": {"case": "uboot-commands", "definition": "lava", "duration": "1195.99", "extra": {"fail": "wait for prompt timed out"}, "level": "2.4", "namespace": "common", "result": "fail"}}
- {"dt": "2024-08-16T00:08:21.573338", "lvl": "error", "msg": "uboot-action failed: 1 of 1 attempts. 'wait for prompt timed out'"}
- {"dt": "2024-08-16T00:08:21.574023", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-08-16T00:08:21.574492", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:20:00) [common]"}
- {"dt": "2024-08-16T00:08:21.574938", "lvl": "results", "msg": {"case": "uboot-action", "definition": "lava", "duration": "1200.12", "extra": {"fail": "wait for prompt timed out"}, "level": "2", "namespace": "common", "result": "fail"}}
- {"dt": "2024-08-16T00:08:21.575984", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-08-16T00:08:21.576616", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35933/nbd-deploy-2hwyeya7/initrd"}
- {"dt": "2024-08-16T00:08:21.578391", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35933/nbd-deploy-2hwyeya7/kernel"}
- {"dt": "2024-08-16T00:08:21.586008", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35933/nbd-deploy-2hwyeya7/dtb"}
- {"dt": "2024-08-16T00:08:21.587351", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35933/nbd-deploy-2hwyeya7/nbdroot"}
- {"dt": "2024-08-16T00:08:21.877974", "lvl": "debug", "msg": "start: 7.1 power-off (timeout 00:00:10) [common]"}
- {"dt": "2024-08-16T00:08:21.878980", "lvl": "debug", "msg": "Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '7'"}
- {"dt": "2024-08-16T00:08:25.323507", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2024-08-16T00:08:25.365877", "lvl": "debug", "msg": "Returned 0 in 3 seconds"}
- {"dt": "2024-08-16T00:08:25.468802", "lvl": "debug", "msg": "end: 7.1 power-off (duration 00:00:04) [common]"}
- {"dt": "2024-08-16T00:08:25.470833", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "3.59", "extra": {"status": "success"}, "level": "7.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-16T00:08:25.474811", "lvl": "debug", "msg": "start: 7.2 read-feedback (timeout 00:29:56) [common]"}
- {"dt": "2024-08-16T00:08:25.479375", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2024-08-16T00:08:26.478546", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2024-08-16T00:08:26.480848", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2024-08-16T00:08:26.482686", "lvl": "target", "msg": "\uFFFD"}
- {"dt": "2024-08-16T00:08:26.586749", "lvl": "debug", "msg": "end: 7.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2024-08-16T00:08:26.588832", "lvl": "debug", "msg": "lava-xnbd cleanup"}
- {"dt": "2024-08-16T00:08:26.590320", "lvl": "debug", "msg": "clean NBD port 61980"}
- {"dt": "2024-08-16T00:08:29.884007", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/35933"}
- {"dt": "2024-08-16T00:08:29.982052", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/35933"}
- {"dt": "2024-08-16T00:08:29.983135", "lvl": "error", "msg": "JobError: Your job cannot terminate cleanly."}
- {"dt": "2024-08-16T00:08:29.983675", "lvl": "results", "msg": {"case": "job", "definition": "lava", "error_msg": "wait for prompt timed out", "error_type": "Job", "result": "fail"}}
