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
369
370
371
|
user-level: 0.943
KVM: 0.922
peripherals: 0.922
hypervisor: 0.921
permissions: 0.905
TCG: 0.903
VMM: 0.902
performance: 0.877
debug: 0.874
device: 0.855
graphic: 0.853
arm: 0.848
assembly: 0.847
vnc: 0.839
register: 0.829
ppc: 0.822
risc-v: 0.822
boot: 0.812
files: 0.811
socket: 0.809
PID: 0.808
virtual: 0.808
mistranslation: 0.797
architecture: 0.793
kernel: 0.793
network: 0.792
semantic: 0.790
x86: 0.746
i386: 0.742
ARM M: Systick first wrap delayed (qemu-timers/icount prb?)
When running this kind of code with qemu:
static void SysTickISR(void)
{
printf("SysTick\n");
}
void main()
{
volatile int i, j;
printf("setup timer\n");
*(uint32_t*) 0xE000E014 = 0x8FFFFF; //reload value
*(uint32_t*) 0xE000E018 = 0; //force reload
*(uint32_t*) 0xE000E010 = 7; //cpu clk + ISR + enable
for (j = 0; j < 0x100; j++) {
for (i = 0; i < 0x100000; i++)
;
printf("cnt %08x -- %8x\n", *(uint32_t*) 0xE000E018, *(uint32_t*)0xE000E010);
}
}
I get the following output (comments added after '#'):
setup timer
cnt 007cccca -- 7
cnt 006998a2 -- 7
cnt 00566479 -- 7
cnt 0043304f -- 7
cnt 002ffc26 -- 7
cnt 001cc7fd -- 7
cnt 000993d5 -- 7
cnt 00000000 -- 7 <--- problem here, systick should wrap and raise isr
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
SysTick <--- delayed isr occuring here
cnt 000986e0 -- 10007
SysTick
cnt 00865290 -- 10007 <---- then running fine as long as regs not modified
cnt 00731e51 -- 7
cnt 005fea27 -- 7
cnt 004cb5ff -- 7
cnt 003981d6 -- 7
cnt 00264dad -- 7
cnt 00131984 -- 7
SysTick
cnt 008fe545 -- 10007
cnt 007cb106 -- 7
cnt 00697cdd -- 7
cnt 005648b4 -- 7
cnt 0043148b -- 7
cnt 002fe061 -- 7
cnt 001cac38 -- 7
cnt 00097810 -- 7
SysTick
cnt 008643d6 -- 10007
cnt 00730f97 -- 7
cnt 005fdb6d -- 7
cnt 004ca745 -- 7
cnt 0039731c -- 7
cnt 00263ef3 -- 7
cnt 00130aca -- 7
SysTick
cnt 008fd68b -- 10007
cnt 007ca24c -- 7
cnt 00696e23 -- 7
cnt 005639fa -- 7
cnt 004305d1 -- 7
cnt 002fd1a8 -- 7
cnt 001c9d7f -- 7
cnt 00096956 -- 7
SysTick
cnt 0086351d -- 10007
cnt 007300dd -- 7
cnt 005fccb4 -- 7
cnt 004c988c -- 7
cnt 00396463 -- 7
cnt 00263039 -- 7
cnt 0012fc10 -- 7
[...]
Command line and version:
qemu-system-arm -M lm3s6965evb -nographic -kernel hello.bin -monitor stdio -serial file:/dev/pts/6 -icount 4 -cpu cortex-m4
QEMU 2.11.50
I am compiling from git repo, head is:
commit f32408f3b472a088467474ab152be3b6285b2d7b
Author: Daniel P. Berrangé <email address hidden>
Date: Tue Mar 6 13:43:17 2018 +0000
Config options:
./configure --target-list=arm-softmmu --enable-debug --disable-slirp --enable-tcg-interpreter --disable-blobs --disable-docs --disable-guest-agent --disable-gnutls --disable-nettle --disable-gcrypt --disable-sdl --disable-gtk --disable-vnc --disable-virtfs --disable-mpath --disable-xen --disable-brlapi --disable-curl --disable-bluez --disable-kvm --disable-hax --disable-hvf --disable-whpx --disable-rdma --disable-vde --disable-netmap --disable-linux-aio --disable-cap-ng --disable-attr --disable-vhost-net --disable-spice --disable-rbd --disable-libiscsi --disable-libnfs --disable-smartcard --disable-libusb --disable-live-block-migration --disable-usb-redir --disable-lzo --disable-snappy --disable-bzip2 --disable-seccomp --disable-glusterfs --disable-tpm --disable-libssh2 --disable-numa --disable-libxml2 --disable-tcmalloc --disable-jemalloc --disable-replication --disable-vhost-vsock --disable-opengl --disable-virglrenderer --disable-xfsctl --disable-qom-cast-debug --disable-vxhs --disable-crypto-afalg --disable-vhost-user --disable-capstone --disable-pie --extra-cflags=-mtune=native
Not working with git tag 2.10.0 (almost same config)
Working with stock qemu-arm 2.5.0 from Ubuntu 16.04.
I started investigating, though I am not familiar with qemu code and I could see that the execution is not geting out of qemu_tcg_rr_cpu_thread_fn() 'while' loop and timers are not triggered because the values in cpu->icount_extra or cpu->icount_budget are not to modified accordingly after the timer is set (host side) when the systick register is written (target side).
Delay between the counter hitting zero and the ISR firing is architecturally permitted (the interrupt must be recognized in finite time or at a context synchronizing event, but not necessarily at the same 'clock tick' that the counter hits zero). If you want to ensure that an interrupt has been taken before you read the counter value, you need to use an ISB instruction in your loop.
(There are also some buggy behaviours in our systick device implementation, but in this case I don't think you're running into them.)
I tried to insert an ISB in the loop but I get more or less the same result.
However, I guess from your response that I did not explain the problem well enough. I understand that qemu will not be cycle accurate, however, here, we are not even "one million cycles accurate"! The counter would have the time to wrap twice before qemu is taking into account the first ISR... and if we check the following ISR time, we have a good accuracy, so I still think this is a bug.
Morever, as said above, if I test with qemu 2.5.0 from Ubuntu package I get an accurate behavior:
setup timer
cnt 00799997 -- 7
cnt 0063323b -- 7
cnt 004ccade -- 7
cnt 00366383 -- 7
cnt 001ffc26 -- 7
cnt 000994ca -- 7
SysTick
cnt 00832d5e -- 10007
cnt 006cc5eb -- 7
cnt 00565e8f -- 7
cnt 003ff733 -- 7
cnt 00298fd7 -- 7
cnt 0013287b -- 7
SysTick
cnt 008cc108 -- 10007
cnt 00765996 -- 7
cnt 005ff239 -- 7
cnt 00498add -- 7
cnt 00332381 -- 7
cnt 001cbc24 -- 7
cnt 000654c8 -- 7
SysTick
cnt 007fed5c -- 10007
cnt 006985ea -- 7
cnt 00531e8d -- 7
cnt 003cb731 -- 7
cnt 00264fd5 -- 7
cnt 000fe879 -- 7
SysTick
cnt 0089810c -- 10007
cnt 0073199a -- 7
cnt 005cb23d -- 7
[...]
So here I would suspect either a regression in the code or a wrong combination of options when I compile it myself. I am trying to recompile version 2.5 myself to sort this out but I am running in other errors.
OK, I will see if I can find some time to investigate this. Can you attach your guest binary, please?
Please find the binary attached.
I have been trying several versions and it looks like the regression occured between v2.8.0 and v2.9.0.
Ok I spent more time trying to identify the commits giving problem.
So before 8d04fb5, qemu is executing the binary as expected:
setup timer
cnt 007cccca -- 7
cnt 006998a2 -- 7
cnt 00566479 -- 7
cnt 0043304f -- 7
cnt 002ffc26 -- 7
cnt 001cc7fd -- 7
cnt 000993d5 -- 7
SysTick
cnt 00865f9c -- 10007
cnt 00732b5c -- 7
cnt 005ff733 -- 7
cnt 004cc30a -- 7
[...]
Then, after this commit "tcg: drop global lock during TCG code execution":
https://git.qemu.org/?p=qemu.git;a=commit;h=8d04fb55dec381bc5105cb47f29d918e579e8cbd
things start to look bad (but not the same way I first ran into):
setup timer
SysTick
cnt 00000000 -- 10007
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 008ff3e3 -- 7
cnt 007cbfba -- 7
cnt 00698b92 -- 7
cnt 00565768 -- 7
cnt 0043233f -- 7
cnt 002fef16 -- 7
cnt 001cbaed -- 7
cnt 000986c5 -- 7
SysTick
cnt 0086528b -- 10007
cnt 00731e4c -- 7
cnt 005fea23 -- 7
cnt 004cb5fa -- 7
cnt 003981d1 -- 7
[...]
Then, not long after, this commit changes a little bit the prb "icount: process QEMU_CLOCK_VIRTUAL timers in vCPU thread"
https://git.qemu.org/?p=qemu.git;a=commit;h=6b8f0187a4d7c263e356302f8d308655372a4b5b
Output then looks like:
setup timer
cnt 007cccca -- 7
cnt 006998a2 -- 7
cnt 00566479 -- 7
cnt 0043304f -- 7
cnt 002ffc26 -- 7
cnt 001cc7fd -- 7
cnt 000993d5 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
cnt 00000000 -- 7
SysTick
cnt 000986e0 -- 10007
SysTick
cnt 00865290 -- 10007
cnt 00731e51 -- 7
cnt 005fea27 -- 7
[...]
... and it seems this very problem has been occurring up to now.
I am here using the binary attached, with this command line:
qemu-system-arm -M lm3s6965evb -nographic -kernel hello.bin -serial file:$(tty) -icount 4 -cpu cortex-m4
And with these build options:
./configure --target-list=arm-softmmu --disable-slirp --disable-blobs --disable-docs --disable-guest-agent --disable-gnutls --disable-nettle --disable-gcrypt --disable-sdl --disable-gtk --disable-vnc --disable-virtfs --disable-xen --disable-brlapi --disable-curl --disable-bluez --disable-kvm --disable-rdma --disable-vde --disable-netmap --disable-linux-aio --disable-cap-ng --disable-attr --disable-vhost-net --disable-spice --disable-rbd --disable-libiscsi --disable-libnfs --disable-smartcard --disable-libusb --disable-usb-redir --disable-lzo --disable-snappy --disable-bzip2 --disable-seccomp --disable-glusterfs --disable-tpm --disable-libssh2 --disable-numa --disable-tcmalloc --disable-jemalloc --disable-opengl --disable-virglrenderer --disable-xfsctl --disable-qom-cast-debug --disable-pie --extra-cflags=-mtune=native
Note that, to prevent MTTCG/icount error, we must modify configure for the arm target with:
mttcg="no"
I finally implemented a workaround to correct the problem:
in cpus.c : qemu_start_warp_timer(), in the "if (deadline > 0) { ... }" part, I added:
CPUState *cpu;
CPU_FOREACH(cpu) {
atomic_mb_set(&cpu->exit_request, 1);
}
I do not understand more than 5% of the code I am messing up, so this hack is probably broken...
Then I tested a bit more the code with different testcases... and I found a new bug when writing a reload value smaller than the current counter (the counter will then read as 0). It is due to this piece of code in armv7m_systick.c : systick_read() :
/* The interrupt in triggered when the timer reaches zero.
However the counter is not reloaded until the next clock
tick. This is a hack to return zero during the first tick. */
if (val > s->reload) {
val = 0;
}
Well this is not really a prb for me with normal code, and it looks like under control, but I can open another bug if needed.
The workaround I described above is actually not the good one, because of this check occurring just before:
if (!all_cpu_threads_idle()) {
return;
}
The exit request setting must be done before, so my code looks like this:
CPUState *cpu;
CPU_FOREACH(cpu) {
atomic_mb_set(&cpu->exit_request, 1);
}
if (!all_cpu_threads_idle()) {
return;
}
(version is v2.11.0-2122-g9fa673c-dirty)
Thanks for the test case; that was very useful. I've sent a patch which should fix this bug:
https://patchwork.ozlabs.org/patch/895693/
The "writing a reload value smaller than the current counter" bug is one of the ones I know about in our systick implementation. I may have time to overhaul that code in the 2.13 timeframe.
Hi Peter,
I just tested your patch, I confirm it is also working on my side. Many thanks.
Now fixed in master, commit c52e7132d7c885, and will be in 2.12.0.
|