diff options
Diffstat (limited to 'results/classifier/gemma3:12b/debug/1992')
| -rw-r--r-- | results/classifier/gemma3:12b/debug/1992 | 910 |
1 files changed, 910 insertions, 0 deletions
diff --git a/results/classifier/gemma3:12b/debug/1992 b/results/classifier/gemma3:12b/debug/1992 new file mode 100644 index 000000000..914dc8f08 --- /dev/null +++ b/results/classifier/gemma3:12b/debug/1992 @@ -0,0 +1,910 @@ + +ReverseDebugging_ppc64 avocado test is not working reliably +Description of problem: +The tests/avocado/reverse_debugging.py:ReverseDebugging_ppc64.test_ppc64_powernv test is sometimes failing in the gitlab-CI. Looking at the logs, it seems like QEMU is dying early here, so this might be a real bug and not only an issue with the test. Full debug.log from the failing job: + +``` +08:28:31 DEBUG| PARAMS (key=arch, path=*, default=ppc64) => 'ppc64' +08:28:31 DEBUG| PARAMS (key=cpu, path=*, default=None) => None +08:28:31 DEBUG| PARAMS (key=qemu_bin, path=*, default=./qemu-system-ppc64) => './qemu-system-ppc64' +08:28:31 DEBUG| PARAMS (key=machine, path=*, default=powernv) => 'powernv' +08:28:31 INFO | creating qcow2 image for VM snapshots +08:28:31 INFO | Running '/builds/thuth/qemu/build/qemu-img create -f qcow2 /builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/disk.qcow2 128M' +08:28:31 DEBUG| [stdout] Formatting '/builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/disk.qcow2', fmt=qcow2 cluster_size=65536 extended_l2=off compression_type=zlib size=134217728 lazy_refcounts=off refcount_bits=16 +08:28:31 INFO | Command '/builds/thuth/qemu/build/qemu-img create -f qcow2 /builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/disk.qcow2 128M' finished with 0 after 0.024550681999926383s +08:28:31 DEBUG| QEMUMachine "1646a50b-5d2a-405b-8636-45a38b5fde30" created +08:28:31 DEBUG| QEMUMachine "1646a50b-5d2a-405b-8636-45a38b5fde30" temp_dir: /builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/qemu-machine-uq5k4nlc +08:28:31 DEBUG| QEMUMachine "1646a50b-5d2a-405b-8636-45a38b5fde30" log_dir: /builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv +08:28:31 INFO | recording the execution... +08:28:31 DEBUG| Using selector: EpollSelector +08:28:31 DEBUG| Registering <qemu.qmp.events.EventListener object at 0x7ff6584bae50>. +08:28:31 DEBUG| VM launch command: './qemu-system-ppc64 -display none -vga none -chardev socket,id=mon,fd=5 -mon chardev=mon,mode=control -machine powernv -chardev socket,id=console,fd=19 -serial chardev:console -icount shift=7,rr=record,rrfile=/builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/replay.bin,rrsnapshot=init -net none -drive file=/builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/disk.qcow2,if=none' +08:28:31 DEBUG| Transitioning from 'Runstate.IDLE' to 'Runstate.CONNECTING'. +08:28:31 DEBUG| Connecting with existing socket: fd=12, family=<AddressFamily.AF_UNIX: 1>, type=<SocketKind.SOCK_STREAM: 1> +08:28:31 DEBUG| Connected. +08:28:31 DEBUG| Awaiting greeting ... +08:28:31 DEBUG| <-- { + "QMP": { + "version": { + "qemu": { + "micro": 90, + "minor": 1, + "major": 8 + }, + "package": "v5.2.0-26508-gaf9264da80" + }, + "capabilities": [ + "oob" + ] + } +} +08:28:31 DEBUG| Negotiating capabilities ... +08:28:31 DEBUG| --> { + "execute": "qmp_capabilities", + "arguments": { + "enable": [ + "oob" + ] + } +} +08:28:31 DEBUG| <-- { + "return": {} +} +08:28:31 DEBUG| Transitioning from 'Runstate.CONNECTING' to 'Runstate.RUNNING'. +08:28:31 DEBUG| Opening console socket +08:28:31 DEBUG| --> { + "execute": "query-replay" +} +08:28:31 DEBUG| <-- { + "return": { + "icount": 5521801, + "mode": "record", + "filename": "/builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/replay.bin" + } +} +08:28:31 DEBUG| --> { + "execute": "query-replay" +} +08:28:31 DEBUG| [ 0.230392217,5] OPAL v7.0 starting... +08:28:31 DEBUG| [ 0.230674939,7] initial console log level: memory 7, driver 5 +08:28:31 DEBUG| [ 0.231048494,6] CPU: P9 generation processor (max 4 threads/core) +08:28:31 DEBUG| [ 0.231412547,7] CPU: Boot CPU PIR is 0x0000 PVR is 0x004e1202 +08:28:31 DEBUG| [ 0.231857798,7] OPAL table +08:28:31 DEBUG| <-- { + "return": { + "icount": 5655658, + "mode": "record", + "filename": "/builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/replay.bin" + } +} +08:28:31 DEBUG| Shutting down VM appliance; timeout=30 +08:28:31 DEBUG| Attempting graceful termination +08:28:31 DEBUG| Closing console socket +08:28:31 DEBUG| Politely asking QEMU to terminate +08:28:31 DEBUG| --> { + "execute": "quit" +} +08:28:31 DEBUG| <-- { + "return": {} +} +08:28:31 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 453159 + }, + "event": "SHUTDOWN", + "data": { + "guest": false, + "reason": "host-qmp-quit" + } +} +08:28:31 DEBUG| disconnect() called. +08:28:31 DEBUG| Transitioning from 'Runstate.RUNNING' to 'Runstate.DISCONNECTING'. +08:28:31 DEBUG| Scheduling disconnect. +08:28:31 DEBUG| Draining the outbound queue ... +08:28:31 DEBUG| Flushing the StreamWriter ... +08:28:31 DEBUG| Cancelling writer task. +08:28:31 DEBUG| Cancelling reader task. +08:28:31 DEBUG| Waiting for tasks to complete ... +08:28:31 DEBUG| Task.Writer: cancelled. +08:28:31 DEBUG| Task.Writer: exiting. +08:28:31 DEBUG| Task.Reader: cancelled. +08:28:31 DEBUG| Task.Reader: exiting. +08:28:31 DEBUG| Closing StreamWriter. +08:28:31 DEBUG| Waiting for StreamWriter to close ... +08:28:31 DEBUG| StreamWriter closed. +08:28:31 DEBUG| Disconnected. +08:28:31 DEBUG| QMP Disconnected. +08:28:31 DEBUG| Transitioning from 'Runstate.DISCONNECTING' to 'Runstate.IDLE'. +08:28:31 DEBUG| Waiting (timeout=30) for QEMU process (pid=1580) to terminate +08:28:31 DEBUG| Cleaning up after VM process +08:28:31 INFO | recorded log with 5655658+ steps +08:28:31 DEBUG| QEMUMachine "1dfa83ad-c638-4858-b96d-ec21870ab53a" created +08:28:31 DEBUG| QEMUMachine "1dfa83ad-c638-4858-b96d-ec21870ab53a" temp_dir: /builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/qemu-machine-i11yz6dd +08:28:31 DEBUG| QEMUMachine "1dfa83ad-c638-4858-b96d-ec21870ab53a" log_dir: /builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv +08:28:31 INFO | replaying the execution... +08:28:31 DEBUG| Registering <qemu.qmp.events.EventListener object at 0x7ff655d27700>. +08:28:31 DEBUG| VM launch command: './qemu-system-ppc64 -display none -vga none -chardev socket,id=mon,fd=5 -mon chardev=mon,mode=control -machine powernv -chardev socket,id=console,fd=19 -serial chardev:console -gdb tcp::21192 -S -icount shift=7,rr=replay,rrfile=/builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/replay.bin,rrsnapshot=init -net none -drive file=/builds/thuth/qemu/build/tests/results/job-2023-11-21T08.18-1c1e081/test-results/tmp_dirvmnrd25o/79-tests_avocado_reverse_debugging.py_ReverseDebugging_ppc64.test_ppc64_powernv/disk.qcow2,if=none' +08:28:31 DEBUG| Transitioning from 'Runstate.IDLE' to 'Runstate.CONNECTING'. +08:28:31 DEBUG| Connecting with existing socket: fd=12, family=<AddressFamily.AF_UNIX: 1>, type=<SocketKind.SOCK_STREAM: 1> +08:28:31 DEBUG| Connected. +08:28:31 DEBUG| Awaiting greeting ... +08:28:31 DEBUG| <-- { + "QMP": { + "version": { + "qemu": { + "micro": 90, + "minor": 1, + "major": 8 + }, + "package": "v5.2.0-26508-gaf9264da80" + }, + "capabilities": [ + "oob" + ] + } +} +08:28:31 DEBUG| Negotiating capabilities ... +08:28:31 DEBUG| --> { + "execute": "qmp_capabilities", + "arguments": { + "enable": [ + "oob" + ] + } +} +08:28:31 DEBUG| <-- { + "return": {} +} +08:28:31 DEBUG| Transitioning from 'Runstate.CONNECTING' to 'Runstate.RUNNING'. +08:28:31 DEBUG| Opening console socket +08:28:31 INFO | connecting to gdbstub +08:28:31 INFO | stepping forward +08:28:31 INFO | saving position 10 +08:28:31 INFO | saving position 14 +08:28:31 INFO | saving position 40 +08:28:31 INFO | saving position 44 +08:28:31 INFO | saving position 3008 +08:28:31 INFO | saving position 300c +08:28:31 INFO | saving position 3010 +08:28:31 INFO | saving position 3014 +08:28:31 INFO | saving position 3018 +08:28:31 INFO | saving position 301c +08:28:31 INFO | stepping backward +08:28:31 INFO | found position 301c +08:28:31 INFO | found position 3018 +08:28:31 INFO | found position 3014 +08:28:31 INFO | found position 3010 +08:28:31 INFO | found position 300c +08:28:31 INFO | found position 3008 +08:28:31 INFO | found position 44 +08:28:31 INFO | found position 40 +08:28:32 INFO | found position 14 +08:28:32 INFO | found position 10 +08:28:32 INFO | stepping forward +08:28:32 INFO | found position 10 +08:28:32 INFO | found position 14 +08:28:32 INFO | found position 40 +08:28:32 INFO | found position 44 +08:28:32 INFO | found position 3008 +08:28:32 INFO | found position 300c +08:28:32 INFO | found position 3010 +08:28:32 INFO | found position 3014 +08:28:32 INFO | found position 3018 +08:28:32 INFO | found position 301c +08:28:32 INFO | setting breakpoints +08:28:32 INFO | continuing execution +08:28:32 DEBUG| --> { + "execute": "replay-break", + "arguments": { + "icount": 5655657 + } +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 630400 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 630738 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 630965 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 631155 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 631438 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 631653 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 631935 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 632127 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 632380 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 632593 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 632858 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 633051 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 633316 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 633517 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 633775 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 633973 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 634247 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 634437 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 634707 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 634910 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 681146 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 681795 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 722346 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 723103 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 764757 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 765468 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 806932 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 807686 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 849868 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 850664 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 892036 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 892734 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 934846 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 935520 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 976442 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555311, + "microseconds": 977155 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 29287 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 30093 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 74012 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 74271 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 74873 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 75471 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 75800 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 75987 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 76239 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 76423 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 76666 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 76861 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 77106 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 77321 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 77564 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 77760 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 77987 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 78176 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 78408 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 78598 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 78846 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 79033 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 79267 + }, + "event": "RESUME" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 79451 + }, + "event": "STOP" +} +08:28:32 DEBUG| <-- { + "return": {} +} +08:28:32 DEBUG| [ 0.230392217,5] OPAL v7.0 starting... +08:28:32 DEBUG| [ 0.230674939,7] initial console log level: memory 7, driver 5 +08:28:32 DEBUG| [ 0.231048494,6] CPU: P9 generation processor (max 4 threads/core) +08:28:32 DEBUG| [ +08:28:32 DEBUG| [ 0.231412547,7] CPU: Boot CPU PIR is 0x0000 PVR is 0x004e1202 +08:28:32 DEBUG| [ +08:28:32 ERROR| +08:28:32 ERROR| Reproduced traceback from: /builds/thuth/qemu/build/pyvenv/lib64/python3.8/site-packages/avocado/core/test.py:770 +08:28:32 ERROR| Traceback (most recent call last): +08:28:32 ERROR| File "/builds/thuth/qemu/build/tests/avocado/reverse_debugging.py", line 262, in test_ppc64_powernv +08:28:32 ERROR| self.reverse_debugging() +08:28:32 ERROR| File "/builds/thuth/qemu/build/tests/avocado/reverse_debugging.py", line 178, in reverse_debugging +08:28:32 ERROR| g.cmd(b'c') +08:28:32 ERROR| File "/builds/thuth/qemu/build/pyvenv/lib64/python3.8/site-packages/avocado/utils/gdb.py", line 783, in cmd +08:28:32 ERROR| response_payload = self.decode(result) +08:28:32 ERROR| File "/builds/thuth/qemu/build/pyvenv/lib64/python3.8/site-packages/avocado/utils/gdb.py", line 738, in decode +08:28:32 ERROR| raise InvalidPacketError +08:28:32 ERROR| avocado.utils.gdb.InvalidPacketError +08:28:32 ERROR| +08:28:32 DEBUG| Local variables: +08:28:32 DEBUG| -> self <class 'reverse_debugging.ReverseDebugging_ppc64'>: 79-tests/avocado/reverse_debugging.py:ReverseDebugging_ppc64.test_ppc64_powernv +08:28:32 DEBUG| Shutting down VM appliance; timeout=30 +08:28:32 DEBUG| Attempting graceful termination +08:28:32 DEBUG| Closing console socket +08:28:32 DEBUG| Politely asking QEMU to terminate +08:28:32 DEBUG| --> { + "execute": "quit" +} +08:28:32 DEBUG| <-- { + "timestamp": { + "seconds": 1700555312, + "microseconds": 86122 + }, + "event": "RESUME" +} +08:28:32 ERROR| Task.Reader: BrokenPipeError: [Errno 32] Broken pipe +08:28:32 DEBUG| Task.Reader: failure: + | Traceback (most recent call last): + | File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 870, in _bh_loop_forever + | await async_fn() + | File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 908, in _bh_recv_message + | msg = await self._recv() + | File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 1009, in _recv + | message = await self._do_recv() + | File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 402, in _do_recv + | msg_bytes = await self._readline() + | File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 973, in _readline + | msg_bytes = await self._reader.readline() + | File "/usr/lib64/python3.8/asyncio/streams.py", line 540, in readline + | line = await self.readuntil(sep) + | File "/usr/lib64/python3.8/asyncio/streams.py", line 632, in readuntil + | await self._wait_for_data('readuntil') + | File "/usr/lib64/python3.8/asyncio/streams.py", line 517, in _wait_for_data + | await self._waiter + | File "/usr/lib64/python3.8/asyncio/selector_events.py", line 910, in write + | n = self._sock.send(data) + | BrokenPipeError: [Errno 32] Broken pipe + +08:28:32 DEBUG| Transitioning from 'Runstate.RUNNING' to 'Runstate.DISCONNECTING'. +08:28:32 DEBUG| Scheduling disconnect. +08:28:32 DEBUG| Task.Reader: exiting. +08:28:32 DEBUG| Cancelling writer task. +08:28:32 DEBUG| Waiting for tasks to complete ... +08:28:32 DEBUG| Task.Writer: cancelled. +08:28:32 DEBUG| Task.Writer: exiting. +08:28:32 DEBUG| Waiting for StreamWriter to close ... +08:28:32 DEBUG| Discarding Exception from wait_closed: + | Traceback (most recent call last): + | File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 834, in _bh_close_stream + | await wait_closed(self._writer) + | File "/builds/thuth/qemu/python/qemu/qmp/util.py", line 130, in wait_closed + | await writer.wait_closed() + | File "/usr/lib64/python3.8/asyncio/streams.py", line 359, in wait_closed + | await self._protocol._get_close_waiter(self) + | File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 870, in _bh_loop_forever + | await async_fn() + | File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 908, in _bh_recv_message + | msg = await self._recv() + | File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 1009, in _recv + | message = await self._do_recv() + | File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 402, in _do_recv + | msg_bytes = await self._readline() + | File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 973, in _readline + | msg_bytes = await self._reader.readline() + | File "/usr/lib64/python3.8/asyncio/streams.py", line 540, in readline + | line = await self.readuntil(sep) + | File "/usr/lib64/python3.8/asyncio/streams.py", line 632, in readuntil + | await self._wait_for_data('readuntil') + | File "/usr/lib64/python3.8/asyncio/streams.py", line 517, in _wait_for_data + | await self._waiter + | File "/usr/lib64/python3.8/asyncio/selector_events.py", line 910, in write + | n = self._sock.send(data) + | BrokenPipeError: [Errno 32] Broken pipe + +08:28:32 DEBUG| StreamWriter closed. +08:28:32 DEBUG| Disconnected. +08:28:32 DEBUG| Cancelling pending executions +08:28:32 DEBUG| Cancelling execution 'None' +08:28:32 DEBUG| QMP Disconnected. +08:28:32 DEBUG| disconnect() called. +08:28:32 DEBUG| Transitioning from 'Runstate.DISCONNECTING' to 'Runstate.IDLE'. +08:28:32 DEBUG| Graceful shutdown failed +Traceback (most recent call last): + File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 574, in _soft_shutdown + self.qmp('quit') + File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 705, in qmp + ret = self._qmp.cmd_raw(cmd, args=qmp_args) + File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 208, in cmd_raw + return self.cmd_obj(qmp_cmd) + File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 186, in cmd_obj + self._sync( + File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 102, in _sync + return self._aloop.run_until_complete( + File "/usr/lib64/python3.8/asyncio/base_events.py", line 616, in run_until_complete + return future.result() + File "/usr/lib64/python3.8/asyncio/tasks.py", line 455, in wait_for + return await fut + File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 547, in _raw + return await self._execute(msg, assign_id=assign_id) + File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 496, in _execute + return await self._reply(exec_id) + File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 463, in _reply + raise result +qemu.qmp.qmp_client.ExecInterruptedError: Disconnected + +During handling of the above exception, another exception occurred: + +Traceback (most recent call last): + File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 605, in _do_shutdown + self._soft_shutdown(timeout) + File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 577, in _soft_shutdown + self._close_qmp_connection() + File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 495, in _close_qmp_connection + self._qmp.close() + File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 281, in close + self._sync( + File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 102, in _sync + return self._aloop.run_until_complete( + File "/usr/lib64/python3.8/asyncio/base_events.py", line 616, in run_until_complete + return future.result() + File "/usr/lib64/python3.8/asyncio/tasks.py", line 455, in wait_for + return await fut + File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 399, in disconnect + await self._wait_disconnect() + File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 719, in _wait_disconnect + await all_defined_tasks # Raise Exceptions from the bottom half. + File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 834, in _bh_close_stream + await wait_closed(self._writer) + File "/builds/thuth/qemu/python/qemu/qmp/util.py", line 130, in wait_closed + await writer.wait_closed() + File "/usr/lib64/python3.8/asyncio/streams.py", line 359, in wait_closed + await self._protocol._get_close_waiter(self) + File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 870, in _bh_loop_forever + await async_fn() + File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 908, in _bh_recv_message + msg = await self._recv() + File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 1009, in _recv + message = await self._do_recv() + File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 402, in _do_recv + msg_bytes = await self._readline() + File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 973, in _readline + msg_bytes = await self._reader.readline() + File "/usr/lib64/python3.8/asyncio/streams.py", line 540, in readline + line = await self.readuntil(sep) + File "/usr/lib64/python3.8/asyncio/streams.py", line 632, in readuntil + await self._wait_for_data('readuntil') + File "/usr/lib64/python3.8/asyncio/streams.py", line 517, in _wait_for_data + await self._waiter + File "/usr/lib64/python3.8/asyncio/selector_events.py", line 910, in write + n = self._sock.send(data) +BrokenPipeError: [Errno 32] Broken pipe +08:28:32 DEBUG| Falling back to hard shutdown +08:28:32 DEBUG| Performing hard shutdown +08:28:32 DEBUG| Cleaning up after VM process +08:28:32 ERROR| +08:28:32 ERROR| Reproduced traceback from: /builds/thuth/qemu/build/pyvenv/lib64/python3.8/site-packages/avocado/core/test.py:796 +08:28:32 ERROR| Traceback (most recent call last): +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 574, in _soft_shutdown +08:28:32 ERROR| self.qmp('quit') +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 705, in qmp +08:28:32 ERROR| ret = self._qmp.cmd_raw(cmd, args=qmp_args) +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 208, in cmd_raw +08:28:32 ERROR| return self.cmd_obj(qmp_cmd) +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 186, in cmd_obj +08:28:32 ERROR| self._sync( +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 102, in _sync +08:28:32 ERROR| return self._aloop.run_until_complete( +08:28:32 ERROR| File "/usr/lib64/python3.8/asyncio/base_events.py", line 616, in run_until_complete +08:28:32 ERROR| return future.result() +08:28:32 ERROR| File "/usr/lib64/python3.8/asyncio/tasks.py", line 455, in wait_for +08:28:32 ERROR| return await fut +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 547, in _raw +08:28:32 ERROR| return await self._execute(msg, assign_id=assign_id) +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 496, in _execute +08:28:32 ERROR| return await self._reply(exec_id) +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 463, in _reply +08:28:32 ERROR| raise result +08:28:32 ERROR| qemu.qmp.qmp_client.ExecInterruptedError: Disconnected +08:28:32 ERROR| +08:28:32 ERROR| During handling of the above exception, another exception occurred: +08:28:32 ERROR| +08:28:32 ERROR| Traceback (most recent call last): +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 605, in _do_shutdown +08:28:32 ERROR| self._soft_shutdown(timeout) +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 577, in _soft_shutdown +08:28:32 ERROR| self._close_qmp_connection() +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 495, in _close_qmp_connection +08:28:32 ERROR| self._qmp.close() +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 281, in close +08:28:32 ERROR| self._sync( +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/legacy.py", line 102, in _sync +08:28:32 ERROR| return self._aloop.run_until_complete( +08:28:32 ERROR| File "/usr/lib64/python3.8/asyncio/base_events.py", line 616, in run_until_complete +08:28:32 ERROR| return future.result() +08:28:32 ERROR| File "/usr/lib64/python3.8/asyncio/tasks.py", line 455, in wait_for +08:28:32 ERROR| return await fut +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 399, in disconnect +08:28:32 ERROR| await self._wait_disconnect() +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 719, in _wait_disconnect +08:28:32 ERROR| await all_defined_tasks # Raise Exceptions from the bottom half. +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 834, in _bh_close_stream +08:28:32 ERROR| await wait_closed(self._writer) +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/util.py", line 130, in wait_closed +08:28:32 ERROR| await writer.wait_closed() +08:28:32 ERROR| File "/usr/lib64/python3.8/asyncio/streams.py", line 359, in wait_closed +08:28:32 ERROR| await self._protocol._get_close_waiter(self) +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 870, in _bh_loop_forever +08:28:32 ERROR| await async_fn() +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 908, in _bh_recv_message +08:28:32 ERROR| msg = await self._recv() +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 1009, in _recv +08:28:32 ERROR| message = await self._do_recv() +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/qmp_client.py", line 402, in _do_recv +08:28:32 ERROR| msg_bytes = await self._readline() +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/qmp/protocol.py", line 973, in _readline +08:28:32 ERROR| msg_bytes = await self._reader.readline() +08:28:32 ERROR| File "/usr/lib64/python3.8/asyncio/streams.py", line 540, in readline +08:28:32 ERROR| line = await self.readuntil(sep) +08:28:32 ERROR| File "/usr/lib64/python3.8/asyncio/streams.py", line 632, in readuntil +08:28:32 ERROR| await self._wait_for_data('readuntil') +08:28:32 ERROR| File "/usr/lib64/python3.8/asyncio/streams.py", line 517, in _wait_for_data +08:28:32 ERROR| await self._waiter +08:28:32 ERROR| File "/usr/lib64/python3.8/asyncio/selector_events.py", line 910, in write +08:28:32 ERROR| n = self._sock.send(data) +08:28:32 ERROR| BrokenPipeError: [Errno 32] Broken pipe +08:28:32 ERROR| +08:28:32 ERROR| The above exception was the direct cause of the following exception: +08:28:32 ERROR| +08:28:32 ERROR| Traceback (most recent call last): +08:28:32 ERROR| File "/builds/thuth/qemu/build/tests/avocado/avocado_qemu/__init__.py", line 384, in tearDown +08:28:32 ERROR| vm.shutdown() +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 642, in shutdown +08:28:32 ERROR| self._do_shutdown(timeout) +08:28:32 ERROR| File "/builds/thuth/qemu/python/qemu/machine/machine.py", line 612, in _do_shutdown +08:28:32 ERROR| raise AbnormalShutdown("Could not perform graceful shutdown") \ +08:28:32 ERROR| qemu.machine.machine.AbnormalShutdown: Could not perform graceful shutdown +08:28:32 ERROR| +08:28:32 DEBUG| DATA (filename=output.expected) => NOT FOUND (data sources: variant, test, file) +08:28:32 DEBUG| DATA (filename=stdout.expected) => NOT FOUND (data sources: variant, test, file) +08:28:32 DEBUG| DATA (filename=stderr.expected) => NOT FOUND (data sources: variant, test, file) +08:28:32 ERROR| Traceback (most recent call last): + +08:28:32 ERROR| File "/builds/thuth/qemu/build/pyvenv/lib64/python3.8/site-packages/avocado/core/test.py", line 858, in _run_avocado + raise test_exception + +08:28:32 ERROR| File "/builds/thuth/qemu/build/pyvenv/lib64/python3.8/site-packages/avocado/core/test.py", line 765, in _run_avocado + testMethod() + +08:28:32 ERROR| File "/builds/thuth/qemu/build/tests/avocado/reverse_debugging.py", line 262, in test_ppc64_powernv + self.reverse_debugging() + +08:28:32 ERROR| File "/builds/thuth/qemu/build/tests/avocado/reverse_debugging.py", line 178, in reverse_debugging + g.cmd(b'c') + +08:28:32 ERROR| File "/builds/thuth/qemu/build/pyvenv/lib64/python3.8/site-packages/avocado/utils/gdb.py", line 783, in cmd + response_payload = self.decode(result) + +08:28:32 ERROR| File "/builds/thuth/qemu/build/pyvenv/lib64/python3.8/site-packages/avocado/utils/gdb.py", line 738, in decode + raise InvalidPacketError + +08:28:32 ERROR| avocado.utils.gdb.InvalidPacketError + +08:28:32 ERROR| ERROR 79-tests/avocado/reverse_debugging.py:ReverseDebugging_ppc64.test_ppc64_powernv -> InvalidPacketError: +08:28:32 INFO | +``` |