- {"dt": "2024-09-09T08:52:01.502395", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2024.05.dev0067"}
- {"dt": "2024-09-09T08:52:01.502482", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-09-09T08:52:01.502553", "lvl": "info", "msg": "Start time: 2024-09-09 08:52:01.502546+00:00 (UTC)"}
- {"dt": "2024-09-09T08:52:01.502656", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxmake/builds/91/Image.gz exists"}
- {"dt": "2024-09-09T08:52:01.502738", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4.xz exists"}
- {"dt": "2024-09-09T08:52:01.502812", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxmake/builds/91/modules.tar.xz exists"}
- {"dt": "2024-09-09T08:52:01.502908", "lvl": "debug", "msg": "Calling: ['docker', 'pull', 'docker.io/linaro/tuxrun-qemu:master']"}
- {"dt": "2024-09-09T08:52:01.534125", "lvl": "debug", "msg": ">> Trying to pull docker.io/linaro/tuxrun-qemu:master..."}
- {"dt": "2024-09-09T08:52:03.196700", "lvl": "debug", "msg": ">> Getting image source signatures"}
- {"dt": "2024-09-09T08:52:03.197082", "lvl": "debug", "msg": ">> Copying blob sha256:f4078a8d2540026e08753e643da1f12f1d734119d95c402e7ec9de2301957f8a"}
- {"dt": "2024-09-09T08:52:03.197182", "lvl": "debug", "msg": ">> Copying blob sha256:cd0a60b90b74b4322168fd167654152528c807988cf773e6f4039bc2e37bbe49"}
- {"dt": "2024-09-09T08:52:03.197240", "lvl": "debug", "msg": ">> Copying blob sha256:8cd46d290033f265db57fd808ac81c444ec5a5b3f189c3d6d85043b647336913"}
- {"dt": "2024-09-09T08:52:03.197291", "lvl": "debug", "msg": ">> Copying blob sha256:d520a5cb6055d04f7905abe10be0c1db39866de7cf5aaaff1360c30ef85b8857"}
- {"dt": "2024-09-09T08:52:03.197831", "lvl": "debug", "msg": ">> Copying config sha256:dbd5ee70c9e9519f8ec8c84b50890ec2412d21a524a5c02f334948f70c59a34c"}
- {"dt": "2024-09-09T08:52:03.236243", "lvl": "debug", "msg": ">> Writing manifest to image destination"}
- {"dt": "2024-09-09T08:52:03.290171", "lvl": "debug", "msg": ">> dbd5ee70c9e9519f8ec8c84b50890ec2412d21a524a5c02f334948f70c59a34c"}
- {"dt": "2024-09-09T08:52:03.292693", "lvl": "debug", "msg": "Returned 0 in 1 seconds"}
- {"dt": "2024-09-09T08:52:03.805087", "lvl": "info", "msg": "qemu, installed at version: 9.1.50, host architecture: x86_64"}
- {"dt": "2024-09-09T08:52:03.805279", "lvl": "warning", "msg": "Missing image arg for rootfs.modules"}
- {"dt": "2024-09-09T08:52:03.805434", "lvl": "info", "msg": "validate duration: 2.30"}
- {"dt": "2024-09-09T08:52:03.805540", "lvl": "results", "msg": {"definition": "lava", "case": "validate", "result": "pass"}}
- {"dt": "2024-09-09T08:52:03.805751", "lvl": "info", "msg": "start: 1 deployimages (timeout 00:05:00) [common]"}
- {"dt": "2024-09-09T08:52:03.805891", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2024-09-09T08:52:03.806066", "lvl": "debug", "msg": "start: 1.1.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2024-09-09T08:52:03.806337", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxmake/builds/91/Image.gz"}
- {"dt": "2024-09-09T08:52:03.806492", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/kernel/Image"}
- {"dt": "2024-09-09T08:52:03.806635", "lvl": "debug", "msg": "total size: 8209986 (7\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.806784", "lvl": "info", "msg": "Using gunzip to decompress gz"}
- {"dt": "2024-09-09T08:52:03.807525", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.811751", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.815391", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.820422", "lvl": "debug", "msg": "progress  15\u202F% (1\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.823847", "lvl": "debug", "msg": "progress  20\u202F% (1\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.829121", "lvl": "debug", "msg": "progress  25\u202F% (1\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.834577", "lvl": "debug", "msg": "progress  30\u202F% (2\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.838479", "lvl": "debug", "msg": "progress  35\u202F% (2\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.845100", "lvl": "debug", "msg": "progress  40\u202F% (3\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.849282", "lvl": "debug", "msg": "progress  45\u202F% (3\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.855083", "lvl": "debug", "msg": "progress  50\u202F% (3\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.859363", "lvl": "debug", "msg": "progress  55\u202F% (4\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.865181", "lvl": "debug", "msg": "progress  60\u202F% (4\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.869191", "lvl": "debug", "msg": "progress  65\u202F% (5\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.875275", "lvl": "debug", "msg": "progress  70\u202F% (5\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.880719", "lvl": "debug", "msg": "progress  75\u202F% (5\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.884822", "lvl": "debug", "msg": "progress  80\u202F% (6\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.890898", "lvl": "debug", "msg": "progress  85\u202F% (6\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.909528", "lvl": "debug", "msg": "progress  90\u202F% (7\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.916708", "lvl": "debug", "msg": "progress  95\u202F% (7\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.921916", "lvl": "debug", "msg": "progress 100\u202F% (7\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.937883", "lvl": "info", "msg": "7\u202FMB downloaded in 0.13\u202Fs (59.66\u202FMB/s)"}
- {"dt": "2024-09-09T08:52:03.938098", "lvl": "debug", "msg": "end: 1.1.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-09-09T08:52:03.938210", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.1.1", "duration": "0.13", "result": "pass", "extra": {"label": "kernel", "size": ! "8209986", "md5sum": "db72a48ab48c3e729ec23b32f1631d11", "sha256sum": "6524a287858874945b16184fc32b6cc516d04dc4522ab8e872f642092eb44be8", "sha512sum": "c01416b8079abf20c4c44e4805857ef4e5f2ef2028a4a3ed79c4633422eb6d601d632c53c7baa8c09554d2c5519bb9ae06ec9d46d4265f30bd65fa4ded752322"}}}
- {"dt": "2024-09-09T08:52:03.938444", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-09-09T08:52:03.938565", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2024-09-09T08:52:03.938688", "lvl": "debug", "msg": "start: 1.2.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2024-09-09T08:52:03.938852", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4.xz"}
- {"dt": "2024-09-09T08:52:03.938944", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4"}
- {"dt": "2024-09-09T08:52:03.939024", "lvl": "debug", "msg": "total size: 123070596 (117\u202FMB)"}
- {"dt": "2024-09-09T08:52:03.939107", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-09-09T08:52:03.939666", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-09-09T08:52:04.132021", "lvl": "debug", "msg": "progress   5\u202F% (5\u202FMB)"}
- {"dt": "2024-09-09T08:52:04.288128", "lvl": "debug", "msg": "progress  10\u202F% (11\u202FMB)"}
- {"dt": "2024-09-09T08:52:04.451078", "lvl": "debug", "msg": "progress  15\u202F% (17\u202FMB)"}
- {"dt": "2024-09-09T08:52:04.618553", "lvl": "debug", "msg": "progress  20\u202F% (23\u202FMB)"}
- {"dt": "2024-09-09T08:52:04.772700", "lvl": "debug", "msg": "progress  25\u202F% (29\u202FMB)"}
- {"dt": "2024-09-09T08:52:05.008927", "lvl": "debug", "msg": "progress  30\u202F% (35\u202FMB)"}
- {"dt": "2024-09-09T08:52:05.255002", "lvl": "debug", "msg": "progress  35\u202F% (41\u202FMB)"}
- {"dt": "2024-09-09T08:52:05.426549", "lvl": "debug", "msg": "progress  40\u202F% (46\u202FMB)"}
- {"dt": "2024-09-09T08:52:05.626229", "lvl": "debug", "msg": "progress  45\u202F% (52\u202FMB)"}
- {"dt": "2024-09-09T08:52:05.836337", "lvl": "debug", "msg": "progress  50\u202F% (58\u202FMB)"}
- {"dt": "2024-09-09T08:52:06.009405", "lvl": "debug", "msg": "progress  55\u202F% (64\u202FMB)"}
- {"dt": "2024-09-09T08:52:06.181476", "lvl": "debug", "msg": "progress  60\u202F% (70\u202FMB)"}
- {"dt": "2024-09-09T08:52:06.354821", "lvl": "debug", "msg": "progress  65\u202F% (76\u202FMB)"}
- {"dt": "2024-09-09T08:52:06.525700", "lvl": "debug", "msg": "progress  70\u202F% (82\u202FMB)"}
- {"dt": "2024-09-09T08:52:06.713647", "lvl": "debug", "msg": "progress  75\u202F% (88\u202FMB)"}
- {"dt": "2024-09-09T08:52:06.928524", "lvl": "debug", "msg": "progress  80\u202F% (93\u202FMB)"}
- {"dt": "2024-09-09T08:52:07.106955", "lvl": "debug", "msg": "progress  85\u202F% (99\u202FMB)"}
- {"dt": "2024-09-09T08:52:07.264976", "lvl": "debug", "msg": "progress  90\u202F% (105\u202FMB)"}
- {"dt": "2024-09-09T08:52:07.362976", "lvl": "debug", "msg": "progress  95\u202F% (111\u202FMB)"}
- {"dt": "2024-09-09T08:52:09.112532", "lvl": "debug", "msg": "progress 100\u202F% (117\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.172327", "lvl": "info", "msg": "117\u202FMB downloaded in 6.23\u202Fs (18.83\u202FMB/s)"}
- {"dt": "2024-09-09T08:52:10.172647", "lvl": "debug", "msg": "end: 1.2.1 file-download (duration 00:00:06) [common]"}
- {"dt": "2024-09-09T08:52:10.172757", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.2.1", "duration": "6.23", "result": "pass", "extra": {"label": "rootfs", "size": ! "123070596", "md5sum": "e42e101f61e8eee488693b3e3f8bf11e", "sha256sum": "873453756e2be489ea659c9b968c503783ac34c23625535d1972098bdd1123fe", "sha512sum": "36023464c61589f7c584fb10780b0fd8b90cb8e9c0003673698b386eb9f05f72584872f9fe332ace7e46734ebabb4cbd9b2085ff1f31eab9abd1060ce1ee7ced"}}}
- {"dt": "2024-09-09T08:52:10.173009", "lvl": "debug", "msg": "start: 1.2.2 download-retry (timeout 00:04:54) [common]"}
- {"dt": "2024-09-09T08:52:10.173143", "lvl": "debug", "msg": "start: 1.2.2.1 file-download (timeout 00:04:54) [common]"}
- {"dt": "2024-09-09T08:52:10.173324", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxmake/builds/91/modules.tar.xz"}
- {"dt": "2024-09-09T08:52:10.173426", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs.modules/modules.tar"}
- {"dt": "2024-09-09T08:52:10.173504", "lvl": "debug", "msg": "total size: 4565624 (4\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.173596", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-09-09T08:52:10.174146", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.176108", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.177544", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.178976", "lvl": "debug", "msg": "progress  15\u202F% (0\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.180402", "lvl": "debug", "msg": "progress  20\u202F% (0\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.181817", "lvl": "debug", "msg": "progress  25\u202F% (1\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.183199", "lvl": "debug", "msg": "progress  30\u202F% (1\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.184615", "lvl": "debug", "msg": "progress  35\u202F% (1\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.186028", "lvl": "debug", "msg": "progress  40\u202F% (1\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.187416", "lvl": "debug", "msg": "progress  45\u202F% (1\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.188832", "lvl": "debug", "msg": "progress  50\u202F% (2\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.190231", "lvl": "debug", "msg": "progress  55\u202F% (2\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.191626", "lvl": "debug", "msg": "progress  60\u202F% (2\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.193053", "lvl": "debug", "msg": "progress  65\u202F% (2\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.194447", "lvl": "debug", "msg": "progress  70\u202F% (3\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.195884", "lvl": "debug", "msg": "progress  75\u202F% (3\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.197287", "lvl": "debug", "msg": "progress  80\u202F% (3\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.198709", "lvl": "debug", "msg": "progress  85\u202F% (3\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.200126", "lvl": "debug", "msg": "progress  90\u202F% (3\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.201556", "lvl": "debug", "msg": "progress  95\u202F% (4\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.202993", "lvl": "debug", "msg": "progress 100\u202F% (4\u202FMB)"}
- {"dt": "2024-09-09T08:52:10.299892", "lvl": "info", "msg": "4\u202FMB downloaded in 0.13\u202Fs (34.45\u202FMB/s)"}
- {"dt": "2024-09-09T08:52:10.300140", "lvl": "debug", "msg": "end: 1.2.2.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-09-09T08:52:10.300253", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.2.2.1", "duration": "0.13", "result": "pass", "extra": {"label": "rootfs.modules", "size": ! "4565624", "md5sum": "fca65cd67029e22aa0a6557bc8b87543", "sha256sum": "2dadc98d14571721647f6c4a8de9acebae9b1e899eb98837b529fde0fe21b03c", "sha512sum": "c7ae8b73ededac21c4492d395fd60f1ff0e23504a813512a12c936f96392fbccfb7b9fc74783016c7e9c6509b394bee992e6cf789bf6e4c5de2a50fd74d39714"}}}
- {"dt": "2024-09-09T08:52:10.300479", "lvl": "debug", "msg": "end: 1.2.2 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-09-09T08:52:10.300597", "lvl": "debug", "msg": "start: 1.2.3 append-overlays (timeout 00:04:54) [common]"}
- {"dt": "2024-09-09T08:52:10.300703", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4'"}
- {"dt": "2024-09-09T08:52:12.022230", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2024-09-09T08:52:12.023235", "lvl": "debug", "msg": "- rootfs.modules: '/var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs.modules/modules.tar' to '/usr/'"}
- {"dt": "2024-09-09T08:52:12.326929", "lvl": "debug", "msg": "end: 1.2.3 append-overlays (duration 00:00:02) [common]"}
- {"dt": "2024-09-09T08:52:12.327470", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:08) [common]"}
- {"dt": "2024-09-09T08:52:12.327629", "lvl": "info", "msg": "end: 1 deployimages (duration 00:00:09) [common]"}
- {"dt": "2024-09-09T08:52:12.327788", "lvl": "info", "msg": "start: 2 boot-image-retry (timeout 00:15:00) [common]"}
- {"dt": "2024-09-09T08:52:12.327930", "lvl": "debug", "msg": "start: 2.1 boot-qemu-image (timeout 00:15:00) [common]"}
- {"dt": "2024-09-09T08:52:12.328048", "lvl": "debug", "msg": "start: 2.1.1 execute-qemu (timeout 00:15:00) [common]"}
- {"dt": "2024-09-09T08:52:12.328837", "lvl": "info", "msg": "Pulling docker image"}
- {"dt": "2024-09-09T08:52:12.328974", "lvl": "debug", "msg": "Calling: ['docker', 'pull', 'docker.io/linaro/tuxrun-qemu:master']"}
- {"dt": "2024-09-09T08:52:12.355940", "lvl": "debug", "msg": ">> Trying to pull docker.io/linaro/tuxrun-qemu:master..."}
- {"dt": "2024-09-09T08:52:13.737964", "lvl": "debug", "msg": ">> Getting image source signatures"}
- {"dt": "2024-09-09T08:52:13.738177", "lvl": "debug", "msg": ">> Copying blob sha256:cd0a60b90b74b4322168fd167654152528c807988cf773e6f4039bc2e37bbe49"}
- {"dt": "2024-09-09T08:52:13.738310", "lvl": "debug", "msg": ">> Copying blob sha256:d520a5cb6055d04f7905abe10be0c1db39866de7cf5aaaff1360c30ef85b8857"}
- {"dt": "2024-09-09T08:52:13.738426", "lvl": "debug", "msg": ">> Copying blob sha256:8cd46d290033f265db57fd808ac81c444ec5a5b3f189c3d6d85043b647336913"}
- {"dt": "2024-09-09T08:52:13.738537", "lvl": "debug", "msg": ">> Copying blob sha256:f4078a8d2540026e08753e643da1f12f1d734119d95c402e7ec9de2301957f8a"}
- {"dt": "2024-09-09T08:52:13.738842", "lvl": "debug", "msg": ">> Copying config sha256:dbd5ee70c9e9519f8ec8c84b50890ec2412d21a524a5c02f334948f70c59a34c"}
- {"dt": "2024-09-09T08:52:13.777020", "lvl": "debug", "msg": ">> Writing manifest to image destination"}
- {"dt": "2024-09-09T08:52:13.833006", "lvl": "debug", "msg": ">> dbd5ee70c9e9519f8ec8c84b50890ec2412d21a524a5c02f334948f70c59a34c"}
- {"dt": "2024-09-09T08:52:13.835054", "lvl": "debug", "msg": "Returned 0 in 1 seconds"}
- {"dt": "2024-09-09T08:52:13.862629", "lvl": "info", "msg": "Boot command: docker run --network=host --cap-add=NET_ADMIN --interactive --tty --rm --init --name=lava-docker-qemu-1-2.1.1-qszcfeerd3 --device=/dev/kvm --mount=type=bind,source=/var/lib/lava/dispatcher/tmp,destination=/var/lib/lava/dispatcher/tmp docker.io/linaro/tuxrun-qemu:master qemu-system-riscv64 -cpu rv64 -machine virt -nographic -nic none -m 4G -monitor none -no-reboot -smp 2 -kernel /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/kernel/Image -append \"console=ttyS0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog systemd.log_level=warning rw earlycon\" -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4,format=raw,id=hd0 -device virtio-blk-device,drive=hd0"}
- {"dt": "2024-09-09T08:52:13.866287", "lvl": "debug", "msg": "started a shell command"}
- {"dt": "2024-09-09T08:52:13.866657", "lvl": "debug", "msg": "end: 2.1.1 execute-qemu (duration 00:00:02) [common]"}
- {"dt": "2024-09-09T08:52:13.866745", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "execute-qemu", "level": "2.1.1", "duration": "1.54", "result": "pass", "extra": {"qemu_version": "9.1.50", "host_arch": "x86_64", "job_arch": "riscv64"}}}
- {"dt": "2024-09-09T08:52:13.866897", "lvl": "debug", "msg": "end: 2.1 boot-qemu-image (duration 00:00:02) [common]"}
- {"dt": "2024-09-09T08:52:13.866998", "lvl": "debug", "msg": "start: 2.2 auto-login-action (timeout 00:14:58) [common]"}
- {"dt": "2024-09-09T08:52:13.867089", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2024-09-09T08:52:13.867151", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:15:00)"}
- {"dt": "2024-09-09T08:52:13.876962", "lvl": "target", "msg": "SRC: '/usr/local/bin/docker run --network=host --cap-add=NET_ADMIN --interactive --tty --rm --init --name=lava-docker-qemu-1-2.1.1-qszcfeerd3 --device=/dev/kvm --mount=type=bind,source=/var/lib/lava/dispatcher/tmp,destination=/var/lib/lava/dispatcher/tmp docker.io/linaro/tuxrun-qemu:master qemu-system-riscv64 -cpu rv64 -machine virt -nographic -nic none -m 4G -monitor none -no-reboot -smp 2 -kernel /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/kernel/Image -append console=ttyS0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog systemd.log_level=warning rw earlycon -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4,format=raw,id=hd0 -device virtio-blk-device,drive=hd0'"}
- {"dt": "2024-09-09T08:52:13.877064", "lvl": "target", "msg": "DST: '/usr/bin/podman --remote --url unix://run/podman/podman.sock run --log-driver=none --network=host --cap-add=NET_ADMIN --interactive --tty --rm --init --name=lava-docker-qemu-1-2.1.1-qszcfeerd3 --device=/dev/kvm --mount=type=bind,source=/tmp/tuxrun-1jbgvq2y/dispatcher/tmp,destination=/var/lib/lava/dispatcher/tmp docker.io/linaro/tuxrun-qemu:master qemu-system-riscv64 -cpu rv64 -machine virt -nographic -nic none -m 4G -monitor none -no-reboot -smp 2 -kernel /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/kernel/Image -append console=ttyS0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog systemd.log_level=warning rw earlycon -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4,format=raw,id=hd0 -device virtio-blk-device,drive=hd0'"}
- {"dt": "2024-09-09T08:52:14.032728", "lvl": "target", "msg": "qemu-system-riscv64: -drive file=/var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4,format=raw,id=hd0: Drive 'hd0' is already in use because it has been automatically connected to another device (did you need 'if=none' in the drive options?)"}
- {"dt": "2024-09-09T08:52:14.310989", "lvl": "exception", "msg": "Connection closed"}
- {"dt": "2024-09-09T08:52:14.311139", "lvl": "debug", "msg": "end: 2.2 auto-login-action (duration 00:00:00) [common]"}
- {"dt": "2024-09-09T08:52:14.311220", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "auto-login-action", "level": "2.2", "duration": "0.44", "result": "fail", "extra": {"fail": "Connection closed"}}}
- {"dt": "2024-09-09T08:52:14.311336", "lvl": "error", "msg": "boot-image-retry failed: 1 of 1 attempts. 'Connection closed'"}
- {"dt": "2024-09-09T08:52:14.311401", "lvl": "info", "msg": "Stopping the qemu container lava-docker-qemu-1-2.1.1-qszcfeerd3"}
- {"dt": "2024-09-09T08:52:14.340140", "lvl": "exception", "msg": "Connection closed"}
- {"dt": "2024-09-09T08:52:14.340239", "lvl": "info", "msg": "end: 2 boot-image-retry (duration 00:00:02) [common]"}
- {"dt": "2024-09-09T08:52:14.340312", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "boot-image-retry", "level": "2", "duration": "2.01", "result": "fail", "extra": {"fail": "Connection closed"}}}
- {"dt": "2024-09-09T08:52:14.340457", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-09-09T08:52:14.340552", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/kernel"}
- {"dt": "2024-09-09T08:52:14.343017", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs"}
- {"dt": "2024-09-09T08:52:14.419337", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1/deployimages-qfi9xeq7/rootfs.modules"}
- {"dt": "2024-09-09T08:52:14.421662", "lvl": "info", "msg": "Stopping the qemu container lava-docker-qemu-1-2.1.1-qszcfeerd3"}
- {"dt": "2024-09-09T08:52:14.449338", "lvl": "debug", "msg": "start: 3.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2024-09-09T08:52:14.449499", "lvl": "debug", "msg": "end: 3.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2024-09-09T08:52:14.449604", "lvl": "debug", "msg": "start: 3.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2024-09-09T08:52:14.449832", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2024-09-09T08:52:14.449969", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2024-09-09T08:52:14.550212", "lvl": "debug", "msg": "end: 3.2 read-feedback (duration 00:00:00) [common]"}
- {"dt": "2024-09-09T08:52:14.550327", "lvl": "info", "msg": "Removing root tmp directory at /var/lib/lava/dispatcher/tmp/tuxrun-1jbgvq2y-1"}
- {"dt": "2024-09-09T08:52:14.550499", "lvl": "error", "msg": "InfrastructureError: The Infrastructure is not working correctly. Please report this error to LAVA admins."}
- {"dt": "2024-09-09T08:52:14.550569", "lvl": "results", "msg": {"definition": "lava", "case": "job", "result": "fail", "error_msg": "Connection closed", "error_type": "Infrastructure"}}
