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
|
permissions: 0.985
architecture: 0.980
user-level: 0.979
debug: 0.979
arm: 0.979
kernel: 0.975
graphic: 0.974
network: 0.973
assembly: 0.972
device: 0.970
performance: 0.969
semantic: 0.968
alpha: 0.967
boot: 0.967
socket: 0.966
register: 0.964
files: 0.962
PID: 0.959
risc-v: 0.950
mistranslation: 0.948
peripherals: 0.945
vnc: 0.945
virtual: 0.940
ppc: 0.939
TCG: 0.938
operating system: 0.911
hypervisor: 0.908
VMM: 0.892
KVM: 0.881
x86: 0.865
i386: 0.851
[Bug] Take more 150s to boot qemu on ARM64
Hi all,
I encounter a issue with kernel 5.19-rc1 on a ARM64 board: it takes
about 150s between beginning to run qemu command and beginng to boot
Linux kernel ("EFI stub: Booting Linux Kernel...").
But in kernel 5.18-rc4, it only takes about 5s. I git bisect the kernel
code and it finds c2445d387850 ("srcu: Add contention check to
call_srcu() srcu_data ->lock acquisition").
The qemu (qemu version is 6.2.92) command i run is :
./qemu-system-aarch64 -m 4G,slots=4,maxmem=8g \
--trace "kvm*" \
-cpu host \
-machine virt,accel=kvm,gic-version=3 \
-machine smp.cpus=2,smp.sockets=2 \
-no-reboot \
-nographic \
-monitor unix:/home/cx/qmp-test,server,nowait \
-bios /home/cx/boot/QEMU_EFI.fd \
-kernel /home/cx/boot/Image \
-device
pcie-root-port,port=0x8,chassis=1,id=net1,bus=pcie.0,multifunction=on,addr=0x1
\
-device vfio-pci,host=7d:01.3,id=net0 \
-device virtio-blk-pci,drive=drive0,id=virtblk0,num-queues=4 \
-drive file=/home/cx/boot/boot_ubuntu.img,if=none,id=drive0 \
-append "rdinit=init console=ttyAMA0 root=/dev/vda rootfstype=ext4 rw " \
-net none \
-D /home/cx/qemu_log.txt
I am not familiar with rcu code, and don't know how it causes the issue.
Do you have any idea about this issue?
Best Regard,
Xiang Chen
On Mon, Jun 13, 2022 at 08:26:34PM +0800, chenxiang (M) wrote:
>
Hi all,
>
>
I encounter a issue with kernel 5.19-rc1 on a ARM64 board: it takes about
>
150s between beginning to run qemu command and beginng to boot Linux kernel
>
("EFI stub: Booting Linux Kernel...").
>
>
But in kernel 5.18-rc4, it only takes about 5s. I git bisect the kernel code
>
and it finds c2445d387850 ("srcu: Add contention check to call_srcu()
>
srcu_data ->lock acquisition").
>
>
The qemu (qemu version is 6.2.92) command i run is :
>
>
./qemu-system-aarch64 -m 4G,slots=4,maxmem=8g \
>
--trace "kvm*" \
>
-cpu host \
>
-machine virt,accel=kvm,gic-version=3 \
>
-machine smp.cpus=2,smp.sockets=2 \
>
-no-reboot \
>
-nographic \
>
-monitor unix:/home/cx/qmp-test,server,nowait \
>
-bios /home/cx/boot/QEMU_EFI.fd \
>
-kernel /home/cx/boot/Image \
>
-device
>
pcie-root-port,port=0x8,chassis=1,id=net1,bus=pcie.0,multifunction=on,addr=0x1
>
\
>
-device vfio-pci,host=7d:01.3,id=net0 \
>
-device virtio-blk-pci,drive=drive0,id=virtblk0,num-queues=4 \
>
-drive file=/home/cx/boot/boot_ubuntu.img,if=none,id=drive0 \
>
-append "rdinit=init console=ttyAMA0 root=/dev/vda rootfstype=ext4 rw " \
>
-net none \
>
-D /home/cx/qemu_log.txt
>
>
I am not familiar with rcu code, and don't know how it causes the issue. Do
>
you have any idea about this issue?
Please see the discussion here:
https://lore.kernel.org/all/20615615-0013-5adc-584f-2b1d5c03ebfc@linaro.org/
Though that report requires ACPI to be forced on to get the
delay, which results in more than 9,000 back-to-back calls to
synchronize_srcu_expedited(). I cannot reproduce this on my setup, even
with an artificial tight loop invoking synchronize_srcu_expedited(),
but then again I don't have ARM hardware.
My current guess is that the following patch, but with larger values for
SRCU_MAX_NODELAY_PHASE. Here "larger" might well be up in the hundreds,
or perhaps even larger.
If you get a chance to experiment with this, could you please reply
to the discussion at the above URL? (Or let me know, and I can CC
you on the next message in that thread.)
Thanx, Paul
------------------------------------------------------------------------
diff --git a/kernel/rcu/srcutree.c b/kernel/rcu/srcutree.c
index 50ba70f019dea..0db7873f4e95b 100644
--- a/kernel/rcu/srcutree.c
+++ b/kernel/rcu/srcutree.c
@@ -513,7 +513,7 @@ static bool srcu_readers_active(struct srcu_struct *ssp)
#define SRCU_INTERVAL 1 // Base delay if no expedited GPs
pending.
#define SRCU_MAX_INTERVAL 10 // Maximum incremental delay from slow
readers.
-#define SRCU_MAX_NODELAY_PHASE 1 // Maximum per-GP-phase consecutive
no-delay instances.
+#define SRCU_MAX_NODELAY_PHASE 3 // Maximum per-GP-phase consecutive
no-delay instances.
#define SRCU_MAX_NODELAY 100 // Maximum consecutive no-delay
instances.
/*
@@ -522,16 +522,22 @@ static bool srcu_readers_active(struct srcu_struct *ssp)
*/
static unsigned long srcu_get_delay(struct srcu_struct *ssp)
{
+ unsigned long gpstart;
+ unsigned long j;
unsigned long jbase = SRCU_INTERVAL;
if (ULONG_CMP_LT(READ_ONCE(ssp->srcu_gp_seq),
READ_ONCE(ssp->srcu_gp_seq_needed_exp)))
jbase = 0;
- if (rcu_seq_state(READ_ONCE(ssp->srcu_gp_seq)))
- jbase += jiffies - READ_ONCE(ssp->srcu_gp_start);
- if (!jbase) {
- WRITE_ONCE(ssp->srcu_n_exp_nodelay,
READ_ONCE(ssp->srcu_n_exp_nodelay) + 1);
- if (READ_ONCE(ssp->srcu_n_exp_nodelay) > SRCU_MAX_NODELAY_PHASE)
- jbase = 1;
+ if (rcu_seq_state(READ_ONCE(ssp->srcu_gp_seq))) {
+ j = jiffies - 1;
+ gpstart = READ_ONCE(ssp->srcu_gp_start);
+ if (time_after(j, gpstart))
+ jbase += j - gpstart;
+ if (!jbase) {
+ WRITE_ONCE(ssp->srcu_n_exp_nodelay,
READ_ONCE(ssp->srcu_n_exp_nodelay) + 1);
+ if (READ_ONCE(ssp->srcu_n_exp_nodelay) >
SRCU_MAX_NODELAY_PHASE)
+ jbase = 1;
+ }
}
return jbase > SRCU_MAX_INTERVAL ? SRCU_MAX_INTERVAL : jbase;
}
å¨ 2022/6/13 21:22, Paul E. McKenney åé:
On Mon, Jun 13, 2022 at 08:26:34PM +0800, chenxiang (M) wrote:
Hi all,
I encounter a issue with kernel 5.19-rc1 on a ARM64 board: it takes about
150s between beginning to run qemu command and beginng to boot Linux kernel
("EFI stub: Booting Linux Kernel...").
But in kernel 5.18-rc4, it only takes about 5s. I git bisect the kernel code
and it finds c2445d387850 ("srcu: Add contention check to call_srcu()
srcu_data ->lock acquisition").
The qemu (qemu version is 6.2.92) command i run is :
./qemu-system-aarch64 -m 4G,slots=4,maxmem=8g \
--trace "kvm*" \
-cpu host \
-machine virt,accel=kvm,gic-version=3 \
-machine smp.cpus=2,smp.sockets=2 \
-no-reboot \
-nographic \
-monitor unix:/home/cx/qmp-test,server,nowait \
-bios /home/cx/boot/QEMU_EFI.fd \
-kernel /home/cx/boot/Image \
-device
pcie-root-port,port=0x8,chassis=1,id=net1,bus=pcie.0,multifunction=on,addr=0x1
\
-device vfio-pci,host=7d:01.3,id=net0 \
-device virtio-blk-pci,drive=drive0,id=virtblk0,num-queues=4 \
-drive file=/home/cx/boot/boot_ubuntu.img,if=none,id=drive0 \
-append "rdinit=init console=ttyAMA0 root=/dev/vda rootfstype=ext4 rw " \
-net none \
-D /home/cx/qemu_log.txt
I am not familiar with rcu code, and don't know how it causes the issue. Do
you have any idea about this issue?
Please see the discussion here:
https://lore.kernel.org/all/20615615-0013-5adc-584f-2b1d5c03ebfc@linaro.org/
Though that report requires ACPI to be forced on to get the
delay, which results in more than 9,000 back-to-back calls to
synchronize_srcu_expedited(). I cannot reproduce this on my setup, even
with an artificial tight loop invoking synchronize_srcu_expedited(),
but then again I don't have ARM hardware.
My current guess is that the following patch, but with larger values for
SRCU_MAX_NODELAY_PHASE. Here "larger" might well be up in the hundreds,
or perhaps even larger.
If you get a chance to experiment with this, could you please reply
to the discussion at the above URL? (Or let me know, and I can CC
you on the next message in that thread.)
Ok, thanks, i will reply it on above URL.
Thanx, Paul
------------------------------------------------------------------------
diff --git a/kernel/rcu/srcutree.c b/kernel/rcu/srcutree.c
index 50ba70f019dea..0db7873f4e95b 100644
--- a/kernel/rcu/srcutree.c
+++ b/kernel/rcu/srcutree.c
@@ -513,7 +513,7 @@ static bool srcu_readers_active(struct srcu_struct *ssp)
#define SRCU_INTERVAL 1 // Base delay if no expedited GPs pending.
#define SRCU_MAX_INTERVAL 10 // Maximum incremental delay from slow
readers.
-#define SRCU_MAX_NODELAY_PHASE 1 // Maximum per-GP-phase consecutive
no-delay instances.
+#define SRCU_MAX_NODELAY_PHASE 3 // Maximum per-GP-phase consecutive
no-delay instances.
#define SRCU_MAX_NODELAY 100 // Maximum consecutive no-delay
instances.
/*
@@ -522,16 +522,22 @@ static bool srcu_readers_active(struct srcu_struct *ssp)
*/
static unsigned long srcu_get_delay(struct srcu_struct *ssp)
{
+ unsigned long gpstart;
+ unsigned long j;
unsigned long jbase = SRCU_INTERVAL;
if (ULONG_CMP_LT(READ_ONCE(ssp->srcu_gp_seq), READ_ONCE(ssp->srcu_gp_seq_needed_exp)))
jbase = 0;
- if (rcu_seq_state(READ_ONCE(ssp->srcu_gp_seq)))
- jbase += jiffies - READ_ONCE(ssp->srcu_gp_start);
- if (!jbase) {
- WRITE_ONCE(ssp->srcu_n_exp_nodelay,
READ_ONCE(ssp->srcu_n_exp_nodelay) + 1);
- if (READ_ONCE(ssp->srcu_n_exp_nodelay) > SRCU_MAX_NODELAY_PHASE)
- jbase = 1;
+ if (rcu_seq_state(READ_ONCE(ssp->srcu_gp_seq))) {
+ j = jiffies - 1;
+ gpstart = READ_ONCE(ssp->srcu_gp_start);
+ if (time_after(j, gpstart))
+ jbase += j - gpstart;
+ if (!jbase) {
+ WRITE_ONCE(ssp->srcu_n_exp_nodelay,
READ_ONCE(ssp->srcu_n_exp_nodelay) + 1);
+ if (READ_ONCE(ssp->srcu_n_exp_nodelay) >
SRCU_MAX_NODELAY_PHASE)
+ jbase = 1;
+ }
}
return jbase > SRCU_MAX_INTERVAL ? SRCU_MAX_INTERVAL : jbase;
}
.
|