- {"dt": "2024-08-15T20:15:10.571467", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2023.10"}
- {"dt": "2024-08-15T20:15:10.573882", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-08-15T20:15:10.575343", "lvl": "info", "msg": "Start time: 2024-08-15 20:15:10.575280+00:00 (UTC)"}
- {"dt": "2024-08-15T20:15:10.577034", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30168/3/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz exists"}
- {"dt": "2024-08-15T20:15:10.809271", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30168/3/raspberrypi4/Image exists"}
- {"dt": "2024-08-15T20:15:11.036455", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30168/3/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb exists"}
- {"dt": "2024-08-15T20:15:11.263033", "lvl": "debug", "msg": "Validating that http://download.automotivelinux.org/AGL/upload/ci/30168/3/raspberrypi4/agl-ivi-demo-qt-raspberrypi4-64.ext4.xz exists"}
- {"dt": "2024-08-15T20:15:11.497106", "lvl": "info", "msg": "validate duration: 0.92"}
- {"dt": "2024-08-15T20:15:11.498030", "lvl": "results", "msg": {"case": "validate", "definition": "lava", "result": "pass"}}
- {"dt": "2024-08-15T20:15:11.499206", "lvl": "info", "msg": "start: 1 nbd-deploy (timeout 01:30:00) [common]"}
- {"dt": "2024-08-15T20:15:11.499902", "lvl": "info", "msg": "Making protocol call for nbd-deploy using lava-xnbd"}
- {"dt": "2024-08-15T20:15:11.500618", "lvl": "debug", "msg": "[nbd-deploy] Checking protocol data for lava-xnbd"}
- {"dt": "2024-08-15T20:15:11.501309", "lvl": "debug", "msg": "Get a port from pool"}
- {"dt": "2024-08-15T20:15:11.502529", "lvl": "debug", "msg": "Set_port 61977"}
- {"dt": "2024-08-15T20:15:11.503413", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 01:30:00) [common]"}
- {"dt": "2024-08-15T20:15:11.504219", "lvl": "debug", "msg": "start: 1.1.1 http-download (timeout 01:30:00) [common]"}
- {"dt": "2024-08-15T20:15:11.505721", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30168/3/raspberrypi4/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T20:15:11.506398", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/35926/nbd-deploy-d1lhil5_/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T20:15:11.506969", "lvl": "debug", "msg": "total size: 2153291 (2\u202FMB)"}
- {"dt": "2024-08-15T20:15:11.507513", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-08-15T20:15:11.824846", "lvl": "debug", "msg": "progress   1\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.029044", "lvl": "debug", "msg": "progress   6\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.133122", "lvl": "debug", "msg": "progress  12\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.232194", "lvl": "debug", "msg": "progress  18\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.240377", "lvl": "debug", "msg": "progress  24\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.247326", "lvl": "debug", "msg": "progress  30\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.334699", "lvl": "debug", "msg": "progress  35\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.341267", "lvl": "debug", "msg": "progress  41\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.347889", "lvl": "debug", "msg": "progress  47\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.354814", "lvl": "debug", "msg": "progress  53\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.361339", "lvl": "debug", "msg": "progress  59\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.438245", "lvl": "debug", "msg": "progress  65\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.443523", "lvl": "debug", "msg": "progress  70\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.450519", "lvl": "debug", "msg": "progress  76\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.457016", "lvl": "debug", "msg": "progress  82\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.463412", "lvl": "debug", "msg": "progress  88\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.538427", "lvl": "debug", "msg": "progress  94\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.545393", "lvl": "debug", "msg": "progress 100\u202F% (2\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.547310", "lvl": "info", "msg": "2\u202FMB downloaded in 1.04\u202Fs (1.97\u202FMB/s)"}
- {"dt": "2024-08-15T20:15:12.548491", "lvl": "debug", "msg": "end: 1.1.1 http-download (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:15:12.549083", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "1.04", "extra": {"label": "initrd", "md5sum": "2b63d1eab5ebf5de288e5c5ac358ddff", "sha256sum": "8f622757f5d572ecd3b220e1ade3554999780dff39188cc5c49376863a041935", "sha512sum": "19bde4b652106110b456fa90ff51dc730035369ef1e80c96db05c467a6b1da4ce9b0b59d355af1fb258fe8fa84a436e428014f54d37d7bea8a42f85b671d5335", "size": ! "2153291"}, "level": "1.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:15:12.550441", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:15:12.551126", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 01:29:59) [common]"}
- {"dt": "2024-08-15T20:15:12.551772", "lvl": "debug", "msg": "start: 1.2.1 http-download (timeout 01:29:59) [common]"}
- {"dt": "2024-08-15T20:15:12.552978", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30168/3/raspberrypi4/Image"}
- {"dt": "2024-08-15T20:15:12.553606", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/35926/nbd-deploy-d1lhil5_/kernel/Image"}
- {"dt": "2024-08-15T20:15:12.554092", "lvl": "debug", "msg": "total size: 28535296 (27\u202FMB)"}
- {"dt": "2024-08-15T20:15:12.554653", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-08-15T20:15:12.876635", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:13.496118", "lvl": "debug", "msg": "progress   5\u202F% (1\u202FMB)"}
- {"dt": "2024-08-15T20:15:13.707318", "lvl": "debug", "msg": "progress  10\u202F% (2\u202FMB)"}
- {"dt": "2024-08-15T20:15:13.914085", "lvl": "debug", "msg": "progress  15\u202F% (4\u202FMB)"}
- {"dt": "2024-08-15T20:15:14.125093", "lvl": "debug", "msg": "progress  20\u202F% (5\u202FMB)"}
- {"dt": "2024-08-15T20:15:14.397363", "lvl": "debug", "msg": "progress  25\u202F% (6\u202FMB)"}
- {"dt": "2024-08-15T20:15:14.603042", "lvl": "debug", "msg": "progress  30\u202F% (8\u202FMB)"}
- {"dt": "2024-08-15T20:15:14.739614", "lvl": "debug", "msg": "progress  35\u202F% (9\u202FMB)"}
- {"dt": "2024-08-15T20:15:14.941203", "lvl": "debug", "msg": "progress  40\u202F% (10\u202FMB)"}
- {"dt": "2024-08-15T20:15:15.136964", "lvl": "debug", "msg": "progress  45\u202F% (12\u202FMB)"}
- {"dt": "2024-08-15T20:15:15.333060", "lvl": "debug", "msg": "progress  50\u202F% (13\u202FMB)"}
- {"dt": "2024-08-15T20:15:15.558755", "lvl": "debug", "msg": "progress  55\u202F% (14\u202FMB)"}
- {"dt": "2024-08-15T20:15:15.736285", "lvl": "debug", "msg": "progress  60\u202F% (16\u202FMB)"}
- {"dt": "2024-08-15T20:15:15.960101", "lvl": "debug", "msg": "progress  65\u202F% (17\u202FMB)"}
- {"dt": "2024-08-15T20:15:16.170849", "lvl": "debug", "msg": "progress  70\u202F% (19\u202FMB)"}
- {"dt": "2024-08-15T20:15:16.444554", "lvl": "debug", "msg": "progress  75\u202F% (20\u202FMB)"}
- {"dt": "2024-08-15T20:15:16.655038", "lvl": "debug", "msg": "progress  80\u202F% (21\u202FMB)"}
- {"dt": "2024-08-15T20:15:16.883670", "lvl": "debug", "msg": "progress  85\u202F% (23\u202FMB)"}
- {"dt": "2024-08-15T20:15:17.190595", "lvl": "debug", "msg": "progress  90\u202F% (24\u202FMB)"}
- {"dt": "2024-08-15T20:15:17.491402", "lvl": "debug", "msg": "progress  95\u202F% (25\u202FMB)"}
- {"dt": "2024-08-15T20:15:17.766433", "lvl": "debug", "msg": "progress 100\u202F% (27\u202FMB)"}
- {"dt": "2024-08-15T20:15:17.768597", "lvl": "info", "msg": "27\u202FMB downloaded in 5.21\u202Fs (5.22\u202FMB/s)"}
- {"dt": "2024-08-15T20:15:17.769946", "lvl": "debug", "msg": "end: 1.2.1 http-download (duration 00:00:05) [common]"}
- {"dt": "2024-08-15T20:15:17.770828", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "5.22", "extra": {"label": "kernel", "md5sum": "6fb1fd92b04099c5272721d44179c1c3", "sha256sum": "38f20e78efb94b69b140c2e12915b6c3e743383ff8bd2c831b4c9f04d88f79da", "sha512sum": "523b97e16d642ea1a81965251c0fe69cb01bdf60896a9f3e4a764f1c6b34e6f2fd0392544bb57cc2e75e39bc4a91526854cfaee44b21190199203fe0fb0cbe30", "size": ! "28535296"}, "level": "1.2.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:15:17.772490", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:05) [common]"}
- {"dt": "2024-08-15T20:15:17.773514", "lvl": "debug", "msg": "start: 1.3 download-retry (timeout 01:29:54) [common]"}
- {"dt": "2024-08-15T20:15:17.774454", "lvl": "debug", "msg": "start: 1.3.1 http-download (timeout 01:29:54) [common]"}
- {"dt": "2024-08-15T20:15:17.775685", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30168/3/raspberrypi4/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T20:15:17.776600", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/35926/nbd-deploy-d1lhil5_/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T20:15:17.777301", "lvl": "debug", "msg": "total size: 54759 (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:17.778054", "lvl": "debug", "msg": "No compression specified"}
- {"dt": "2024-08-15T20:15:18.094350", "lvl": "debug", "msg": "progress  59\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:18.195357", "lvl": "debug", "msg": "progress 100\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:18.196974", "lvl": "info", "msg": "0\u202FMB downloaded in 0.42\u202Fs (0.12\u202FMB/s)"}
- {"dt": "2024-08-15T20:15:18.198037", "lvl": "debug", "msg": "end: 1.3.1 http-download (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:15:18.198653", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "0.42", "extra": {"label": "dtb", "md5sum": "8148061872e529fe20707e8f5c677261", "sha256sum": "1adf34a5564e59d473c570c15f579e4d5e76eaa4075cc7de3b0ff791eb331780", "sha512sum": "9ff04a457be78d59fcedbfd99fb68d45d2902d85c59dd81de3de83d150135ac59f9023d063fef0c4a2f2aafbb67378d80c9d21f49ad6a3ebd92993535f10e125", "size": ! "54759"}, "level": "1.3.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:15:18.199972", "lvl": "debug", "msg": "end: 1.3 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:15:18.200744", "lvl": "debug", "msg": "start: 1.4 download-retry (timeout 01:29:53) [common]"}
- {"dt": "2024-08-15T20:15:18.201470", "lvl": "debug", "msg": "start: 1.4.1 http-download (timeout 01:29:53) [common]"}
- {"dt": "2024-08-15T20:15:18.202604", "lvl": "info", "msg": "downloading http://download.automotivelinux.org/AGL/upload/ci/30168/3/raspberrypi4/agl-ivi-demo-qt-raspberrypi4-64.ext4.xz"}
- {"dt": "2024-08-15T20:15:18.203251", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/35926/nbd-deploy-d1lhil5_/nbdroot/agl-ivi-demo-qt-raspberrypi4-64.ext4"}
- {"dt": "2024-08-15T20:15:18.203762", "lvl": "debug", "msg": "total size: 494211776 (471\u202FMB)"}
- {"dt": "2024-08-15T20:15:18.204252", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-08-15T20:15:18.526181", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-08-15T20:15:26.165541", "lvl": "debug", "msg": "progress   5\u202F% (23\u202FMB)"}
- {"dt": "2024-08-15T20:15:32.041826", "lvl": "debug", "msg": "progress  10\u202F% (47\u202FMB)"}
- {"dt": "2024-08-15T20:15:40.019619", "lvl": "debug", "msg": "progress  15\u202F% (70\u202FMB)"}
- {"dt": "2024-08-15T20:15:53.946763", "lvl": "debug", "msg": "progress  20\u202F% (94\u202FMB)"}
- {"dt": "2024-08-15T20:16:21.673266", "lvl": "debug", "msg": "progress  25\u202F% (117\u202FMB)"}
- {"dt": "2024-08-15T20:16:27.894196", "lvl": "debug", "msg": "progress  30\u202F% (141\u202FMB)"}
- {"dt": "2024-08-15T20:16:34.407544", "lvl": "debug", "msg": "progress  35\u202F% (164\u202FMB)"}
- {"dt": "2024-08-15T20:16:41.857255", "lvl": "debug", "msg": "progress  40\u202F% (188\u202FMB)"}
- {"dt": "2024-08-15T20:16:48.343685", "lvl": "debug", "msg": "progress  45\u202F% (212\u202FMB)"}
- {"dt": "2024-08-15T20:16:56.022918", "lvl": "debug", "msg": "progress  50\u202F% (235\u202FMB)"}
- {"dt": "2024-08-15T20:17:03.455133", "lvl": "debug", "msg": "progress  55\u202F% (259\u202FMB)"}
- {"dt": "2024-08-15T20:17:12.333111", "lvl": "debug", "msg": "progress  60\u202F% (282\u202FMB)"}
- {"dt": "2024-08-15T20:17:18.848881", "lvl": "debug", "msg": "progress  65\u202F% (306\u202FMB)"}
- {"dt": "2024-08-15T20:17:26.233209", "lvl": "debug", "msg": "progress  70\u202F% (329\u202FMB)"}
- {"dt": "2024-08-15T20:17:33.799833", "lvl": "debug", "msg": "progress  75\u202F% (353\u202FMB)"}
- {"dt": "2024-08-15T20:17:41.068580", "lvl": "debug", "msg": "progress  80\u202F% (377\u202FMB)"}
- {"dt": "2024-08-15T20:17:47.637122", "lvl": "debug", "msg": "progress  85\u202F% (400\u202FMB)"}
- {"dt": "2024-08-15T20:17:53.867455", "lvl": "debug", "msg": "progress  90\u202F% (424\u202FMB)"}
- {"dt": "2024-08-15T20:17:59.538497", "lvl": "debug", "msg": "progress  95\u202F% (447\u202FMB)"}
- {"dt": "2024-08-15T20:18:13.858725", "lvl": "debug", "msg": "progress 100\u202F% (471\u202FMB)"}
- {"dt": "2024-08-15T20:18:17.691512", "lvl": "info", "msg": "471\u202FMB downloaded in 179.49\u202Fs (2.63\u202FMB/s)"}
- {"dt": "2024-08-15T20:18:17.692715", "lvl": "debug", "msg": "end: 1.4.1 http-download (duration 00:02:59) [common]"}
- {"dt": "2024-08-15T20:18:17.693337", "lvl": "results", "msg": {"case": "http-download", "definition": "lava", "duration": "179.49", "extra": {"label": "nbdroot", "md5sum": "8117debcf4b780e81d926fcc031648cc", "sha256sum": "2c7920206aae153a536148e44a01522b84e16da09ee49f2cc6169ca38344eb4c", "sha512sum": "0a67e856e2f15f519c20a99df2d7d9bdc7463a04a30edd91ee04964675b4a15a41bfa191a1f4cd24b758a61bc38066e081ff7a04416b0e941ab778b0ec7d6b2a", "size": ! "494211776"}, "level": "1.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:17.694676", "lvl": "debug", "msg": "end: 1.4 download-retry (duration 00:02:59) [common]"}
- {"dt": "2024-08-15T20:18:17.695339", "lvl": "debug", "msg": "start: 1.5 lava-overlay (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T20:18:17.696836", "lvl": "debug", "msg": "[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr"}
- {"dt": "2024-08-15T20:18:17.698258", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin"}
- {"dt": "2024-08-15T20:18:17.699439", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/tests"}
- {"dt": "2024-08-15T20:18:17.700655", "lvl": "debug", "msg": "makedir: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/results"}
- {"dt": "2024-08-15T20:18:17.701857", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-add-keys"}
- {"dt": "2024-08-15T20:18:17.703370", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-add-sources"}
- {"dt": "2024-08-15T20:18:17.704937", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-background-process-start"}
- {"dt": "2024-08-15T20:18:17.706571", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-background-process-stop"}
- {"dt": "2024-08-15T20:18:17.708209", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-common-functions"}
- {"dt": "2024-08-15T20:18:17.709804", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-echo-ipv4"}
- {"dt": "2024-08-15T20:18:17.711342", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-install-packages"}
- {"dt": "2024-08-15T20:18:17.712892", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-installed-packages"}
- {"dt": "2024-08-15T20:18:17.714411", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-os-build"}
- {"dt": "2024-08-15T20:18:17.715922", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-probe-channel"}
- {"dt": "2024-08-15T20:18:17.717569", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-probe-ip"}
- {"dt": "2024-08-15T20:18:17.719096", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-target-ip"}
- {"dt": "2024-08-15T20:18:17.720665", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-target-mac"}
- {"dt": "2024-08-15T20:18:17.722191", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-target-storage"}
- {"dt": "2024-08-15T20:18:17.723736", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-test-case"}
- {"dt": "2024-08-15T20:18:17.725270", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-test-event"}
- {"dt": "2024-08-15T20:18:17.726760", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-test-feedback"}
- {"dt": "2024-08-15T20:18:17.728276", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-test-raise"}
- {"dt": "2024-08-15T20:18:17.729946", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-test-reference"}
- {"dt": "2024-08-15T20:18:17.731464", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-test-runner"}
- {"dt": "2024-08-15T20:18:17.733049", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-test-set"}
- {"dt": "2024-08-15T20:18:17.734562", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-test-shell"}
- {"dt": "2024-08-15T20:18:17.736148", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-install-packages (oe)"}
- {"dt": "2024-08-15T20:18:17.737940", "lvl": "debug", "msg": "Updating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/bin/lava-installed-packages (oe)"}
- {"dt": "2024-08-15T20:18:17.739471", "lvl": "debug", "msg": "Creating /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/environment"}
- {"dt": "2024-08-15T20:18:17.740779", "lvl": "debug", "msg": "LAVA metadata"}
- {"dt": "2024-08-15T20:18:17.741682", "lvl": "debug", "msg": "- LAVA_JOB_ID=35926"}
- {"dt": "2024-08-15T20:18:17.742476", "lvl": "debug", "msg": "- LAVA_DISPATCHER_IP=192.168.66.1"}
- {"dt": "2024-08-15T20:18:17.743595", "lvl": "debug", "msg": "start: 1.5.1 ssh-authorize (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T20:18:17.746231", "lvl": "debug", "msg": "end: 1.5.1 ssh-authorize (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:17.747283", "lvl": "debug", "msg": "start: 1.5.2 lava-vland-overlay (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T20:18:17.748098", "lvl": "debug", "msg": "skipped lava-vland-overlay"}
- {"dt": "2024-08-15T20:18:17.749087", "lvl": "debug", "msg": "end: 1.5.2 lava-vland-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:17.750053", "lvl": "debug", "msg": "start: 1.5.3 lava-multinode-overlay (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T20:18:17.750873", "lvl": "debug", "msg": "skipped lava-multinode-overlay"}
- {"dt": "2024-08-15T20:18:17.751757", "lvl": "debug", "msg": "end: 1.5.3 lava-multinode-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:17.752729", "lvl": "debug", "msg": "start: 1.5.4 test-definition (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T20:18:17.753620", "lvl": "info", "msg": "Loading test definitions"}
- {"dt": "2024-08-15T20:18:17.754630", "lvl": "debug", "msg": "start: 1.5.4.1 git-repo-action (timeout 01:26:54) [common]"}
- {"dt": "2024-08-15T20:18:17.755479", "lvl": "debug", "msg": "Using /lava-35926 at stage 0"}
- {"dt": "2024-08-15T20:18:17.756659", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T20:18:17.757538", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/0/tests/0_network-veth'"}
- {"dt": "2024-08-15T20:18:18.487821", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/0/tests/0_network-veth/test-suites/short-smoke/network-veth.yaml"}
- {"dt": "2024-08-15T20:18:18.490045", "lvl": "debug", "msg": "uuid=35926_1.5.4.1 testdef=None"}
- {"dt": "2024-08-15T20:18:18.490889", "lvl": "debug", "msg": "end: 1.5.4.1 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:18:18.491413", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.74", "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-15T20:18:18.492927", "lvl": "debug", "msg": "start: 1.5.4.2 test-overlay (timeout 01:26:53) [common]"}
- {"dt": "2024-08-15T20:18:18.497650", "lvl": "debug", "msg": "end: 1.5.4.2 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:18.498485", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "extra": {"from": "git", "name": "network-veth", "path": "test-suites/short-smoke/network-veth.yaml", "repository": "https://git.automotivelinux.org/src/qa-testdefinitions", "uuid": "35926_1.5.4.1"}, "level": "1.5.4.2", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:18.500068", "lvl": "debug", "msg": "start: 1.5.4.3 test-install-overlay (timeout 01:26:53) [common]"}
- {"dt": "2024-08-15T20:18:18.506510", "lvl": "debug", "msg": "end: 1.5.4.3 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:18.507424", "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": "35926_1.5.4.1", "uuid": "35926_1.5.4.1"}, "level": "1.5.4.3", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:18.509305", "lvl": "debug", "msg": "start: 1.5.4.4 test-runscript-overlay (timeout 01:26:53) [common]"}
- {"dt": "2024-08-15T20:18:18.515267", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/0/tests/0_network-veth test_uuid 35926_1.5.4.1"}
- {"dt": "2024-08-15T20:18:18.516974", "lvl": "debug", "msg": "end: 1.5.4.4 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:18.517854", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/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": "35926_1.5.4.1"}, "level": "1.5.4.4", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:18.519953", "lvl": "debug", "msg": "start: 1.5.4.5 git-repo-action (timeout 01:26:53) [common]"}
- {"dt": "2024-08-15T20:18:18.520872", "lvl": "debug", "msg": "Using /lava-35926 at stage 1"}
- {"dt": "2024-08-15T20:18:18.521973", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T20:18:18.523344", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/1_ci-busybox'"}
- {"dt": "2024-08-15T20:18:19.117417", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/1_ci-busybox"}
- {"dt": "2024-08-15T20:18:19.126932", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/1_ci-busybox/test-suites/short-smoke/busybox.yaml"}
- {"dt": "2024-08-15T20:18:19.129351", "lvl": "debug", "msg": "uuid=35926_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-15T20:18:19.130154", "lvl": "debug", "msg": "end: 1.5.4.5 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:18:19.130632", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.61", "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-15T20:18:19.131757", "lvl": "debug", "msg": "start: 1.5.4.6 test-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T20:18:19.136828", "lvl": "debug", "msg": "end: 1.5.4.6 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:19.137392", "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": "35926_1.5.4.5"}, "level": "1.5.4.6", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:19.138688", "lvl": "debug", "msg": "start: 1.5.4.7 test-install-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T20:18:19.145534", "lvl": "debug", "msg": "end: 1.5.4.7 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:19.146149", "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": "35926_1.5.4.5", "uuid": "35926_1.5.4.5"}, "level": "1.5.4.7", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:19.147422", "lvl": "debug", "msg": "start: 1.5.4.8 test-runscript-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T20:18:19.154908", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/1_ci-busybox test_uuid 35926_1.5.4.5"}
- {"dt": "2024-08-15T20:18:19.156277", "lvl": "debug", "msg": "end: 1.5.4.8 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:19.156942", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/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": "35926_1.5.4.5"}, "level": "1.5.4.8", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:19.158305", "lvl": "debug", "msg": "start: 1.5.4.9 git-repo-action (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T20:18:19.158811", "lvl": "debug", "msg": "Using /lava-35926 at stage 1"}
- {"dt": "2024-08-15T20:18:19.159551", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T20:18:19.160184", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/2_ci-smoke-tests-basic'"}
- {"dt": "2024-08-15T20:18:19.857170", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/2_ci-smoke-tests-basic"}
- {"dt": "2024-08-15T20:18:19.866678", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/2_ci-smoke-tests-basic/test-suites/short-smoke/smoke-tests-basic.yaml"}
- {"dt": "2024-08-15T20:18:19.869083", "lvl": "debug", "msg": "uuid=35926_1.5.4.9 testdef=None"}
- {"dt": "2024-08-15T20:18:19.870196", "lvl": "debug", "msg": "end: 1.5.4.9 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:18:19.871075", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.71", "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-15T20:18:19.872660", "lvl": "debug", "msg": "start: 1.5.4.10 test-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T20:18:19.877535", "lvl": "debug", "msg": "end: 1.5.4.10 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:19.878436", "lvl": "results", "msg": {"case": "test-overlay", "definition": "lava", "duration": "0.00", "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": "35926_1.5.4.9"}, "level": "1.5.4.10", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:19.880115", "lvl": "debug", "msg": "start: 1.5.4.11 test-install-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T20:18:19.886920", "lvl": "debug", "msg": "end: 1.5.4.11 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:19.887830", "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": "35926_1.5.4.9", "uuid": "35926_1.5.4.9"}, "level": "1.5.4.11", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:19.889577", "lvl": "debug", "msg": "start: 1.5.4.12 test-runscript-overlay (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T20:18:19.896913", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/2_ci-smoke-tests-basic test_uuid 35926_1.5.4.9"}
- {"dt": "2024-08-15T20:18:19.899247", "lvl": "debug", "msg": "end: 1.5.4.12 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:19.900164", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/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": "35926_1.5.4.9"}, "level": "1.5.4.12", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:19.901922", "lvl": "debug", "msg": "start: 1.5.4.13 git-repo-action (timeout 01:26:52) [common]"}
- {"dt": "2024-08-15T20:18:19.902798", "lvl": "debug", "msg": "Using /lava-35926 at stage 1"}
- {"dt": "2024-08-15T20:18:19.903921", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T20:18:19.904870", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/3_ci-service-check'"}
- {"dt": "2024-08-15T20:18:20.532960", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/3_ci-service-check"}
- {"dt": "2024-08-15T20:18:20.542043", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/3_ci-service-check/test-suites/short-smoke/service-check.yaml"}
- {"dt": "2024-08-15T20:18:20.544465", "lvl": "debug", "msg": "uuid=35926_1.5.4.13 testdef=None"}
- {"dt": "2024-08-15T20:18:20.545563", "lvl": "debug", "msg": "end: 1.5.4.13 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:18:20.546475", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.64", "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-15T20:18:20.547954", "lvl": "debug", "msg": "start: 1.5.4.14 test-overlay (timeout 01:26:51) [common]"}
- {"dt": "2024-08-15T20:18:20.553240", "lvl": "debug", "msg": "end: 1.5.4.14 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:20.554148", "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": "35926_1.5.4.13"}, "level": "1.5.4.14", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:20.555923", "lvl": "debug", "msg": "start: 1.5.4.15 test-install-overlay (timeout 01:26:51) [common]"}
- {"dt": "2024-08-15T20:18:20.563641", "lvl": "debug", "msg": "end: 1.5.4.15 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:20.564579", "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": "35926_1.5.4.13", "uuid": "35926_1.5.4.13"}, "level": "1.5.4.15", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:20.566343", "lvl": "debug", "msg": "start: 1.5.4.16 test-runscript-overlay (timeout 01:26:51) [common]"}
- {"dt": "2024-08-15T20:18:20.573211", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1/tests/3_ci-service-check test_uuid 35926_1.5.4.13"}
- {"dt": "2024-08-15T20:18:20.574182", "lvl": "debug", "msg": "BUILD_TAGS=''"}
- {"dt": "2024-08-15T20:18:20.575002", "lvl": "debug", "msg": "DEVICE_TAGS=''"}
- {"dt": "2024-08-15T20:18:20.576582", "lvl": "debug", "msg": "end: 1.5.4.16 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:20.577527", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/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": "35926_1.5.4.13"}, "level": "1.5.4.16", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:20.579246", "lvl": "debug", "msg": "start: 1.5.4.17 git-repo-action (timeout 01:26:51) [common]"}
- {"dt": "2024-08-15T20:18:20.580142", "lvl": "debug", "msg": "Using /lava-35926 at stage 2"}
- {"dt": "2024-08-15T20:18:20.581343", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T20:18:20.582243", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/2/tests/4_screenshooter'"}
- {"dt": "2024-08-15T20:18:21.220650", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/2/tests/4_screenshooter/test-suites/short-smoke/screenshooter.yaml"}
- {"dt": "2024-08-15T20:18:21.222457", "lvl": "debug", "msg": "uuid=35926_1.5.4.17 testdef=None"}
- {"dt": "2024-08-15T20:18:21.223223", "lvl": "debug", "msg": "end: 1.5.4.17 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:18:21.223751", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.64", "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-15T20:18:21.224963", "lvl": "debug", "msg": "start: 1.5.4.18 test-overlay (timeout 01:26:50) [common]"}
- {"dt": "2024-08-15T20:18:21.228928", "lvl": "debug", "msg": "end: 1.5.4.18 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:21.229819", "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": "35926_1.5.4.17"}, "level": "1.5.4.18", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:21.231413", "lvl": "debug", "msg": "start: 1.5.4.19 test-install-overlay (timeout 01:26:50) [common]"}
- {"dt": "2024-08-15T20:18:21.238536", "lvl": "debug", "msg": "end: 1.5.4.19 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:21.239423", "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": "35926_1.5.4.17", "uuid": "35926_1.5.4.17"}, "level": "1.5.4.19", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:21.241126", "lvl": "debug", "msg": "start: 1.5.4.20 test-runscript-overlay (timeout 01:26:50) [common]"}
- {"dt": "2024-08-15T20:18:21.255764", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/2/tests/4_screenshooter test_uuid 35926_1.5.4.17"}
- {"dt": "2024-08-15T20:18:21.257505", "lvl": "debug", "msg": "end: 1.5.4.20 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:21.258400", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.02", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/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": "35926_1.5.4.17"}, "level": "1.5.4.20", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:21.260042", "lvl": "debug", "msg": "start: 1.5.4.21 git-repo-action (timeout 01:26:50) [common]"}
- {"dt": "2024-08-15T20:18:21.260966", "lvl": "debug", "msg": "Using /lava-35926 at stage 3"}
- {"dt": "2024-08-15T20:18:21.262028", "lvl": "info", "msg": "Fetching tests from https://git.automotivelinux.org/src/qa-testdefinitions"}
- {"dt": "2024-08-15T20:18:21.262855", "lvl": "debug", "msg": "Running '/usr/bin/git clone --depth=1 https://git.automotivelinux.org/src/qa-testdefinitions /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/3/tests/5_ci-dumpjournal'"}
- {"dt": "2024-08-15T20:18:21.981276", "lvl": "debug", "msg": "Removing '.git' directory in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/3/tests/5_ci-dumpjournal"}
- {"dt": "2024-08-15T20:18:21.991686", "lvl": "debug", "msg": "Tests stored (tmp) in /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/3/tests/5_ci-dumpjournal/test-suites/short-smoke/dumpjournal.yaml"}
- {"dt": "2024-08-15T20:18:21.994086", "lvl": "debug", "msg": "uuid=35926_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-15T20:18:21.994873", "lvl": "debug", "msg": "end: 1.5.4.21 git-repo-action (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:18:21.995427", "lvl": "results", "msg": {"case": "git-repo-action", "definition": "lava", "duration": "0.73", "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-15T20:18:21.996622", "lvl": "debug", "msg": "start: 1.5.4.22 test-overlay (timeout 01:26:50) [common]"}
- {"dt": "2024-08-15T20:18:22.001491", "lvl": "debug", "msg": "end: 1.5.4.22 test-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:22.002075", "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": "35926_1.5.4.21"}, "level": "1.5.4.22", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:22.003359", "lvl": "debug", "msg": "start: 1.5.4.23 test-install-overlay (timeout 01:26:49) [common]"}
- {"dt": "2024-08-15T20:18:22.010475", "lvl": "debug", "msg": "end: 1.5.4.23 test-install-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:22.011094", "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": "35926_1.5.4.21", "uuid": "35926_1.5.4.21"}, "level": "1.5.4.23", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:22.012623", "lvl": "debug", "msg": "start: 1.5.4.24 test-runscript-overlay (timeout 01:26:49) [common]"}
- {"dt": "2024-08-15T20:18:22.019171", "lvl": "debug", "msg": "runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/3/tests/5_ci-dumpjournal test_uuid 35926_1.5.4.21"}
- {"dt": "2024-08-15T20:18:22.020568", "lvl": "debug", "msg": "end: 1.5.4.24 test-runscript-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:22.021193", "lvl": "results", "msg": {"case": "test-runscript-overlay", "definition": "lava", "duration": "0.01", "extra": {"filename": "/var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/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": "35926_1.5.4.21"}, "level": "1.5.4.24", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:22.022371", "lvl": "info", "msg": "Creating lava-test-runner.conf files"}
- {"dt": "2024-08-15T20:18:22.022840", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/0 for stage 0"}
- {"dt": "2024-08-15T20:18:22.023662", "lvl": "debug", "msg": "- 0_network-veth"}
- {"dt": "2024-08-15T20:18:22.024480", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/1 for stage 1"}
- {"dt": "2024-08-15T20:18:22.025380", "lvl": "debug", "msg": "- 1_ci-busybox"}
- {"dt": "2024-08-15T20:18:22.026237", "lvl": "debug", "msg": "- 2_ci-smoke-tests-basic"}
- {"dt": "2024-08-15T20:18:22.027044", "lvl": "debug", "msg": "- 3_ci-service-check"}
- {"dt": "2024-08-15T20:18:22.027730", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/2 for stage 2"}
- {"dt": "2024-08-15T20:18:22.028653", "lvl": "debug", "msg": "- 4_screenshooter"}
- {"dt": "2024-08-15T20:18:22.029380", "lvl": "debug", "msg": "Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/35926/lava-overlay-_druoovr/lava-35926/3 for stage 3"}
- {"dt": "2024-08-15T20:18:22.030233", "lvl": "debug", "msg": "- 5_ci-dumpjournal"}
- {"dt": "2024-08-15T20:18:22.031114", "lvl": "debug", "msg": "end: 1.5.4 test-definition (duration 00:00:04) [common]"}
- {"dt": "2024-08-15T20:18:22.031792", "lvl": "debug", "msg": "start: 1.5.5 compress-overlay (timeout 01:26:49) [common]"}
- {"dt": "2024-08-15T20:18:22.732805", "lvl": "debug", "msg": "end: 1.5.5 compress-overlay (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:18:22.733607", "lvl": "debug", "msg": "start: 1.5.6 persistent-nfs-overlay (timeout 01:26:49) [common]"}
- {"dt": "2024-08-15T20:18:22.734282", "lvl": "debug", "msg": "end: 1.5.6 persistent-nfs-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:22.735313", "lvl": "debug", "msg": "end: 1.5 lava-overlay (duration 00:00:05) [common]"}
- {"dt": "2024-08-15T20:18:22.736042", "lvl": "debug", "msg": "start: 1.6 prepare-kernel (timeout 01:26:49) [common]"}
- {"dt": "2024-08-15T20:18:22.736763", "lvl": "debug", "msg": "start: 1.6.1 uboot-prepare-kernel (timeout 01:26:49) [common]"}
- {"dt": "2024-08-15T20:18:22.737488", "lvl": "debug", "msg": "end: 1.6.1 uboot-prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:22.738114", "lvl": "debug", "msg": "end: 1.6 prepare-kernel (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:22.738759", "lvl": "debug", "msg": "start: 1.7 xnbd-server-deploy (timeout 01:26:49) [common]"}
- {"dt": "2024-08-15T20:18:22.739279", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server"}
- {"dt": "2024-08-15T20:18:22.739800", "lvl": "debug", "msg": "NBD-IP: 192.168.66.1, NBD-PORT: 61977, NBD-ROOT: 35926/nbd-deploy-d1lhil5_/nbdroot/agl-ivi-demo-qt-raspberrypi4-64.ext4"}
- {"dt": "2024-08-15T20:18:22.743024", "lvl": "debug", "msg": "nbd-server 61977 /var/lib/lava/dispatcher/tmp/35926/nbd-deploy-d1lhil5_/nbdroot/agl-ivi-demo-qt-raspberrypi4-64.ext4"}
- {"dt": "2024-08-15T20:18:22.755596", "lvl": "debug", "msg": "output: "}
- {"dt": "2024-08-15T20:18:22.756424", "lvl": "debug", "msg": "output: ** (process:2127): WARNING **: 20:18:22.754: Specifying an export on the command line no longer uses the oldstyle protocol."}
- {"dt": "2024-08-15T20:18:22.756951", "lvl": "debug", "msg": "output: "}
- {"dt": "2024-08-15T20:18:22.757398", "lvl": "debug", "msg": "xnbd-server-deploy: starting nbd-server done"}
- {"dt": "2024-08-15T20:18:22.758026", "lvl": "debug", "msg": "end: 1.7 xnbd-server-deploy (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:22.758736", "lvl": "info", "msg": "end: 1 nbd-deploy (duration 00:03:11) [common]"}
- {"dt": "2024-08-15T20:18:22.759720", "lvl": "info", "msg": "start: 2 uboot-action (timeout 00:20:00) [common]"}
- {"dt": "2024-08-15T20:18:22.761298", "lvl": "debug", "msg": "start: 2.1 uboot-from-media (timeout 00:20:00) [common]"}
- {"dt": "2024-08-15T20:18:22.762315", "lvl": "debug", "msg": "end: 2.1 uboot-from-media (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:22.763315", "lvl": "debug", "msg": "start: 2.2 bootloader-overlay (timeout 00:20:00) [common]"}
- {"dt": "2024-08-15T20:18:22.764618", "lvl": "debug", "msg": "substitutions:"}
- {"dt": "2024-08-15T20:18:22.765499", "lvl": "debug", "msg": "- {BOOTX}: booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-08-15T20:18:22.766290", "lvl": "debug", "msg": "- {DTB_ADDR}: 0x02400000"}
- {"dt": "2024-08-15T20:18:22.767075", "lvl": "debug", "msg": "- {DTB}: 35926/nbd-deploy-d1lhil5_/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T20:18:22.767818", "lvl": "debug", "msg": "- {INITRD}: 35926/nbd-deploy-d1lhil5_/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T20:18:22.769017", "lvl": "debug", "msg": "- {KERNEL_ADDR}: 0x00080000"}
- {"dt": "2024-08-15T20:18:22.769887", "lvl": "debug", "msg": "- {KERNEL}: 35926/nbd-deploy-d1lhil5_/kernel/Image"}
- {"dt": "2024-08-15T20:18:22.770652", "lvl": "debug", "msg": "- {LAVA_MAC}: None"}
- {"dt": "2024-08-15T20:18:22.771826", "lvl": "debug", "msg": "- {NBDSERVERIP}: 192.168.66.1"}
- {"dt": "2024-08-15T20:18:22.772688", "lvl": "debug", "msg": "- {NBDSERVERPORT}: 61977"}
- {"dt": "2024-08-15T20:18:22.773467", "lvl": "debug", "msg": "- {PRESEED_CONFIG}: None"}
- {"dt": "2024-08-15T20:18:22.774556", "lvl": "debug", "msg": "- {PRESEED_LOCAL}: None"}
- {"dt": "2024-08-15T20:18:22.775343", "lvl": "debug", "msg": "- {RAMDISK_ADDR}: 0x02700000"}
- {"dt": "2024-08-15T20:18:22.776169", "lvl": "debug", "msg": "- {RAMDISK}: 35926/nbd-deploy-d1lhil5_/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T20:18:22.777357", "lvl": "debug", "msg": "- {ROOT_PART}: None"}
- {"dt": "2024-08-15T20:18:22.778218", "lvl": "debug", "msg": "- {ROOT}: None"}
- {"dt": "2024-08-15T20:18:22.779044", "lvl": "debug", "msg": "- {SERVER_IP}: 192.168.66.1"}
- {"dt": "2024-08-15T20:18:22.779784", "lvl": "debug", "msg": "- {TEE_ADDR}: 0x83000000"}
- {"dt": "2024-08-15T20:18:22.780579", "lvl": "debug", "msg": "- {TEE}: None"}
- {"dt": "2024-08-15T20:18:22.781350", "lvl": "info", "msg": "Parsed boot commands:"}
- {"dt": "2024-08-15T20:18:22.782104", "lvl": "info", "msg": "- setenv autoload no"}
- {"dt": "2024-08-15T20:18:22.782857", "lvl": "info", "msg": "- setenv initrd_high 0xffffffff"}
- {"dt": "2024-08-15T20:18:22.783595", "lvl": "info", "msg": "- setenv fdt_high 0xffffffff"}
- {"dt": "2024-08-15T20:18:22.784391", "lvl": "info", "msg": "- dhcp"}
- {"dt": "2024-08-15T20:18:22.785607", "lvl": "info", "msg": "- setenv serverip 192.168.66.1"}
- {"dt": "2024-08-15T20:18:22.786455", "lvl": "info", "msg": "- tftp 0x00080000 35926/nbd-deploy-d1lhil5_/kernel/Image"}
- {"dt": "2024-08-15T20:18:22.787238", "lvl": "info", "msg": "- tftp 0x02700000 35926/nbd-deploy-d1lhil5_/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T20:18:22.788097", "lvl": "info", "msg": "- setenv initrd_size ${filesize}"}
- {"dt": "2024-08-15T20:18:22.788930", "lvl": "info", "msg": "- tftp 0x02400000 35926/nbd-deploy-d1lhil5_/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T20:18:22.789700", "lvl": "info", "msg": "- setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61977 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-15T20:18:22.790512", "lvl": "info", "msg": "- fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-08-15T20:18:22.791737", "lvl": "debug", "msg": "end: 2.2 bootloader-overlay (duration 00:00:00) [common]"}
- {"dt": "2024-08-15T20:18:22.792698", "lvl": "results", "msg": {"case": "bootloader-overlay", "definition": "lava", "duration": "0.03", "extra": {"dtb_addr": "0x02400000", "kernel_addr": "0x00080000", "ramdisk_addr": "0x02700000", "tee_addr": "0x83000000"}, "level": "2.2", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:22.794682", "lvl": "debug", "msg": "start: 2.3 connect-device (timeout 00:20:00) [common]"}
- {"dt": "2024-08-15T20:18:22.795591", "lvl": "info", "msg": "[common] connect-device Connecting to device using 'telnet 127.0.0.1 63003'"}
- {"dt": "2024-08-15T20:18:26.729576", "lvl": "debug", "msg": "Setting prompt string to ['lava-test: # ']"}
- {"dt": "2024-08-15T20:18:26.731911", "lvl": "debug", "msg": "end: 2.3 connect-device (duration 00:00:04) [common]"}
- {"dt": "2024-08-15T20:18:26.732919", "lvl": "debug", "msg": "start: 2.4 uboot-commands (timeout 00:19:56) [common]"}
- {"dt": "2024-08-15T20:18:26.733689", "lvl": "debug", "msg": "start: 2.4.1 reset-device (timeout 00:19:56) [common]"}
- {"dt": "2024-08-15T20:18:26.736025", "lvl": "debug", "msg": "start: 2.4.1.1 pdu-reboot (timeout 00:19:56) [common]"}
- {"dt": "2024-08-15T20:18:26.737360", "lvl": "debug", "msg": "Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'reset' '7'"}
- {"dt": "2024-08-15T20:18:31.255807", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2024-08-15T20:18:32.321083", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2024-08-15T20:18:32.368797", "lvl": "debug", "msg": "Returned 0 in 5 seconds"}
- {"dt": "2024-08-15T20:18:32.470344", "lvl": "debug", "msg": "end: 2.4.1.1 pdu-reboot (duration 00:00:06) [common]"}
- {"dt": "2024-08-15T20:18:32.471166", "lvl": "results", "msg": {"case": "pdu-reboot", "definition": "lava", "duration": "5.73", "extra": {"status": "success"}, "level": "2.4.1.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:18:32.473275", "lvl": "debug", "msg": "end: 2.4.1 reset-device (duration 00:00:06) [common]"}
- {"dt": "2024-08-15T20:18:32.473901", "lvl": "debug", "msg": "start: 2.4.2 bootloader-interrupt (timeout 00:19:50) [common]"}
- {"dt": "2024-08-15T20:18:32.474453", "lvl": "debug", "msg": "Setting prompt string to ['Hit any key to stop autoboot']"}
- {"dt": "2024-08-15T20:18:32.474981", "lvl": "debug", "msg": "bootloader-interrupt: Wait for prompt ['Hit any key to stop autoboot'] (timeout 00:20:00)"}
- {"dt": "2024-08-15T20:18:32.476522", "lvl": "target", "msg": "Trying 127.0.0.1..."}
- {"dt": "2024-08-15T20:18:32.477115", "lvl": "target", "msg": "Connected to 127.0.0.1."}
- {"dt": "2024-08-15T20:18:32.477516", "lvl": "target", "msg": "Escape character is '^]'."}
- {"dt": "2024-08-15T20:18:38.978261", "lvl": "target", "msg": "\0"}
- {"dt": "2024-08-15T20:18:38.979459", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T20:18:38.993936", "lvl": "target", "msg": "U-Boot 2020.07-00717-gfee68b98fe-dirty (Jul 17 2020 - 09:59:08 +0200)"}
- {"dt": "2024-08-15T20:18:38.994773", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T20:18:39.138125", "lvl": "target", "msg": "DRAM:  3.9 GiB"}
- {"dt": "2024-08-15T20:18:39.169831", "lvl": "target", "msg": "RPI 4 Model B (0xc03111)"}
- {"dt": "2024-08-15T20:18:39.207377", "lvl": "target", "msg": "MMC:   emmc2@7e340000: 0, mmcnr@7e300000: 1"}
- {"dt": "2024-08-15T20:18:39.273507", "lvl": "target", "msg": "Loading Environment from FAT... *** Warning - bad CRC, using default environment"}
- {"dt": "2024-08-15T20:18:39.274235", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T20:18:39.302337", "lvl": "target", "msg": "In:    serial"}
- {"dt": "2024-08-15T20:18:39.303055", "lvl": "target", "msg": "Out:   serial"}
- {"dt": "2024-08-15T20:18:39.303516", "lvl": "target", "msg": "Err:   serial"}
- {"dt": "2024-08-15T20:18:39.303941", "lvl": "target", "msg": "Net:   eth0: genet@7d580000"}
- {"dt": "2024-08-15T20:18:39.304419", "lvl": "target", "msg": "starting USB..."}
- {"dt": "2024-08-15T20:18:39.304871", "lvl": "target", "msg": "No working controllers found"}
- {"dt": "2024-08-15T20:18:39.306249", "lvl": "input", "msg": "c"}
- {"dt": "2024-08-15T20:18:39.307699", "lvl": "debug", "msg": "end: 2.4.2 bootloader-interrupt (duration 00:00:07) [common]"}
- {"dt": "2024-08-15T20:18:39.308800", "lvl": "debug", "msg": "start: 2.4.3 bootloader-commands (timeout 00:19:43) [common]"}
- {"dt": "2024-08-15T20:18:39.309678", "lvl": "debug", "msg": "Setting prompt string to ['U-Boot>']"}
- {"dt": "2024-08-15T20:18:39.310475", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>'] (timeout 00:19:43)"}
- {"dt": "2024-08-15T20:18:39.321261", "lvl": "target", "msg": "Hit any key to stop autoboot:  2 \x03\b\b\b 0 "}
- {"dt": "2024-08-15T20:18:39.322719", "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-15T20:18:39.323638", "lvl": "input", "msg": "setenv autoload no\n"}
- {"dt": "2024-08-15T20:18:39.424890", "lvl": "target", "msg": "U-Boot> setenv autoload no"}
- {"dt": "2024-08-15T20:18:39.426157", "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:43)"}
- {"dt": "2024-08-15T20:18:39.432008", "lvl": "target", "msg": "setenv autoload no"}
- {"dt": "2024-08-15T20:18:39.433205", "lvl": "input", "msg": "setenv initrd_high 0xffffffff\n"}
- {"dt": "2024-08-15T20:18:39.534418", "lvl": "target", "msg": "U-Boot> setenv initrd_high 0xffffffff"}
- {"dt": "2024-08-15T20:18:39.535756", "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:43)"}
- {"dt": "2024-08-15T20:18:39.544232", "lvl": "target", "msg": "setenv initrd_high 0xffffffff"}
- {"dt": "2024-08-15T20:18:39.545490", "lvl": "input", "msg": "setenv fdt_high 0xffffffff\n"}
- {"dt": "2024-08-15T20:18:39.646931", "lvl": "target", "msg": "U-Boot> setenv fdt_high 0xffffffff"}
- {"dt": "2024-08-15T20:18:39.648269", "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:43)"}
- {"dt": "2024-08-15T20:18:39.656065", "lvl": "target", "msg": "setenv fdt_high 0xffffffff"}
- {"dt": "2024-08-15T20:18:39.657313", "lvl": "input", "msg": "dhcp\n"}
- {"dt": "2024-08-15T20:18:39.758770", "lvl": "target", "msg": "U-Boot> dhcp"}
- {"dt": "2024-08-15T20:18:39.760163", "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:43)"}
- {"dt": "2024-08-15T20:18:39.768087", "lvl": "target", "msg": "dhcp"}
- {"dt": "2024-08-15T20:18:42.981371", "lvl": "target", "msg": "genet@7d580000 Waiting for PHY auto negotiation to complete....... done"}
- {"dt": "2024-08-15T20:18:42.982062", "lvl": "target", "msg": "BOOTP broadcast 1"}
- {"dt": "2024-08-15T20:18:43.236984", "lvl": "target", "msg": "BOOTP broadcast 2"}
- {"dt": "2024-08-15T20:18:43.731423", "lvl": "target", "msg": "BOOTP broadcast 3"}
- {"dt": "2024-08-15T20:18:44.018986", "lvl": "target", "msg": "DHCP client bound to address 192.168.66.241 (1028 ms)"}
- {"dt": "2024-08-15T20:18:44.020060", "lvl": "input", "msg": "setenv serverip 192.168.66.1\n"}
- {"dt": "2024-08-15T20:18:44.121057", "lvl": "target", "msg": "U-Boot> setenv serverip 192.168.66.1"}
- {"dt": "2024-08-15T20:18:44.122149", "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-15T20:18:44.129970", "lvl": "target", "msg": "setenv serverip 192.168.66.1"}
- {"dt": "2024-08-15T20:18:44.131081", "lvl": "input", "msg": "tftp 0x00080000 35926/nbd-deploy-d1lhil5_/kernel/Image\n"}
- {"dt": "2024-08-15T20:18:44.232423", "lvl": "target", "msg": "U-Boot> tftp 0x00080000 35926/nbd-deploy-d1lhil5_/kernel/Image"}
- {"dt": "2024-08-15T20:18:44.233322", "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-15T20:18:44.241931", "lvl": "target", "msg": "tftp 0x00080000 35926/nbd-deploy-d1lhil5_/kernel/Image"}
- {"dt": "2024-08-15T20:18:44.242617", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2024-08-15T20:18:44.260726", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2024-08-15T20:18:44.263971", "lvl": "target", "msg": "Filename '35926/nbd-deploy-d1lhil5_/kernel/Image'."}
- {"dt": "2024-08-15T20:18:44.264712", "lvl": "target", "msg": "Load address: 0x80000"}
- {"dt": "2024-08-15T20:18:58.978868", "lvl": "target", "msg": "Loading: *\b#########################T #########################  27.2 MiB"}
- {"dt": "2024-08-15T20:18:58.980535", "lvl": "target", "msg": "\t 1.9 MiB/s"}
- {"dt": "2024-08-15T20:18:58.981969", "lvl": "target", "msg": "done"}
- {"dt": "2024-08-15T20:18:58.985126", "lvl": "target", "msg": "Bytes transferred = 28535296 (1b36a00 hex)"}
- {"dt": "2024-08-15T20:18:58.987367", "lvl": "input", "msg": "tftp 0x02700000 35926/nbd-deploy-d1lhil5_/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz\n"}
- {"dt": "2024-08-15T20:18:59.088418", "lvl": "target", "msg": "U-Boot> tftp 0x02700000 35926/nbd-deploy-d1lhil5_/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T20:18:59.090082", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['U-Boot>', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:24)"}
- {"dt": "2024-08-15T20:18:59.097762", "lvl": "target", "msg": "tftp 0x02700000 35926/nbd-deploy-d1lhil5_/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz"}
- {"dt": "2024-08-15T20:18:59.099097", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2024-08-15T20:18:59.140903", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2024-08-15T20:18:59.141941", "lvl": "target", "msg": "Filename '35926/nbd-deploy-d1lhil5_/initrd/initramfs-netboot-image-raspberrypi4-64.ext4.gz'."}
- {"dt": "2024-08-15T20:18:59.142759", "lvl": "target", "msg": "Load address: 0x2700000"}
- {"dt": "2024-08-15T20:18:59.870704", "lvl": "target", "msg": "Loading: *\b##################################################  2.1 MiB"}
- {"dt": "2024-08-15T20:18:59.872269", "lvl": "target", "msg": "\t 2.8 MiB/s"}
- {"dt": "2024-08-15T20:18:59.874203", "lvl": "target", "msg": "done"}
- {"dt": "2024-08-15T20:18:59.876481", "lvl": "target", "msg": "Bytes transferred = 2153291 (20db4b hex)"}
- {"dt": "2024-08-15T20:18:59.878658", "lvl": "input", "msg": "setenv initrd_size ${filesize}\n"}
- {"dt": "2024-08-15T20:18:59.981003", "lvl": "target", "msg": "U-Boot> setenv initrd_size ${filesize}"}
- {"dt": "2024-08-15T20:18:59.983551", "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:23)"}
- {"dt": "2024-08-15T20:19:00.000436", "lvl": "target", "msg": "setenv initrd_size ${filesize}"}
- {"dt": "2024-08-15T20:19:00.001826", "lvl": "input", "msg": "tftp 0x02400000 35926/nbd-deploy-d1lhil5_/dtb/bcm2711-rpi-4-b+vc4.dtb\n"}
- {"dt": "2024-08-15T20:19:00.103261", "lvl": "target", "msg": "U-Boot> tftp 0x02400000 35926/nbd-deploy-d1lhil5_/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T20:19:00.105885", "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:23)"}
- {"dt": "2024-08-15T20:19:00.141081", "lvl": "target", "msg": "tftp 0x02400000 35926/nbd-deploy-d1lhil5_/dtb/bcm2711-rpi-4-b+vc4.dtb"}
- {"dt": "2024-08-15T20:19:00.141898", "lvl": "target", "msg": "Using genet@7d580000 device"}
- {"dt": "2024-08-15T20:19:00.189182", "lvl": "target", "msg": "TFTP from server 192.168.66.1; our IP address is 192.168.66.241"}
- {"dt": "2024-08-15T20:19:00.190961", "lvl": "target", "msg": "Filename '35926/nbd-deploy-d1lhil5_/dtb/bcm2711-rpi-4-b+vc4.dtb'."}
- {"dt": "2024-08-15T20:19:00.192597", "lvl": "target", "msg": "Load address: 0x2400000"}
- {"dt": "2024-08-15T20:19:00.194187", "lvl": "target", "msg": "Loading: *\b##################################################  53.5 KiB"}
- {"dt": "2024-08-15T20:19:00.195711", "lvl": "target", "msg": "\t 2.2 MiB/s"}
- {"dt": "2024-08-15T20:19:00.197323", "lvl": "target", "msg": "done"}
- {"dt": "2024-08-15T20:19:00.198869", "lvl": "target", "msg": "Bytes transferred = 54759 (d5e7 hex)"}
- {"dt": "2024-08-15T20:19:00.200853", "lvl": "input", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61977 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-15T20:19:00.301898", "lvl": "target", "msg": "U-Boot> setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61977 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-15T20:19:00.304491", "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:22)"}
- {"dt": "2024-08-15T20:19:00.308258", "lvl": "target", "msg": "setenv bootargs 'console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61977 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-15T20:19:00.349401", "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-15T20:19:00.451783", "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-15T20:19:00.454020", "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-15T20:19:00.455804", "lvl": "debug", "msg": "bootloader-commands: Wait for prompt ['Starting kernel', 'Resetting CPU', 'Must RESET board to recover', 'TIMEOUT', 'Retry count exceeded', 'Retry time exceeded; starting again', 'ERROR: The remote end did not respond in time.', 'File not found', 'Bad Linux ARM64 Image magic!', 'Wrong Ramdisk Image Format', 'Ramdisk image is corrupt or invalid', 'ERROR: Failed to allocate', 'TFTP error: trying to overwrite reserved memory', 'Bad Linux RISCV Image magic!', 'Wrong Image Format for boot', 'ERROR: Did not find a cmdline Flattened Device Tree', 'ERROR: RD image overlaps OS image'] (timeout 00:19:22)"}
- {"dt": "2024-08-15T20:19:00.462647", "lvl": "target", "msg": "fdt addr 0x02400000; fdt boardsetup; fdt resize; fdt set audio status okay; booti 0x00080000 0x02700000:${initrd_size} 0x02400000"}
- {"dt": "2024-08-15T20:19:00.463238", "lvl": "target", "msg": "libfdt fdt_path_offset() returned FDT_ERR_BADPATH"}
- {"dt": "2024-08-15T20:19:00.684704", "lvl": "target", "msg": "## Flattened Device Tree blob at 02400000"}
- {"dt": "2024-08-15T20:19:00.687099", "lvl": "target", "msg": "   Booting using the fdt blob at 0x2400000"}
- {"dt": "2024-08-15T20:19:00.689058", "lvl": "target", "msg": "   Loading Ramdisk to 3ad3b000, end 3af48b4b ... OK"}
- {"dt": "2024-08-15T20:19:00.705170", "lvl": "target", "msg": "   Loading Device Tree to 000000003ad2a000, end 000000003ad3afff ... OK"}
- {"dt": "2024-08-15T20:19:00.708126", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T20:19:00.709177", "lvl": "target", "msg": "Starting kernel ..."}
- {"dt": "2024-08-15T20:19:00.710019", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T20:19:00.711627", "lvl": "debug", "msg": "end: 2.4.3 bootloader-commands (duration 00:00:21) [common]"}
- {"dt": "2024-08-15T20:19:00.712916", "lvl": "debug", "msg": "start: 2.4.4 auto-login-action (timeout 00:19:22) [common]"}
- {"dt": "2024-08-15T20:19:00.713871", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2024-08-15T20:19:00.714808", "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-15T20:19:00.715821", "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-15T20:19:02.797976", "lvl": "target", "msg": "[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]"}
- {"dt": "2024-08-15T20:19:02.799377", "lvl": "debug", "msg": "start: 2.4.4.1 login-action (timeout 00:19:20) [common]"}
- {"dt": "2024-08-15T20:19:02.800079", "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-15T20:19:02.800660", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2024-08-15T20:19:02.801188", "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-15T20:19:02.801687", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2024-08-15T20:19:02.802136", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2024-08-15T20:19:02.802593", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2024-08-15T20:19:02.802996", "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-15T20:19:02.803886", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:19:20)"}
- {"dt": "2024-08-15T20:19:02.807282", "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-15T20:19:02.808114", "lvl": "target", "msg": "[    0.000000] KASLR disabled due to lack of seed"}
- {"dt": "2024-08-15T20:19:02.809038", "lvl": "target", "msg": "[    0.000000] Machine model: Raspberry Pi 4 Model B"}
- {"dt": "2024-08-15T20:19:02.809723", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2024-08-15T20:19:02.810261", "lvl": "target", "msg": "[    0.000000] Reserved memory: created CMA memory pool at 0x0000000010400000, size 508 MiB"}
- {"dt": "2024-08-15T20:19:02.842241", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool"}
- {"dt": "2024-08-15T20:19:02.843536", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: 0x0000000010400000..0x000000002fffffff (520192 KiB) map reusable linux,cma"}
- {"dt": "2024-08-15T20:19:02.844250", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2024-08-15T20:19:02.844931", "lvl": "target", "msg": "[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003fffffff]"}
- {"dt": "2024-08-15T20:19:02.845835", "lvl": "target", "msg": "[    0.000000]   DMA32    [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2024-08-15T20:19:02.846887", "lvl": "target", "msg": "[    0.000000]   Normal   empty"}
- {"dt": "2024-08-15T20:19:02.848105", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2024-08-15T20:19:02.849159", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2024-08-15T20:19:02.885783", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]"}
- {"dt": "2024-08-15T20:19:02.886848", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000fbffffff]"}
- {"dt": "2024-08-15T20:19:02.887725", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]"}
- {"dt": "2024-08-15T20:19:02.888663", "lvl": "target", "msg": "[    0.000000] On node 0, zone DMA32: 19456 pages in unavailable ranges"}
- {"dt": "2024-08-15T20:19:02.889515", "lvl": "target", "msg": "[    0.000000] On node 0, zone DMA32: 16384 pages in unavailable ranges"}
- {"dt": "2024-08-15T20:19:02.890345", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 31 pages/cpu s86632 r8192 d32152 u126976"}
- {"dt": "2024-08-15T20:19:02.891782", "lvl": "target", "msg": "[    0.000000] Detected PIPT I-cache on CPU0"}
- {"dt": "2024-08-15T20:19:02.929411", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v2"}
- {"dt": "2024-08-15T20:19:02.931687", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v3a"}
- {"dt": "2024-08-15T20:19:02.933804", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-v4"}
- {"dt": "2024-08-15T20:19:02.935712", "lvl": "target", "msg": "[    0.000000] CPU features: detected: Spectre-BHB"}
- {"dt": "2024-08-15T20:19:02.937737", "lvl": "target", "msg": "[    0.000000] CPU features: detected: ARM erratum 1742098"}
- {"dt": "2024-08-15T20:19:02.939608", "lvl": "target", "msg": "[    0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923"}
- {"dt": "2024-08-15T20:19:02.941507", "lvl": "target", "msg": "[    0.000000] alternatives: applying boot alternatives"}
- {"dt": "2024-08-15T20:19:02.973728", "lvl": "target", "msg": "[    0.000000] Kernel command line: console=ttyS0,115200n8 rw nbd.server=192.168.66.1 nbd.port=61977 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-15T20:19:02.976011", "lvl": "target", "msg": "[    0.000000] Unknown kernel command line parameters \\\"verbose earlyprintk ${extraargs} fstab=no\\\", will be passed to user space."}
- {"dt": "2024-08-15T20:19:02.978319", "lvl": "target", "msg": "[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.017766", "lvl": "target", "msg": "[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.018780", "lvl": "target", "msg": "[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 996912"}
- {"dt": "2024-08-15T20:19:03.019537", "lvl": "target", "msg": "[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off"}
- {"dt": "2024-08-15T20:19:03.020252", "lvl": "target", "msg": "[    0.000000] software IO TLB: area num 4."}
- {"dt": "2024-08-15T20:19:03.021070", "lvl": "target", "msg": "[    0.000000] software IO TLB: mapped [mem 0x0000000036d2a000-0x000000003ad2a000] (64MB)"}
- {"dt": "2024-08-15T20:19:03.022477", "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-15T20:19:03.060708", "lvl": "target", "msg": "[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1"}
- {"dt": "2024-08-15T20:19:03.061698", "lvl": "target", "msg": "[    0.000000] ftrace: allocating 49049 entries in 192 pages"}
- {"dt": "2024-08-15T20:19:03.062679", "lvl": "target", "msg": "[    0.000000] ftrace: allocated 192 pages with 2 groups"}
- {"dt": "2024-08-15T20:19:03.064756", "lvl": "target", "msg": "[    0.000000] trace event string verifier disabled"}
- {"dt": "2024-08-15T20:19:03.066001", "lvl": "target", "msg": "[    0.000000] rcu: Preemptible hierarchical RCU implementation."}
- {"dt": "2024-08-15T20:19:03.067226", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU event tracing is enabled."}
- {"dt": "2024-08-15T20:19:03.068037", "lvl": "target", "msg": "[    0.000000] rcu: \tRCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4."}
- {"dt": "2024-08-15T20:19:03.068799", "lvl": "target", "msg": "[    0.000000] \tTrampoline variant of Tasks RCU enabled."}
- {"dt": "2024-08-15T20:19:03.104537", "lvl": "target", "msg": "[    0.000000] \tRude variant of Tasks RCU enabled."}
- {"dt": "2024-08-15T20:19:03.107116", "lvl": "target", "msg": "[    0.000000] \tTracing variant of Tasks RCU enabled."}
- {"dt": "2024-08-15T20:19:03.109051", "lvl": "target", "msg": "[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies."}
- {"dt": "2024-08-15T20:19:03.110970", "lvl": "target", "msg": "[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4"}
- {"dt": "2024-08-15T20:19:03.112945", "lvl": "target", "msg": "[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0"}
- {"dt": "2024-08-15T20:19:03.113840", "lvl": "target", "msg": "[    0.000000] Root IRQ handler: gic_handle_irq"}
- {"dt": "2024-08-15T20:19:03.114709", "lvl": "target", "msg": "[    0.000000] GIC: Using split EOI/Deactivate mode"}
- {"dt": "2024-08-15T20:19:03.115735", "lvl": "target", "msg": "[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention."}
- {"dt": "2024-08-15T20:19:03.148728", "lvl": "target", "msg": "[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys)."}
- {"dt": "2024-08-15T20:19:03.150232", "lvl": "target", "msg": "[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns"}
- {"dt": "2024-08-15T20:19:03.152685", "lvl": "target", "msg": "[    0.000001] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns"}
- {"dt": "2024-08-15T20:19:03.153996", "lvl": "target", "msg": "[    0.000330] Console: colour dummy device 80x25"}
- {"dt": "2024-08-15T20:19:03.155055", "lvl": "target", "msg": "[    0.000381] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)"}
- {"dt": "2024-08-15T20:19:03.192232", "lvl": "target", "msg": "[    0.000399] pid_max: default: 32768 minimum: 301"}
- {"dt": "2024-08-15T20:19:03.193591", "lvl": "target", "msg": "[    0.000474] LSM: initializing lsm=capability,integrity"}
- {"dt": "2024-08-15T20:19:03.194594", "lvl": "target", "msg": "[    0.000677] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.197133", "lvl": "target", "msg": "[    0.000722] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.198170", "lvl": "target", "msg": "[    0.001618] cgroup: Disabling memory control group subsystem"}
- {"dt": "2024-08-15T20:19:03.199308", "lvl": "target", "msg": "[    0.003266] RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1."}
- {"dt": "2024-08-15T20:19:03.200537", "lvl": "target", "msg": "[    0.003394] RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1."}
- {"dt": "2024-08-15T20:19:03.236943", "lvl": "target", "msg": "[    0.003503] RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1."}
- {"dt": "2024-08-15T20:19:03.238355", "lvl": "target", "msg": "[    0.003775] rcu: Hierarchical SRCU implementation."}
- {"dt": "2024-08-15T20:19:03.239796", "lvl": "target", "msg": "[    0.003781] rcu: \tMax phase no-delay instances is 1000."}
- {"dt": "2024-08-15T20:19:03.240970", "lvl": "target", "msg": "[    0.005672] EFI services will not be available."}
- {"dt": "2024-08-15T20:19:03.242410", "lvl": "target", "msg": "[    0.006023] smp: Bringing up secondary CPUs ..."}
- {"dt": "2024-08-15T20:19:03.243069", "lvl": "target", "msg": "[    0.006675] Detected PIPT I-cache on CPU1"}
- {"dt": "2024-08-15T20:19:03.243589", "lvl": "target", "msg": "[    0.006796] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]"}
- {"dt": "2024-08-15T20:19:03.244225", "lvl": "target", "msg": "[    0.007514] Detected PIPT I-cache on CPU2"}
- {"dt": "2024-08-15T20:19:03.279486", "lvl": "target", "msg": "[    0.007604] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]"}
- {"dt": "2024-08-15T20:19:03.281157", "lvl": "target", "msg": "[    0.008350] Detected PIPT I-cache on CPU3"}
- {"dt": "2024-08-15T20:19:03.282559", "lvl": "target", "msg": "[    0.008442] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]"}
- {"dt": "2024-08-15T20:19:03.283929", "lvl": "target", "msg": "[    0.008543] smp: Brought up 1 node, 4 CPUs"}
- {"dt": "2024-08-15T20:19:03.285370", "lvl": "target", "msg": "[    0.008554] SMP: Total of 4 processors activated."}
- {"dt": "2024-08-15T20:19:03.286720", "lvl": "target", "msg": "[    0.008561] CPU features: detected: 32-bit EL0 Support"}
- {"dt": "2024-08-15T20:19:03.288076", "lvl": "target", "msg": "[    0.008566] CPU features: detected: 32-bit EL1 Support"}
- {"dt": "2024-08-15T20:19:03.288775", "lvl": "target", "msg": "[    0.008574] CPU features: detected: CRC32 instructions"}
- {"dt": "2024-08-15T20:19:03.289876", "lvl": "target", "msg": "[    0.008676] CPU: All CPU(s) started at EL2"}
- {"dt": "2024-08-15T20:19:03.323467", "lvl": "target", "msg": "[    0.008704] alternatives: applying system-wide alternatives"}
- {"dt": "2024-08-15T20:19:03.324745", "lvl": "target", "msg": "[    0.011000] devtmpfs: initialized"}
- {"dt": "2024-08-15T20:19:03.325810", "lvl": "target", "msg": "[    0.020621] Enabled cp15_barrier support"}
- {"dt": "2024-08-15T20:19:03.326716", "lvl": "target", "msg": "[    0.020646] Enabled setend support"}
- {"dt": "2024-08-15T20:19:03.328024", "lvl": "target", "msg": "[    0.020943] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns"}
- {"dt": "2024-08-15T20:19:03.329217", "lvl": "target", "msg": "[    0.020963] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.330266", "lvl": "target", "msg": "[    0.033166] pinctrl core: initialized pinctrl subsystem"}
- {"dt": "2024-08-15T20:19:03.332689", "lvl": "target", "msg": "[    0.033679] DMI not present or invalid."}
- {"dt": "2024-08-15T20:19:03.368029", "lvl": "target", "msg": "[    0.034416] NET: Registered PF_NETLINK/PF_ROUTE protocol family"}
- {"dt": "2024-08-15T20:19:03.369843", "lvl": "target", "msg": "[    0.036308] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations"}
- {"dt": "2024-08-15T20:19:03.371357", "lvl": "target", "msg": "[    0.036563] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations"}
- {"dt": "2024-08-15T20:19:03.373370", "lvl": "target", "msg": "[    0.036978] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations"}
- {"dt": "2024-08-15T20:19:03.375485", "lvl": "target", "msg": "[    0.037038] audit: initializing netlink subsys (disabled)"}
- {"dt": "2024-08-15T20:19:03.379104", "lvl": "target", "msg": "[    0.037219] audit: type=2000 audit(0.036:1): state=initialized audit_enabled=0 res=1"}
- {"dt": "2024-08-15T20:19:03.410796", "lvl": "target", "msg": "[    0.037731] thermal_sys: Registered thermal governor 'step_wise'"}
- {"dt": "2024-08-15T20:19:03.412126", "lvl": "target", "msg": "[    0.037783] cpuidle: using governor menu"}
- {"dt": "2024-08-15T20:19:03.413438", "lvl": "target", "msg": "[    0.038026] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers."}
- {"dt": "2024-08-15T20:19:03.414611", "lvl": "target", "msg": "[    0.038132] ASID allocator initialised with 65536 entries"}
- {"dt": "2024-08-15T20:19:03.415762", "lvl": "target", "msg": "[    0.039043] Serial: AMBA PL011 UART driver"}
- {"dt": "2024-08-15T20:19:03.416672", "lvl": "target", "msg": "[    0.045643] bcm2835-mbox fe00b880.mailbox: mailbox enabled"}
- {"dt": "2024-08-15T20:19:03.417257", "lvl": "target", "msg": "[    0.056157] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-01-22T17:23:15, variant start"}
- {"dt": "2024-08-15T20:19:03.455144", "lvl": "target", "msg": "[    0.060154] raspberrypi-firmware soc:firmware: Firmware hash is acb03c7d18aa08f25f6419d696d0cc39761d3e62"}
- {"dt": "2024-08-15T20:19:03.455983", "lvl": "target", "msg": "[    0.070120] Modules: 25504 pages in range for non-PLT usage"}
- {"dt": "2024-08-15T20:19:03.456692", "lvl": "target", "msg": "[    0.070131] Modules: 517024 pages in range for PLT usage"}
- {"dt": "2024-08-15T20:19:03.457334", "lvl": "target", "msg": "[    0.076898] bcm2835-dma fe007000.dma-controller: DMA legacy API manager, dmachans=0x1"}
- {"dt": "2024-08-15T20:19:03.457971", "lvl": "target", "msg": "[    0.078614] iommu: Default domain type: Translated"}
- {"dt": "2024-08-15T20:19:03.458599", "lvl": "target", "msg": "[    0.078622] iommu: DMA domain TLB invalidation policy: strict mode"}
- {"dt": "2024-08-15T20:19:03.459153", "lvl": "target", "msg": "[    0.079052] SCSI subsystem initialized"}
- {"dt": "2024-08-15T20:19:03.461083", "lvl": "target", "msg": "[    0.080264] usbcore: registered new interface driver usbfs"}
- {"dt": "2024-08-15T20:19:03.498757", "lvl": "target", "msg": "[    0.080304] usbcore: registered new interface driver hub"}
- {"dt": "2024-08-15T20:19:03.500078", "lvl": "target", "msg": "[    0.080349] usbcore: registered new device driver usb"}
- {"dt": "2024-08-15T20:19:03.501050", "lvl": "target", "msg": "[    0.080763] pps_core: LinuxPPS API ver. 1 registered"}
- {"dt": "2024-08-15T20:19:03.502073", "lvl": "target", "msg": "[    0.080770] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>"}
- {"dt": "2024-08-15T20:19:03.503069", "lvl": "target", "msg": "[    0.080787] PTP clock support registered"}
- {"dt": "2024-08-15T20:19:03.503998", "lvl": "target", "msg": "[    0.081035] Advanced Linux Sound Architecture Driver Initialized."}
- {"dt": "2024-08-15T20:19:03.504927", "lvl": "target", "msg": "[    0.081934] vgaarb: loaded"}
- {"dt": "2024-08-15T20:19:03.507334", "lvl": "target", "msg": "[    0.082378] clocksource: Switched to clocksource arch_sys_counter"}
- {"dt": "2024-08-15T20:19:03.543355", "lvl": "target", "msg": "[    1.102850] VFS: Disk quotas dquot_6.6.0"}
- {"dt": "2024-08-15T20:19:03.544469", "lvl": "target", "msg": "[    1.102903] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"}
- {"dt": "2024-08-15T20:19:03.545142", "lvl": "target", "msg": "[    1.103012] FS-Cache: Loaded"}
- {"dt": "2024-08-15T20:19:03.545968", "lvl": "target", "msg": "[    1.103228] CacheFiles: Loaded"}
- {"dt": "2024-08-15T20:19:03.546749", "lvl": "target", "msg": "[    1.111693] NET: Registered PF_INET protocol family"}
- {"dt": "2024-08-15T20:19:03.547388", "lvl": "target", "msg": "[    1.112105] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.548049", "lvl": "target", "msg": "[    1.116840] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.586135", "lvl": "target", "msg": "[    1.116891] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.587565", "lvl": "target", "msg": "[    1.116911] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.588052", "lvl": "target", "msg": "[    1.117097] TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.588770", "lvl": "target", "msg": "[    1.118191] TCP: Hash tables configured (established 32768 bind 32768)"}
- {"dt": "2024-08-15T20:19:03.589933", "lvl": "target", "msg": "[    1.118586] MPTCP token hash table entries: 4096 (order: 4, 98304 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.591086", "lvl": "target", "msg": "[    1.118780] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.630258", "lvl": "target", "msg": "[    1.118832] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)"}
- {"dt": "2024-08-15T20:19:03.631551", "lvl": "target", "msg": "[    1.119079] NET: Registered PF_UNIX/PF_LOCAL protocol family"}
- {"dt": "2024-08-15T20:19:03.632546", "lvl": "target", "msg": "[    1.119712] RPC: Registered named UNIX socket transport module."}
- {"dt": "2024-08-15T20:19:03.633574", "lvl": "target", "msg": "[    1.119722] RPC: Registered udp transport module."}
- {"dt": "2024-08-15T20:19:03.634817", "lvl": "target", "msg": "[    1.119728] RPC: Registered tcp transport module."}
- {"dt": "2024-08-15T20:19:03.636027", "lvl": "target", "msg": "[    1.119733] RPC: Registered tcp-with-tls transport module."}
- {"dt": "2024-08-15T20:19:03.637106", "lvl": "target", "msg": "[    1.119738] RPC: Registered tcp NFSv4.1 backchannel transport module."}
- {"dt": "2024-08-15T20:19:03.638131", "lvl": "target", "msg": "[    1.119755] PCI: CLS 0 bytes, default 64"}
- {"dt": "2024-08-15T20:19:03.673364", "lvl": "target", "msg": "[    1.120326] Trying to unpack rootfs image as initramfs..."}
- {"dt": "2024-08-15T20:19:03.674025", "lvl": "target", "msg": "[    1.120680] rootfs image is not initramfs (no cpio magic); looks like an initrd"}
- {"dt": "2024-08-15T20:19:03.674593", "lvl": "target", "msg": "[    1.122682] kvm [1]: IPA Size Limit: 44 bits"}
- {"dt": "2024-08-15T20:19:03.675165", "lvl": "target", "msg": "[    1.124127] kvm [1]: vgic interrupt IRQ9"}
- {"dt": "2024-08-15T20:19:03.677962", "lvl": "target", "msg": "[    1.124189] kvm [1]: Hyp mode initialized successfully"}
- {"dt": "2024-08-15T20:19:03.679071", "lvl": "target", "msg": "[    1.126046] Freeing initrd memory: 2100K"}
- {"dt": "2024-08-15T20:19:03.680055", "lvl": "target", "msg": "[    1.126460] Initialise system trusted keyrings"}
- {"dt": "2024-08-15T20:19:03.681068", "lvl": "target", "msg": "[    1.126763] workingset: timestamp_bits=46 max_order=20 bucket_order=0"}
- {"dt": "2024-08-15T20:19:03.681913", "lvl": "target", "msg": "[    1.126821] zbud: loaded"}
- {"dt": "2024-08-15T20:19:03.717795", "lvl": "target", "msg": "[    1.127508] NFS: Registering the id_resolver key type"}
- {"dt": "2024-08-15T20:19:03.719034", "lvl": "target", "msg": "[    1.127555] Key type id_resolver registered"}
- {"dt": "2024-08-15T20:19:03.720002", "lvl": "target", "msg": "[    1.127561] Key type id_legacy registered"}
- {"dt": "2024-08-15T20:19:03.721006", "lvl": "target", "msg": "[    1.127584] nfs4filelayout_init: NFSv4 File Layout Driver Registering..."}
- {"dt": "2024-08-15T20:19:03.721841", "lvl": "target", "msg": "[    1.127592] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering..."}
- {"dt": "2024-08-15T20:19:03.722525", "lvl": "target", "msg": "[    1.128321] NET: Registered PF_ALG protocol family"}
- {"dt": "2024-08-15T20:19:03.723143", "lvl": "target", "msg": "[    1.128334] Key type asymmetric registered"}
- {"dt": "2024-08-15T20:19:03.723742", "lvl": "target", "msg": "[    1.128340] Asymmetric key parser 'x509' registered"}
- {"dt": "2024-08-15T20:19:03.761231", "lvl": "target", "msg": "[    1.128392] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)"}
- {"dt": "2024-08-15T20:19:03.762539", "lvl": "target", "msg": "[    1.128555] io scheduler mq-deadline registered"}
- {"dt": "2024-08-15T20:19:03.763643", "lvl": "target", "msg": "[    1.128563] io scheduler kyber registered"}
- {"dt": "2024-08-15T20:19:03.764939", "lvl": "target", "msg": "[    1.128601] io scheduler bfq registered"}
- {"dt": "2024-08-15T20:19:03.767983", "lvl": "target", "msg": "[    1.129386] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 23)"}
- {"dt": "2024-08-15T20:19:03.769314", "lvl": "target", "msg": "[    1.134111] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:"}
- {"dt": "2024-08-15T20:19:03.770342", "lvl": "target", "msg": "[    1.134138] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]"}
- {"dt": "2024-08-15T20:19:03.805121", "lvl": "target", "msg": "[    1.134177] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000"}
- {"dt": "2024-08-15T20:19:03.806421", "lvl": "target", "msg": "[    1.134213] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000"}
- {"dt": "2024-08-15T20:19:03.807713", "lvl": "target", "msg": "[    1.135218] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00"}
- {"dt": "2024-08-15T20:19:03.808980", "lvl": "target", "msg": "[    1.135233] pci_bus 0000:00: root bus resource [bus 00-ff]"}
- {"dt": "2024-08-15T20:19:03.809636", "lvl": "target", "msg": "[    1.135247] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])"}
- {"dt": "2024-08-15T20:19:03.811606", "lvl": "target", "msg": "[    1.135290] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400"}
- {"dt": "2024-08-15T20:19:03.848776", "lvl": "target", "msg": "[    1.135376] pci 0000:00:00.0: PME# supported from D0 D3hot"}
- {"dt": "2024-08-15T20:19:03.849477", "lvl": "target", "msg": "[    1.138800] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring"}
- {"dt": "2024-08-15T20:19:03.850080", "lvl": "target", "msg": "[    1.138940] pci_bus 0000:01: supply vpcie3v3 not found, using dummy regulator"}
- {"dt": "2024-08-15T20:19:03.850654", "lvl": "target", "msg": "[    1.139066] pci_bus 0000:01: supply vpcie3v3aux not found, using dummy regulator"}
- {"dt": "2024-08-15T20:19:03.851223", "lvl": "target", "msg": "[    1.139122] pci_bus 0000:01: supply vpcie12v not found, using dummy regulator"}
- {"dt": "2024-08-15T20:19:03.851802", "lvl": "target", "msg": "[    1.248464] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)"}
- {"dt": "2024-08-15T20:19:03.892240", "lvl": "target", "msg": "[    1.248519] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330"}
- {"dt": "2024-08-15T20:19:03.894891", "lvl": "target", "msg": "[    1.248555] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]"}
- {"dt": "2024-08-15T20:19:03.895896", "lvl": "target", "msg": "[    1.248684] pci 0000:01:00.0: PME# supported from D0 D3cold"}
- {"dt": "2024-08-15T20:19:03.897011", "lvl": "target", "msg": "[    1.249045] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01"}
- {"dt": "2024-08-15T20:19:03.897975", "lvl": "target", "msg": "[    1.249079] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]"}
- {"dt": "2024-08-15T20:19:03.898883", "lvl": "target", "msg": "[    1.249095] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]"}
- {"dt": "2024-08-15T20:19:03.899777", "lvl": "target", "msg": "[    1.249118] pci 0000:00:00.0: PCI bridge to [bus 01]"}
- {"dt": "2024-08-15T20:19:03.935892", "lvl": "target", "msg": "[    1.249129] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]"}
- {"dt": "2024-08-15T20:19:03.937533", "lvl": "target", "msg": "[    1.249354] pcieport 0000:00:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2024-08-15T20:19:03.938635", "lvl": "target", "msg": "[    1.249491] pcieport 0000:00:00.0: PME: Signaling with IRQ 27"}
- {"dt": "2024-08-15T20:19:03.939546", "lvl": "target", "msg": "[    1.249825] pcieport 0000:00:00.0: AER: enabled with IRQ 27"}
- {"dt": "2024-08-15T20:19:03.940050", "lvl": "target", "msg": "[    1.253841] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled"}
- {"dt": "2024-08-15T20:19:03.940587", "lvl": "target", "msg": "[    1.255800] iproc-rng200 fe104000.rng: hwrng registered"}
- {"dt": "2024-08-15T20:19:03.941208", "lvl": "target", "msg": "[    1.256042] vc-mem: phys_addr:0x00000000 mem_base=0x00000000 mem_size:0x00000000(0 MiB)"}
- {"dt": "2024-08-15T20:19:03.941737", "lvl": "target", "msg": "[    1.256222] random: crng init done"}
- {"dt": "2024-08-15T20:19:03.980264", "lvl": "target", "msg": "[    1.260876] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:03.981319", "lvl": "target", "msg": "[    1.260897] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:03.985347", "lvl": "target", "msg": "[    1.261236] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:03.986737", "lvl": "target", "msg": "[    1.271281] brd: module loaded"}
- {"dt": "2024-08-15T20:19:03.987984", "lvl": "target", "msg": "[    1.277263] loop: module loaded"}
- {"dt": "2024-08-15T20:19:03.989209", "lvl": "target", "msg": "[    1.297690] Loading iSCSI transport class v2.0-870."}
- {"dt": "2024-08-15T20:19:03.990316", "lvl": "target", "msg": "[    1.301503] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000"}
- {"dt": "2024-08-15T20:19:04.023214", "lvl": "target", "msg": "[    1.494451] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus"}
- {"dt": "2024-08-15T20:19:04.024178", "lvl": "target", "msg": "[    1.495424] usbcore: registered new device driver r8152-cfgselector"}
- {"dt": "2024-08-15T20:19:04.024983", "lvl": "target", "msg": "[    1.495461] usbcore: registered new interface driver r8152"}
- {"dt": "2024-08-15T20:19:04.025662", "lvl": "target", "msg": "[    1.495501] usbcore: registered new interface driver lan78xx"}
- {"dt": "2024-08-15T20:19:04.027943", "lvl": "target", "msg": "[    1.496808] xhci_hcd 0000:01:00.0: enabling device (0000 -> 0002)"}
- {"dt": "2024-08-15T20:19:04.029040", "lvl": "target", "msg": "[    1.496866] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2024-08-15T20:19:04.030309", "lvl": "target", "msg": "[    1.496891] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1"}
- {"dt": "2024-08-15T20:19:04.067243", "lvl": "target", "msg": "[    1.498530] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0700240000000890"}
- {"dt": "2024-08-15T20:19:04.068182", "lvl": "target", "msg": "[    1.499032] xhci_hcd 0000:01:00.0: xHCI Host Controller"}
- {"dt": "2024-08-15T20:19:04.068808", "lvl": "target", "msg": "[    1.499049] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2"}
- {"dt": "2024-08-15T20:19:04.069292", "lvl": "target", "msg": "[    1.499066] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed"}
- {"dt": "2024-08-15T20:19:04.069721", "lvl": "target", "msg": "[    1.499240] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06"}
- {"dt": "2024-08-15T20:19:04.070499", "lvl": "target", "msg": "[    1.499255] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2024-08-15T20:19:04.071957", "lvl": "target", "msg": "[    1.499265] usb usb1: Product: xHCI Host Controller"}
- {"dt": "2024-08-15T20:19:04.110494", "lvl": "target", "msg": "[    1.499274] usb usb1: Manufacturer: Linux 6.6.22-v8 xhci-hcd"}
- {"dt": "2024-08-15T20:19:04.111933", "lvl": "target", "msg": "[    1.499282] usb usb1: SerialNumber: 0000:01:00.0"}
- {"dt": "2024-08-15T20:19:04.112518", "lvl": "target", "msg": "[    1.499833] hub 1-0:1.0: USB hub found"}
- {"dt": "2024-08-15T20:19:04.112976", "lvl": "target", "msg": "[    1.499872] hub 1-0:1.0: 1 port detected"}
- {"dt": "2024-08-15T20:19:04.113412", "lvl": "target", "msg": "[    1.500442] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.06"}
- {"dt": "2024-08-15T20:19:04.113852", "lvl": "target", "msg": "[    1.500457] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1"}
- {"dt": "2024-08-15T20:19:04.114308", "lvl": "target", "msg": "[    1.500467] usb usb2: Product: xHCI Host Controller"}
- {"dt": "2024-08-15T20:19:04.114869", "lvl": "target", "msg": "[    1.500475] usb usb2: Manufacturer: Linux 6.6.22-v8 xhci-hcd"}
- {"dt": "2024-08-15T20:19:04.154269", "lvl": "target", "msg": "[    1.500483] usb usb2: SerialNumber: 0000:01:00.0"}
- {"dt": "2024-08-15T20:19:04.159297", "lvl": "target", "msg": "[    1.500953] hub 2-0:1.0: USB hub found"}
- {"dt": "2024-08-15T20:19:04.160118", "lvl": "target", "msg": "[    1.500990] hub 2-0:1.0: 4 ports detected"}
- {"dt": "2024-08-15T20:19:04.160939", "lvl": "target", "msg": "[    1.501834] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)"}
- {"dt": "2024-08-15T20:19:04.161684", "lvl": "target", "msg": "[    1.502628] usbcore: registered new interface driver uas"}
- {"dt": "2024-08-15T20:19:04.162409", "lvl": "target", "msg": "[    1.502682] usbcore: registered new interface driver usb-storage"}
- {"dt": "2024-08-15T20:19:04.163115", "lvl": "target", "msg": "[    1.502773] usbcore: registered new interface driver usbserial_generic"}
- {"dt": "2024-08-15T20:19:04.163818", "lvl": "target", "msg": "[    1.502800] usbserial: USB Serial support registered for generic"}
- {"dt": "2024-08-15T20:19:04.197925", "lvl": "target", "msg": "[    1.502835] usbcore: registered new interface driver cp210x"}
- {"dt": "2024-08-15T20:19:04.198521", "lvl": "target", "msg": "[    1.502860] usbserial: USB Serial support registered for cp210x"}
- {"dt": "2024-08-15T20:19:04.199950", "lvl": "target", "msg": "[    1.503292] mousedev: PS/2 mouse device common for all mice"}
- {"dt": "2024-08-15T20:19:04.200598", "lvl": "target", "msg": "[    1.503778] usbcore: registered new interface driver i2c-tiny-usb"}
- {"dt": "2024-08-15T20:19:04.201053", "lvl": "target", "msg": "[    1.506903] sdhci: Secure Digital Host Controller Interface driver"}
- {"dt": "2024-08-15T20:19:04.201603", "lvl": "target", "msg": "[    1.506914] sdhci: Copyright(c) Pierre Ossman"}
- {"dt": "2024-08-15T20:19:04.202049", "lvl": "target", "msg": "[    1.507133] sdhci-pltfm: SDHCI platform and OF driver helper"}
- {"dt": "2024-08-15T20:19:04.241913", "lvl": "target", "msg": "[    1.510329] ledtrig-cpu: registered to indicate activity on CPUs"}
- {"dt": "2024-08-15T20:19:04.242877", "lvl": "target", "msg": "[    1.510517] hid: raw HID events driver (C) Jiri Kosina"}
- {"dt": "2024-08-15T20:19:04.247429", "lvl": "target", "msg": "[    1.510650] usbcore: registered new interface driver usbhid"}
- {"dt": "2024-08-15T20:19:04.248527", "lvl": "target", "msg": "[    1.510655] usbhid: USB HID core driver"}
- {"dt": "2024-08-15T20:19:04.249210", "lvl": "target", "msg": "[    1.514041] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available"}
- {"dt": "2024-08-15T20:19:04.249858", "lvl": "target", "msg": "[    1.514525] usbcore: registered new interface driver snd-usb-audio"}
- {"dt": "2024-08-15T20:19:04.250497", "lvl": "target", "msg": "[    1.514936] NET: Registered PF_PACKET protocol family"}
- {"dt": "2024-08-15T20:19:04.251129", "lvl": "target", "msg": "[    1.514990] Key type dns_resolver registered"}
- {"dt": "2024-08-15T20:19:04.251775", "lvl": "target", "msg": "[    1.526865] registered taskstats version 1"}
- {"dt": "2024-08-15T20:19:04.285584", "lvl": "target", "msg": "[    1.526984] Loading compiled-in X.509 certificates"}
- {"dt": "2024-08-15T20:19:04.286483", "lvl": "target", "msg": "[    1.530696] Key type .fscrypt registered"}
- {"dt": "2024-08-15T20:19:04.288563", "lvl": "target", "msg": "[    1.530703] Key type fscrypt-provisioning registered"}
- {"dt": "2024-08-15T20:19:04.290171", "lvl": "target", "msg": "[    1.534244] uart-pl011 fe201000.serial: there is not valid maps for state default"}
- {"dt": "2024-08-15T20:19:04.291825", "lvl": "target", "msg": "[    1.534515] uart-pl011 fe201000.serial: cts_event_workaround enabled"}
- {"dt": "2024-08-15T20:19:04.293605", "lvl": "target", "msg": "[    1.534714] fe201000.serial: ttyAMA1 at MMIO 0xfe201000 (irq = 37, base_baud = 0) is a PL011 rev2"}
- {"dt": "2024-08-15T20:19:04.294528", "lvl": "target", "msg": "[    1.534828] serial serial0: tty port ttyAMA1 registered"}
- {"dt": "2024-08-15T20:19:04.331218", "lvl": "target", "msg": "[    1.535601] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default"}
- {"dt": "2024-08-15T20:19:04.331781", "lvl": "target", "msg": "[    1.535943] printk: console [ttyS0] disabled"}
- {"dt": "2024-08-15T20:19:04.332342", "lvl": "target", "msg": "[    1.536237] fe215040.serial: ttyS0 at MMIO 0xfe215040 (irq = 38, base_baud = 62500000) is a 16550"}
- {"dt": "2024-08-15T20:19:04.332880", "lvl": "target", "msg": "[    1.536265] printk: console [ttyS0] enabled"}
- {"dt": "2024-08-15T20:19:04.333352", "lvl": "target", "msg": "[    3.092907] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:04.333851", "lvl": "target", "msg": "[    3.101488] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:04.370885", "lvl": "target", "msg": "[    3.108513] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:04.372288", "lvl": "target", "msg": "[    3.114944] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer"}
- {"dt": "2024-08-15T20:19:04.372886", "lvl": "target", "msg": "[    3.121520] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver"}
- {"dt": "2024-08-15T20:19:04.373346", "lvl": "target", "msg": "[    3.129254] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0"}
- {"dt": "2024-08-15T20:19:04.373891", "lvl": "target", "msg": "[    3.135358] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated"}
- {"dt": "2024-08-15T20:19:04.432993", "lvl": "target", "msg": "[    3.167837] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:04.433602", "lvl": "target", "msg": "[    3.176502] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:04.434088", "lvl": "target", "msg": "[    3.183593] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:04.434515", "lvl": "target", "msg": "[    3.190638] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:04.434896", "lvl": "target", "msg": "[    3.199217] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:04.437370", "lvl": "target", "msg": "[    3.206223] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:04.477253", "lvl": "target", "msg": "[    3.212893] of_cfs_init"}
- {"dt": "2024-08-15T20:19:04.478147", "lvl": "target", "msg": "[    3.215437] of_cfs_init: OK"}
- {"dt": "2024-08-15T20:19:04.480178", "lvl": "target", "msg": "[    3.218395] usb 1-1: new high-speed USB device number 2 using xhci_hcd"}
- {"dt": "2024-08-15T20:19:04.480868", "lvl": "target", "msg": "[    3.222943] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA"}
- {"dt": "2024-08-15T20:19:04.481257", "lvl": "target", "msg": "[    3.233532] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:04.481632", "lvl": "target", "msg": "[    3.234180] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)"}
- {"dt": "2024-08-15T20:19:04.482091", "lvl": "target", "msg": "[    3.242180] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:04.499768", "lvl": "target", "msg": "[    3.251180] bcmgenet fd580000.ethernet eth0: Link is Down"}
- {"dt": "2024-08-15T20:19:04.502581", "lvl": "target", "msg": "[    3.257568] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:04.532435", "lvl": "target", "msg": "[    3.295703] mmc1: new high speed SDIO card at address 0001"}
- {"dt": "2024-08-15T20:19:04.624694", "lvl": "target", "msg": "[    3.355315] mmc0: new ultra high speed DDR50 SDHC card at address 59b4"}
- {"dt": "2024-08-15T20:19:04.626173", "lvl": "target", "msg": "[    3.362392] mmcblk0: mmc0:59b4 USDU1 7.51 GiB"}
- {"dt": "2024-08-15T20:19:04.627648", "lvl": "target", "msg": "[    3.368364]  mmcblk0: p1 p2"}
- {"dt": "2024-08-15T20:19:04.628677", "lvl": "target", "msg": "[    3.371448] mmcblk0: mmc0:59b4 USDU1 7.51 GiB"}
- {"dt": "2024-08-15T20:19:04.629436", "lvl": "target", "msg": "[    3.371575] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.20"}
- {"dt": "2024-08-15T20:19:04.629919", "lvl": "target", "msg": "[    3.376884] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:04.631168", "lvl": "target", "msg": "[    3.384165] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0"}
- {"dt": "2024-08-15T20:19:04.678665", "lvl": "target", "msg": "[    3.392726] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:04.679935", "lvl": "target", "msg": "[    3.399958] usb 1-1: Product: USB2.0 Hub"}
- {"dt": "2024-08-15T20:19:04.681178", "lvl": "target", "msg": "[    3.406984] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:04.682348", "lvl": "target", "msg": "[    3.417473] hub 1-1:1.0: USB hub found"}
- {"dt": "2024-08-15T20:19:04.683354", "lvl": "target", "msg": "[    3.421429] hub 1-1:1.0: 4 ports detected"}
- {"dt": "2024-08-15T20:19:04.685720", "lvl": "target", "msg": "[    3.433429] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:04.686785", "lvl": "target", "msg": "[    3.442010] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:04.687643", "lvl": "target", "msg": "[    3.449023] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:04.710101", "lvl": "target", "msg": "[    3.455914] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:04.711030", "lvl": "target", "msg": "[    3.464497] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:04.713274", "lvl": "target", "msg": "[    3.471488] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:04.960255", "lvl": "target", "msg": "[    3.718402] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd"}
- {"dt": "2024-08-15T20:19:05.092378", "lvl": "target", "msg": "[    3.823943] usb 1-1.3: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2024-08-15T20:19:05.093020", "lvl": "target", "msg": "[    3.832446] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2024-08-15T20:19:05.093511", "lvl": "target", "msg": "[    3.839879] usb 1-1.3: Product: USB2.0 Hub             "}
- {"dt": "2024-08-15T20:19:05.093974", "lvl": "target", "msg": "[    3.845190] usb 1-1.3: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2024-08-15T20:19:05.094510", "lvl": "target", "msg": "[    3.852463] hub 1-1.3:1.0: USB hub found"}
- {"dt": "2024-08-15T20:19:05.095989", "lvl": "target", "msg": "[    3.856668] hub 1-1.3:1.0: 4 ports detected"}
- {"dt": "2024-08-15T20:19:05.124458", "lvl": "target", "msg": "[    3.871787] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:05.126225", "lvl": "target", "msg": "[    3.880358] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:05.126901", "lvl": "target", "msg": "[    3.888701] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:05.408618", "lvl": "target", "msg": "[    4.166401] usb 1-1.3.1: new high-speed USB device number 4 using xhci_hcd"}
- {"dt": "2024-08-15T20:19:05.561345", "lvl": "target", "msg": "[    4.287865] usb 1-1.3.1: New USB device found, idVendor=2109, idProduct=2812, bcdDevice= b.e0"}
- {"dt": "2024-08-15T20:19:05.561973", "lvl": "target", "msg": "[    4.296546] usb 1-1.3.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0"}
- {"dt": "2024-08-15T20:19:05.562489", "lvl": "target", "msg": "[    4.304150] usb 1-1.3.1: Product: USB2.0 Hub             "}
- {"dt": "2024-08-15T20:19:05.562959", "lvl": "target", "msg": "[    4.309640] usb 1-1.3.1: Manufacturer: VIA Labs, Inc.         "}
- {"dt": "2024-08-15T20:19:05.563382", "lvl": "target", "msg": "[    4.316994] hub 1-1.3.1:1.0: USB hub found"}
- {"dt": "2024-08-15T20:19:05.563914", "lvl": "target", "msg": "[    4.321356] hub 1-1.3.1:1.0: 4 ports detected"}
- {"dt": "2024-08-15T20:19:05.588213", "lvl": "target", "msg": "[    4.335260] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:05.589143", "lvl": "target", "msg": "[    4.343858] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:05.591530", "lvl": "target", "msg": "[    4.351025] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:05.872923", "lvl": "target", "msg": "[    4.630402] usb 1-1.3.1.1: new high-speed USB device number 5 using xhci_hcd"}
- {"dt": "2024-08-15T20:19:06.024625", "lvl": "target", "msg": "[    4.761955] usb 1-1.3.1.1: New USB device found, idVendor=0bda, idProduct=2838, bcdDevice= 1.00"}
- {"dt": "2024-08-15T20:19:06.028668", "lvl": "target", "msg": "[    4.770808] usb 1-1.3.1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3"}
- {"dt": "2024-08-15T20:19:06.030207", "lvl": "target", "msg": "[    4.778598] usb 1-1.3.1.1: Product: RTL2838UHIDIR"}
- {"dt": "2024-08-15T20:19:06.031594", "lvl": "target", "msg": "[    4.783381] usb 1-1.3.1.1: Manufacturer: Realtek"}
- {"dt": "2024-08-15T20:19:06.033282", "lvl": "target", "msg": "[    4.788076] usb 1-1.3.1.1: SerialNumber: 00000001"}
- {"dt": "2024-08-15T20:19:06.057338", "lvl": "target", "msg": "[    4.804028] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:06.058157", "lvl": "target", "msg": "[    4.812613] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:06.060088", "lvl": "target", "msg": "[    4.819832] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:08.603614", "lvl": "target", "msg": "[    7.358818] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx"}
- {"dt": "2024-08-15T20:19:08.661415", "lvl": "target", "msg": "[    7.382394] Sending DHCP requests ., OK"}
- {"dt": "2024-08-15T20:19:08.666153", "lvl": "target", "msg": "[    7.402323] IP-Config: Got DHCP answer from 192.168.66.1, my address is 192.168.66.241"}
- {"dt": "2024-08-15T20:19:08.667884", "lvl": "target", "msg": "[    7.410397] IP-Config: Complete:"}
- {"dt": "2024-08-15T20:19:08.669102", "lvl": "target", "msg": "[    7.413669]      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-15T20:19:08.670216", "lvl": "target", "msg": "[    7.424194]      host=192.168.66.241, domain=, nis-domain=(none)"}
- {"dt": "2024-08-15T20:19:08.671349", "lvl": "target", "msg": "[    7.430301]      bootserver=0.0.0.0, rootserver=0.0.0.0, rootpath="}
- {"dt": "2024-08-15T20:19:08.672703", "lvl": "target", "msg": "[    7.430310]      nameserver0=10.1.1.1"}
- {"dt": "2024-08-15T20:19:08.688296", "lvl": "target", "msg": "[    7.441470] clk: Disabling unused clocks"}
- {"dt": "2024-08-15T20:19:08.689235", "lvl": "target", "msg": "[    7.445704] ALSA device list:"}
- {"dt": "2024-08-15T20:19:08.689981", "lvl": "target", "msg": "[    7.448747]   No soundcards found."}
- {"dt": "2024-08-15T20:19:08.692237", "lvl": "target", "msg": "[    7.452382] Waiting 7 sec before mounting root device..."}
- {"dt": "2024-08-15T20:19:15.784942", "lvl": "target", "msg": "[   14.558512] RAMDISK: gzip image found at block 0"}
- {"dt": "2024-08-15T20:19:15.991441", "lvl": "target", "msg": "[   14.711510] EXT4-fs (ram0): mounted filesystem 84ccdbe1-a143-4fb0-956a-39466191e825 r/w with ordered data mode. Quota mode: none."}
- {"dt": "2024-08-15T20:19:15.994315", "lvl": "target", "msg": "[   14.723421] VFS: Mounted root (ext4 filesystem) on device 1:0."}
- {"dt": "2024-08-15T20:19:15.995702", "lvl": "target", "msg": "[   14.729458] devtmpfs: mounted"}
- {"dt": "2024-08-15T20:19:15.996910", "lvl": "target", "msg": "[   14.737565] Freeing unused kernel memory: 5376K"}
- {"dt": "2024-08-15T20:19:15.998238", "lvl": "target", "msg": "[   14.746450] Run /sbin/init as init process"}
- {"dt": "2024-08-15T20:19:15.999546", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2024-08-15T20:19:16.000208", "lvl": "target", "msg": "         ___   ________                _   __     __  __                __"}
- {"dt": "2024-08-15T20:19:16.036609", "lvl": "target", "msg": "        /   | / ____/ /               / | / /__  / /_/ /_  ____  ____  / /_"}
- {"dt": "2024-08-15T20:19:16.037756", "lvl": "target", "msg": "       / /| |/ / __/ /      ______   /  |/ / _ \\/ __/ __ \\/ __ \\/ __ \\/ __/"}
- {"dt": "2024-08-15T20:19:16.038691", "lvl": "target", "msg": "      / ___ / /_/ / /___   /_____/  / /|  /  __/ /_/ /_/ / /_/ / /_/ / /_"}
- {"dt": "2024-08-15T20:19:16.039315", "lvl": "target", "msg": "     /_/  |_\\____/_____/           /_/ |_/\\___/\\__/_.___/\\____/\\____/\\__/"}
- {"dt": "2024-08-15T20:19:16.039846", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2024-08-15T20:19:16.041955", "lvl": "target", "msg": "/sbin/init[1]: starting initrd script"}
- {"dt": "2024-08-15T20:19:16.042657", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: proc /proc"}
- {"dt": "2024-08-15T20:19:16.083562", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: sysfs /sys"}
- {"dt": "2024-08-15T20:19:16.084591", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devtmpfs /dev"}
- {"dt": "2024-08-15T20:19:16.086267", "lvl": "target", "msg": "/sbin/init[1]: /dev (devtmpfs) already mounted"}
- {"dt": "2024-08-15T20:19:16.086913", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: devpts /dev/pts"}
- {"dt": "2024-08-15T20:19:16.087494", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /dev/shm"}
- {"dt": "2024-08-15T20:19:16.088086", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /tmp"}
- {"dt": "2024-08-15T20:19:16.088720", "lvl": "target", "msg": "/sbin/init[1]: mounting FS: tmpfs /run"}
- {"dt": "2024-08-15T20:19:16.089407", "lvl": "target", "msg": "/sbin/init[1]: NBD parameters: device /dev/nbd0, server 192.168.66.1:61977"}
- {"dt": "2024-08-15T20:19:16.090009", "lvl": "target", "msg": "/sbin/init[1]: Starting NBD client"}
- {"dt": "2024-08-15T20:19:16.124560", "lvl": "target", "msg": "[   14.883399] nbd0: detected capacity change from 0 to 8938544"}
- {"dt": "2024-08-15T20:19:16.125346", "lvl": "target", "msg": "/sbin/init[1]: NBD client successfully started"}
- {"dt": "2024-08-15T20:19:17.153252", "lvl": "target", "msg": "[   15.896155] EXT4-fs (nbd0): recovery complete"}
- {"dt": "2024-08-15T20:19:17.155237", "lvl": "target", "msg": "[   15.901683] EXT4-fs (nbd0): mounted filesystem 3d0730e2-0bd6-4199-97a1-50233b1ad7e3 r/w with ordered data mode. Quota mode: none."}
- {"dt": "2024-08-15T20:19:17.156008", "lvl": "target", "msg": "/sbin/init[1]: Moving /dev to new rootfs"}
- {"dt": "2024-08-15T20:19:17.156886", "lvl": "target", "msg": "/sbin/init[1]: Moving /proc to new rootfs"}
- {"dt": "2024-08-15T20:19:17.185974", "lvl": "target", "msg": "/sbin/init[1]: Moving /sys to new rootfs"}
- {"dt": "2024-08-15T20:19:17.187518", "lvl": "target", "msg": "/sbin/init[1]: Moving /tmp to new rootfs"}
- {"dt": "2024-08-15T20:19:17.188133", "lvl": "target", "msg": "/sbin/init[1]: Moving /run to new rootfs"}
- {"dt": "2024-08-15T20:19:17.189680", "lvl": "target", "msg": "/sbin/init[1]: Switching to new rootfs"}
- {"dt": "2024-08-15T20:19:17.827987", "lvl": "target", "msg": "/sbin/init[1]: find_active_interface: first active interface is eth0"}
- {"dt": "2024-08-15T20:19:17.831136", "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-15T20:19:17.954236", "lvl": "target", "msg": "mkdir: cannot create directory '/etc/systemd/system/systemd-network-generator.service.d/': File exists"}
- {"dt": "2024-08-15T20:19:18.002106", "lvl": "target", "msg": "/sbin/init[1]: Unmounting /tmp and /run"}
- {"dt": "2024-08-15T20:19:18.138749", "lvl": "target", "msg": "/sbin/init[1]: Exec'ing systemd"}
- {"dt": "2024-08-15T20:19:18.139900", "lvl": "target", "msg": "________________________________________________________________________________"}
- {"dt": "2024-08-15T20:19:18.143311", "lvl": "target", "msg": "      ___   ________       ____              __  _"}
- {"dt": "2024-08-15T20:19:18.144647", "lvl": "target", "msg": "     /   | / ____/ /      / __ )____  ____  / /_(_)___  ____ _"}
- {"dt": "2024-08-15T20:19:18.146060", "lvl": "target", "msg": "    / /| |/ / __/ /      / __  / __ \\/ __ \\/ __/ / __ \\/ __ `/"}
- {"dt": "2024-08-15T20:19:18.147294", "lvl": "target", "msg": "   / ___ / /_/ / /___   / /_/ / /_/ / /_/ / /_/ / / / / /_/ /   _     _     _"}
- {"dt": "2024-08-15T20:19:18.148602", "lvl": "target", "msg": "  /_/  |_\\____/_____/  /_____/\\____/\\____/\\__/_/_/ /_/\\__, /   (_)   (_)   (_)"}
- {"dt": "2024-08-15T20:19:18.155937", "lvl": "target", "msg": "_____________________________________________________/____/_____________________"}
- {"dt": "2024-08-15T20:19:18.890915", "lvl": "target", "msg": "[   17.632574] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:18.892179", "lvl": "target", "msg": "[   17.641399] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:18.896083", "lvl": "target", "msg": "[   17.648886] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:18.898043", "lvl": "target", "msg": "[   17.656678] platform gpu: deferred probe pending"}
- {"dt": "2024-08-15T20:19:19.268641", "lvl": "target", "msg": "[   18.026869] systemd[1]: System time before build time, advancing clock."}
- {"dt": "2024-08-15T20:19:20.293959", "lvl": "target", "msg": "[   19.026782] 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-15T20:19:20.296599", "lvl": "target", "msg": "[   19.059148] systemd[1]: Detected architecture arm64."}
- {"dt": "2024-08-15T20:19:20.438910", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T20:19:20.440447", "lvl": "target", "msg": "Welcome to Automotive Grade Linux 18.90.0 (salmon)!"}
- {"dt": "2024-08-15T20:19:20.441840", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T20:19:20.487894", "lvl": "target", "msg": "[   19.246809] systemd[1]: Hostname set to <h3ulcb>."}
- {"dt": "2024-08-15T20:19:25.909878", "lvl": "target", "msg": "[   24.667563] systemd[1]: Binding to IPv6 address not available since kernel does not support IPv6."}
- {"dt": "2024-08-15T20:19:26.005617", "lvl": "target", "msg": "[   24.766049] systemd[1]: Queued start job for default target Graphical Interface."}
- {"dt": "2024-08-15T20:19:26.039357", "lvl": "target", "msg": "[   24.797632] systemd[1]: Created slice Slice /system/getty."}
- {"dt": "2024-08-15T20:19:26.042547", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/getty."}
- {"dt": "2024-08-15T20:19:26.120339", "lvl": "target", "msg": "[   24.819866] systemd[1]: Created slice Slice /system/modprobe."}
- {"dt": "2024-08-15T20:19:26.121027", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/modprobe."}
- {"dt": "2024-08-15T20:19:26.122559", "lvl": "target", "msg": "[   24.839767] systemd[1]: Created slice Slice /system/serial-getty."}
- {"dt": "2024-08-15T20:19:26.123176", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/serial-getty."}
- {"dt": "2024-08-15T20:19:26.123710", "lvl": "target", "msg": "[   24.859559] systemd[1]: Created slice Slice /system/wireplumber."}
- {"dt": "2024-08-15T20:19:26.124235", "lvl": "target", "msg": "[  OK  ] Created slice Slice /system/wireplumber."}
- {"dt": "2024-08-15T20:19:26.124805", "lvl": "target", "msg": "[   24.879310] systemd[1]: Created slice User and Session Slice."}
- {"dt": "2024-08-15T20:19:26.125319", "lvl": "target", "msg": "[  OK  ] Created slice User and Session Slice."}
- {"dt": "2024-08-15T20:19:26.192285", "lvl": "target", "msg": "[   24.898795] systemd[1]: Started Dispatch Password Requests to Console Directory Watch."}
- {"dt": "2024-08-15T20:19:26.193039", "lvl": "target", "msg": "[  OK  ] Started Dispatch Password Requests to Console Directory Watch."}
- {"dt": "2024-08-15T20:19:26.193621", "lvl": "target", "msg": "[   24.922720] systemd[1]: Started Forward Password Requests to Wall Directory Watch."}
- {"dt": "2024-08-15T20:19:26.194180", "lvl": "target", "msg": "[  OK  ] Started Forward Password Requests to Wall Directory Watch."}
- {"dt": "2024-08-15T20:19:26.194732", "lvl": "target", "msg": "[   24.946661] systemd[1]: Reached target Host and Network Name Lookups."}
- {"dt": "2024-08-15T20:19:26.195273", "lvl": "target", "msg": "[  OK  ] Reached target Host and Network Name Lookups."}
- {"dt": "2024-08-15T20:19:26.196716", "lvl": "target", "msg": "[   24.966518] systemd[1]: Reached target Path Units."}
- {"dt": "2024-08-15T20:19:26.220521", "lvl": "target", "msg": "[  OK  ] Reached target Path Units."}
- {"dt": "2024-08-15T20:19:26.223579", "lvl": "target", "msg": "[   24.982552] systemd[1]: Reached target Remote File Systems."}
- {"dt": "2024-08-15T20:19:26.224895", "lvl": "target", "msg": "[  OK  ] Reached target Remote File Systems."}
- {"dt": "2024-08-15T20:19:26.254611", "lvl": "target", "msg": "[   25.002507] systemd[1]: Reached target Slice Units."}
- {"dt": "2024-08-15T20:19:26.255650", "lvl": "target", "msg": "[  OK  ] Reached target Slice Units."}
- {"dt": "2024-08-15T20:19:26.257804", "lvl": "target", "msg": "[   25.018559] systemd[1]: Reached target Swaps."}
- {"dt": "2024-08-15T20:19:26.258565", "lvl": "target", "msg": "[  OK  ] Reached target Swaps."}
- {"dt": "2024-08-15T20:19:26.291189", "lvl": "target", "msg": "[   25.048968] systemd[1]: Listening on Process Core Dump Socket."}
- {"dt": "2024-08-15T20:19:26.293473", "lvl": "target", "msg": "[  OK  ] Listening on Process Core Dump Socket."}
- {"dt": "2024-08-15T20:19:26.312258", "lvl": "target", "msg": "[   25.070863] systemd[1]: Listening on initctl Compatibility Named Pipe."}
- {"dt": "2024-08-15T20:19:26.315399", "lvl": "target", "msg": "[  OK  ] Listening on initctl Compatibility Named Pipe."}
- {"dt": "2024-08-15T20:19:26.375401", "lvl": "target", "msg": "[   25.095589] systemd[1]: Listening on Journal Audit Socket."}
- {"dt": "2024-08-15T20:19:26.376072", "lvl": "target", "msg": "[  OK  ] Listening on Journal Audit Socket."}
- {"dt": "2024-08-15T20:19:26.377541", "lvl": "target", "msg": "[   25.115072] systemd[1]: Listening on Journal Socket (/dev/log)."}
- {"dt": "2024-08-15T20:19:26.378126", "lvl": "target", "msg": "[  OK  ] Listening on Journal Socket (/dev/log)."}
- {"dt": "2024-08-15T20:19:26.378691", "lvl": "target", "msg": "[   25.135151] systemd[1]: Listening on Journal Socket."}
- {"dt": "2024-08-15T20:19:26.379395", "lvl": "target", "msg": "[  OK  ] Listening on Journal Socket."}
- {"dt": "2024-08-15T20:19:26.437592", "lvl": "target", "msg": "[   25.155251] systemd[1]: Listening on Network Service Netlink Socket."}
- {"dt": "2024-08-15T20:19:26.438556", "lvl": "target", "msg": "[  OK  ] Listening on Network Service Netlink Socket."}
- {"dt": "2024-08-15T20:19:26.439333", "lvl": "target", "msg": "[   25.175208] systemd[1]: Listening on udev Control Socket."}
- {"dt": "2024-08-15T20:19:26.440038", "lvl": "target", "msg": "[  OK  ] Listening on udev Control Socket."}
- {"dt": "2024-08-15T20:19:26.440686", "lvl": "target", "msg": "[   25.194990] systemd[1]: Listening on udev Kernel Socket."}
- {"dt": "2024-08-15T20:19:26.441473", "lvl": "target", "msg": "[  OK  ] Listening on udev Kernel Socket."}
- {"dt": "2024-08-15T20:19:26.478142", "lvl": "target", "msg": "[   25.215013] systemd[1]: Listening on User Database Manager Socket."}
- {"dt": "2024-08-15T20:19:26.478886", "lvl": "target", "msg": "[  OK  ] Listening on User Database Manager Socket."}
- {"dt": "2024-08-15T20:19:26.481303", "lvl": "target", "msg": "[   25.235049] systemd[1]: Huge Pages File System was skipped because of an unmet condition check (ConditionPathExists=/sys/kernel/mm/hugepages)."}
- {"dt": "2024-08-15T20:19:26.531156", "lvl": "target", "msg": "[   25.286635] systemd[1]: Mounting POSIX Message Queue File System..."}
- {"dt": "2024-08-15T20:19:26.531924", "lvl": "target", "msg": "         Mounting POSIX Message Queue File System..."}
- {"dt": "2024-08-15T20:19:26.551777", "lvl": "target", "msg": "[   25.310047] systemd[1]: Mounting Kernel Debug File System..."}
- {"dt": "2024-08-15T20:19:26.554950", "lvl": "target", "msg": "         Mounting Kernel Debug File System..."}
- {"dt": "2024-08-15T20:19:26.572918", "lvl": "target", "msg": "[   25.332525] systemd[1]: Mounting Kernel Trace File System..."}
- {"dt": "2024-08-15T20:19:26.576038", "lvl": "target", "msg": "         Mounting Kernel Trace File System..."}
- {"dt": "2024-08-15T20:19:26.599624", "lvl": "target", "msg": "[   25.358999] systemd[1]: Mounting Temporary Directory /tmp..."}
- {"dt": "2024-08-15T20:19:26.600645", "lvl": "target", "msg": "         Mounting Temporary Directory /tmp..."}
- {"dt": "2024-08-15T20:19:26.638928", "lvl": "target", "msg": "[   25.378918] 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-15T20:19:26.639726", "lvl": "target", "msg": "[   25.398428] systemd[1]: Starting Load Kernel Module configfs..."}
- {"dt": "2024-08-15T20:19:26.642017", "lvl": "target", "msg": "         Starting Load Kernel Module configfs..."}
- {"dt": "2024-08-15T20:19:26.659885", "lvl": "target", "msg": "[   25.420723] systemd[1]: Starting Load Kernel Module drm..."}
- {"dt": "2024-08-15T20:19:26.663065", "lvl": "target", "msg": "         Starting Load Kernel Module drm..."}
- {"dt": "2024-08-15T20:19:26.680873", "lvl": "target", "msg": "[   25.440606] systemd[1]: Starting Load Kernel Module fuse..."}
- {"dt": "2024-08-15T20:19:26.684068", "lvl": "target", "msg": "         Starting Load Kernel Module fuse..."}
- {"dt": "2024-08-15T20:19:26.701821", "lvl": "target", "msg": "[   25.460577] systemd[1]: Starting Start psplash boot splash screen..."}
- {"dt": "2024-08-15T20:19:26.704995", "lvl": "target", "msg": "         Starting Start psplash boot splash screen..."}
- {"dt": "2024-08-15T20:19:26.745997", "lvl": "target", "msg": "[   25.484273] (psplash)[191]: psplash-start.service: Referenced but unset environment variable evaluates to an empty string: PSPLASH_ARGS"}
- {"dt": "2024-08-15T20:19:26.746849", "lvl": "target", "msg": "[   25.484337] systemd[1]: Starting SELinux autorelabel service loading..."}
- {"dt": "2024-08-15T20:19:26.747546", "lvl": "target", "msg": "         Starting SELinu[   25.505431] systemd[1]: Starting SELinux init for /dev service loading..."}
- {"dt": "2024-08-15T20:19:26.748567", "lvl": "target", "msg": "x autorelabel service loading..."}
- {"dt": "2024-08-15T20:19:26.763081", "lvl": "target", "msg": "         Starting SELinux init for /dev service loading..."}
- {"dt": "2024-08-15T20:19:26.823678", "lvl": "target", "msg": "[   25.566738] systemd[1]: Rebuild Hardware Database was skipped because no trigger condition checks were met."}
- {"dt": "2024-08-15T20:19:26.825348", "lvl": "target", "msg": "[   25.580487] systemd[1]: Starting Journal Service..."}
- {"dt": "2024-08-15T20:19:26.827158", "lvl": "target", "msg": "         Starting Journal Service..."}
- {"dt": "2024-08-15T20:19:26.951645", "lvl": "target", "msg": "[   25.710962] systemd[1]: Starting Load Kernel Modules..."}
- {"dt": "2024-08-15T20:19:26.952283", "lvl": "target", "msg": "         Starting Load Kernel Modules..."}
- {"dt": "2024-08-15T20:19:26.978884", "lvl": "target", "msg": "[   25.733580] systemd[1]: Starting Create Static Device Nodes in /dev gracefully..."}
- {"dt": "2024-08-15T20:19:26.980216", "lvl": "target", "msg": "         Starting Create Static Device Nodes in /dev gracefully..."}
- {"dt": "2024-08-15T20:19:27.003733", "lvl": "target", "msg": "[   25.761858] systemd[1]: Starting Coldplug All udev Devices..."}
- {"dt": "2024-08-15T20:19:27.004660", "lvl": "target", "msg": "         Starting Coldplug All udev Devices..."}
- {"dt": "2024-08-15T20:19:27.040353", "lvl": "target", "msg": "[   25.798006] systemd-journald[194]: Collecting audit messages is enabled."}
- {"dt": "2024-08-15T20:19:27.126286", "lvl": "target", "msg": "[   25.867151] systemd[1]: Bind mount volatile /var/cache was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/var/cache)."}
- {"dt": "2024-08-15T20:19:27.128185", "lvl": "target", "msg": "[   25.880842] systemd[1]: Bind mount volatile /var/lib was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/var/lib)."}
- {"dt": "2024-08-15T20:19:27.208455", "lvl": "target", "msg": "[   25.918917] systemd[1]: Starting Load/Save OS Random Seed..."}
- {"dt": "2024-08-15T20:19:27.209130", "lvl": "target", "msg": "         Starting Load/Save OS Random Seed..."}
- {"dt": "2024-08-15T20:19:27.210820", "lvl": "target", "msg": "[   25.938622] systemd[1]: Bind mount volatile /var/spool was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/var/spool)."}
- {"dt": "2024-08-15T20:19:27.211626", "lvl": "target", "msg": "[   25.952200] systemd[1]: Bind mount volatile /srv was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/srv)."}
- {"dt": "2024-08-15T20:19:27.212443", "lvl": "target", "msg": "[   25.970134] systemd[1]: Started Journal Service."}
- {"dt": "2024-08-15T20:19:27.213313", "lvl": "target", "msg": "[  OK  ] Started Journal Service."}
- {"dt": "2024-08-15T20:19:27.241823", "lvl": "target", "msg": "[   25.987027] audit: type=1130 audit(1721815285.955: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-15T20:19:27.245073", "lvl": "target", "msg": "[  OK  ] Mounted POSIX Message Queue File System."}
- {"dt": "2024-08-15T20:19:27.258118", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Debug File System."}
- {"dt": "2024-08-15T20:19:27.274899", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Trace File System."}
- {"dt": "2024-08-15T20:19:27.290230", "lvl": "target", "msg": "[  OK  ] Mounted Temporary Directory /tmp."}
- {"dt": "2024-08-15T20:19:27.306267", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module configfs."}
- {"dt": "2024-08-15T20:19:27.358711", "lvl": "target", "msg": "[   26.086805] audit: type=1130 audit(1721815286.055: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-15T20:19:27.359819", "lvl": "target", "msg": "[   26.106053] audit: type=1131 audit(1721815286.055: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-15T20:19:27.362424", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module drm."}
- {"dt": "2024-08-15T20:19:27.414056", "lvl": "target", "msg": "[   26.142635] audit: type=1130 audit(1721815286.111: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-15T20:19:27.415807", "lvl": "target", "msg": "[   26.161480] audit: type=1131 audit(1721815286.111: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-15T20:19:27.417362", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Module fuse."}
- {"dt": "2024-08-15T20:19:27.467054", "lvl": "target", "msg": "[   26.194614] audit: type=1130 audit(1721815286.163: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-15T20:19:27.469339", "lvl": "target", "msg": "[   26.213492] audit: type=1131 audit(1721815286.163: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-15T20:19:27.471964", "lvl": "target", "msg": "[FAILED] Failed to start Start psplash boot splash screen."}
- {"dt": "2024-08-15T20:19:27.483917", "lvl": "target", "msg": "See 'systemctl status psplash-start.service' for details."}
- {"dt": "2024-08-15T20:19:27.534453", "lvl": "target", "msg": "[DEPEND] Dependency failed for Start psplash\u2026emd progress communication helper."}
- {"dt": "2024-08-15T20:19:27.535373", "lvl": "target", "msg": "[   26.278657] audit: type=1130 audit(1721815286.247: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-15T20:19:27.536421", "lvl": "target", "msg": "[  OK  ] Finished SELinux autorelabel service loading."}
- {"dt": "2024-08-15T20:19:27.589513", "lvl": "target", "msg": "[   26.314588] audit: type=1130 audit(1721815286.283: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-15T20:19:27.591238", "lvl": "target", "msg": "[   26.334032] audit: type=1131 audit(1721815286.283: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-15T20:19:27.591958", "lvl": "target", "msg": "[  OK  ] Finished SELinux init for /dev service loading."}
- {"dt": "2024-08-15T20:19:27.604834", "lvl": "target", "msg": "[  OK  ] Finished Load Kernel Modules."}
- {"dt": "2024-08-15T20:19:27.628837", "lvl": "target", "msg": "[  OK  ] Finished Create Static Device Nodes in /dev gracefully."}
- {"dt": "2024-08-15T20:19:27.629960", "lvl": "target", "msg": "[  OK  ] Finished Coldplug All udev Devices."}
- {"dt": "2024-08-15T20:19:27.644661", "lvl": "target", "msg": "[  OK  ] Finished Load/Save OS Random Seed."}
- {"dt": "2024-08-15T20:19:27.707686", "lvl": "target", "msg": "         Mounting Kernel Configuration File System..."}
- {"dt": "2024-08-15T20:19:27.724125", "lvl": "target", "msg": "         Starting Flush Journal to Persistent Storage..."}
- {"dt": "2024-08-15T20:19:27.739615", "lvl": "target", "msg": "         Starting Apply Kernel Variables..."}
- {"dt": "2024-08-15T20:19:27.756552", "lvl": "target", "msg": "         Starting Create System Users..."}
- {"dt": "2024-08-15T20:19:27.772401", "lvl": "target", "msg": "[  OK  ] Mounted Kernel Configuration File System."}
- {"dt": "2024-08-15T20:19:27.804654", "lvl": "target", "msg": "[   26.564966] systemd-journald[194]: Received client request to flush runtime journal."}
- {"dt": "2024-08-15T20:19:27.820478", "lvl": "target", "msg": "[  OK  ] Finished Flush Journal to Persistent Storage."}
- {"dt": "2024-08-15T20:19:27.868212", "lvl": "target", "msg": "[  OK  ] Finished Apply Kernel Variables."}
- {"dt": "2024-08-15T20:19:27.979364", "lvl": "target", "msg": "         Starting User Database Manager..."}
- {"dt": "2024-08-15T20:19:28.059071", "lvl": "target", "msg": "[  OK  ] Started User Database Manager."}
- {"dt": "2024-08-15T20:19:28.091678", "lvl": "target", "msg": "[  OK  ] Finished Create System Users."}
- {"dt": "2024-08-15T20:19:28.139360", "lvl": "target", "msg": "         Starting Create Static Device Nodes in /dev..."}
- {"dt": "2024-08-15T20:19:28.155828", "lvl": "target", "msg": "[  OK  ] Finished Create Static Device Nodes in /dev."}
- {"dt": "2024-08-15T20:19:28.183043", "lvl": "target", "msg": "[  OK  ] Reached target Preparation for Local File Systems."}
- {"dt": "2024-08-15T20:19:28.186461", "lvl": "target", "msg": "[  OK  ] Reached target Local File Systems."}
- {"dt": "2024-08-15T20:19:28.218616", "lvl": "target", "msg": "         Starting Rebuild Dynamic Linker Cache..."}
- {"dt": "2024-08-15T20:19:28.233427", "lvl": "target", "msg": "         Starting SELinux resolv.conf relabeling..."}
- {"dt": "2024-08-15T20:19:28.264975", "lvl": "target", "msg": "         Starting SELinux init service loading..."}
- {"dt": "2024-08-15T20:19:28.281043", "lvl": "target", "msg": "         Starting Create Volatile Files and Directories..."}
- {"dt": "2024-08-15T20:19:28.301996", "lvl": "target", "msg": "         Starting Rule-based Manager for Device Events and Files..."}
- {"dt": "2024-08-15T20:19:28.317821", "lvl": "target", "msg": "[  OK  ] Finished SELinux init service loading."}
- {"dt": "2024-08-15T20:19:28.409203", "lvl": "target", "msg": "[   27.145343] EXT4-fs error (device nbd0): ext4_lookup:1855: inode #95811: comm systemd-tmpfile: iget: checksum invalid"}
- {"dt": "2024-08-15T20:19:28.409884", "lvl": "target", "msg": "[  OK  ] Finished SELinu[   27.157907] EXT4-fs error (device nbd0): ext4_lookup:1855: inode #95814: comm systemd-tmpfile: iget: checksum invalid"}
- {"dt": "2024-08-15T20:19:28.410379", "lvl": "target", "msg": "x resolv[   27.164296] EXT4-fs error (device nbd0): ext4_lookup:1855: inode #95817: comm ldconfig: iget: checksum invalid"}
- {"dt": "2024-08-15T20:19:28.424817", "lvl": "target", "msg": ".conf re[   27.169463] EXT4-fs error (device nbd0): ext4_lookup:1855: inode #95815: comm systemd-tmpfile: iget: checksum invalid"}
- {"dt": "2024-08-15T20:19:28.425469", "lvl": "target", "msg": "labeling."}
- {"dt": "2024-08-15T20:19:28.489492", "lvl": "target", "msg": "[  OK  ] Finished Create Volatile Files and Directories."}
- {"dt": "2024-08-15T20:19:28.520860", "lvl": "target", "msg": "         Starting Load Audit Rules..."}
- {"dt": "2024-08-15T20:19:28.537035", "lvl": "target", "msg": "         Starting Rebuild Journal Catalog..."}
- {"dt": "2024-08-15T20:19:29.415417", "lvl": "target", "msg": "[  OK  ] Finished Rebuild Journal Catalog."}
- {"dt": "2024-08-15T20:19:29.515983", "lvl": "target", "msg": "[   28.264262] EXT4-fs error (device nbd0): ext4_validate_block_bitmap:421: comm cp: bg 1: bad block bitmap checksum"}
- {"dt": "2024-08-15T20:19:29.518368", "lvl": "target", "msg": "[   28.274740] EXT4-fs error (device nbd0) in ext4_mb_clear_bb:6631: Filesystem failed CRC"}
- {"dt": "2024-08-15T20:19:29.595814", "lvl": "target", "msg": "[  OK  ] Finished Load Audit Rules."}
- {"dt": "2024-08-15T20:19:29.627289", "lvl": "target", "msg": "         Starting Security Audit Logging Service..."}
- {"dt": "2024-08-15T20:19:29.866950", "lvl": "target", "msg": "[  OK  ] Started Security Audit Logging Service."}
- {"dt": "2024-08-15T20:19:29.931944", "lvl": "target", "msg": "         Starting Record System Boot/Shutdown in UTMP..."}
- {"dt": "2024-08-15T20:19:30.011789", "lvl": "target", "msg": "[  OK  ] Finished Record System Boot/Shutdown in UTMP."}
- {"dt": "2024-08-15T20:19:30.106666", "lvl": "target", "msg": "[  OK  ] Started Rule-based Manager for Device Events and Files."}
- {"dt": "2024-08-15T20:19:30.378902", "lvl": "target", "msg": "[   29.136308] bcmgenet fd580000.ethernet end0: renamed from eth0 (while UP)"}
- {"dt": "2024-08-15T20:19:30.824833", "lvl": "target", "msg": "         Starting Virtual Console Setup..."}
- {"dt": "2024-08-15T20:19:32.263689", "lvl": "target", "msg": "[  OK  ] Finished Virtual Console Setup."}
- {"dt": "2024-08-15T20:19:34.346132", "lvl": "target", "msg": "[*     ] A start job is running for Rebuild \u2026namic Linker Cache (8s / no limit)"}
- {"dt": "2024-08-15T20:19:34.846365", "lvl": "target", "msg": "M[K[**    ] A start job is running for Rebuild \u2026namic Linker Cache (8s / no limit)"}
- {"dt": "2024-08-15T20:19:35.345970", "lvl": "target", "msg": "M[K[***   ] A start job is running for Rebuild \u2026namic Linker Cache (9s / no limit)"}
- {"dt": "2024-08-15T20:19:35.846515", "lvl": "target", "msg": "M[K[ ***  ] A start job is running for Rebuild \u2026namic Linker Cache (9s / no limit)"}
- {"dt": "2024-08-15T20:19:36.347286", "lvl": "target", "msg": "M[K[  *** ] A start job is running for Rebuild \u2026amic Linker Cache (10s / no limit)"}
- {"dt": "2024-08-15T20:19:36.847636", "lvl": "target", "msg": "M[K[   ***] A start job is running for Rebuild \u2026amic Linker Cache (10s / no limit)"}
- {"dt": "2024-08-15T20:19:37.342397", "lvl": "target", "msg": "M[K[    **] A start job is running for Rebuild \u2026amic Linker Cache (11s / no limit)"}
- {"dt": "2024-08-15T20:19:37.845890", "lvl": "target", "msg": "M[K[     *] A start job is running for Rebuild \u2026amic Linker Cache (11s / no limit)"}
- {"dt": "2024-08-15T20:19:38.346417", "lvl": "target", "msg": "M[K[    **] A start job is running for Rebuild \u2026amic Linker Cache (12s / no limit)"}
- {"dt": "2024-08-15T20:19:38.846297", "lvl": "target", "msg": "M[K[   ***] A start job is running for Rebuild \u2026amic Linker Cache (12s / no limit)"}
- {"dt": "2024-08-15T20:19:39.346420", "lvl": "target", "msg": "M[K[  *** ] A start job is running for Rebuild \u2026amic Linker Cache (13s / no limit)"}
- {"dt": "2024-08-15T20:19:39.847198", "lvl": "target", "msg": "M[K[ ***  ] A start job is running for Rebuild \u2026amic Linker Cache (13s / no limit)"}
- {"dt": "2024-08-15T20:19:40.347996", "lvl": "target", "msg": "M[K[***   ] A start job is running for Rebuild \u2026amic Linker Cache (14s / no limit)"}
- {"dt": "2024-08-15T20:19:40.847817", "lvl": "target", "msg": "M[K[**    ] A start job is running for Rebuild \u2026amic Linker Cache (14s / no limit)"}
- {"dt": "2024-08-15T20:19:41.343000", "lvl": "target", "msg": "M[K[*     ] A start job is running for Rebuild \u2026amic Linker Cache (15s / no limit)"}
- {"dt": "2024-08-15T20:19:41.845964", "lvl": "target", "msg": "M[K[**    ] A start job is running for Rebuild \u2026amic Linker Cache (15s / no limit)"}
- {"dt": "2024-08-15T20:19:42.345770", "lvl": "target", "msg": "M[K[***   ] A start job is running for Rebuild \u2026amic Linker Cache (16s / no limit)"}
- {"dt": "2024-08-15T20:19:42.457995", "lvl": "target", "msg": "M[K[  OK  ] Finished Rebuild Dynamic Linker Cache."}
- {"dt": "2024-08-15T20:19:42.506846", "lvl": "target", "msg": "[K         Starting Update is Completed..."}
- {"dt": "2024-08-15T20:19:42.553697", "lvl": "target", "msg": "[  OK  ] Finished Update is Completed."}
- {"dt": "2024-08-15T20:19:42.569451", "lvl": "target", "msg": "[  OK  ] Reached target System Initialization."}
- {"dt": "2024-08-15T20:19:42.584634", "lvl": "target", "msg": "[  OK  ] Started Daily Cleanup of Temporary Directories."}
- {"dt": "2024-08-15T20:19:42.633315", "lvl": "target", "msg": "[  OK  ] Reached target Timer Units."}
- {"dt": "2024-08-15T20:19:42.635353", "lvl": "target", "msg": "[  OK  ] Listening on agl-compositor, a Wayl\u2026ositor, as a systemd user service."}
- {"dt": "2024-08-15T20:19:42.636352", "lvl": "target", "msg": "[  OK  ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket."}
- {"dt": "2024-08-15T20:19:42.637314", "lvl": "target", "msg": "[  OK  ] Listening on D-Bus System Message Bus Socket."}
- {"dt": "2024-08-15T20:19:42.692294", "lvl": "target", "msg": "[  OK  ] Listening on GPS (Global Positioning System) Daemon Sockets."}
- {"dt": "2024-08-15T20:19:42.724915", "lvl": "target", "msg": "[  OK  ] Listening on mpd.socket."}
- {"dt": "2024-08-15T20:19:42.755738", "lvl": "target", "msg": "         Starting PipeWire Multimedia System Manager Socket..."}
- {"dt": "2024-08-15T20:19:42.771714", "lvl": "target", "msg": "         Starting PipeWire Multimedia System Socket..."}
- {"dt": "2024-08-15T20:19:42.787551", "lvl": "target", "msg": "         Starting sshd.socket..."}
- {"dt": "2024-08-15T20:19:42.819848", "lvl": "target", "msg": "[  OK  ] Listening on PipeWire Multimedia System Manager Socket."}
- {"dt": "2024-08-15T20:19:42.835833", "lvl": "target", "msg": "[  OK  ] Listening on PipeWire Multimedia System Socket."}
- {"dt": "2024-08-15T20:19:42.900206", "lvl": "target", "msg": "[  OK  ] Listening on sshd.socket."}
- {"dt": "2024-08-15T20:19:42.915597", "lvl": "target", "msg": "[  OK  ] Reached target Socket Units."}
- {"dt": "2024-08-15T20:19:42.932024", "lvl": "target", "msg": "[  OK  ] Reached target Basic System."}
- {"dt": "2024-08-15T20:19:42.992279", "lvl": "target", "msg": "         Starting CAN interface helper..."}
- {"dt": "2024-08-15T20:19:42.995524", "lvl": "target", "msg": "         Starting D-Bus System Message Bus..."}
- {"dt": "2024-08-15T20:19:43.022961", "lvl": "target", "msg": "         Starting IPv6 Packet Filtering Framework..."}
- {"dt": "2024-08-15T20:19:43.025412", "lvl": "target", "msg": "         Starting IPv4 Packet Filtering Framework..."}
- {"dt": "2024-08-15T20:19:43.041934", "lvl": "target", "msg": "         Starting Telephony service..."}
- {"dt": "2024-08-15T20:19:43.057980", "lvl": "target", "msg": "[  OK  ] Started PipeWire Multimedia Service."}
- {"dt": "2024-08-15T20:19:43.073938", "lvl": "target", "msg": "         Starting Authorization Manager..."}
- {"dt": "2024-08-15T20:19:43.105075", "lvl": "target", "msg": "         Starting User Login Management..."}
- {"dt": "2024-08-15T20:19:43.120762", "lvl": "target", "msg": "         Starting Disk Manager..."}
- {"dt": "2024-08-15T20:19:43.152879", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager."}
- {"dt": "2024-08-15T20:19:43.168941", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager (bluetooth)."}
- {"dt": "2024-08-15T20:19:43.187737", "lvl": "target", "msg": "[  OK  ] Started Multimedia Service Session Manager (policy)."}
- {"dt": "2024-08-15T20:19:43.205776", "lvl": "target", "msg": "         Starting OpenSSH Key Generation..."}
- {"dt": "2024-08-15T20:19:43.221795", "lvl": "target", "msg": "[  OK  ] Finished IPv6 Packet Filtering Framework."}
- {"dt": "2024-08-15T20:19:43.237706", "lvl": "target", "msg": "[  OK  ] Finished IPv4 Packet Filtering Framework."}
- {"dt": "2024-08-15T20:19:43.270027", "lvl": "target", "msg": "[  OK  ] Reached target Preparation for Network."}
- {"dt": "2024-08-15T20:19:43.286898", "lvl": "target", "msg": "         Starting Network Configuration..."}
- {"dt": "2024-08-15T20:19:43.493465", "lvl": "target", "msg": "[  OK  ] Finished CAN interface helper."}
- {"dt": "2024-08-15T20:19:43.653403", "lvl": "target", "msg": "[  OK  ] Started User Login Management."}
- {"dt": "2024-08-15T20:19:45.123853", "lvl": "target", "msg": "[  OK  ] Started Network Configuration."}
- {"dt": "2024-08-15T20:19:45.673533", "lvl": "target", "msg": "[   44.427267] EXT4-fs error (device nbd0): ext4_lookup:1855: inode #84114: comm sshd_check_keys: iget: checksum invalid"}
- {"dt": "2024-08-15T20:19:45.785097", "lvl": "target", "msg": "[  OK  ] Started D-Bus System Message Bus."}
- {"dt": "2024-08-15T20:19:45.815863", "lvl": "target", "msg": "         Starting Connection service..."}
- {"dt": "2024-08-15T20:19:45.831592", "lvl": "target", "msg": "[  OK  ] Started Telephony service."}
- {"dt": "2024-08-15T20:19:45.949829", "lvl": "target", "msg": "[   44.706056] pipewire[331]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set"}
- {"dt": "2024-08-15T20:19:46.651548", "lvl": "target", "msg": "[  OK  ] Started Connection service."}
- {"dt": "2024-08-15T20:19:46.667331", "lvl": "target", "msg": "[  OK  ] Reached target Network."}
- {"dt": "2024-08-15T20:19:46.731127", "lvl": "target", "msg": "[  OK  ] Started agl-service-radio.service."}
- {"dt": "2024-08-15T20:19:46.747253", "lvl": "target", "msg": "         Starting Avahi mDNS/DNS-SD Stack..."}
- {"dt": "2024-08-15T20:19:46.843741", "lvl": "target", "msg": "[  OK  ] Started Eclipse KUKSA.val databroker."}
- {"dt": "2024-08-15T20:19:46.891166", "lvl": "target", "msg": "[  OK  ] Started agl-service-audiomixer.service."}
- {"dt": "2024-08-15T20:19:46.906630", "lvl": "target", "msg": "[  OK  ] Started agl-service-hvac.service."}
- {"dt": "2024-08-15T20:19:46.923150", "lvl": "target", "msg": "         Starting agl-vss-helper.service..."}
- {"dt": "2024-08-15T20:19:46.938959", "lvl": "target", "msg": "[  OK  ] Started Eclipse KUKSA.val DBC feeder."}
- {"dt": "2024-08-15T20:19:46.971832", "lvl": "target", "msg": "         Starting Permit User Sessions..."}
- {"dt": "2024-08-15T20:19:46.986711", "lvl": "target", "msg": "[  OK  ] Finished OpenSSH Key Generation."}
- {"dt": "2024-08-15T20:19:47.082692", "lvl": "target", "msg": "[  OK  ] Started Avahi mDNS/DNS-SD Stack."}
- {"dt": "2024-08-15T20:19:47.098392", "lvl": "target", "msg": "[  OK  ] Finished Permit User Sessions."}
- {"dt": "2024-08-15T20:19:47.146389", "lvl": "target", "msg": "         Starting AGL compositor..."}
- {"dt": "2024-08-15T20:19:47.163494", "lvl": "target", "msg": "[  OK  ] Started Getty on tty1."}
- {"dt": "2024-08-15T20:19:47.195429", "lvl": "target", "msg": "[  OK  ] Started Serial Getty on ttyS0."}
- {"dt": "2024-08-15T20:19:47.211238", "lvl": "target", "msg": "[  OK  ] Reached target Login Prompts."}
- {"dt": "2024-08-15T20:19:47.993373", "lvl": "target", "msg": "         Starting Hostname Service..."}
- {"dt": "2024-08-15T20:19:48.009542", "lvl": "target", "msg": "         Starting WPA supplicant..."}
- {"dt": "2024-08-15T20:19:48.265081", "lvl": "target", "msg": "[  OK  ] Started Hostname Service."}
- {"dt": "2024-08-15T20:19:49.687732", "lvl": "target", "msg": "[  OK  ] Started WPA supplicant."}
- {"dt": "2024-08-15T20:19:49.751403", "lvl": "target", "msg": "[  OK  ] Created slice User Slice of UID 1001."}
- {"dt": "2024-08-15T20:19:49.799573", "lvl": "target", "msg": "         Starting User Runtime Directory /run/user/1001..."}
- {"dt": "2024-08-15T20:19:49.975443", "lvl": "target", "msg": "[  OK  ] Finished User Runtime Directory /run/user/1001."}
- {"dt": "2024-08-15T20:19:50.039236", "lvl": "target", "msg": "         Starting User Manager for UID 1001..."}
- {"dt": "2024-08-15T20:19:50.214911", "lvl": "target", "msg": "[  OK  ] Started Authorization Manager."}
- {"dt": "2024-08-15T20:19:50.278572", "lvl": "target", "msg": "         Starting applaunchd.service..."}
- {"dt": "2024-08-15T20:19:50.610063", "lvl": "target", "msg": "[   49.357678] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:50.610888", "lvl": "target", "msg": "[   49.366940] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:50.613650", "lvl": "target", "msg": "[   49.376670] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:51.284277", "lvl": "target", "msg": "[  OK  ] Started Disk Manager."}
- {"dt": "2024-08-15T20:19:51.352794", "lvl": "target", "msg": "[   50.097961] raspberrypi-firmware soc:firmware: Request 0x00030066 returned status 0x80000001"}
- {"dt": "2024-08-15T20:19:51.355275", "lvl": "target", "msg": "[  OK  ] Started[   50.107734] vc4-drm gpu: [drm] Couldn't stop firmware display driver: -22"}
- {"dt": "2024-08-15T20:19:51.356454", "lvl": "target", "msg": " Automount Disk [   50.116031] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops)"}
- {"dt": "2024-08-15T20:19:51.357014", "lvl": "target", "msg": "Manager."}
- {"dt": "2024-08-15T20:19:51.371019", "lvl": "target", "msg": "[  OK  ] Started User Manager for UID 1001."}
- {"dt": "2024-08-15T20:19:52.139157", "lvl": "target", "msg": "[  OK  ] Started Session c1 of User agl-driver."}
- {"dt": "2024-08-15T20:19:53.308169", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T20:19:53.308841", "lvl": "target", "msg": "Automotive Grade Linux 18.90.0 h3ulcb ttyS0"}
- {"dt": "2024-08-15T20:19:53.309245", "lvl": "target", "msg": ""}
- {"dt": "2024-08-15T20:19:53.310746", "lvl": "debug", "msg": "Matched prompt #13: login:"}
- {"dt": "2024-08-15T20:19:53.311393", "lvl": "results", "msg": {"case": "kernel-messages", "definition": "lava", "duration": "50.51", "extra": {"extra": []}, "level": "2.4.4.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:19:53.312436", "lvl": "debug", "msg": "Sending username root"}
- {"dt": "2024-08-15T20:19:53.312870", "lvl": "input", "msg": "root\n"}
- {"dt": "2024-08-15T20:19:53.413655", "lvl": "target", "msg": "h3ulcb login: root"}
- {"dt": "2024-08-15T20:19:53.414608", "lvl": "debug", "msg": "Setting prompt string to ['root@raspberrypi4-64:~', 'raspberrypi4-64:~#', '/ #']"}
- {"dt": "2024-08-15T20:19:53.415291", "lvl": "debug", "msg": "login-action: Wait for prompt ['root@raspberrypi4-64:~', 'raspberrypi4-64:~#', '/ #', 'Login incorrect', 'Login timed out'] (timeout 00:18:29)"}
- {"dt": "2024-08-15T20:19:53.423099", "lvl": "target", "msg": "root"}
- {"dt": "2024-08-15T20:38:22.790094", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-08-15T20:38:22.792073", "lvl": "debug", "msg": "end: 2.4.4.1 login-action (duration 00:19:20) [common]"}
- {"dt": "2024-08-15T20:38:22.793835", "lvl": "results", "msg": {"case": "login-action", "definition": "lava", "duration": "1159.99", "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-15T20:38:22.797338", "lvl": "error", "msg": "auto-login-action failed: 1 of 1 attempts. 'wait for prompt timed out'"}
- {"dt": "2024-08-15T20:38:22.799176", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-08-15T20:38:22.800862", "lvl": "debug", "msg": "end: 2.4.4 auto-login-action (duration 00:19:22) [common]"}
- {"dt": "2024-08-15T20:38:22.801497", "lvl": "results", "msg": {"case": "auto-login-action", "definition": "lava", "duration": "1162.09", "extra": {"fail": "wait for prompt timed out"}, "level": "2.4.4", "namespace": "common", "result": "fail"}}
- {"dt": "2024-08-15T20:38:22.802535", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-08-15T20:38:22.803033", "lvl": "debug", "msg": "end: 2.4 uboot-commands (duration 00:19:56) [common]"}
- {"dt": "2024-08-15T20:38:22.803533", "lvl": "results", "msg": {"case": "uboot-commands", "definition": "lava", "duration": "1196.07", "extra": {"fail": "wait for prompt timed out"}, "level": "2.4", "namespace": "common", "result": "fail"}}
- {"dt": "2024-08-15T20:38:22.804434", "lvl": "error", "msg": "uboot-action failed: 1 of 1 attempts. 'wait for prompt timed out'"}
- {"dt": "2024-08-15T20:38:22.805049", "lvl": "exception", "msg": "wait for prompt timed out"}
- {"dt": "2024-08-15T20:38:22.805528", "lvl": "info", "msg": "end: 2 uboot-action (duration 00:20:00) [common]"}
- {"dt": "2024-08-15T20:38:22.806073", "lvl": "results", "msg": {"case": "uboot-action", "definition": "lava", "duration": "1200.05", "extra": {"fail": "wait for prompt timed out"}, "level": "2", "namespace": "common", "result": "fail"}}
- {"dt": "2024-08-15T20:38:22.807176", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-08-15T20:38:22.807764", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35926/nbd-deploy-d1lhil5_/initrd"}
- {"dt": "2024-08-15T20:38:22.809755", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35926/nbd-deploy-d1lhil5_/kernel"}
- {"dt": "2024-08-15T20:38:22.817178", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35926/nbd-deploy-d1lhil5_/dtb"}
- {"dt": "2024-08-15T20:38:22.818487", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/35926/nbd-deploy-d1lhil5_/nbdroot"}
- {"dt": "2024-08-15T20:38:22.822030", "lvl": "debug", "msg": "start: 7.1 power-off (timeout 00:00:10) [common]"}
- {"dt": "2024-08-15T20:38:22.823032", "lvl": "debug", "msg": "Calling: '/usr/local/bin/acme-cli' '-s' '192.168.66.2' 'switch_off' '7'"}
- {"dt": "2024-08-15T20:38:26.248086", "lvl": "debug", "msg": ">> Success\r"}
- {"dt": "2024-08-15T20:38:26.293427", "lvl": "debug", "msg": "Returned 0 in 3 seconds"}
- {"dt": "2024-08-15T20:38:26.397078", "lvl": "debug", "msg": "end: 7.1 power-off (duration 00:00:04) [common]"}
- {"dt": "2024-08-15T20:38:26.399081", "lvl": "results", "msg": {"case": "power-off", "definition": "lava", "duration": "3.57", "extra": {"status": "success"}, "level": "7.1", "namespace": "common", "result": "pass"}}
- {"dt": "2024-08-15T20:38:26.403278", "lvl": "debug", "msg": "start: 7.2 read-feedback (timeout 00:29:56) [common]"}
- {"dt": "2024-08-15T20:38:26.407655", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2024-08-15T20:38:27.407181", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2024-08-15T20:38:27.409527", "lvl": "info", "msg": "Disconnecting from shell: Finalise"}
- {"dt": "2024-08-15T20:38:27.411442", "lvl": "target", "msg": "7[r[999;999H[6nroot@h3ulcb:~# "}
- {"dt": "2024-08-15T20:38:27.514886", "lvl": "debug", "msg": "end: 7.2 read-feedback (duration 00:00:01) [common]"}
- {"dt": "2024-08-15T20:38:27.516954", "lvl": "debug", "msg": "lava-xnbd cleanup"}
- {"dt": "2024-08-15T20:38:27.518640", "lvl": "debug", "msg": "clean NBD port 61977"}
- {"dt": "2024-08-15T20:38:30.784135", "lvl": "info", "msg": "Override tmp directory removed at /var/lib/lava/dispatcher/tmp/35926"}
- {"dt": "2024-08-15T20:38:30.886041", "lvl": "info", "msg": "Root tmp directory removed at /var/lib/lava/dispatcher/tmp/35926"}
- {"dt": "2024-08-15T20:38:30.887069", "lvl": "error", "msg": "JobError: Your job cannot terminate cleanly."}
- {"dt": "2024-08-15T20:38:30.887600", "lvl": "results", "msg": {"case": "job", "definition": "lava", "error_msg": "wait for prompt timed out", "error_type": "Job", "result": "fail"}}
