1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
|
Aarch64 reverse debugging test is unreliable
Description of problem:
The reverse-debugging test for the aarch64 target is not working reliably, especially if the host system is under load, approx. 1 or 2 out of 10 test runs fail. The log looks like this:
```
2025-04-14 10:24:35,042 test L0310 INFO | INIT 1-ReverseDebugging_AArch64.test_aarch64_virt
2025-04-14 10:24:35,043 parameters L0142 DEBUG| PARAMS (key=timeout, path=*, default=10) => 10
2025-04-14 10:24:35,043 test L0338 DEBUG| Test metadata:
2025-04-14 10:24:35,043 test L0340 DEBUG| filename: /.../tmp/qemu-build/tests/avocado/reverse_debugging.py
2025-04-14 10:24:35,044 test L0346 DEBUG| teststmpdir: /var/tmp/avocado_w5d2bkam
2025-04-14 10:24:35,044 test L0536 INFO | START 1-ReverseDebugging_AArch64.test_aarch64_virt
2025-04-14 10:24:35,044 test L0207 DEBUG| DATA (filename=output.expected) => NOT FOUND (data sources: variant, test, file)
2025-04-14 10:24:35,045 parameters L0142 DEBUG| PARAMS (key=arch, path=*, default=aarch64) => 'aarch64'
2025-04-14 10:24:35,045 parameters L0142 DEBUG| PARAMS (key=cpu, path=*, default=cortex-a53) => 'cortex-a53'
2025-04-14 10:24:35,046 parameters L0142 DEBUG| PARAMS (key=qemu_bin, path=*, default=./qemu-system-aarch64) => './qemu-system-aarch64'
2025-04-14 10:24:35,272 parameters L0142 DEBUG| PARAMS (key=machine, path=*, default=virt) => 'virt'
2025-04-14 10:24:35,290 test L0465 DEBUG| Test workdir initialized at: /var/tmp/.avocado-taskky_yb2qf/test-results/tmp_dir56wqq7g0/1-ReverseDebugging_AArch64.test_aarch64_virt
2025-04-14 10:24:35,290 process L0658 INFO | Running '/.../tmp/qemu-build/qemu-img create -f qcow2 /var/tmp/.avocado-taskky_yb2qf/test-results/tmp_dir56wqq7g0/1-ReverseDebugging_AArch64.test_aarch64_virt/disk.qcow2 128M'
2025-04-14 10:24:35,347 process L0470 DEBUG| [stdout] Formatting '/var/tmp/.avocado-taskky_yb2qf/test-results/tmp_dir56wqq7g0/1-ReverseDebugging_AArch64.test_aarch64_virt/disk.qcow2', fmt=qcow2 cluster_size=65536 extended_l2=off compression_type=zlib size=134217728 lazy_refcounts=off refcount_bits=16
2025-04-14 10:24:35,393 process L0739 INFO | Command '/.../tmp/qemu-build/qemu-img create -f qcow2 /var/tmp/.avocado-taskky_yb2qf/test-results/tmp_dir56wqq7g0/1-ReverseDebugging_AArch64.test_aarch64_virt/disk.qcow2 128M' finished with 0 after 0.100170269s
2025-04-14 10:24:35,475 __init__ L0314 DEBUG| QEMUMachine "28fc0d7d-bd0a-44c0-afa8-f24a1800132f" created
2025-04-14 10:24:35,475 __init__ L0315 DEBUG| QEMUMachine "28fc0d7d-bd0a-44c0-afa8-f24a1800132f" temp_dir: /var/tmp/.avocado-taskky_yb2qf/test-results/tmp_dir56wqq7g0/1-ReverseDebugging_AArch64.test_aarch64_virt/qemu-machine-052_8e_k
2025-04-14 10:24:35,475 __init__ L0316 DEBUG| QEMUMachine "28fc0d7d-bd0a-44c0-afa8-f24a1800132f" log_dir: /var/tmp/.avocado-taskky_yb2qf/test-results/1-ReverseDebugging_AArch64.test_aarch64_virt
2025-04-14 10:24:36,195 __init__ L0314 DEBUG| QEMUMachine "3f348d83-7aa3-4381-9919-389bc85ed85b" created
2025-04-14 10:24:36,196 __init__ L0315 DEBUG| QEMUMachine "3f348d83-7aa3-4381-9919-389bc85ed85b" temp_dir: /var/tmp/.avocado-taskky_yb2qf/test-results/tmp_dir56wqq7g0/1-ReverseDebugging_AArch64.test_aarch64_virt/qemu-machine-vxlortdq
2025-04-14 10:24:36,196 __init__ L0316 DEBUG| QEMUMachine "3f348d83-7aa3-4381-9919-389bc85ed85b" log_dir: /var/tmp/.avocado-taskky_yb2qf/test-results/1-ReverseDebugging_AArch64.test_aarch64_virt
2025-04-14 10:24:37,623 stacktrace L0039 ERROR|
2025-04-14 10:24:37,628 stacktrace L0041 ERROR| Reproduced traceback from: /usr/lib/python3.13/site-packages/avocado/core/test.py:793
2025-04-14 10:24:37,643 stacktrace L0045 ERROR| Traceback (most recent call last):
2025-04-14 10:24:37,643 stacktrace L0045 ERROR| File "/usr/lib/python3.13/site-packages/avocado/core/decorators.py", line 90, in wrapper
2025-04-14 10:24:37,643 stacktrace L0045 ERROR| return function(obj, *args, **kwargs)
2025-04-14 10:24:37,643 stacktrace L0045 ERROR| File "/.../tmp/qemu-build/tests/avocado/reverse_debugging.py", line 239, in test_aarch64_virt
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| self.reverse_debugging(
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| ~~~~~~~~~~~~~~~~~~~~~~^
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| args=('-kernel', kernel_path))
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| File "/.../tmp/qemu-build/tests/avocado/reverse_debugging.py", line 179, in reverse_debugging
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| if self.vm_get_icount(vm) == last_icount - 1:
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| ~~~~~~~~~~~~~~~~~~^^^^
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| File "/.../tmp/qemu-build/tests/avocado/reverse_debugging.py", line 100, in vm_get_icount
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| return vm.qmp('query-replay')['return']['icount']
2025-04-14 10:24:37,644 stacktrace L0045 ERROR| ~~~~~~^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/machine/machine.py", line 711, in qmp
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| ret = self._qmp.cmd_raw(cmd, args=qmp_args)
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 208, in cmd_raw
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| return self.cmd_obj(qmp_cmd)
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| ~~~~~~~~~~~~^^^^^^^^^
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 186, in cmd_obj
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| self._sync(
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| ~~~~~~~~~~^
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| # pylint: disable=protected-access
2025-04-14 10:24:37,645 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,646 stacktrace L0045 ERROR| ...<5 lines>...
2025-04-14 10:24:37,646 stacktrace L0045 ERROR| self._timeout
2025-04-14 10:24:37,646 stacktrace L0045 ERROR| ^^^^^^^^^^^^^
2025-04-14 10:24:37,646 stacktrace L0045 ERROR| )
2025-04-14 10:24:37,646 stacktrace L0045 ERROR| ^
2025-04-14 10:24:37,646 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 102, in _sync
2025-04-14 10:24:37,646 stacktrace L0045 ERROR| return self._aloop.run_until_complete(
2025-04-14 10:24:37,647 stacktrace L0045 ERROR| ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
2025-04-14 10:24:37,647 stacktrace L0045 ERROR| asyncio.wait_for(future, timeout=timeout)
2025-04-14 10:24:37,647 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,647 stacktrace L0045 ERROR| )
2025-04-14 10:24:37,647 stacktrace L0045 ERROR| ^
2025-04-14 10:24:37,647 stacktrace L0045 ERROR| File "/usr/lib64/python3.13/asyncio/base_events.py", line 725, in run_until_complete
2025-04-14 10:24:37,647 stacktrace L0045 ERROR| return future.result()
2025-04-14 10:24:37,647 stacktrace L0045 ERROR| ~~~~~~~~~~~~~^^
2025-04-14 10:24:37,647 stacktrace L0045 ERROR| File "/usr/lib64/python3.13/asyncio/tasks.py", line 507, in wait_for
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| return await fut
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| ^^^^^^^^^
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/qmp_client.py", line 547, in _raw
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| return await self._execute(msg, assign_id=assign_id)
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/qmp_client.py", line 496, in _execute
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| return await self._reply(exec_id)
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/qmp_client.py", line 463, in _reply
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| raise result
2025-04-14 10:24:37,648 stacktrace L0045 ERROR| qemu.qmp.qmp_client.ExecInterruptedError: Disconnected
2025-04-14 10:24:37,649 stacktrace L0046 ERROR|
2025-04-14 10:24:37,649 test L0798 DEBUG| Local variables:
2025-04-14 10:24:37,671 test L0801 DEBUG| -> obj <class 'reverse_debugging.ReverseDebugging_AArch64'>: 1-ReverseDebugging_AArch64.test_aarch64_virt
2025-04-14 10:24:37,671 test L0801 DEBUG| -> args <class 'tuple'>: ()
2025-04-14 10:24:37,671 test L0801 DEBUG| -> kwargs <class 'dict'>: {}
2025-04-14 10:24:37,671 test L0801 DEBUG| -> condition <class 'str'>: 1
2025-04-14 10:24:37,671 test L0801 DEBUG| -> function <class 'function'>: <function ReverseDebugging_AArch64.test_aarch64_virt at 0x7fc6d4cc87c0>
2025-04-14 10:24:37,672 test L0801 DEBUG| -> message <class 'str'>: Test is unstable on GitLab
2025-04-14 10:24:37,672 test L0801 DEBUG| -> negate <class 'bool'>: True
2025-04-14 10:24:37,673 stacktrace L0039 ERROR|
2025-04-14 10:24:37,673 stacktrace L0041 ERROR| Reproduced traceback from: /usr/lib/python3.13/site-packages/avocado/core/test.py:819
2025-04-14 10:24:37,678 stacktrace L0045 ERROR| Traceback (most recent call last):
2025-04-14 10:24:37,679 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/machine/machine.py", line 580, in _soft_shutdown
2025-04-14 10:24:37,679 stacktrace L0045 ERROR| self.qmp('quit')
2025-04-14 10:24:37,679 stacktrace L0045 ERROR| ~~~~~~~~^^^^^^^^
2025-04-14 10:24:37,679 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/machine/machine.py", line 711, in qmp
2025-04-14 10:24:37,679 stacktrace L0045 ERROR| ret = self._qmp.cmd_raw(cmd, args=qmp_args)
2025-04-14 10:24:37,679 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 208, in cmd_raw
2025-04-14 10:24:37,679 stacktrace L0045 ERROR| return self.cmd_obj(qmp_cmd)
2025-04-14 10:24:37,679 stacktrace L0045 ERROR| ~~~~~~~~~~~~^^^^^^^^^
2025-04-14 10:24:37,679 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 192, in cmd_obj
2025-04-14 10:24:37,680 stacktrace L0045 ERROR| self._qmp._raw(qmp_cmd, assign_id=False),
2025-04-14 10:24:37,680 stacktrace L0045 ERROR| ~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,680 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 155, in _wrapper
2025-04-14 10:24:37,680 stacktrace L0045 ERROR| raise StateError(emsg, proto.runstate, required_state)
2025-04-14 10:24:37,680 stacktrace L0045 ERROR| qemu.qmp.protocol.StateError: QMPClient is disconnecting. Call disconnect() to return to IDLE state.
2025-04-14 10:24:37,680 stacktrace L0045 ERROR|
2025-04-14 10:24:37,680 stacktrace L0045 ERROR| During handling of the above exception, another exception occurred:
2025-04-14 10:24:37,680 stacktrace L0045 ERROR|
2025-04-14 10:24:37,680 stacktrace L0045 ERROR| Traceback (most recent call last):
2025-04-14 10:24:37,680 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/machine/machine.py", line 611, in _do_shutdown
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| self._soft_shutdown(timeout)
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| ~~~~~~~~~~~~~~~~~~~^^^^^^^^^
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/machine/machine.py", line 583, in _soft_shutdown
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| self._close_qmp_connection()
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| ~~~~~~~~~~~~~~~~~~~~~~~~~~^^
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/machine/machine.py", line 501, in _close_qmp_connection
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| self._qmp.close()
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| ~~~~~~~~~~~~~~~^^
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 281, in close
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| self._sync(
2025-04-14 10:24:37,681 stacktrace L0045 ERROR| ~~~~~~~~~~^
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| self._qmp.disconnect()
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| )
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| ^
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 102, in _sync
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| return self._aloop.run_until_complete(
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| asyncio.wait_for(future, timeout=timeout)
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| )
2025-04-14 10:24:37,682 stacktrace L0045 ERROR| ^
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| File "/usr/lib64/python3.13/asyncio/base_events.py", line 725, in run_until_complete
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| return future.result()
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| ~~~~~~~~~~~~~^^
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| File "/usr/lib64/python3.13/asyncio/tasks.py", line 507, in wait_for
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| return await fut
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| ^^^^^^^^^
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 399, in disconnect
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| await self._wait_disconnect()
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 719, in _wait_disconnect
2025-04-14 10:24:37,683 stacktrace L0045 ERROR| await all_defined_tasks # Raise Exceptions from the bottom half.
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 870, in _bh_loop_forever
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| await async_fn()
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 908, in _bh_recv_message
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| msg = await self._recv()
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 1009, in _recv
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| message = await self._do_recv()
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/qmp_client.py", line 402, in _do_recv
2025-04-14 10:24:37,684 stacktrace L0045 ERROR| msg_bytes = await self._readline()
2025-04-14 10:24:37,685 stacktrace L0045 ERROR| ^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,685 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 977, in _readline
2025-04-14 10:24:37,685 stacktrace L0045 ERROR| raise EOFError
2025-04-14 10:24:37,685 stacktrace L0045 ERROR| EOFError
2025-04-14 10:24:37,685 stacktrace L0045 ERROR|
2025-04-14 10:24:37,685 stacktrace L0045 ERROR| The above exception was the direct cause of the following exception:
2025-04-14 10:24:37,685 stacktrace L0045 ERROR|
2025-04-14 10:24:37,685 stacktrace L0045 ERROR| Traceback (most recent call last):
2025-04-14 10:24:37,685 stacktrace L0045 ERROR| File "/.../tmp/qemu-build/tests/avocado/avocado_qemu/__init__.py", line 372, in tearDown
2025-04-14 10:24:37,685 stacktrace L0045 ERROR| vm.shutdown()
2025-04-14 10:24:37,685 stacktrace L0045 ERROR| ~~~~~~~~~~~^^
2025-04-14 10:24:37,686 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/machine/machine.py", line 648, in shutdown
2025-04-14 10:24:37,686 stacktrace L0045 ERROR| self._do_shutdown(timeout)
2025-04-14 10:24:37,686 stacktrace L0045 ERROR| ~~~~~~~~~~~~~~~~~^^^^^^^^^
2025-04-14 10:24:37,686 stacktrace L0045 ERROR| File "/.../devel/qemu/python/qemu/machine/machine.py", line 618, in _do_shutdown
2025-04-14 10:24:37,686 stacktrace L0045 ERROR| raise AbnormalShutdown("Could not perform graceful shutdown") \
2025-04-14 10:24:37,686 stacktrace L0045 ERROR| from exc
2025-04-14 10:24:37,686 stacktrace L0045 ERROR| qemu.machine.machine.AbnormalShutdown: Could not perform graceful shutdown
2025-04-14 10:24:37,686 stacktrace L0046 ERROR|
2025-04-14 10:24:37,694 test L0941 ERROR| Traceback (most recent call last):
2025-04-14 10:24:37,694 test L0941 ERROR| File "/usr/lib/python3.13/site-packages/avocado/core/test.py", line 881, in _run_avocado
raise test_exception
2025-04-14 10:24:37,694 test L0941 ERROR| File "/usr/lib/python3.13/site-packages/avocado/core/test.py", line 788, in _run_avocado
testMethod()
~~~~~~~~~~^^
2025-04-14 10:24:37,695 test L0941 ERROR| File "/usr/lib/python3.13/site-packages/avocado/core/decorators.py", line 90, in wrapper
return function(obj, *args, **kwargs)
2025-04-14 10:24:37,695 test L0941 ERROR| File "/.../tmp/qemu-build/tests/avocado/reverse_debugging.py", line 239, in test_aarch64_virt
self.reverse_debugging(
~~~~~~~~~~~~~~~~~~~~~~^
args=('-kernel', kernel_path))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,695 test L0941 ERROR| File "/.../tmp/qemu-build/tests/avocado/reverse_debugging.py", line 179, in reverse_debugging
if self.vm_get_icount(vm) == last_icount - 1:
~~~~~~~~~~~~~~~~~~^^^^
2025-04-14 10:24:37,695 test L0941 ERROR| File "/.../tmp/qemu-build/tests/avocado/reverse_debugging.py", line 100, in vm_get_icount
return vm.qmp('query-replay')['return']['icount']
~~~~~~^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,695 test L0941 ERROR| File "/.../devel/qemu/python/qemu/machine/machine.py", line 711, in qmp
ret = self._qmp.cmd_raw(cmd, args=qmp_args)
2025-04-14 10:24:37,695 test L0941 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 208, in cmd_raw
return self.cmd_obj(qmp_cmd)
~~~~~~~~~~~~^^^^^^^^^
2025-04-14 10:24:37,695 test L0941 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 186, in cmd_obj
self._sync(
~~~~~~~~~~^
# pylint: disable=protected-access
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
...<5 lines>...
self._timeout
^^^^^^^^^^^^^
)
^
2025-04-14 10:24:37,695 test L0941 ERROR| File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 102, in _sync
return self._aloop.run_until_complete(
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
asyncio.wait_for(future, timeout=timeout)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
)
^
2025-04-14 10:24:37,695 test L0941 ERROR| File "/usr/lib64/python3.13/asyncio/base_events.py", line 725, in run_until_complete
return future.result()
~~~~~~~~~~~~~^^
2025-04-14 10:24:37,695 test L0941 ERROR| File "/usr/lib64/python3.13/asyncio/tasks.py", line 507, in wait_for
return await fut
^^^^^^^^^
2025-04-14 10:24:37,696 test L0941 ERROR| File "/.../devel/qemu/python/qemu/qmp/qmp_client.py", line 547, in _raw
return await self._execute(msg, assign_id=assign_id)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,696 test L0941 ERROR| File "/.../devel/qemu/python/qemu/qmp/qmp_client.py", line 496, in _execute
return await self._reply(exec_id)
^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-04-14 10:24:37,696 test L0941 ERROR| File "/.../devel/qemu/python/qemu/qmp/qmp_client.py", line 463, in _reply
raise result
2025-04-14 10:24:37,696 test L0941 ERROR| qemu.qmp.qmp_client.ExecInterruptedError: Disconnected
2025-04-14 10:24:37,696 test L0956 ERROR| ERROR 1-ReverseDebugging_AArch64.test_aarch64_virt -> ExecInterruptedError: Disconnected
2025-04-14 10:24:37,696 test L0948 INFO |
```
Steps to reproduce:
1. ``make check-venv``
2. Run something in the background that keeps all CPUs busy
3. ``for ((x=0;x<20;x++)); do QEMU_TEST_FLAKY_TESTS=1 pyvenv/bin/avocado run tests/avocado/reverse_debugging.py:ReverseDebugging_AArch64.test_aarch64_virt ; done``
Additional information:
The problem can be reproduced with the test converted to the functional framework, too (that's where I noticed it first). In that case the stack trace looked like this:
```
$ QEMU_TEST_ALLOW_SLOW=1 QEMU_TEST_ALLOW_UNTRUSTED_CODE=1 QEMU_TEST_FLAKY_TESTS=1 QEMU_TEST_ALLOW_LARGE_STORAGE=1 ~/devel/qemu/tests/functional/test_aarch64_reverse_debug.py
TAP version 13
Traceback (most recent call last):
File "/.../devel/qemu/tests/functional/test_aarch64_reverse_debug.py", line 33, in test_aarch64_virt
self.reverse_debugging(args=('-kernel', kernel_path))
~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/.../devel/qemu/tests/functional/reverse_debugging.py", line 147, in reverse_debugging
pc = self.get_pc(g)
File "/.../devel/qemu/tests/functional/reverse_debugging.py", line 82, in get_pc
return self.get_reg(g, self.REG_PC)
~~~~~~~~~~~~^^^^^^^^^^^^^^^^
File "/.../devel/qemu/tests/functional/reverse_debugging.py", line 77, in get_reg
return self.get_reg_le(g, reg)
~~~~~~~~~~~~~~~^^^^^^^^
File "/.../devel/qemu/tests/functional/reverse_debugging.py", line 63, in get_reg_le
res = g.cmd(b'p%x' % reg)
File "/usr/lib/python3.13/site-packages/avocado/utils/gdb.py", line 783, in cmd
response_payload = self.decode(result)
File "/usr/lib/python3.13/site-packages/avocado/utils/gdb.py", line 738, in decode
raise InvalidPacketError
avocado.utils.gdb.InvalidPacketError
not ok 1 test_aarch64_reverse_debug.ReverseDebugging_AArch64.test_aarch64_virt
Traceback (most recent call last):
File "/.../devel/qemu/python/qemu/machine/machine.py", line 580, in _soft_shutdown
self.qmp('quit')
~~~~~~~~^^^^^^^^
File "/.../devel/qemu/python/qemu/machine/machine.py", line 711, in qmp
ret = self._qmp.cmd_raw(cmd, args=qmp_args)
File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 208, in cmd_raw
return self.cmd_obj(qmp_cmd)
~~~~~~~~~~~~^^^^^^^^^
File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 186, in cmd_obj
self._sync(
~~~~~~~~~~^
# pylint: disable=protected-access
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
...<5 lines>...
self._timeout
^^^^^^^^^^^^^
)
^
File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 102, in _sync
return self._aloop.run_until_complete(
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
asyncio.wait_for(future, timeout=timeout)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
)
^
File "/usr/lib64/python3.13/asyncio/base_events.py", line 725, in run_until_complete
return future.result()
~~~~~~~~~~~~~^^
File "/usr/lib64/python3.13/asyncio/tasks.py", line 507, in wait_for
return await fut
^^^^^^^^^
File "/.../devel/qemu/python/qemu/qmp/qmp_client.py", line 547, in _raw
return await self._execute(msg, assign_id=assign_id)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/.../devel/qemu/python/qemu/qmp/qmp_client.py", line 496, in _execute
return await self._reply(exec_id)
^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/.../devel/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 "/.../devel/qemu/python/qemu/machine/machine.py", line 611, in _do_shutdown
self._soft_shutdown(timeout)
~~~~~~~~~~~~~~~~~~~^^^^^^^^^
File "/.../devel/qemu/python/qemu/machine/machine.py", line 583, in _soft_shutdown
self._close_qmp_connection()
~~~~~~~~~~~~~~~~~~~~~~~~~~^^
File "/.../devel/qemu/python/qemu/machine/machine.py", line 501, in _close_qmp_connection
self._qmp.close()
~~~~~~~~~~~~~~~^^
File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 281, in close
self._sync(
~~~~~~~~~~^
self._qmp.disconnect()
^^^^^^^^^^^^^^^^^^^^^^
)
^
File "/.../devel/qemu/python/qemu/qmp/legacy.py", line 102, in _sync
return self._aloop.run_until_complete(
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
asyncio.wait_for(future, timeout=timeout)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
)
^
File "/usr/lib64/python3.13/asyncio/base_events.py", line 725, in run_until_complete
return future.result()
~~~~~~~~~~~~~^^
File "/usr/lib64/python3.13/asyncio/tasks.py", line 507, in wait_for
return await fut
^^^^^^^^^
File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 399, in disconnect
await self._wait_disconnect()
File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 719, in _wait_disconnect
await all_defined_tasks # Raise Exceptions from the bottom half.
^^^^^^^^^^^^^^^^^^^^^^^
File "/.../devel/qemu/python/qemu/qmp/protocol.py", line 834, in _bh_close_stream
await wait_closed(self._writer)
File "/.../devel/qemu/python/qemu/qmp/util.py", line 130, in wait_closed
await writer.wait_closed()
File "/usr/lib64/python3.13/asyncio/streams.py", line 358, in wait_closed
await self._protocol._get_close_waiter(self)
File "/usr/lib64/python3.13/asyncio/selector_events.py", line 1067, in write
n = self._sock.send(data)
BrokenPipeError: [Errno 32] Broken pipe
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/.../devel/qemu/tests/functional/qemu_test/testcase.py", line 398, in tearDown
vm.shutdown()
~~~~~~~~~~~^^
File "/.../devel/qemu/python/qemu/machine/machine.py", line 648, in shutdown
self._do_shutdown(timeout)
~~~~~~~~~~~~~~~~~^^^^^^^^^
File "/.../devel/qemu/python/qemu/machine/machine.py", line 618, in _do_shutdown
raise AbnormalShutdown("Could not perform graceful shutdown") \
from exc
qemu.machine.machine.AbnormalShutdown: Could not perform graceful shutdown
not ok 1 test_aarch64_reverse_debug.ReverseDebugging_AArch64.test_aarch64_virt
1..1
```
|