- {"dt": "2024-09-06T11:47:02.990163", "lvl": "info", "msg": "lava-dispatcher, installed at version: 2024.05.dev0067"}
- {"dt": "2024-09-06T11:47:02.990253", "lvl": "info", "msg": "start: 0 validate"}
- {"dt": "2024-09-06T11:47:02.990332", "lvl": "info", "msg": "Start time: 2024-09-06 11:47:02.990324+00:00 (UTC)"}
- {"dt": "2024-09-06T11:47:02.990424", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxmake/builds/91/Image.gz exists"}
- {"dt": "2024-09-06T11:47:02.990508", "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-06T11:47:02.990583", "lvl": "debug", "msg": "Validating that file:///home/anders/.cache/tuxmake/builds/91/modules.tar.xz exists"}
- {"dt": "2024-09-06T11:47:03.005448", "lvl": "info", "msg": "qemu, installed at version: 8.2.4, host architecture: x86_64"}
- {"dt": "2024-09-06T11:47:03.005600", "lvl": "warning", "msg": "Missing image arg for rootfs.modules"}
- {"dt": "2024-09-06T11:47:03.005701", "lvl": "info", "msg": "validate duration: 0.02"}
- {"dt": "2024-09-06T11:47:03.005752", "lvl": "results", "msg": {"definition": "lava", "case": "validate", "result": "pass"}}
- {"dt": "2024-09-06T11:47:03.005841", "lvl": "info", "msg": "start: 1 deployimages (timeout 00:05:00) [common]"}
- {"dt": "2024-09-06T11:47:03.005900", "lvl": "debug", "msg": "start: 1.1 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2024-09-06T11:47:03.005957", "lvl": "debug", "msg": "start: 1.1.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2024-09-06T11:47:03.006106", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxmake/builds/91/Image.gz"}
- {"dt": "2024-09-06T11:47:03.006159", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1/deployimages-fw43257e/kernel/Image"}
- {"dt": "2024-09-06T11:47:03.006201", "lvl": "debug", "msg": "total size: 8209986 (7\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.006242", "lvl": "info", "msg": "Using gunzip to decompress gz"}
- {"dt": "2024-09-06T11:47:03.006556", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.011039", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.017172", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.021035", "lvl": "debug", "msg": "progress  15\u202F% (1\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.026874", "lvl": "debug", "msg": "progress  20\u202F% (1\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.030379", "lvl": "debug", "msg": "progress  25\u202F% (1\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.036531", "lvl": "debug", "msg": "progress  30\u202F% (2\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.040419", "lvl": "debug", "msg": "progress  35\u202F% (2\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.046853", "lvl": "debug", "msg": "progress  40\u202F% (3\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.050620", "lvl": "debug", "msg": "progress  45\u202F% (3\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.057425", "lvl": "debug", "msg": "progress  50\u202F% (3\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.063754", "lvl": "debug", "msg": "progress  55\u202F% (4\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.068244", "lvl": "debug", "msg": "progress  60\u202F% (4\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.074682", "lvl": "debug", "msg": "progress  65\u202F% (5\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.079256", "lvl": "debug", "msg": "progress  70\u202F% (5\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.085456", "lvl": "debug", "msg": "progress  75\u202F% (5\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.090016", "lvl": "debug", "msg": "progress  80\u202F% (6\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.097026", "lvl": "debug", "msg": "progress  85\u202F% (6\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.121321", "lvl": "debug", "msg": "progress  90\u202F% (7\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.126657", "lvl": "debug", "msg": "progress  95\u202F% (7\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.149160", "lvl": "debug", "msg": "progress 100\u202F% (7\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.150701", "lvl": "info", "msg": "7\u202FMB downloaded in 0.14\u202Fs (54.19\u202FMB/s)"}
- {"dt": "2024-09-06T11:47:03.150924", "lvl": "debug", "msg": "end: 1.1.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:03.151031", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.1.1", "duration": "0.14", "result": "pass", "extra": {"label": "kernel", "size": ! "8209986", "md5sum": "db72a48ab48c3e729ec23b32f1631d11", "sha256sum": "6524a287858874945b16184fc32b6cc516d04dc4522ab8e872f642092eb44be8", "sha512sum": "c01416b8079abf20c4c44e4805857ef4e5f2ef2028a4a3ed79c4633422eb6d601d632c53c7baa8c09554d2c5519bb9ae06ec9d46d4265f30bd65fa4ded752322"}}}
- {"dt": "2024-09-06T11:47:03.151263", "lvl": "debug", "msg": "end: 1.1 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:03.151387", "lvl": "debug", "msg": "start: 1.2 download-retry (timeout 00:05:00) [common]"}
- {"dt": "2024-09-06T11:47:03.151502", "lvl": "debug", "msg": "start: 1.2.1 file-download (timeout 00:05:00) [common]"}
- {"dt": "2024-09-06T11:47:03.151773", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxrun/assets/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4.xz"}
- {"dt": "2024-09-06T11:47:03.151881", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1/deployimages-fw43257e/rootfs/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4"}
- {"dt": "2024-09-06T11:47:03.151968", "lvl": "debug", "msg": "total size: 123070596 (117\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.152049", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-09-06T11:47:03.160861", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.363766", "lvl": "debug", "msg": "progress   5\u202F% (5\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.528994", "lvl": "debug", "msg": "progress  10\u202F% (11\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.702260", "lvl": "debug", "msg": "progress  15\u202F% (17\u202FMB)"}
- {"dt": "2024-09-06T11:47:03.885623", "lvl": "debug", "msg": "progress  20\u202F% (23\u202FMB)"}
- {"dt": "2024-09-06T11:47:04.053865", "lvl": "debug", "msg": "progress  25\u202F% (29\u202FMB)"}
- {"dt": "2024-09-06T11:47:04.315619", "lvl": "debug", "msg": "progress  30\u202F% (35\u202FMB)"}
- {"dt": "2024-09-06T11:47:04.590596", "lvl": "debug", "msg": "progress  35\u202F% (41\u202FMB)"}
- {"dt": "2024-09-06T11:47:04.769908", "lvl": "debug", "msg": "progress  40\u202F% (46\u202FMB)"}
- {"dt": "2024-09-06T11:47:04.983441", "lvl": "debug", "msg": "progress  45\u202F% (52\u202FMB)"}
- {"dt": "2024-09-06T11:47:05.209409", "lvl": "debug", "msg": "progress  50\u202F% (58\u202FMB)"}
- {"dt": "2024-09-06T11:47:05.392292", "lvl": "debug", "msg": "progress  55\u202F% (64\u202FMB)"}
- {"dt": "2024-09-06T11:47:05.572124", "lvl": "debug", "msg": "progress  60\u202F% (70\u202FMB)"}
- {"dt": "2024-09-06T11:47:05.754077", "lvl": "debug", "msg": "progress  65\u202F% (76\u202FMB)"}
- {"dt": "2024-09-06T11:47:05.932133", "lvl": "debug", "msg": "progress  70\u202F% (82\u202FMB)"}
- {"dt": "2024-09-06T11:47:06.130718", "lvl": "debug", "msg": "progress  75\u202F% (88\u202FMB)"}
- {"dt": "2024-09-06T11:47:06.360097", "lvl": "debug", "msg": "progress  80\u202F% (93\u202FMB)"}
- {"dt": "2024-09-06T11:47:06.547651", "lvl": "debug", "msg": "progress  85\u202F% (99\u202FMB)"}
- {"dt": "2024-09-06T11:47:06.713733", "lvl": "debug", "msg": "progress  90\u202F% (105\u202FMB)"}
- {"dt": "2024-09-06T11:47:06.818187", "lvl": "debug", "msg": "progress  95\u202F% (111\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.185444", "lvl": "debug", "msg": "progress 100\u202F% (117\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.640668", "lvl": "info", "msg": "117\u202FMB downloaded in 6.49\u202Fs (18.09\u202FMB/s)"}
- {"dt": "2024-09-06T11:47:09.640937", "lvl": "debug", "msg": "end: 1.2.1 file-download (duration 00:00:06) [common]"}
- {"dt": "2024-09-06T11:47:09.641017", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "file-download", "level": "1.2.1", "duration": "6.49", "result": "pass", "extra": {"label": "rootfs", "size": ! "123070596", "md5sum": "e42e101f61e8eee488693b3e3f8bf11e", "sha256sum": "873453756e2be489ea659c9b968c503783ac34c23625535d1972098bdd1123fe", "sha512sum": "36023464c61589f7c584fb10780b0fd8b90cb8e9c0003673698b386eb9f05f72584872f9fe332ace7e46734ebabb4cbd9b2085ff1f31eab9abd1060ce1ee7ced"}}}
- {"dt": "2024-09-06T11:47:09.641187", "lvl": "debug", "msg": "start: 1.2.2 download-retry (timeout 00:04:53) [common]"}
- {"dt": "2024-09-06T11:47:09.641274", "lvl": "debug", "msg": "start: 1.2.2.1 file-download (timeout 00:04:53) [common]"}
- {"dt": "2024-09-06T11:47:09.641507", "lvl": "info", "msg": "downloading file:///home/anders/.cache/tuxmake/builds/91/modules.tar.xz"}
- {"dt": "2024-09-06T11:47:09.641581", "lvl": "debug", "msg": "saving as /var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1/deployimages-fw43257e/rootfs.modules/modules.tar"}
- {"dt": "2024-09-06T11:47:09.641639", "lvl": "debug", "msg": "total size: 4565624 (4\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.641684", "lvl": "info", "msg": "Using unxz to decompress xz"}
- {"dt": "2024-09-06T11:47:09.642051", "lvl": "debug", "msg": "progress   0\u202F% (0\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.643661", "lvl": "debug", "msg": "progress   5\u202F% (0\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.644448", "lvl": "debug", "msg": "progress  10\u202F% (0\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.645226", "lvl": "debug", "msg": "progress  15\u202F% (0\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.645995", "lvl": "debug", "msg": "progress  20\u202F% (0\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.646772", "lvl": "debug", "msg": "progress  25\u202F% (1\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.647558", "lvl": "debug", "msg": "progress  30\u202F% (1\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.648342", "lvl": "debug", "msg": "progress  35\u202F% (1\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.649117", "lvl": "debug", "msg": "progress  40\u202F% (1\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.649907", "lvl": "debug", "msg": "progress  45\u202F% (1\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.650829", "lvl": "debug", "msg": "progress  50\u202F% (2\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.651652", "lvl": "debug", "msg": "progress  55\u202F% (2\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.652501", "lvl": "debug", "msg": "progress  60\u202F% (2\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.653888", "lvl": "debug", "msg": "progress  65\u202F% (2\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.655534", "lvl": "debug", "msg": "progress  70\u202F% (3\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.657147", "lvl": "debug", "msg": "progress  75\u202F% (3\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.658804", "lvl": "debug", "msg": "progress  80\u202F% (3\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.659603", "lvl": "debug", "msg": "progress  85\u202F% (3\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.660394", "lvl": "debug", "msg": "progress  90\u202F% (3\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.661195", "lvl": "debug", "msg": "progress  95\u202F% (4\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.661986", "lvl": "debug", "msg": "progress 100\u202F% (4\u202FMB)"}
- {"dt": "2024-09-06T11:47:09.774978", "lvl": "info", "msg": "4\u202FMB downloaded in 0.13\u202Fs (32.66\u202FMB/s)"}
- {"dt": "2024-09-06T11:47:09.775287", "lvl": "debug", "msg": "end: 1.2.2.1 file-download (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:09.775405", "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-06T11:47:09.775643", "lvl": "debug", "msg": "end: 1.2.2 download-retry (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:09.775772", "lvl": "debug", "msg": "start: 1.2.3 append-overlays (timeout 00:04:53) [common]"}
- {"dt": "2024-09-06T11:47:09.775878", "lvl": "info", "msg": "Modifying '/var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1/deployimages-fw43257e/rootfs/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4'"}
- {"dt": "2024-09-06T11:47:11.538012", "lvl": "debug", "msg": "Overlays:"}
- {"dt": "2024-09-06T11:47:11.539210", "lvl": "debug", "msg": "- rootfs.modules: '/var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1/deployimages-fw43257e/rootfs.modules/modules.tar' to '/usr/'"}
- {"dt": "2024-09-06T11:47:11.886346", "lvl": "debug", "msg": "end: 1.2.3 append-overlays (duration 00:00:02) [common]"}
- {"dt": "2024-09-06T11:47:11.886899", "lvl": "debug", "msg": "end: 1.2 download-retry (duration 00:00:09) [common]"}
- {"dt": "2024-09-06T11:47:11.887054", "lvl": "info", "msg": "end: 1 deployimages (duration 00:00:09) [common]"}
- {"dt": "2024-09-06T11:47:11.887211", "lvl": "info", "msg": "start: 2 boot-image-retry (timeout 00:15:00) [common]"}
- {"dt": "2024-09-06T11:47:11.887355", "lvl": "debug", "msg": "start: 2.1 boot-qemu-image (timeout 00:15:00) [common]"}
- {"dt": "2024-09-06T11:47:11.887480", "lvl": "debug", "msg": "start: 2.1.1 execute-qemu (timeout 00:15:00) [common]"}
- {"dt": "2024-09-06T11:47:11.887924", "lvl": "info", "msg": "Boot command: /usr/bin/qemu-system-riscv64 -cpu max -machine virt -nographic -nic none -m 4G -monitor none -no-reboot -smp 2 -kernel /var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1/deployimages-fw43257e/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-p6swkth5-1/deployimages-fw43257e/rootfs/https___storage.tuxboot.com_debian_sid_riscv64_rootfs.ext4,format=raw,id=hd0 -device virtio-blk-device,drive=hd0"}
- {"dt": "2024-09-06T11:47:11.891977", "lvl": "debug", "msg": "started a shell command"}
- {"dt": "2024-09-06T11:47:11.892530", "lvl": "debug", "msg": "end: 2.1.1 execute-qemu (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:11.892664", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "execute-qemu", "level": "2.1.1", "duration": "0.01", "result": "pass", "extra": {"qemu_version": "8.2.4", "host_arch": "x86_64", "job_arch": "riscv64"}}}
- {"dt": "2024-09-06T11:47:11.892907", "lvl": "debug", "msg": "end: 2.1 boot-qemu-image (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:11.893050", "lvl": "debug", "msg": "start: 2.2 auto-login-action (timeout 00:15:00) [common]"}
- {"dt": "2024-09-06T11:47:11.893187", "lvl": "debug", "msg": "Setting prompt string to ['Linux version [0-9]']"}
- {"dt": "2024-09-06T11:47:11.893299", "lvl": "debug", "msg": "auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:15:00)"}
- {"dt": "2024-09-06T11:47:11.939904", "lvl": "target", "msg": ""}
- {"dt": "2024-09-06T11:47:11.940311", "lvl": "target", "msg": "OpenSBI v1.3"}
- {"dt": "2024-09-06T11:47:11.940421", "lvl": "target", "msg": "   ____                    _____ ____ _____"}
- {"dt": "2024-09-06T11:47:11.940516", "lvl": "target", "msg": "  / __ \\                  / ____|  _ \\_   _|"}
- {"dt": "2024-09-06T11:47:11.940634", "lvl": "target", "msg": " | |  | |_ __   ___ _ __ | (___ | |_) || |"}
- {"dt": "2024-09-06T11:47:11.940744", "lvl": "target", "msg": " | |  | | '_ \\ / _ \\ '_ \\ \\___ \\|  _ < | |"}
- {"dt": "2024-09-06T11:47:11.940879", "lvl": "target", "msg": " | |__| | |_) |  __/ | | |____) | |_) || |_"}
- {"dt": "2024-09-06T11:47:11.941227", "lvl": "target", "msg": "  \\____/| .__/ \\___|_| |_|_____/|___\0/_____|"}
- {"dt": "2024-09-06T11:47:11.941325", "lvl": "target", "msg": "        | |"}
- {"dt": "2024-09-06T11:47:11.941406", "lvl": "target", "msg": "        |_|"}
- {"dt": "2024-09-06T11:47:11.941482", "lvl": "target", "msg": ""}
- {"dt": "2024-09-06T11:47:11.951680", "lvl": "target", "msg": "Platform Name             : riscv-virtio,qemu"}
- {"dt": "2024-09-06T11:47:11.951883", "lvl": "target", "msg": "Platform Features         : medeleg"}
- {"dt": "2024-09-06T11:47:11.952022", "lvl": "target", "msg": "Platform HART Count       : 2"}
- {"dt": "2024-09-06T11:47:11.952211", "lvl": "target", "msg": "Platform IPI Device       : aclint-mswi"}
- {"dt": "2024-09-06T11:47:11.952492", "lvl": "target", "msg": "Platform Timer Device     : aclint-mtimer @ 10000000Hz"}
- {"dt": "2024-09-06T11:47:11.952655", "lvl": "target", "msg": "Platform Console Device   : uart8250"}
- {"dt": "2024-09-06T11:47:11.952811", "lvl": "target", "msg": "Platform HSM Device       : ---"}
- {"dt": "2024-09-06T11:47:11.952969", "lvl": "target", "msg": "Platform PMU Device       : ---"}
- {"dt": "2024-09-06T11:47:11.953199", "lvl": "target", "msg": "Platform Reboot Device    : sifive_test"}
- {"dt": "2024-09-06T11:47:11.953390", "lvl": "target", "msg": "Platform Shutdown Device  : sifive_test"}
- {"dt": "2024-09-06T11:47:11.953536", "lvl": "target", "msg": "Platform Suspend Device   : ---"}
- {"dt": "2024-09-06T11:47:11.953700", "lvl": "target", "msg": "Platform CPPC Device      : ---"}
- {"dt": "2024-09-06T11:47:11.953894", "lvl": "target", "msg": "Firmware Base             : 0x80000000"}
- {"dt": "2024-09-06T11:47:11.954054", "lvl": "target", "msg": "Firmware Size             : 332 KB"}
- {"dt": "2024-09-06T11:47:11.954215", "lvl": "target", "msg": "Firmware RW Offset        : 0x40000"}
- {"dt": "2024-09-06T11:47:11.954374", "lvl": "target", "msg": "Firmware RW Size          : 76 KB"}
- {"dt": "2024-09-06T11:47:11.954698", "lvl": "target", "msg": "Firmware Heap Offset      : 0x4a000"}
- {"dt": "2024-09-06T11:47:11.955036", "lvl": "target", "msg": "Firmware Heap Size        : 36 KB (total), 2 KB (reserved), 9 KB (used), 24 KB (free)"}
- {"dt": "2024-09-06T11:47:11.955138", "lvl": "target", "msg": "Firmware Scratch Size     : 4096 B (total), 760 B (used), 3336 B (free)"}
- {"dt": "2024-09-06T11:47:11.955263", "lvl": "target", "msg": "Runtime SBI Version       : 1.0"}
- {"dt": "2024-09-06T11:47:11.955355", "lvl": "target", "msg": ""}
- {"dt": "2024-09-06T11:47:11.955443", "lvl": "target", "msg": "Domain0 Name              : root"}
- {"dt": "2024-09-06T11:47:11.955531", "lvl": "target", "msg": "Domain0 Boot HART         : 0"}
- {"dt": "2024-09-06T11:47:11.955814", "lvl": "target", "msg": "Domain0 HARTs             : 0*,1*"}
- {"dt": "2024-09-06T11:47:11.956128", "lvl": "target", "msg": "Domain0 Region00          : 0x0000000002000000-0x000000000200ffff M: (I,R,W) S/U: ()"}
- {"dt": "2024-09-06T11:47:11.956422", "lvl": "target", "msg": "Domain0 Region01          : 0x0000000080040000-0x000000008005ffff M: (R,W) S/U: ()"}
- {"dt": "2024-09-06T11:47:11.956814", "lvl": "target", "msg": "Domain0 Region02          : 0x0000000080000000-0x000000008003ffff M: (R,X) S/U: ()"}
- {"dt": "2024-09-06T11:47:11.957118", "lvl": "target", "msg": "Domain0 Region03          : 0x0000000000000000-0xffffffffffffffff M: (R,W,X) S/U: (R,W,X)"}
- {"dt": "2024-09-06T11:47:11.957222", "lvl": "target", "msg": "Domain0 Next Address      : 0x0000000080200000"}
- {"dt": "2024-09-06T11:47:11.957314", "lvl": "target", "msg": "Domain0 Next Arg1         : 0x00000000bfe00000"}
- {"dt": "2024-09-06T11:47:11.957580", "lvl": "target", "msg": "Domain0 Next Mode         : S-mode"}
- {"dt": "2024-09-06T11:47:11.957665", "lvl": "target", "msg": "Domain0 SysReset          : yes"}
- {"dt": "2024-09-06T11:47:11.957751", "lvl": "target", "msg": "Domain0 SysSuspend        : yes"}
- {"dt": "2024-09-06T11:47:11.957824", "lvl": "target", "msg": ""}
- {"dt": "2024-09-06T11:47:11.957908", "lvl": "target", "msg": "Boot HART ID              : 0"}
- {"dt": "2024-09-06T11:47:11.957993", "lvl": "target", "msg": "Boot HART Domain          : root"}
- {"dt": "2024-09-06T11:47:11.958084", "lvl": "target", "msg": "Boot HART Priv Version    : v1.12"}
- {"dt": "2024-09-06T11:47:11.958382", "lvl": "target", "msg": "Boot HART Base ISA        : rv64imafdcjvhg"}
- {"dt": "2024-09-06T11:47:11.958732", "lvl": "target", "msg": "Boot HART ISA Extensions  : sscofpmf,time,smstateen,sstc"}
- {"dt": "2024-09-06T11:47:11.958828", "lvl": "target", "msg": "Boot HART PMP Count       : 16"}
- {"dt": "2024-09-06T11:47:11.958916", "lvl": "target", "msg": "Boot HART PMP Granularity : 4"}
- {"dt": "2024-09-06T11:47:11.959001", "lvl": "target", "msg": "Boot HART PMP Address Bits: 54"}
- {"dt": "2024-09-06T11:47:11.959092", "lvl": "target", "msg": "Boot HART MHPM Count      : 16"}
- {"dt": "2024-09-06T11:47:11.959403", "lvl": "target", "msg": "Boot HART MIDELEG         : 0x0000000000003666"}
- {"dt": "2024-09-06T11:47:11.959498", "lvl": "target", "msg": "Boot HART MEDELEG         : 0x0000000000f0b509"}
- {"dt": "2024-09-06T11:47:11.991938", "lvl": "debug", "msg": "start: 2.2.1 login-action (timeout 00:15:00) [common]"}
- {"dt": "2024-09-06T11:47:11.992085", "lvl": "debug", "msg": "Setting prompt string to []"}
- {"dt": "2024-09-06T11:47:11.992206", "lvl": "debug", "msg": "Setting prompt string to ['-\\\\[ cut here \\\\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing']"}
- {"dt": "2024-09-06T11:47:11.992335", "lvl": "debug", "msg": "Using line separator: #'\\n'#"}
- {"dt": "2024-09-06T11:47:11.992420", "lvl": "info", "msg": "Waiting for the login prompt"}
- {"dt": "2024-09-06T11:47:11.992501", "lvl": "info", "msg": "Parsing kernel messages"}
- {"dt": "2024-09-06T11:47:11.992576", "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@(.*):[/~]#", "login:", "Login incorrect"]}
- {"dt": "2024-09-06T11:47:11.992739", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:15:00)"}
- {"dt": "2024-09-06T11:47:11.992831", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:07:30)"}
- {"dt": "2024-09-06T11:47:11.993615", "lvl": "target", "msg": "[    0.000000] Linux version 6.11.0-rc6-next-20240906 (tuxmake@tuxmake) (riscv64-linux-gnu-gcc (Debian 13.3.0-5) 13.3.0, GNU ld (GNU Binutils for Debian) 2.43) #1 SMP @1725613813"}
- {"dt": "2024-09-06T11:47:11.993724", "lvl": "target", "msg": "[    0.000000] random: crng init done"}
- {"dt": "2024-09-06T11:47:11.993808", "lvl": "target", "msg": "[    0.000000] Machine model: riscv-virtio,qemu"}
- {"dt": "2024-09-06T11:47:11.993884", "lvl": "target", "msg": "[    0.000000] SBI specification v1.0 detected"}
- {"dt": "2024-09-06T11:47:11.993956", "lvl": "target", "msg": "[    0.000000] SBI implementation ID=0x1 Version=0x10003"}
- {"dt": "2024-09-06T11:47:11.994028", "lvl": "target", "msg": "[    0.000000] SBI TIME extension detected"}
- {"dt": "2024-09-06T11:47:11.994098", "lvl": "target", "msg": "[    0.000000] SBI IPI extension detected"}
- {"dt": "2024-09-06T11:47:11.994167", "lvl": "target", "msg": "[    0.000000] SBI RFENCE extension detected"}
- {"dt": "2024-09-06T11:47:11.994236", "lvl": "target", "msg": "[    0.000000] SBI SRST extension detected"}
- {"dt": "2024-09-06T11:47:11.994333", "lvl": "target", "msg": "[    0.000000] efi: UEFI not found."}
- {"dt": "2024-09-06T11:47:11.994431", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: 0x0000000080000000..0x000000008003ffff (256 KiB) nomap non-reusable mmode_resv1@80000000"}
- {"dt": "2024-09-06T11:47:11.994537", "lvl": "target", "msg": "[    0.000000] OF: reserved mem: 0x0000000080040000..0x000000008005ffff (128 KiB) nomap non-reusable mmode_resv0@80040000"}
- {"dt": "2024-09-06T11:47:11.994728", "lvl": "target", "msg": "[    0.000000] earlycon: ns16550a0 at MMIO 0x0000000010000000 (options '')"}
- {"dt": "2024-09-06T11:47:11.995139", "lvl": "target", "msg": "[    0.000000] printk: legacy bootconsole [ns16550a0] enabled"}
- {"dt": "2024-09-06T11:47:12.017888", "lvl": "target", "msg": "[    0.000000] Zone ranges:"}
- {"dt": "2024-09-06T11:47:12.018323", "lvl": "target", "msg": "[    0.000000]   DMA32    [mem 0x0000000080000000-0x00000000ffffffff]"}
- {"dt": "2024-09-06T11:47:12.018540", "lvl": "target", "msg": "[    0.000000]   Normal   [mem 0x0000000100000000-0x000000017fffffff]"}
- {"dt": "2024-09-06T11:47:12.018887", "lvl": "target", "msg": "[    0.000000] Movable zone start for each node"}
- {"dt": "2024-09-06T11:47:12.018994", "lvl": "target", "msg": "[    0.000000] Early memory node ranges"}
- {"dt": "2024-09-06T11:47:12.019367", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000080000000-0x000000008005ffff]"}
- {"dt": "2024-09-06T11:47:12.019560", "lvl": "target", "msg": "[    0.000000]   node   0: [mem 0x0000000080060000-0x000000017fffffff]"}
- {"dt": "2024-09-06T11:47:12.019989", "lvl": "target", "msg": "[    0.000000] Initmem setup node 0 [mem 0x0000000080000000-0x000000017fffffff]"}
- {"dt": "2024-09-06T11:47:12.066183", "lvl": "target", "msg": "[    0.000000] SBI HSM extension detected"}
- {"dt": "2024-09-06T11:47:12.067529", "lvl": "target", "msg": "[    0.000000] Falling back to deprecated \"riscv,isa\""}
- {"dt": "2024-09-06T11:47:12.068868", "lvl": "target", "msg": "[    0.000000] riscv: base ISA extensions acdfhimv"}
- {"dt": "2024-09-06T11:47:12.069243", "lvl": "target", "msg": "[    0.000000] riscv: ELF capabilities acdfimv"}
- {"dt": "2024-09-06T11:47:12.085072", "lvl": "target", "msg": "[    0.000000] percpu: Embedded 22 pages/cpu s49960 r8192 d31960 u90112"}
- {"dt": "2024-09-06T11:47:12.085806", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: s49960 r8192 d31960 u90112 alloc=22*4096"}
- {"dt": "2024-09-06T11:47:12.086131", "lvl": "target", "msg": "[    0.000000] pcpu-alloc: [0] 0 [0] 1 "}
- {"dt": "2024-09-06T11:47:12.087818", "lvl": "target", "msg": "[    0.000000] Kernel command line: console=ttyS0,115200 rootwait root=/dev/vda debug verbose console_msg_format=syslog systemd.log_level=warning rw earlycon"}
- {"dt": "2024-09-06T11:47:12.089330", "lvl": "target", "msg": "<5>[    0.000000] Unknown kernel command line parameters \"verbose\", will be passed to user space."}
- {"dt": "2024-09-06T11:47:12.092380", "lvl": "debug", "msg": "Matched prompt #5: Oops(?: -|:)"}
- {"dt": "2024-09-06T11:47:12.092497", "lvl": "debug", "msg": "Setting prompt string to ['\\\\r', 'root@(.*):[/~]#', 'login:', 'Login incorrect']"}
- {"dt": "2024-09-06T11:47:12.092700", "lvl": "target", "msg": "<0>[    0.000000] Oops - illegal instruction [#1]"}
- {"dt": "2024-09-06T11:47:12.092801", "lvl": "target", "msg": "<4>[    0.000000] Modules linked in:"}
- {"dt": "2024-09-06T11:47:12.092900", "lvl": "target", "msg": "<4>[    0.000000] CPU: 0 UID: 0 PID: 0 Comm: swapper Not tainted 6.11.0-rc6-next-20240906 #1"}
- {"dt": "2024-09-06T11:47:12.093036", "lvl": "target", "msg": "<4>[    0.000000] Hardware name: riscv-virtio,qemu (DT)"}
- {"dt": "2024-09-06T11:47:12.093270", "lvl": "target", "msg": "<4>[    0.000000] epc : random_init_early+0x64/0x176"}
- {"dt": "2024-09-06T11:47:12.093480", "lvl": "target", "msg": "<4>[    0.000000]  ra : random_init_early+0x3c/0x176"}
- {"dt": "2024-09-06T11:47:12.093967", "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', 'root@(.*):[/~]#', 'login:', 'Login incorrect']"}
- {"dt": "2024-09-06T11:47:12.094072", "lvl": "warning", "msg": "login-action: kernel 'oops'"}
- {"dt": "2024-09-06T11:47:12.094165", "lvl": "debug", "msg": "[login-action] Waiting for messages, (timeout 00:15:00)"}
- {"dt": "2024-09-06T11:47:12.094249", "lvl": "debug", "msg": "Waiting using forced prompt support (timeout 00:07:30)"}
- {"dt": "2024-09-06T11:47:12.094411", "lvl": "target", "msg": "<4>[    0.000000] epc : ffffffff80a2fb5e ra : ffffffff80a2fb36 sp : ffffffff81403dd0"}
- {"dt": "2024-09-06T11:47:12.094502", "lvl": "target", "msg": "<4>[    0.000000]  gp : ffffffff815154a0 tp : ffffffff8140cd00 t0 : ffffffff81403e18"}
- {"dt": "2024-09-06T11:47:12.094631", "lvl": "target", "msg": "<4>[    0.000000]  t1 : 0000000000000000 t2 : 6c656e72656b206e s0 : ffffffff81403e80"}
- {"dt": "2024-09-06T11:47:12.095021", "lvl": "target", "msg": "<4>[    0.000000]  s1 : ffffffff80c00038 a0 : ffffffff81403dd8 a1 : 0000000000000000"}
- {"dt": "2024-09-06T11:47:12.095374", "lvl": "target", "msg": "<4>[    0.000000]  a2 : 0000000000000000 a3 : ffffffff81403e18 a4 : 0000000000000064"}
- {"dt": "2024-09-06T11:47:12.095761", "lvl": "target", "msg": "<4>[    0.000000]  a5 : 0000000000000000 a6 : ffffffff815530d8 a7 : 0000000000000009"}
- {"dt": "2024-09-06T11:47:12.096092", "lvl": "target", "msg": "<4>[    0.000000]  s2 : 00000000c0000000 s3 : 0000000000000200 s4 : 0000000080000000"}
- {"dt": "2024-09-06T11:47:12.096454", "lvl": "target", "msg": "<4>[    0.000000]  s5 : 0000000000000008 s6 : ffffffff814f8399 s7 : ffffffff814c5970"}
- {"dt": "2024-09-06T11:47:12.096823", "lvl": "target", "msg": "<4>[    0.000000]  s8 : 0000000000000004 s9 : 0000000000000001 s10: 0000000000000000"}
- {"dt": "2024-09-06T11:47:12.097170", "lvl": "target", "msg": "<4>[    0.000000]  s11: 0000000000000000 t3 : ffffffff81553288 t4 : ffffffff81553288"}
- {"dt": "2024-09-06T11:47:12.097572", "lvl": "target", "msg": "<4>[    0.000000]  t5 : ffffffff81553150 t6 : ffffffff81553288"}
- {"dt": "2024-09-06T11:47:12.097891", "lvl": "target", "msg": "<4>[    0.000000] status: 0000000200000100 badaddr: 0000000001505673 cause: 0000000000000002"}
- {"dt": "2024-09-06T11:47:12.098203", "lvl": "target", "msg": "<4>[    0.000000] [<ffffffff80a2fb5e>] random_init_early+0x64/0x176"}
- {"dt": "2024-09-06T11:47:12.098521", "lvl": "target", "msg": "<4>[    0.000000] [<ffffffff80a00b7c>] start_kernel+0x448/0x826"}
- {"dt": "2024-09-06T11:47:12.098904", "lvl": "target", "msg": "<0>[    0.000000] Code: e2cb 9b17 00ac 0b13 84db 0013 0000 0713 0640 4781 (5673) 0150 "}
- {"dt": "2024-09-06T11:47:12.099169", "lvl": "target", "msg": "<4>[    0.000000] ---[ end trace 0000000000000000 ]---"}
- {"dt": "2024-09-06T11:47:12.099662", "lvl": "debug", "msg": "Matched prompt #9: Kernel panic - not syncing"}
- {"dt": "2024-09-06T11:47:12.099765", "lvl": "debug", "msg": "Setting prompt string to ['end Kernel panic[^\\\\r]*\\\\r', 'root@(.*):[/~]#', 'login:', 'Login incorrect']"}
- {"dt": "2024-09-06T11:47:12.099986", "lvl": "target", "msg": "<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt"}
- {"dt": "2024-09-06T11:47:12.100103", "lvl": "target", "msg": "<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---"}
- {"dt": "2024-09-06T11:47:12.100378", "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', 'root@(.*):[/~]#', 'login:', 'Login incorrect']"}
- {"dt": "2024-09-06T11:47:12.100479", "lvl": "error", "msg": "login-action kernel 'panic'"}
- {"dt": "2024-09-06T11:47:12.100572", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "kernel-messages", "level": "2.2.1", "duration": "0.11", "result": "fail", "extra": {"extra": [{"kind": "oops", "message": "<0>[    0.000000] Oops - illegal instruction [#1]"}, {"kind": "panic", "message": "<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---"}]}}}
- {"dt": "2024-09-06T11:47:12.100812", "lvl": "exception", "msg": "<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---"}
- {"dt": "2024-09-06T11:47:12.100915", "lvl": "debug", "msg": "end: 2.2.1 login-action (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:12.101005", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "login-action", "level": "2.2.1", "duration": "0.11", "result": "fail", "extra": {"fail": "<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---"}}}
- {"dt": "2024-09-06T11:47:12.101169", "lvl": "error", "msg": "auto-login-action failed: 1 of 1 attempts. '<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---'"}
- {"dt": "2024-09-06T11:47:12.101284", "lvl": "exception", "msg": "<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---"}
- {"dt": "2024-09-06T11:47:12.101377", "lvl": "debug", "msg": "end: 2.2 auto-login-action (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:12.101472", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "auto-login-action", "level": "2.2", "duration": "0.21", "result": "fail", "extra": {"fail": "<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---"}}}
- {"dt": "2024-09-06T11:47:12.101628", "lvl": "error", "msg": "boot-image-retry failed: 1 of 1 attempts. '<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---'"}
- {"dt": "2024-09-06T11:47:12.101743", "lvl": "exception", "msg": "<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---"}
- {"dt": "2024-09-06T11:47:12.101833", "lvl": "info", "msg": "end: 2 boot-image-retry (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:12.101922", "lvl": "results", "msg": {"definition": "lava", "namespace": "common", "case": "boot-image-retry", "level": "2", "duration": "0.21", "result": "fail", "extra": {"fail": "<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---"}}}
- {"dt": "2024-09-06T11:47:12.102131", "lvl": "info", "msg": "Cleaning after the job"}
- {"dt": "2024-09-06T11:47:12.102269", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1/deployimages-fw43257e/kernel"}
- {"dt": "2024-09-06T11:47:12.108009", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1/deployimages-fw43257e/rootfs"}
- {"dt": "2024-09-06T11:47:12.108247", "lvl": "debug", "msg": "Cleaning up download directory: /var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1/deployimages-fw43257e/rootfs.modules"}
- {"dt": "2024-09-06T11:47:12.115543", "lvl": "debug", "msg": "start: 3.1 power-off (timeout 00:00:30) [common]"}
- {"dt": "2024-09-06T11:47:12.115698", "lvl": "debug", "msg": "end: 3.1 power-off (duration 00:00:00) [common]"}
- {"dt": "2024-09-06T11:47:12.115822", "lvl": "debug", "msg": "start: 3.2 read-feedback (timeout 00:05:00) [common]"}
- {"dt": "2024-09-06T11:47:12.116019", "lvl": "debug", "msg": "Listened to connection for namespace 'common' for up to 1s"}
- {"dt": "2024-09-06T11:47:13.117054", "lvl": "info", "msg": "Finalising connection for namespace 'common'"}
- {"dt": "2024-09-06T11:47:13.117228", "lvl": "debug", "msg": "Sending line: 'poweroff'"}
- {"dt": "2024-09-06T11:47:13.217513", "lvl": "input", "msg": "poweroff"}
- {"dt": "2024-09-06T11:47:18.222378", "lvl": "debug", "msg": "Already disconnected"}
- {"dt": "2024-09-06T11:47:18.422868", "lvl": "debug", "msg": "end: 3.2 read-feedback (duration 00:00:06) [common]"}
- {"dt": "2024-09-06T11:47:18.423060", "lvl": "info", "msg": "Removing root tmp directory at /var/lib/lava/dispatcher/tmp/tuxrun-p6swkth5-1"}
- {"dt": "2024-09-06T11:47:18.423321", "lvl": "error", "msg": "JobError: Your job cannot terminate cleanly."}
- {"dt": "2024-09-06T11:47:18.423390", "lvl": "results", "msg": {"definition": "lava", "case": "job", "result": "fail", "error_msg": "<0>[    0.000000] Kernel panic - not syncing: Fatal exception in interrupt\r\r\n<0>[    0.000000] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---", "error_type": "Job"}}
