* "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
@ 2021-09-22 10:25 Henning Schild
2021-09-22 12:36 ` Philippe Gerum
0 siblings, 1 reply; 15+ messages in thread
From: Henning Schild @ 2021-09-22 10:25 UTC (permalink / raw)
To: xenomai
Hi,
getting sick of maintaining a "small" kernel config i wanted to switch
to a config derived from the debian11 5.10 kernel. Basically that
config plus the few switches coming in with dovetail.
That passed all tests in qemu but on a real machine (big xeon with
raid0) the "switchtest" has an issue.
# /lib/xenomai/testsuite/switchtest
== Testing FPU check routines...
r0: 1 != 2
r1: 1 != 2
r2: 1 != 2
r3: 1 != 2
r4: 1 != 2
r5: 1 != 2
r6: 1 != 2
r7: 1 != 2
ymm0: 1/1 != 2/2
ymm1: 1/1 != 2/2
ymm2: 1/1 != 2/2
ymm3: 1/1 != 2/2
ymm4: 1/1 != 2/2
ymm5: 1/1 != 2/2
ymm6: 1/1 != 2/2
ymm7: 1/1 != 2/2
== FPU check routines: OK.
== Threads: ... a lot of threads ...
30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19 rtuo_ufps30-20
rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22 sleeper_ufpthread_create:
Resource temporarily unavailable ps31-0 rtk31-1 rtk31-2 rtk_fp31-3
rtk_fp31-4 rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
rtup_ufpp31-9 rtup_ufpp31-10 rtus
followed by only 0s
RTH|---------cpu|ctx switches|-------total
RTD| 0| 0| 0
RTD| 1| 0| 0
RTD| 2| 0| 0
RTD| 3| 0| 0
RTD| 4| 0| 0
RTD| 5| 0| 0
RTD| 6| 0| 0
So it gets a
sleeper_ufpthread_create: Resource temporarily unavailable
but swallows that and keeps going. I think there might be a first issue
with that error return not being dealt with.
A second run get the "switchtest" stuck after crtl+c while the kernel
starts complaining.
[ 1229.072052] list_del corruption. prev->next should be ffffb24e46fb0548, but was ffffffff9a7356b0
[ 1229.072053] ------------[ cut here ]------------
[ 1229.072054] kernel BUG at lib/list_debug.c:51!
[ 1229.072054] invalid opcode: 0000 [#1] SMP PTI IRQ_PIPELINE
[ 1229.072054] CPU: 31 PID: 1857 Comm: switchtest Tainted: G E 5.10.61-xenomai-1 #1
[ 1229.072055] Hardware name: secret
[ 1229.072055] IRQ stage: Linux
[ 1229.072055] RIP: 0010:__list_del_entry_valid.cold+0x31/0x47
[ 1229.072056] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8 51 0d ff ff 0f 0b 48 89 b
[ 1229.072057] RSP: 0018:ffffb24e4b5f7e30 EFLAGS: 00010046
[ 1229.072061] RAX: 0000000000000057 RBX: ffffb24e46fb04b0 RCX: 0000000000000000
[ 1229.072062] RDX: 0000000000000000 RSI: ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68
[ 1229.072064] RBP: 0000000000000000 R08: 0000000000000001 R09: 000000000000000f
[ 1229.072066] R10: 000000000000000f R11: ffffa10e9fd97bd6 R12: 0000000000000000
[ 1229.072069] R13: ffffa0ff488c7380 R14: 0000000000000000 R15: 0000000000000000
[ 1229.072072] FS: 00007f57e687bb80(0000) GS:ffffa10e9fd80000(0000) knlGS:0000000000000000
[ 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1229.072076] CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
[ 1229.072078] Call Trace:
[ 1229.072080] xntimer_destroy+0x81/0x150
[ 1229.072082] __xnthread_cleanup+0x1e/0x2a0
[ 1229.072084] cobalt_handle_taskexit_event+0x1d/0x40
[ 1229.072086] do_exit+0xe1/0xab0
[ 1229.072088] ? signal_wake_up_state+0x23/0x40
[ 1229.072090] do_group_exit+0x33/0xa0
[ 1229.072092] __x64_sys_exit_group+0x14/0x20
[ 1229.072111] do_syscall_64+0x3f/0x90
[ 1229.072113] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 1229.072115] RIP: 0033:0x7f57e6948699
[ 1229.072117] Code: 00 4c 8b 05 f9 27 0f 00 be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00 00 89 0
[ 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
[ 1229.072128] RAX: ffffffffffffffda RBX: 00007f57e6a3d610 RCX: 00007f57e6948699
[ 1229.072130] RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000001
[ 1229.072132] RBP: 0000000000000001 R08: ffffffffffffff70 R09: 0000000000000001
[ 1229.072134] R10: 0000000000000005 R11: 0000000000000246 R12: 00007f57e6a3d610
[ 1229.072136] R13: 0000000000000002 R14: 00007f57e6a3dae8 R15: 0000000000000000
[ 1229.072138] Modules linked in: md4(E) sha512_ssse3(E) sha512_generic(E) cmac(E) nls_utf8(E) cifs)
[ 1229.072169] mei(E) soundcore(E) sysimgblt(E) sg(E) evdev(E) ioatdma(E) joydev(E) watchdog(E) ac)
[ 1229.072185] ---[ end trace a1d1ac68468e74f0 ]---
[ 1229.072186] RIP: 0010:__list_del_entry_valid.cold+0x31/0x47
[ 1229.072187] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8 51 0d ff ff 0f 0b 48 89 b
[ 1229.072187] RSP: 0018:ffffb24e4b5f7e30 EFLAGS: 00010046
[ 1229.072188] RAX: 0000000000000057 RBX: ffffb24e46fb04b0 RCX: 0000000000000000
[ 1229.072188] RDX: 0000000000000000 RSI: ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68
[ 1229.072189] RBP: 0000000000000000 R08: 0000000000000001 R09: 000000000000000f
[ 1229.072189] R10: 000000000000000f R11: ffffa10e9fd97bd6 R12: 0000000000000000
[ 1229.072190] R13: ffffa0ff488c7380 R14: 0000000000000000 R15: 0000000000000000
[ 1229.072190] FS: 00007f57e687bb80(0000) GS:ffffa10e9fd80000(0000) knlGS:0000000000000000
[ 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1229.072191] CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
[ 1229.072191] Fixing recursive fault but reboot is needed!
I will look into that eventually. For now i just wanted to share what i
have so far, maybe someone knows what is going on or can give a hint.
function tracing was way too verbose to find the rootcause of that
EBUSY.
regards,
Henning
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-09-22 10:25 "switchtest" problem with recent 5.10 dovetail and distro-like kernel config Henning Schild
@ 2021-09-22 12:36 ` Philippe Gerum
2021-09-22 14:21 ` Henning Schild
0 siblings, 1 reply; 15+ messages in thread
From: Philippe Gerum @ 2021-09-22 12:36 UTC (permalink / raw)
To: Henning Schild; +Cc: xenomai
Henning Schild via Xenomai <xenomai@xenomai.org> writes:
> Hi,
>
> getting sick of maintaining a "small" kernel config i wanted to switch
> to a config derived from the debian11 5.10 kernel. Basically that
> config plus the few switches coming in with dovetail.
>
> That passed all tests in qemu but on a real machine (big xeon with
> raid0) the "switchtest" has an issue.
>
> # /lib/xenomai/testsuite/switchtest
> == Testing FPU check routines...
> r0: 1 != 2
> r1: 1 != 2
> r2: 1 != 2
> r3: 1 != 2
> r4: 1 != 2
> r5: 1 != 2
> r6: 1 != 2
> r7: 1 != 2
> ymm0: 1/1 != 2/2
> ymm1: 1/1 != 2/2
> ymm2: 1/1 != 2/2
> ymm3: 1/1 != 2/2
> ymm4: 1/1 != 2/2
> ymm5: 1/1 != 2/2
> ymm6: 1/1 != 2/2
> ymm7: 1/1 != 2/2
> == FPU check routines: OK.
> == Threads: ... a lot of threads ...
> 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19 rtuo_ufps30-20
> rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22 sleeper_ufpthread_create:
> Resource temporarily unavailable ps31-0 rtk31-1 rtk31-2 rtk_fp31-3
> rtk_fp31-4 rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
> rtup_ufpp31-9 rtup_ufpp31-10 rtus
>
> followed by only 0s
>
> RTH|---------cpu|ctx switches|-------total
> RTD| 0| 0| 0
> RTD| 1| 0| 0
> RTD| 2| 0| 0
> RTD| 3| 0| 0
> RTD| 4| 0| 0
> RTD| 5| 0| 0
> RTD| 6| 0| 0
>
> So it gets a
>
> sleeper_ufpthread_create: Resource temporarily unavailable
>
> but swallows that and keeps going. I think there might be a first issue
> with that error return not being dealt with.
>
> A second run get the "switchtest" stuck after crtl+c while the kernel
> starts complaining.
>
> [ 1229.072052] list_del corruption. prev->next should be ffffb24e46fb0548, but was ffffffff9a7356b0
> [ 1229.072053] ------------[ cut here ]------------
> [ 1229.072054] kernel BUG at lib/list_debug.c:51!
> [ 1229.072054] invalid opcode: 0000 [#1] SMP PTI IRQ_PIPELINE
> [ 1229.072054] CPU: 31 PID: 1857 Comm: switchtest Tainted: G E 5.10.61-xenomai-1 #1
> [ 1229.072055] Hardware name: secret
> [ 1229.072055] IRQ stage: Linux
> [ 1229.072055] RIP: 0010:__list_del_entry_valid.cold+0x31/0x47
> [ 1229.072056] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8 51 0d ff ff 0f 0b 48 89 b
> [ 1229.072057] RSP: 0018:ffffb24e4b5f7e30 EFLAGS: 00010046
> [ 1229.072061] RAX: 0000000000000057 RBX: ffffb24e46fb04b0 RCX: 0000000000000000
> [ 1229.072062] RDX: 0000000000000000 RSI: ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68
> [ 1229.072064] RBP: 0000000000000000 R08: 0000000000000001 R09: 000000000000000f
> [ 1229.072066] R10: 000000000000000f R11: ffffa10e9fd97bd6 R12: 0000000000000000
> [ 1229.072069] R13: ffffa0ff488c7380 R14: 0000000000000000 R15: 0000000000000000
> [ 1229.072072] FS: 00007f57e687bb80(0000) GS:ffffa10e9fd80000(0000) knlGS:0000000000000000
> [ 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1229.072076] CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
> [ 1229.072078] Call Trace:
> [ 1229.072080] xntimer_destroy+0x81/0x150
> [ 1229.072082] __xnthread_cleanup+0x1e/0x2a0
> [ 1229.072084] cobalt_handle_taskexit_event+0x1d/0x40
> [ 1229.072086] do_exit+0xe1/0xab0
> [ 1229.072088] ? signal_wake_up_state+0x23/0x40
> [ 1229.072090] do_group_exit+0x33/0xa0
> [ 1229.072092] __x64_sys_exit_group+0x14/0x20
> [ 1229.072111] do_syscall_64+0x3f/0x90
> [ 1229.072113] entry_SYSCALL_64_after_hwframe+0x44/0xa9
> [ 1229.072115] RIP: 0033:0x7f57e6948699
> [ 1229.072117] Code: 00 4c 8b 05 f9 27 0f 00 be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00 00 89 0
> [ 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
> [ 1229.072128] RAX: ffffffffffffffda RBX: 00007f57e6a3d610 RCX: 00007f57e6948699
> [ 1229.072130] RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000001
> [ 1229.072132] RBP: 0000000000000001 R08: ffffffffffffff70 R09: 0000000000000001
> [ 1229.072134] R10: 0000000000000005 R11: 0000000000000246 R12: 00007f57e6a3d610
> [ 1229.072136] R13: 0000000000000002 R14: 00007f57e6a3dae8 R15: 0000000000000000
> [ 1229.072138] Modules linked in: md4(E) sha512_ssse3(E) sha512_generic(E) cmac(E) nls_utf8(E) cifs)
> [ 1229.072169] mei(E) soundcore(E) sysimgblt(E) sg(E) evdev(E) ioatdma(E) joydev(E) watchdog(E) ac)
> [ 1229.072185] ---[ end trace a1d1ac68468e74f0 ]---
> [ 1229.072186] RIP: 0010:__list_del_entry_valid.cold+0x31/0x47
> [ 1229.072187] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8 51 0d ff ff 0f 0b 48 89 b
> [ 1229.072187] RSP: 0018:ffffb24e4b5f7e30 EFLAGS: 00010046
> [ 1229.072188] RAX: 0000000000000057 RBX: ffffb24e46fb04b0 RCX: 0000000000000000
> [ 1229.072188] RDX: 0000000000000000 RSI: ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68
> [ 1229.072189] RBP: 0000000000000000 R08: 0000000000000001 R09: 000000000000000f
> [ 1229.072189] R10: 000000000000000f R11: ffffa10e9fd97bd6 R12: 0000000000000000
> [ 1229.072190] R13: ffffa0ff488c7380 R14: 0000000000000000 R15: 0000000000000000
> [ 1229.072190] FS: 00007f57e687bb80(0000) GS:ffffa10e9fd80000(0000) knlGS:0000000000000000
> [ 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1229.072191] CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
> [ 1229.072191] Fixing recursive fault but reboot is needed!
>
> I will look into that eventually. For now i just wanted to share what i
> have so far, maybe someone knows what is going on or can give a hint.
> function tracing was way too verbose to find the rootcause of that
> EBUSY.
>
EAGAIN, switchtest triggers this when many CPUs are available but the
system heap is too small (not enough space there to create thread TCBs
and other core objects). Normally, switchtest exits properly after a
while.
The kernel splat looks like some issue on the error path which might not
have been observed yet (maybe triggered by ^C while switchtest was
unwinding).
--
Philippe.
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-09-22 12:36 ` Philippe Gerum
@ 2021-09-22 14:21 ` Henning Schild
2021-09-24 13:31 ` Henning Schild
0 siblings, 1 reply; 15+ messages in thread
From: Henning Schild @ 2021-09-22 14:21 UTC (permalink / raw)
To: Philippe Gerum; +Cc: xenomai
Am Wed, 22 Sep 2021 14:36:49 +0200
schrieb Philippe Gerum <rpm@xenomai.org>:
> Henning Schild via Xenomai <xenomai@xenomai.org> writes:
>
> > Hi,
> >
> > getting sick of maintaining a "small" kernel config i wanted to
> > switch to a config derived from the debian11 5.10 kernel. Basically
> > that config plus the few switches coming in with dovetail.
> >
> > That passed all tests in qemu but on a real machine (big xeon with
> > raid0) the "switchtest" has an issue.
> >
> > # /lib/xenomai/testsuite/switchtest
> > == Testing FPU check routines...
> > r0: 1 != 2
> > r1: 1 != 2
> > r2: 1 != 2
> > r3: 1 != 2
> > r4: 1 != 2
> > r5: 1 != 2
> > r6: 1 != 2
> > r7: 1 != 2
> > ymm0: 1/1 != 2/2
> > ymm1: 1/1 != 2/2
> > ymm2: 1/1 != 2/2
> > ymm3: 1/1 != 2/2
> > ymm4: 1/1 != 2/2
> > ymm5: 1/1 != 2/2
> > ymm6: 1/1 != 2/2
> > ymm7: 1/1 != 2/2
> > == FPU check routines: OK.
> > == Threads: ... a lot of threads ...
> > 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19 rtuo_ufps30-20
> > rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22 sleeper_ufpthread_create:
> > Resource temporarily unavailable ps31-0 rtk31-1 rtk31-2 rtk_fp31-3
> > rtk_fp31-4 rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
> > rtup_ufpp31-9 rtup_ufpp31-10 rtus
> >
> > followed by only 0s
> >
> > RTH|---------cpu|ctx switches|-------total
> > RTD| 0| 0| 0
> > RTD| 1| 0| 0
> > RTD| 2| 0| 0
> > RTD| 3| 0| 0
> > RTD| 4| 0| 0
> > RTD| 5| 0| 0
> > RTD| 6| 0| 0
> >
> > So it gets a
> >
> > sleeper_ufpthread_create: Resource temporarily unavailable
> >
> > but swallows that and keeps going. I think there might be a first
> > issue with that error return not being dealt with.
> >
> > A second run get the "switchtest" stuck after crtl+c while the
> > kernel starts complaining.
> >
> > [ 1229.072052] list_del corruption. prev->next should be
> > ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
> > ------------[ cut here ]------------ [ 1229.072054] kernel BUG at
> > lib/list_debug.c:51! [ 1229.072054] invalid opcode: 0000 [#1] SMP
> > PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID: 1857 Comm: switchtest
> > Tainted: G E 5.10.61-xenomai-1 #1 [ 1229.072055]
> > Hardware name: secret [ 1229.072055] IRQ stage: Linux
> > [ 1229.072055] RIP: 0010:__list_del_entry_valid.cold+0x31/0x47
> > [ 1229.072056] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a
> > 32 9a e8 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
> > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
> > 0000000000000057 RBX: ffffb24e46fb04b0 RCX: 0000000000000000 [
> > 1229.072062] RDX: 0000000000000000 RSI: ffffa10e9fd9bba0 RDI:
> > ffffa10e9fd97b68 [ 1229.072064] RBP: 0000000000000000 R08:
> > 0000000000000001 R09: 000000000000000f [ 1229.072066] R10:
> > 000000000000000f R11: ffffa10e9fd97bd6 R12: 0000000000000000 [
> > 1229.072069] R13: ffffa0ff488c7380 R14: 0000000000000000 R15:
> > 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
> > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [ 1229.072074] CS:
> > 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1229.072076] CR2:
> > 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0 [
> > 1229.072078] Call Trace: [ 1229.072080] xntimer_destroy+0x81/0x150
> > [ 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
> > cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
> > do_exit+0xe1/0xab0 [ 1229.072088] ? signal_wake_up_state+0x23/0x40
> > [ 1229.072090] do_group_exit+0x33/0xa0 [ 1229.072092]
> > __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
> > do_syscall_64+0x3f/0x90 [ 1229.072113]
> > entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115] RIP:
> > 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05 f9 27 0f 00 be
> > e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00 00 89 0 [ 1229.072119]
> > RSP: 002b:00007ffcfbda0078 EFLAGS: 00000246 ORIG_RAX:
> > 00000000000000e7 [ 1229.072128] RAX: ffffffffffffffda RBX:
> > 00007f57e6a3d610 RCX: 00007f57e6948699 [ 1229.072130] RDX:
> > 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000001 [
> > 1229.072132] RBP: 0000000000000001 R08: ffffffffffffff70 R09:
> > 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
> > 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
> > 0000000000000002 R14: 00007f57e6a3dae8 R15: 0000000000000000 [
> > 1229.072138] Modules linked in: md4(E) sha512_ssse3(E)
> > sha512_generic(E) cmac(E) nls_utf8(E) cifs) [ 1229.072169] mei(E)
> > soundcore(E) sysimgblt(E) sg(E) evdev(E) ioatdma(E) joydev(E)
> > watchdog(E) ac) [ 1229.072185] ---[ end trace a1d1ac68468e74f0 ]---
> > [ 1229.072186] RIP: 0010:__list_del_entry_valid.cold+0x31/0x47 [
> > 1229.072187] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32
> > 9a e8 51 0d ff ff 0f 0b 48 89 b [ 1229.072187] RSP:
> > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072188] RAX:
> > 0000000000000057 RBX: ffffb24e46fb04b0 RCX: 0000000000000000 [
> > 1229.072188] RDX: 0000000000000000 RSI: ffffa10e9fd9bba0 RDI:
> > ffffa10e9fd97b68 [ 1229.072189] RBP: 0000000000000000 R08:
> > 0000000000000001 R09: 000000000000000f [ 1229.072189] R10:
> > 000000000000000f R11: ffffa10e9fd97bd6 R12: 0000000000000000 [
> > 1229.072190] R13: ffffa0ff488c7380 R14: 0000000000000000 R15:
> > 0000000000000000 [ 1229.072190] FS: 00007f57e687bb80(0000)
> > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [ 1229.072190] CS:
> > 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1229.072191] CR2:
> > 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0 [
> > 1229.072191] Fixing recursive fault but reboot is needed!
> >
> > I will look into that eventually. For now i just wanted to share
> > what i have so far, maybe someone knows what is going on or can
> > give a hint. function tracing was way too verbose to find the
> > rootcause of that EBUSY.
> >
>
> EAGAIN, switchtest triggers this when many CPUs are available but the
> system heap is too small (not enough space there to create thread TCBs
> and other core objects). Normally, switchtest exits properly after a
> while.
Ok maybe that changed kernel config did shrink the available heap,
thanks for the hint.
If it is an EAGAIN because of too little resources, maybe it should
keep trying with less and less CPUs. And spit a warning like "could
only run on 20 out of 32 cores".
At least that would be my first idea for a patch in case it is that.
> The kernel splat looks like some issue on the error path which might
> not have been observed yet (maybe triggered by ^C while switchtest was
> unwinding).
I saw exactly that in probably three attempts. First switchtest killed
with ctrl+c when the 0s come ... never any fun kernel message. But
always fun kernel message when the second run was interrupted. So i
would be tempted to call that reproducible and not a one-time bad
timing.
Henning
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-09-22 14:21 ` Henning Schild
@ 2021-09-24 13:31 ` Henning Schild
2021-10-05 14:29 ` Jan Kiszka
0 siblings, 1 reply; 15+ messages in thread
From: Henning Schild @ 2021-09-24 13:31 UTC (permalink / raw)
To: Henning Schild via Xenomai
Am Wed, 22 Sep 2021 16:21:54 +0200
schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
> Am Wed, 22 Sep 2021 14:36:49 +0200
> schrieb Philippe Gerum <rpm@xenomai.org>:
>
> > Henning Schild via Xenomai <xenomai@xenomai.org> writes:
> >
> > > Hi,
> > >
> > > getting sick of maintaining a "small" kernel config i wanted to
> > > switch to a config derived from the debian11 5.10 kernel.
> > > Basically that config plus the few switches coming in with
> > > dovetail.
> > >
> > > That passed all tests in qemu but on a real machine (big xeon with
> > > raid0) the "switchtest" has an issue.
> > >
> > > # /lib/xenomai/testsuite/switchtest
> > > == Testing FPU check routines...
> > > r0: 1 != 2
> > > r1: 1 != 2
> > > r2: 1 != 2
> > > r3: 1 != 2
> > > r4: 1 != 2
> > > r5: 1 != 2
> > > r6: 1 != 2
> > > r7: 1 != 2
> > > ymm0: 1/1 != 2/2
> > > ymm1: 1/1 != 2/2
> > > ymm2: 1/1 != 2/2
> > > ymm3: 1/1 != 2/2
> > > ymm4: 1/1 != 2/2
> > > ymm5: 1/1 != 2/2
> > > ymm6: 1/1 != 2/2
> > > ymm7: 1/1 != 2/2
> > > == FPU check routines: OK.
> > > == Threads: ... a lot of threads ...
> > > 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19 rtuo_ufps30-20
> > > rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22 sleeper_ufpthread_create:
> > > Resource temporarily unavailable ps31-0 rtk31-1 rtk31-2 rtk_fp31-3
> > > rtk_fp31-4 rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
> > > rtup_ufpp31-9 rtup_ufpp31-10 rtus
> > >
> > > followed by only 0s
> > >
> > > RTH|---------cpu|ctx switches|-------total
> > > RTD| 0| 0| 0
> > > RTD| 1| 0| 0
> > > RTD| 2| 0| 0
> > > RTD| 3| 0| 0
> > > RTD| 4| 0| 0
> > > RTD| 5| 0| 0
> > > RTD| 6| 0| 0
> > >
> > > So it gets a
> > >
> > > sleeper_ufpthread_create: Resource temporarily unavailable
> > >
> > > but swallows that and keeps going. I think there might be a first
> > > issue with that error return not being dealt with.
> > >
> > > A second run get the "switchtest" stuck after crtl+c while the
> > > kernel starts complaining.
> > >
> > > [ 1229.072052] list_del corruption. prev->next should be
> > > ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
> > > ------------[ cut here ]------------ [ 1229.072054] kernel BUG at
> > > lib/list_debug.c:51! [ 1229.072054] invalid opcode: 0000 [#1] SMP
> > > PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID: 1857 Comm: switchtest
> > > Tainted: G E 5.10.61-xenomai-1 #1 [ 1229.072055]
> > > Hardware name: secret [ 1229.072055] IRQ stage: Linux
> > > [ 1229.072055] RIP: 0010:__list_del_entry_valid.cold+0x31/0x47
> > > [ 1229.072056] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a
> > > 32 9a e8 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
> > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
> > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX: 0000000000000000 [
> > > 1229.072062] RDX: 0000000000000000 RSI: ffffa10e9fd9bba0 RDI:
> > > ffffa10e9fd97b68 [ 1229.072064] RBP: 0000000000000000 R08:
> > > 0000000000000001 R09: 000000000000000f [ 1229.072066] R10:
> > > 000000000000000f R11: ffffa10e9fd97bd6 R12: 0000000000000000 [
> > > 1229.072069] R13: ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
> > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [ 1229.072074]
> > > CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1229.072076]
> > > CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
> > > [ 1229.072078] Call Trace: [ 1229.072080]
> > > xntimer_destroy+0x81/0x150 [ 1229.072082]
> > > __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
> > > cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
> > > do_exit+0xe1/0xab0 [ 1229.072088] ?
> > > signal_wake_up_state+0x23/0x40 [ 1229.072090]
> > > do_group_exit+0x33/0xa0 [ 1229.072092]
> > > __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
> > > do_syscall_64+0x3f/0x90 [ 1229.072113]
> > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115] RIP:
> > > 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05 f9 27 0f 00
> > > be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00 00 89 0 [
> > > 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS: 00000246
> > > ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX: ffffffffffffffda
> > > RBX: 00007f57e6a3d610 RCX: 00007f57e6948699 [ 1229.072130] RDX:
> > > 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000001 [
> > > 1229.072132] RBP: 0000000000000001 R08: ffffffffffffff70 R09:
> > > 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
> > > 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
> > > 0000000000000002 R14: 00007f57e6a3dae8 R15: 0000000000000000 [
> > > 1229.072138] Modules linked in: md4(E) sha512_ssse3(E)
> > > sha512_generic(E) cmac(E) nls_utf8(E) cifs) [ 1229.072169]
> > > mei(E) soundcore(E) sysimgblt(E) sg(E) evdev(E) ioatdma(E)
> > > joydev(E) watchdog(E) ac) [ 1229.072185] ---[ end trace
> > > a1d1ac68468e74f0 ]--- [ 1229.072186] RIP:
> > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187] Code:
> > > 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8 51 0d ff ff
> > > 0f 0b 48 89 b [ 1229.072187] RSP: 0018:ffffb24e4b5f7e30 EFLAGS:
> > > 00010046 [ 1229.072188] RAX: 0000000000000057 RBX:
> > > ffffb24e46fb04b0 RCX: 0000000000000000 [ 1229.072188] RDX:
> > > 0000000000000000 RSI: ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [
> > > 1229.072189] RBP: 0000000000000000 R08: 0000000000000001 R09:
> > > 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
> > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
> > > ffffa0ff488c7380 R14: 0000000000000000 R15: 0000000000000000 [
> > > 1229.072190] FS: 00007f57e687bb80(0000)
> > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [ 1229.072190]
> > > CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1229.072191]
> > > CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
> > > [ 1229.072191] Fixing recursive fault but reboot is needed!
> > >
> > > I will look into that eventually. For now i just wanted to share
> > > what i have so far, maybe someone knows what is going on or can
> > > give a hint. function tracing was way too verbose to find the
> > > rootcause of that EBUSY.
> > >
> >
> > EAGAIN, switchtest triggers this when many CPUs are available but
> > the system heap is too small (not enough space there to create
> > thread TCBs and other core objects). Normally, switchtest exits
> > properly after a while.
>
> Ok maybe that changed kernel config did shrink the available heap,
> thanks for the hint.
>
> If it is an EAGAIN because of too little resources, maybe it should
> keep trying with less and less CPUs. And spit a warning like "could
> only run on 20 out of 32 cores".
> At least that would be my first idea for a patch in case it is that.
The test runs just fine when reducing the number of cores to run on. In
fact it was one too many ;)
good
./switchtest -T 5 --cpu-affinity=0-30
bad (where affinity includes all cpus)
./switchtest -T 5 --cpu-affinity=0-31
> > The kernel splat looks like some issue on the error path which might
> > not have been observed yet (maybe triggered by ^C while switchtest
> > was unwinding).
>
> I saw exactly that in probably three attempts. First switchtest killed
> with ctrl+c when the 0s come ... never any fun kernel message. But
> always fun kernel message when the second run was interrupted. So i
> would be tempted to call that reproducible and not a one-time bad
> timing.
But when running the bad case two times in a row, it will always
kernel BUG at lib/list_debug.c:51!
Even when none of the two runs was interrupted by ctrl+c.
Henning
> Henning
>
>
>
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-09-24 13:31 ` Henning Schild
@ 2021-10-05 14:29 ` Jan Kiszka
2021-10-05 14:38 ` Bezdeka, Florian
0 siblings, 1 reply; 15+ messages in thread
From: Jan Kiszka @ 2021-10-05 14:29 UTC (permalink / raw)
To: Henning Schild, Henning Schild via Xenomai
On 24.09.21 15:31, Henning Schild via Xenomai wrote:
> Am Wed, 22 Sep 2021 16:21:54 +0200
> schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
>
>> Am Wed, 22 Sep 2021 14:36:49 +0200
>> schrieb Philippe Gerum <rpm@xenomai.org>:
>>
>>> Henning Schild via Xenomai <xenomai@xenomai.org> writes:
>>>
>>>> Hi,
>>>>
>>>> getting sick of maintaining a "small" kernel config i wanted to
>>>> switch to a config derived from the debian11 5.10 kernel.
>>>> Basically that config plus the few switches coming in with
>>>> dovetail.
>>>>
>>>> That passed all tests in qemu but on a real machine (big xeon with
>>>> raid0) the "switchtest" has an issue.
>>>>
>>>> # /lib/xenomai/testsuite/switchtest
>>>> == Testing FPU check routines...
>>>> r0: 1 != 2
>>>> r1: 1 != 2
>>>> r2: 1 != 2
>>>> r3: 1 != 2
>>>> r4: 1 != 2
>>>> r5: 1 != 2
>>>> r6: 1 != 2
>>>> r7: 1 != 2
>>>> ymm0: 1/1 != 2/2
>>>> ymm1: 1/1 != 2/2
>>>> ymm2: 1/1 != 2/2
>>>> ymm3: 1/1 != 2/2
>>>> ymm4: 1/1 != 2/2
>>>> ymm5: 1/1 != 2/2
>>>> ymm6: 1/1 != 2/2
>>>> ymm7: 1/1 != 2/2
>>>> == FPU check routines: OK.
>>>> == Threads: ... a lot of threads ...
>>>> 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19 rtuo_ufps30-20
>>>> rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22 sleeper_ufpthread_create:
>>>> Resource temporarily unavailable ps31-0 rtk31-1 rtk31-2 rtk_fp31-3
>>>> rtk_fp31-4 rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
>>>> rtup_ufpp31-9 rtup_ufpp31-10 rtus
>>>>
>>>> followed by only 0s
>>>>
>>>> RTH|---------cpu|ctx switches|-------total
>>>> RTD| 0| 0| 0
>>>> RTD| 1| 0| 0
>>>> RTD| 2| 0| 0
>>>> RTD| 3| 0| 0
>>>> RTD| 4| 0| 0
>>>> RTD| 5| 0| 0
>>>> RTD| 6| 0| 0
>>>>
>>>> So it gets a
>>>>
>>>> sleeper_ufpthread_create: Resource temporarily unavailable
>>>>
>>>> but swallows that and keeps going. I think there might be a first
>>>> issue with that error return not being dealt with.
>>>>
>>>> A second run get the "switchtest" stuck after crtl+c while the
>>>> kernel starts complaining.
>>>>
>>>> [ 1229.072052] list_del corruption. prev->next should be
>>>> ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
>>>> ------------[ cut here ]------------ [ 1229.072054] kernel BUG at
>>>> lib/list_debug.c:51! [ 1229.072054] invalid opcode: 0000 [#1] SMP
>>>> PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID: 1857 Comm: switchtest
>>>> Tainted: G E 5.10.61-xenomai-1 #1 [ 1229.072055]
>>>> Hardware name: secret [ 1229.072055] IRQ stage: Linux
>>>> [ 1229.072055] RIP: 0010:__list_del_entry_valid.cold+0x31/0x47
>>>> [ 1229.072056] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a
>>>> 32 9a e8 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
>>>> 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
>>>> 0000000000000057 RBX: ffffb24e46fb04b0 RCX: 0000000000000000 [
>>>> 1229.072062] RDX: 0000000000000000 RSI: ffffa10e9fd9bba0 RDI:
>>>> ffffa10e9fd97b68 [ 1229.072064] RBP: 0000000000000000 R08:
>>>> 0000000000000001 R09: 000000000000000f [ 1229.072066] R10:
>>>> 000000000000000f R11: ffffa10e9fd97bd6 R12: 0000000000000000 [
>>>> 1229.072069] R13: ffffa0ff488c7380 R14: 0000000000000000 R15:
>>>> 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [ 1229.072074]
>>>> CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1229.072076]
>>>> CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
>>>> [ 1229.072078] Call Trace: [ 1229.072080]
>>>> xntimer_destroy+0x81/0x150 [ 1229.072082]
>>>> __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
>>>> cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
>>>> do_exit+0xe1/0xab0 [ 1229.072088] ?
>>>> signal_wake_up_state+0x23/0x40 [ 1229.072090]
>>>> do_group_exit+0x33/0xa0 [ 1229.072092]
>>>> __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
>>>> do_syscall_64+0x3f/0x90 [ 1229.072113]
>>>> entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115] RIP:
>>>> 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05 f9 27 0f 00
>>>> be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00 00 89 0 [
>>>> 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS: 00000246
>>>> ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX: ffffffffffffffda
>>>> RBX: 00007f57e6a3d610 RCX: 00007f57e6948699 [ 1229.072130] RDX:
>>>> 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000001 [
>>>> 1229.072132] RBP: 0000000000000001 R08: ffffffffffffff70 R09:
>>>> 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
>>>> 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
>>>> 0000000000000002 R14: 00007f57e6a3dae8 R15: 0000000000000000 [
>>>> 1229.072138] Modules linked in: md4(E) sha512_ssse3(E)
>>>> sha512_generic(E) cmac(E) nls_utf8(E) cifs) [ 1229.072169]
>>>> mei(E) soundcore(E) sysimgblt(E) sg(E) evdev(E) ioatdma(E)
>>>> joydev(E) watchdog(E) ac) [ 1229.072185] ---[ end trace
>>>> a1d1ac68468e74f0 ]--- [ 1229.072186] RIP:
>>>> 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187] Code:
>>>> 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8 51 0d ff ff
>>>> 0f 0b 48 89 b [ 1229.072187] RSP: 0018:ffffb24e4b5f7e30 EFLAGS:
>>>> 00010046 [ 1229.072188] RAX: 0000000000000057 RBX:
>>>> ffffb24e46fb04b0 RCX: 0000000000000000 [ 1229.072188] RDX:
>>>> 0000000000000000 RSI: ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [
>>>> 1229.072189] RBP: 0000000000000000 R08: 0000000000000001 R09:
>>>> 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
>>>> ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
>>>> ffffa0ff488c7380 R14: 0000000000000000 R15: 0000000000000000 [
>>>> 1229.072190] FS: 00007f57e687bb80(0000)
>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [ 1229.072190]
>>>> CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1229.072191]
>>>> CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
>>>> [ 1229.072191] Fixing recursive fault but reboot is needed!
>>>>
>>>> I will look into that eventually. For now i just wanted to share
>>>> what i have so far, maybe someone knows what is going on or can
>>>> give a hint. function tracing was way too verbose to find the
>>>> rootcause of that EBUSY.
>>>>
>>>
>>> EAGAIN, switchtest triggers this when many CPUs are available but
>>> the system heap is too small (not enough space there to create
>>> thread TCBs and other core objects). Normally, switchtest exits
>>> properly after a while.
>>
>> Ok maybe that changed kernel config did shrink the available heap,
>> thanks for the hint.
>>
>> If it is an EAGAIN because of too little resources, maybe it should
>> keep trying with less and less CPUs. And spit a warning like "could
>> only run on 20 out of 32 cores".
>> At least that would be my first idea for a patch in case it is that.
>
> The test runs just fine when reducing the number of cores to run on. In
> fact it was one too many ;)
>
> good
> ./switchtest -T 5 --cpu-affinity=0-30
> bad (where affinity includes all cpus)
> ./switchtest -T 5 --cpu-affinity=0-31
>
>>> The kernel splat looks like some issue on the error path which might
>>> not have been observed yet (maybe triggered by ^C while switchtest
>>> was unwinding).
>>
>> I saw exactly that in probably three attempts. First switchtest killed
>> with ctrl+c when the 0s come ... never any fun kernel message. But
>> always fun kernel message when the second run was interrupted. So i
>> would be tempted to call that reproducible and not a one-time bad
>> timing.
>
> But when running the bad case two times in a row, it will always
>
> kernel BUG at lib/list_debug.c:51!
>
> Even when none of the two runs was interrupted by ctrl+c.
>
So, the main issue was solved by increasing resources, but we still have
a problem with handling errors gracefully - is that the correct summary
of this issue? Or where are we standing with this?
Jan
--
Siemens AG, T RDA IOT
Corporate Competence Center Embedded Linux
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-05 14:29 ` Jan Kiszka
@ 2021-10-05 14:38 ` Bezdeka, Florian
2021-10-05 15:18 ` Henning Schild
0 siblings, 1 reply; 15+ messages in thread
From: Bezdeka, Florian @ 2021-10-05 14:38 UTC (permalink / raw)
To: xenomai, jan.kiszka, henning.schild
On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai wrote:
> On 24.09.21 15:31, Henning Schild via Xenomai wrote:
> > Am Wed, 22 Sep 2021 16:21:54 +0200
> > schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
> >
> > > Am Wed, 22 Sep 2021 14:36:49 +0200
> > > schrieb Philippe Gerum <rpm@xenomai.org>:
> > >
> > > > Henning Schild via Xenomai <xenomai@xenomai.org> writes:
> > > >
> > > > > Hi,
> > > > >
> > > > > getting sick of maintaining a "small" kernel config i wanted to
> > > > > switch to a config derived from the debian11 5.10 kernel.
> > > > > Basically that config plus the few switches coming in with
> > > > > dovetail.
> > > > >
> > > > > That passed all tests in qemu but on a real machine (big xeon with
> > > > > raid0) the "switchtest" has an issue.
> > > > >
> > > > > # /lib/xenomai/testsuite/switchtest
> > > > > == Testing FPU check routines...
> > > > > r0: 1 != 2
> > > > > r1: 1 != 2
> > > > > r2: 1 != 2
> > > > > r3: 1 != 2
> > > > > r4: 1 != 2
> > > > > r5: 1 != 2
> > > > > r6: 1 != 2
> > > > > r7: 1 != 2
> > > > > ymm0: 1/1 != 2/2
> > > > > ymm1: 1/1 != 2/2
> > > > > ymm2: 1/1 != 2/2
> > > > > ymm3: 1/1 != 2/2
> > > > > ymm4: 1/1 != 2/2
> > > > > ymm5: 1/1 != 2/2
> > > > > ymm6: 1/1 != 2/2
> > > > > ymm7: 1/1 != 2/2
> > > > > == FPU check routines: OK.
> > > > > == Threads: ... a lot of threads ...
> > > > > 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19 rtuo_ufps30-20
> > > > > rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22 sleeper_ufpthread_create:
> > > > > Resource temporarily unavailable ps31-0 rtk31-1 rtk31-2 rtk_fp31-3
> > > > > rtk_fp31-4 rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
> > > > > rtup_ufpp31-9 rtup_ufpp31-10 rtus
> > > > >
> > > > > followed by only 0s
> > > > >
> > > > > RTH|---------cpu|ctx switches|-------total
> > > > > RTD| 0| 0| 0
> > > > > RTD| 1| 0| 0
> > > > > RTD| 2| 0| 0
> > > > > RTD| 3| 0| 0
> > > > > RTD| 4| 0| 0
> > > > > RTD| 5| 0| 0
> > > > > RTD| 6| 0| 0
> > > > >
> > > > > So it gets a
> > > > >
> > > > > sleeper_ufpthread_create: Resource temporarily unavailable
> > > > >
> > > > > but swallows that and keeps going. I think there might be a first
> > > > > issue with that error return not being dealt with.
> > > > >
> > > > > A second run get the "switchtest" stuck after crtl+c while the
> > > > > kernel starts complaining.
> > > > >
> > > > > [ 1229.072052] list_del corruption. prev->next should be
> > > > > ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
> > > > > ------------[ cut here ]------------ [ 1229.072054] kernel BUG at
> > > > > lib/list_debug.c:51! [ 1229.072054] invalid opcode: 0000 [#1] SMP
> > > > > PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID: 1857 Comm: switchtest
> > > > > Tainted: G E 5.10.61-xenomai-1 #1 [ 1229.072055]
> > > > > Hardware name: secret [ 1229.072055] IRQ stage: Linux
> > > > > [ 1229.072055] RIP: 0010:__list_del_entry_valid.cold+0x31/0x47
> > > > > [ 1229.072056] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a
> > > > > 32 9a e8 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
> > > > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
> > > > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX: 0000000000000000 [
> > > > > 1229.072062] RDX: 0000000000000000 RSI: ffffa10e9fd9bba0 RDI:
> > > > > ffffa10e9fd97b68 [ 1229.072064] RBP: 0000000000000000 R08:
> > > > > 0000000000000001 R09: 000000000000000f [ 1229.072066] R10:
> > > > > 000000000000000f R11: ffffa10e9fd97bd6 R12: 0000000000000000 [
> > > > > 1229.072069] R13: ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > > > 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
> > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [ 1229.072074]
> > > > > CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1229.072076]
> > > > > CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
> > > > > [ 1229.072078] Call Trace: [ 1229.072080]
> > > > > xntimer_destroy+0x81/0x150 [ 1229.072082]
> > > > > __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
> > > > > cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
> > > > > do_exit+0xe1/0xab0 [ 1229.072088] ?
> > > > > signal_wake_up_state+0x23/0x40 [ 1229.072090]
> > > > > do_group_exit+0x33/0xa0 [ 1229.072092]
> > > > > __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
> > > > > do_syscall_64+0x3f/0x90 [ 1229.072113]
> > > > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115] RIP:
> > > > > 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05 f9 27 0f 00
> > > > > be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00 00 89 0 [
> > > > > 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS: 00000246
> > > > > ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX: ffffffffffffffda
> > > > > RBX: 00007f57e6a3d610 RCX: 00007f57e6948699 [ 1229.072130] RDX:
> > > > > 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000001 [
> > > > > 1229.072132] RBP: 0000000000000001 R08: ffffffffffffff70 R09:
> > > > > 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
> > > > > 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
> > > > > 0000000000000002 R14: 00007f57e6a3dae8 R15: 0000000000000000 [
> > > > > 1229.072138] Modules linked in: md4(E) sha512_ssse3(E)
> > > > > sha512_generic(E) cmac(E) nls_utf8(E) cifs) [ 1229.072169]
> > > > > mei(E) soundcore(E) sysimgblt(E) sg(E) evdev(E) ioatdma(E)
> > > > > joydev(E) watchdog(E) ac) [ 1229.072185] ---[ end trace
> > > > > a1d1ac68468e74f0 ]--- [ 1229.072186] RIP:
> > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187] Code:
> > > > > 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8 51 0d ff ff
> > > > > 0f 0b 48 89 b [ 1229.072187] RSP: 0018:ffffb24e4b5f7e30 EFLAGS:
> > > > > 00010046 [ 1229.072188] RAX: 0000000000000057 RBX:
> > > > > ffffb24e46fb04b0 RCX: 0000000000000000 [ 1229.072188] RDX:
> > > > > 0000000000000000 RSI: ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [
> > > > > 1229.072189] RBP: 0000000000000000 R08: 0000000000000001 R09:
> > > > > 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
> > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
> > > > > ffffa0ff488c7380 R14: 0000000000000000 R15: 0000000000000000 [
> > > > > 1229.072190] FS: 00007f57e687bb80(0000)
> > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [ 1229.072190]
> > > > > CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1229.072191]
> > > > > CR2: 000055921bfa921c CR3: 00000001062fe002 CR4: 00000000001706e0
> > > > > [ 1229.072191] Fixing recursive fault but reboot is needed!
> > > > >
> > > > > I will look into that eventually. For now i just wanted to share
> > > > > what i have so far, maybe someone knows what is going on or can
> > > > > give a hint. function tracing was way too verbose to find the
> > > > > rootcause of that EBUSY.
> > > > >
> > > >
> > > > EAGAIN, switchtest triggers this when many CPUs are available but
> > > > the system heap is too small (not enough space there to create
> > > > thread TCBs and other core objects). Normally, switchtest exits
> > > > properly after a while.
> > >
> > > Ok maybe that changed kernel config did shrink the available heap,
> > > thanks for the hint.
> > >
> > > If it is an EAGAIN because of too little resources, maybe it should
> > > keep trying with less and less CPUs. And spit a warning like "could
> > > only run on 20 out of 32 cores".
> > > At least that would be my first idea for a patch in case it is that.
> >
> > The test runs just fine when reducing the number of cores to run on. In
> > fact it was one too many ;)
> >
> > good
> > ./switchtest -T 5 --cpu-affinity=0-30
> > bad (where affinity includes all cpus)
> > ./switchtest -T 5 --cpu-affinity=0-31
> >
> > > > The kernel splat looks like some issue on the error path which might
> > > > not have been observed yet (maybe triggered by ^C while switchtest
> > > > was unwinding).
> > >
> > > I saw exactly that in probably three attempts. First switchtest killed
> > > with ctrl+c when the 0s come ... never any fun kernel message. But
> > > always fun kernel message when the second run was interrupted. So i
> > > would be tempted to call that reproducible and not a one-time bad
> > > timing.
> >
> > But when running the bad case two times in a row, it will always
> >
> > kernel BUG at lib/list_debug.c:51!
> >
> > Even when none of the two runs was interrupted by ctrl+c.
> >
>
> So, the main issue was solved by increasing resources, but we still have
> a problem with handling errors gracefully - is that the correct summary
> of this issue? Or where are we standing with this?
Might that be related to a registry slot exhaustion? On the affected
system we changed CONFIG_XENO_OPT_DEBUG from 4096 back to its default
(512). Just an idea... ctrl+c might skip the resource cleanup.
Looking into /proc/xenomai/registry/usage might help in such case.
>
> Jan
>
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-05 14:38 ` Bezdeka, Florian
@ 2021-10-05 15:18 ` Henning Schild
2021-10-07 8:37 ` Jan Kiszka
0 siblings, 1 reply; 15+ messages in thread
From: Henning Schild @ 2021-10-05 15:18 UTC (permalink / raw)
To: Bezdeka, Florian (T RDA IOT SES-DE); +Cc: xenomai, Kiszka, Jan (T RDA IOT)
Am Tue, 5 Oct 2021 16:38:12 +0200
schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
<florian.bezdeka@siemens.com>:
> On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai wrote:
> > On 24.09.21 15:31, Henning Schild via Xenomai wrote:
> > > Am Wed, 22 Sep 2021 16:21:54 +0200
> > > schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
> > >
> > > > Am Wed, 22 Sep 2021 14:36:49 +0200
> > > > schrieb Philippe Gerum <rpm@xenomai.org>:
> > > >
> > > > > Henning Schild via Xenomai <xenomai@xenomai.org> writes:
> > > > >
> > > > > > Hi,
> > > > > >
> > > > > > getting sick of maintaining a "small" kernel config i
> > > > > > wanted to switch to a config derived from the debian11 5.10
> > > > > > kernel. Basically that config plus the few switches coming
> > > > > > in with dovetail.
> > > > > >
> > > > > > That passed all tests in qemu but on a real machine (big
> > > > > > xeon with raid0) the "switchtest" has an issue.
> > > > > >
> > > > > > # /lib/xenomai/testsuite/switchtest
> > > > > > == Testing FPU check routines...
> > > > > > r0: 1 != 2
> > > > > > r1: 1 != 2
> > > > > > r2: 1 != 2
> > > > > > r3: 1 != 2
> > > > > > r4: 1 != 2
> > > > > > r5: 1 != 2
> > > > > > r6: 1 != 2
> > > > > > r7: 1 != 2
> > > > > > ymm0: 1/1 != 2/2
> > > > > > ymm1: 1/1 != 2/2
> > > > > > ymm2: 1/1 != 2/2
> > > > > > ymm3: 1/1 != 2/2
> > > > > > ymm4: 1/1 != 2/2
> > > > > > ymm5: 1/1 != 2/2
> > > > > > ymm6: 1/1 != 2/2
> > > > > > ymm7: 1/1 != 2/2
> > > > > > == FPU check routines: OK.
> > > > > > == Threads: ... a lot of threads ...
> > > > > > 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19
> > > > > > rtuo_ufps30-20 rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22
> > > > > > sleeper_ufpthread_create: Resource temporarily unavailable
> > > > > > ps31-0 rtk31-1 rtk31-2 rtk_fp31-3 rtk_fp31-4
> > > > > > rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
> > > > > > rtup_ufpp31-9 rtup_ufpp31-10 rtus
> > > > > >
> > > > > > followed by only 0s
> > > > > >
> > > > > > RTH|---------cpu|ctx switches|-------total
> > > > > > RTD| 0| 0| 0
> > > > > > RTD| 1| 0| 0
> > > > > > RTD| 2| 0| 0
> > > > > > RTD| 3| 0| 0
> > > > > > RTD| 4| 0| 0
> > > > > > RTD| 5| 0| 0
> > > > > > RTD| 6| 0| 0
> > > > > >
> > > > > > So it gets a
> > > > > >
> > > > > > sleeper_ufpthread_create: Resource temporarily unavailable
> > > > > >
> > > > > > but swallows that and keeps going. I think there might be a
> > > > > > first issue with that error return not being dealt with.
> > > > > >
> > > > > > A second run get the "switchtest" stuck after crtl+c while
> > > > > > the kernel starts complaining.
> > > > > >
> > > > > > [ 1229.072052] list_del corruption. prev->next should be
> > > > > > ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
> > > > > > ------------[ cut here ]------------ [ 1229.072054] kernel
> > > > > > BUG at lib/list_debug.c:51! [ 1229.072054] invalid opcode:
> > > > > > 0000 [#1] SMP PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID:
> > > > > > 1857 Comm: switchtest Tainted: G E
> > > > > > 5.10.61-xenomai-1 #1 [ 1229.072055] Hardware name: secret [
> > > > > > 1229.072055] IRQ stage: Linux [ 1229.072055] RIP:
> > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072056]
> > > > > > Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> > > > > > 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
> > > > > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
> > > > > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> > > > > > 0000000000000000 [ 1229.072062] RDX: 0000000000000000 RSI:
> > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072064] RBP:
> > > > > > 0000000000000000 R08: 0000000000000001 R09:
> > > > > > 000000000000000f [ 1229.072066] R10: 000000000000000f R11:
> > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072069] R13:
> > > > > > ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > > > > 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
> > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > 0000000080050033 [ 1229.072076] CR2: 000055921bfa921c CR3:
> > > > > > 00000001062fe002 CR4: 00000000001706e0 [ 1229.072078] Call
> > > > > > Trace: [ 1229.072080] xntimer_destroy+0x81/0x150 [
> > > > > > 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
> > > > > > cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
> > > > > > do_exit+0xe1/0xab0 [ 1229.072088] ?
> > > > > > signal_wake_up_state+0x23/0x40 [ 1229.072090]
> > > > > > do_group_exit+0x33/0xa0 [ 1229.072092]
> > > > > > __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
> > > > > > do_syscall_64+0x3f/0x90 [ 1229.072113]
> > > > > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115]
> > > > > > RIP: 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05
> > > > > > f9 27 0f 00 be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00
> > > > > > 00 89 0 [ 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS:
> > > > > > 00000246 ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX:
> > > > > > ffffffffffffffda RBX: 00007f57e6a3d610 RCX:
> > > > > > 00007f57e6948699 [ 1229.072130] RDX: 000000000000003c RSI:
> > > > > > 00000000000000e7 RDI: 0000000000000001 [ 1229.072132] RBP:
> > > > > > 0000000000000001 R08: ffffffffffffff70 R09:
> > > > > > 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
> > > > > > 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
> > > > > > 0000000000000002 R14: 00007f57e6a3dae8 R15:
> > > > > > 0000000000000000 [ 1229.072138] Modules linked in: md4(E)
> > > > > > sha512_ssse3(E) sha512_generic(E) cmac(E) nls_utf8(E) cifs)
> > > > > > [ 1229.072169] mei(E) soundcore(E) sysimgblt(E) sg(E)
> > > > > > evdev(E) ioatdma(E) joydev(E) watchdog(E) ac) [
> > > > > > 1229.072185] ---[ end trace a1d1ac68468e74f0 ]--- [
> > > > > > 1229.072186] RIP:
> > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187]
> > > > > > Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> > > > > > 51 0d ff ff 0f 0b 48 89 b [ 1229.072187] RSP:
> > > > > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072188] RAX:
> > > > > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> > > > > > 0000000000000000 [ 1229.072188] RDX: 0000000000000000 RSI:
> > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072189] RBP:
> > > > > > 0000000000000000 R08: 0000000000000001 R09:
> > > > > > 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
> > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
> > > > > > ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > > > > 0000000000000000 [ 1229.072190] FS: 00007f57e687bb80(0000)
> > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > 0000000080050033 [ 1229.072191] CR2: 000055921bfa921c CR3:
> > > > > > 00000001062fe002 CR4: 00000000001706e0 [ 1229.072191]
> > > > > > Fixing recursive fault but reboot is needed!
> > > > > >
> > > > > > I will look into that eventually. For now i just wanted to
> > > > > > share what i have so far, maybe someone knows what is going
> > > > > > on or can give a hint. function tracing was way too verbose
> > > > > > to find the rootcause of that EBUSY.
> > > > > >
> > > > >
> > > > > EAGAIN, switchtest triggers this when many CPUs are available
> > > > > but the system heap is too small (not enough space there to
> > > > > create thread TCBs and other core objects). Normally,
> > > > > switchtest exits properly after a while.
> > > >
> > > > Ok maybe that changed kernel config did shrink the available
> > > > heap, thanks for the hint.
> > > >
> > > > If it is an EAGAIN because of too little resources, maybe it
> > > > should keep trying with less and less CPUs. And spit a warning
> > > > like "could only run on 20 out of 32 cores".
> > > > At least that would be my first idea for a patch in case it is
> > > > that.
> > >
> > > The test runs just fine when reducing the number of cores to run
> > > on. In fact it was one too many ;)
> > >
> > > good
> > > ./switchtest -T 5 --cpu-affinity=0-30
> > > bad (where affinity includes all cpus)
> > > ./switchtest -T 5 --cpu-affinity=0-31
> > >
> > > > > The kernel splat looks like some issue on the error path
> > > > > which might not have been observed yet (maybe triggered by ^C
> > > > > while switchtest was unwinding).
> > > >
> > > > I saw exactly that in probably three attempts. First switchtest
> > > > killed with ctrl+c when the 0s come ... never any fun kernel
> > > > message. But always fun kernel message when the second run was
> > > > interrupted. So i would be tempted to call that reproducible
> > > > and not a one-time bad timing.
> > >
> > > But when running the bad case two times in a row, it will always
> > >
> > > kernel BUG at lib/list_debug.c:51!
> > >
> > > Even when none of the two runs was interrupted by ctrl+c.
> > >
> >
> > So, the main issue was solved by increasing resources, but we still
> > have a problem with handling errors gracefully - is that the
> > correct summary of this issue? Or where are we standing with this?
By reducing the number of threads, but yes that issue was "worked
around". The crash is something that was found as well and is still
open, in fact pretty easy to reproduce.
> Might that be related to a registry slot exhaustion? On the affected
> system we changed CONFIG_XENO_OPT_DEBUG from 4096 back to its default
> (512). Just an idea... ctrl+c might skip the resource cleanup.
I have no which ressource was exhausted. We could just try that kernel
with the bigger registry and compare with the smaller one. Thanks for
the hint.
Henning
> Looking into /proc/xenomai/registry/usage might help in such case.
>
> >
> > Jan
> >
>
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-05 15:18 ` Henning Schild
@ 2021-10-07 8:37 ` Jan Kiszka
2021-10-07 8:53 ` Bezdeka, Florian
2021-10-07 13:17 ` Henning Schild
0 siblings, 2 replies; 15+ messages in thread
From: Jan Kiszka @ 2021-10-07 8:37 UTC (permalink / raw)
To: Henning Schild, Bezdeka, Florian (T RDA IOT SES-DE); +Cc: xenomai
On 05.10.21 17:18, Henning Schild wrote:
> Am Tue, 5 Oct 2021 16:38:12 +0200
> schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
> <florian.bezdeka@siemens.com>:
>
>> On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai wrote:
>>> On 24.09.21 15:31, Henning Schild via Xenomai wrote:
>>>> Am Wed, 22 Sep 2021 16:21:54 +0200
>>>> schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
>>>>
>>>>> Am Wed, 22 Sep 2021 14:36:49 +0200
>>>>> schrieb Philippe Gerum <rpm@xenomai.org>:
>>>>>
>>>>>> Henning Schild via Xenomai <xenomai@xenomai.org> writes:
>>>>>>
>>>>>>> Hi,
>>>>>>>
>>>>>>> getting sick of maintaining a "small" kernel config i
>>>>>>> wanted to switch to a config derived from the debian11 5.10
>>>>>>> kernel. Basically that config plus the few switches coming
>>>>>>> in with dovetail.
>>>>>>>
>>>>>>> That passed all tests in qemu but on a real machine (big
>>>>>>> xeon with raid0) the "switchtest" has an issue.
>>>>>>>
>>>>>>> # /lib/xenomai/testsuite/switchtest
>>>>>>> == Testing FPU check routines...
>>>>>>> r0: 1 != 2
>>>>>>> r1: 1 != 2
>>>>>>> r2: 1 != 2
>>>>>>> r3: 1 != 2
>>>>>>> r4: 1 != 2
>>>>>>> r5: 1 != 2
>>>>>>> r6: 1 != 2
>>>>>>> r7: 1 != 2
>>>>>>> ymm0: 1/1 != 2/2
>>>>>>> ymm1: 1/1 != 2/2
>>>>>>> ymm2: 1/1 != 2/2
>>>>>>> ymm3: 1/1 != 2/2
>>>>>>> ymm4: 1/1 != 2/2
>>>>>>> ymm5: 1/1 != 2/2
>>>>>>> ymm6: 1/1 != 2/2
>>>>>>> ymm7: 1/1 != 2/2
>>>>>>> == FPU check routines: OK.
>>>>>>> == Threads: ... a lot of threads ...
>>>>>>> 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19
>>>>>>> rtuo_ufps30-20 rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22
>>>>>>> sleeper_ufpthread_create: Resource temporarily unavailable
>>>>>>> ps31-0 rtk31-1 rtk31-2 rtk_fp31-3 rtk_fp31-4
>>>>>>> rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
>>>>>>> rtup_ufpp31-9 rtup_ufpp31-10 rtus
>>>>>>>
>>>>>>> followed by only 0s
>>>>>>>
>>>>>>> RTH|---------cpu|ctx switches|-------total
>>>>>>> RTD| 0| 0| 0
>>>>>>> RTD| 1| 0| 0
>>>>>>> RTD| 2| 0| 0
>>>>>>> RTD| 3| 0| 0
>>>>>>> RTD| 4| 0| 0
>>>>>>> RTD| 5| 0| 0
>>>>>>> RTD| 6| 0| 0
>>>>>>>
>>>>>>> So it gets a
>>>>>>>
>>>>>>> sleeper_ufpthread_create: Resource temporarily unavailable
>>>>>>>
>>>>>>> but swallows that and keeps going. I think there might be a
>>>>>>> first issue with that error return not being dealt with.
>>>>>>>
>>>>>>> A second run get the "switchtest" stuck after crtl+c while
>>>>>>> the kernel starts complaining.
>>>>>>>
>>>>>>> [ 1229.072052] list_del corruption. prev->next should be
>>>>>>> ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
>>>>>>> ------------[ cut here ]------------ [ 1229.072054] kernel
>>>>>>> BUG at lib/list_debug.c:51! [ 1229.072054] invalid opcode:
>>>>>>> 0000 [#1] SMP PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID:
>>>>>>> 1857 Comm: switchtest Tainted: G E
>>>>>>> 5.10.61-xenomai-1 #1 [ 1229.072055] Hardware name: secret [
>>>>>>> 1229.072055] IRQ stage: Linux [ 1229.072055] RIP:
>>>>>>> 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072056]
>>>>>>> Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
>>>>>>> 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
>>>>>>> 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
>>>>>>> 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
>>>>>>> 0000000000000000 [ 1229.072062] RDX: 0000000000000000 RSI:
>>>>>>> ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072064] RBP:
>>>>>>> 0000000000000000 R08: 0000000000000001 R09:
>>>>>>> 000000000000000f [ 1229.072066] R10: 000000000000000f R11:
>>>>>>> ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072069] R13:
>>>>>>> ffffa0ff488c7380 R14: 0000000000000000 R15:
>>>>>>> 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
>>>>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
>>>>>>> 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0:
>>>>>>> 0000000080050033 [ 1229.072076] CR2: 000055921bfa921c CR3:
>>>>>>> 00000001062fe002 CR4: 00000000001706e0 [ 1229.072078] Call
>>>>>>> Trace: [ 1229.072080] xntimer_destroy+0x81/0x150 [
>>>>>>> 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
>>>>>>> cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
>>>>>>> do_exit+0xe1/0xab0 [ 1229.072088] ?
>>>>>>> signal_wake_up_state+0x23/0x40 [ 1229.072090]
>>>>>>> do_group_exit+0x33/0xa0 [ 1229.072092]
>>>>>>> __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
>>>>>>> do_syscall_64+0x3f/0x90 [ 1229.072113]
>>>>>>> entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115]
>>>>>>> RIP: 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05
>>>>>>> f9 27 0f 00 be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00
>>>>>>> 00 89 0 [ 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS:
>>>>>>> 00000246 ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX:
>>>>>>> ffffffffffffffda RBX: 00007f57e6a3d610 RCX:
>>>>>>> 00007f57e6948699 [ 1229.072130] RDX: 000000000000003c RSI:
>>>>>>> 00000000000000e7 RDI: 0000000000000001 [ 1229.072132] RBP:
>>>>>>> 0000000000000001 R08: ffffffffffffff70 R09:
>>>>>>> 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
>>>>>>> 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
>>>>>>> 0000000000000002 R14: 00007f57e6a3dae8 R15:
>>>>>>> 0000000000000000 [ 1229.072138] Modules linked in: md4(E)
>>>>>>> sha512_ssse3(E) sha512_generic(E) cmac(E) nls_utf8(E) cifs)
>>>>>>> [ 1229.072169] mei(E) soundcore(E) sysimgblt(E) sg(E)
>>>>>>> evdev(E) ioatdma(E) joydev(E) watchdog(E) ac) [
>>>>>>> 1229.072185] ---[ end trace a1d1ac68468e74f0 ]--- [
>>>>>>> 1229.072186] RIP:
>>>>>>> 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187]
>>>>>>> Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
>>>>>>> 51 0d ff ff 0f 0b 48 89 b [ 1229.072187] RSP:
>>>>>>> 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072188] RAX:
>>>>>>> 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
>>>>>>> 0000000000000000 [ 1229.072188] RDX: 0000000000000000 RSI:
>>>>>>> ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072189] RBP:
>>>>>>> 0000000000000000 R08: 0000000000000001 R09:
>>>>>>> 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
>>>>>>> ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
>>>>>>> ffffa0ff488c7380 R14: 0000000000000000 R15:
>>>>>>> 0000000000000000 [ 1229.072190] FS: 00007f57e687bb80(0000)
>>>>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
>>>>>>> 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0:
>>>>>>> 0000000080050033 [ 1229.072191] CR2: 000055921bfa921c CR3:
>>>>>>> 00000001062fe002 CR4: 00000000001706e0 [ 1229.072191]
>>>>>>> Fixing recursive fault but reboot is needed!
>>>>>>>
>>>>>>> I will look into that eventually. For now i just wanted to
>>>>>>> share what i have so far, maybe someone knows what is going
>>>>>>> on or can give a hint. function tracing was way too verbose
>>>>>>> to find the rootcause of that EBUSY.
>>>>>>>
>>>>>>
>>>>>> EAGAIN, switchtest triggers this when many CPUs are available
>>>>>> but the system heap is too small (not enough space there to
>>>>>> create thread TCBs and other core objects). Normally,
>>>>>> switchtest exits properly after a while.
>>>>>
>>>>> Ok maybe that changed kernel config did shrink the available
>>>>> heap, thanks for the hint.
>>>>>
>>>>> If it is an EAGAIN because of too little resources, maybe it
>>>>> should keep trying with less and less CPUs. And spit a warning
>>>>> like "could only run on 20 out of 32 cores".
>>>>> At least that would be my first idea for a patch in case it is
>>>>> that.
>>>>
>>>> The test runs just fine when reducing the number of cores to run
>>>> on. In fact it was one too many ;)
>>>>
>>>> good
>>>> ./switchtest -T 5 --cpu-affinity=0-30
>>>> bad (where affinity includes all cpus)
>>>> ./switchtest -T 5 --cpu-affinity=0-31
>>>>
>>>>>> The kernel splat looks like some issue on the error path
>>>>>> which might not have been observed yet (maybe triggered by ^C
>>>>>> while switchtest was unwinding).
>>>>>
>>>>> I saw exactly that in probably three attempts. First switchtest
>>>>> killed with ctrl+c when the 0s come ... never any fun kernel
>>>>> message. But always fun kernel message when the second run was
>>>>> interrupted. So i would be tempted to call that reproducible
>>>>> and not a one-time bad timing.
>>>>
>>>> But when running the bad case two times in a row, it will always
>>>>
>>>> kernel BUG at lib/list_debug.c:51!
>>>>
>>>> Even when none of the two runs was interrupted by ctrl+c.
>>>>
>>>
>>> So, the main issue was solved by increasing resources, but we still
>>> have a problem with handling errors gracefully - is that the
>>> correct summary of this issue? Or where are we standing with this?
>
> By reducing the number of threads, but yes that issue was "worked
> around". The crash is something that was found as well and is still
> open, in fact pretty easy to reproduce.
>
How can I reproduce that?
Jan
>> Might that be related to a registry slot exhaustion? On the affected
>> system we changed CONFIG_XENO_OPT_DEBUG from 4096 back to its default
>> (512). Just an idea... ctrl+c might skip the resource cleanup.
>
> I have no which ressource was exhausted. We could just try that kernel
> with the bigger registry and compare with the smaller one. Thanks for
> the hint.
>
> Henning
>
>> Looking into /proc/xenomai/registry/usage might help in such case.
>>
>>>
>>> Jan
>>>
>>
>
--
Siemens AG, T RDA IOT
Corporate Competence Center Embedded Linux
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-07 8:37 ` Jan Kiszka
@ 2021-10-07 8:53 ` Bezdeka, Florian
2021-10-07 8:55 ` Bezdeka, Florian
2021-10-07 13:17 ` Henning Schild
1 sibling, 1 reply; 15+ messages in thread
From: Bezdeka, Florian @ 2021-10-07 8:53 UTC (permalink / raw)
To: jan.kiszka, henning.schild; +Cc: xenomai
On Thu, 2021-10-07 at 10:37 +0200, Jan Kiszka wrote:
> On 05.10.21 17:18, Henning Schild wrote:
> > Am Tue, 5 Oct 2021 16:38:12 +0200
> > schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
> > <florian.bezdeka@siemens.com>:
> >
> > > On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai wrote:
> > > > On 24.09.21 15:31, Henning Schild via Xenomai wrote:
> > > > > Am Wed, 22 Sep 2021 16:21:54 +0200
> > > > > schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
> > > > >
> > > > > > Am Wed, 22 Sep 2021 14:36:49 +0200
> > > > > > schrieb Philippe Gerum <rpm@xenomai.org>:
> > > > > >
> > > > > > > Henning Schild via Xenomai <xenomai@xenomai.org> writes:
> > > > > > >
> > > > > > > > Hi,
> > > > > > > >
> > > > > > > > getting sick of maintaining a "small" kernel config i
> > > > > > > > wanted to switch to a config derived from the debian11 5.10
> > > > > > > > kernel. Basically that config plus the few switches coming
> > > > > > > > in with dovetail.
> > > > > > > >
> > > > > > > > That passed all tests in qemu but on a real machine (big
> > > > > > > > xeon with raid0) the "switchtest" has an issue.
> > > > > > > >
> > > > > > > > # /lib/xenomai/testsuite/switchtest
> > > > > > > > == Testing FPU check routines...
> > > > > > > > r0: 1 != 2
> > > > > > > > r1: 1 != 2
> > > > > > > > r2: 1 != 2
> > > > > > > > r3: 1 != 2
> > > > > > > > r4: 1 != 2
> > > > > > > > r5: 1 != 2
> > > > > > > > r6: 1 != 2
> > > > > > > > r7: 1 != 2
> > > > > > > > ymm0: 1/1 != 2/2
> > > > > > > > ymm1: 1/1 != 2/2
> > > > > > > > ymm2: 1/1 != 2/2
> > > > > > > > ymm3: 1/1 != 2/2
> > > > > > > > ymm4: 1/1 != 2/2
> > > > > > > > ymm5: 1/1 != 2/2
> > > > > > > > ymm6: 1/1 != 2/2
> > > > > > > > ymm7: 1/1 != 2/2
> > > > > > > > == FPU check routines: OK.
> > > > > > > > == Threads: ... a lot of threads ...
> > > > > > > > 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19
> > > > > > > > rtuo_ufps30-20 rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22
> > > > > > > > sleeper_ufpthread_create: Resource temporarily unavailable
> > > > > > > > ps31-0 rtk31-1 rtk31-2 rtk_fp31-3 rtk_fp31-4
> > > > > > > > rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
> > > > > > > > rtup_ufpp31-9 rtup_ufpp31-10 rtus
> > > > > > > >
> > > > > > > > followed by only 0s
> > > > > > > >
> > > > > > > > RTH|---------cpu|ctx switches|-------total
> > > > > > > > RTD| 0| 0| 0
> > > > > > > > RTD| 1| 0| 0
> > > > > > > > RTD| 2| 0| 0
> > > > > > > > RTD| 3| 0| 0
> > > > > > > > RTD| 4| 0| 0
> > > > > > > > RTD| 5| 0| 0
> > > > > > > > RTD| 6| 0| 0
> > > > > > > >
> > > > > > > > So it gets a
> > > > > > > >
> > > > > > > > sleeper_ufpthread_create: Resource temporarily unavailable
> > > > > > > >
> > > > > > > > but swallows that and keeps going. I think there might be a
> > > > > > > > first issue with that error return not being dealt with.
> > > > > > > >
> > > > > > > > A second run get the "switchtest" stuck after crtl+c while
> > > > > > > > the kernel starts complaining.
> > > > > > > >
> > > > > > > > [ 1229.072052] list_del corruption. prev->next should be
> > > > > > > > ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
> > > > > > > > ------------[ cut here ]------------ [ 1229.072054] kernel
> > > > > > > > BUG at lib/list_debug.c:51! [ 1229.072054] invalid opcode:
> > > > > > > > 0000 [#1] SMP PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID:
> > > > > > > > 1857 Comm: switchtest Tainted: G E
> > > > > > > > 5.10.61-xenomai-1 #1 [ 1229.072055] Hardware name: secret [
> > > > > > > > 1229.072055] IRQ stage: Linux [ 1229.072055] RIP:
> > > > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072056]
> > > > > > > > Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> > > > > > > > 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
> > > > > > > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
> > > > > > > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> > > > > > > > 0000000000000000 [ 1229.072062] RDX: 0000000000000000 RSI:
> > > > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072064] RBP:
> > > > > > > > 0000000000000000 R08: 0000000000000001 R09:
> > > > > > > > 000000000000000f [ 1229.072066] R10: 000000000000000f R11:
> > > > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072069] R13:
> > > > > > > > ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > > > > > > 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
> > > > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > > > 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > > > 0000000080050033 [ 1229.072076] CR2: 000055921bfa921c CR3:
> > > > > > > > 00000001062fe002 CR4: 00000000001706e0 [ 1229.072078] Call
> > > > > > > > Trace: [ 1229.072080] xntimer_destroy+0x81/0x150 [
> > > > > > > > 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
> > > > > > > > cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
> > > > > > > > do_exit+0xe1/0xab0 [ 1229.072088] ?
> > > > > > > > signal_wake_up_state+0x23/0x40 [ 1229.072090]
> > > > > > > > do_group_exit+0x33/0xa0 [ 1229.072092]
> > > > > > > > __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
> > > > > > > > do_syscall_64+0x3f/0x90 [ 1229.072113]
> > > > > > > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115]
> > > > > > > > RIP: 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05
> > > > > > > > f9 27 0f 00 be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00
> > > > > > > > 00 89 0 [ 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS:
> > > > > > > > 00000246 ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX:
> > > > > > > > ffffffffffffffda RBX: 00007f57e6a3d610 RCX:
> > > > > > > > 00007f57e6948699 [ 1229.072130] RDX: 000000000000003c RSI:
> > > > > > > > 00000000000000e7 RDI: 0000000000000001 [ 1229.072132] RBP:
> > > > > > > > 0000000000000001 R08: ffffffffffffff70 R09:
> > > > > > > > 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
> > > > > > > > 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
> > > > > > > > 0000000000000002 R14: 00007f57e6a3dae8 R15:
> > > > > > > > 0000000000000000 [ 1229.072138] Modules linked in: md4(E)
> > > > > > > > sha512_ssse3(E) sha512_generic(E) cmac(E) nls_utf8(E) cifs)
> > > > > > > > [ 1229.072169] mei(E) soundcore(E) sysimgblt(E) sg(E)
> > > > > > > > evdev(E) ioatdma(E) joydev(E) watchdog(E) ac) [
> > > > > > > > 1229.072185] ---[ end trace a1d1ac68468e74f0 ]--- [
> > > > > > > > 1229.072186] RIP:
> > > > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187]
> > > > > > > > Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> > > > > > > > 51 0d ff ff 0f 0b 48 89 b [ 1229.072187] RSP:
> > > > > > > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072188] RAX:
> > > > > > > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> > > > > > > > 0000000000000000 [ 1229.072188] RDX: 0000000000000000 RSI:
> > > > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072189] RBP:
> > > > > > > > 0000000000000000 R08: 0000000000000001 R09:
> > > > > > > > 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
> > > > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
> > > > > > > > ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > > > > > > 0000000000000000 [ 1229.072190] FS: 00007f57e687bb80(0000)
> > > > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > > > 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > > > 0000000080050033 [ 1229.072191] CR2: 000055921bfa921c CR3:
> > > > > > > > 00000001062fe002 CR4: 00000000001706e0 [ 1229.072191]
> > > > > > > > Fixing recursive fault but reboot is needed!
> > > > > > > >
> > > > > > > > I will look into that eventually. For now i just wanted to
> > > > > > > > share what i have so far, maybe someone knows what is going
> > > > > > > > on or can give a hint. function tracing was way too verbose
> > > > > > > > to find the rootcause of that EBUSY.
> > > > > > > >
> > > > > > >
> > > > > > > EAGAIN, switchtest triggers this when many CPUs are available
> > > > > > > but the system heap is too small (not enough space there to
> > > > > > > create thread TCBs and other core objects). Normally,
> > > > > > > switchtest exits properly after a while.
> > > > > >
> > > > > > Ok maybe that changed kernel config did shrink the available
> > > > > > heap, thanks for the hint.
> > > > > >
> > > > > > If it is an EAGAIN because of too little resources, maybe it
> > > > > > should keep trying with less and less CPUs. And spit a warning
> > > > > > like "could only run on 20 out of 32 cores".
> > > > > > At least that would be my first idea for a patch in case it is
> > > > > > that.
> > > > >
> > > > > The test runs just fine when reducing the number of cores to run
> > > > > on. In fact it was one too many ;)
> > > > >
> > > > > good
> > > > > ./switchtest -T 5 --cpu-affinity=0-30
> > > > > bad (where affinity includes all cpus)
> > > > > ./switchtest -T 5 --cpu-affinity=0-31
> > > > >
> > > > > > > The kernel splat looks like some issue on the error path
> > > > > > > which might not have been observed yet (maybe triggered by ^C
> > > > > > > while switchtest was unwinding).
> > > > > >
> > > > > > I saw exactly that in probably three attempts. First switchtest
> > > > > > killed with ctrl+c when the 0s come ... never any fun kernel
> > > > > > message. But always fun kernel message when the second run was
> > > > > > interrupted. So i would be tempted to call that reproducible
> > > > > > and not a one-time bad timing.
> > > > >
> > > > > But when running the bad case two times in a row, it will always
> > > > >
> > > > > kernel BUG at lib/list_debug.c:51!
> > > > >
> > > > > Even when none of the two runs was interrupted by ctrl+c.
> > > > >
> > > >
> > > > So, the main issue was solved by increasing resources, but we still
> > > > have a problem with handling errors gracefully - is that the
> > > > correct summary of this issue? Or where are we standing with this?
> >
> > By reducing the number of threads, but yes that issue was "worked
> > around". The crash is something that was found as well and is still
> > open, in fact pretty easy to reproduce.
> >
>
> How can I reproduce that?
I tried it again on the system that Henning was using when reporting
the problem. We increased CONFIG_XENO_OPT_DEBUG from 512 to 4096 in the
meantime.
Taken while switchtest is running on that system:
# cat /proc/xenomai/registry/usage
523/4096
So with the old 512 slots we would run into a exhaustion on such a big
system. IMHO that should be the root cause.
Configuration problem, no bug.
Henning, please correct me if you disagree.
>
> Jan
>
> > > Might that be related to a registry slot exhaustion? On the affected
> > > system we changed CONFIG_XENO_OPT_DEBUG from 4096 back to its default
> > > (512). Just an idea... ctrl+c might skip the resource cleanup.
> >
> > I have no which ressource was exhausted. We could just try that kernel
> > with the bigger registry and compare with the smaller one. Thanks for
> > the hint.
> >
> > Henning
> >
> > > Looking into /proc/xenomai/registry/usage might help in such case.
> > >
> > > >
> > > > Jan
> > > >
> > >
> >
>
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-07 8:53 ` Bezdeka, Florian
@ 2021-10-07 8:55 ` Bezdeka, Florian
2021-10-07 9:05 ` Bezdeka, Florian
2021-10-07 13:29 ` Henning Schild
0 siblings, 2 replies; 15+ messages in thread
From: Bezdeka, Florian @ 2021-10-07 8:55 UTC (permalink / raw)
To: jan.kiszka, henning.schild; +Cc: xenomai
On Thu, 2021-10-07 at 08:53 +0000, Bezdeka, Florian via Xenomai wrote:
> On Thu, 2021-10-07 at 10:37 +0200, Jan Kiszka wrote:
> > On 05.10.21 17:18, Henning Schild wrote:
> > > Am Tue, 5 Oct 2021 16:38:12 +0200
> > > schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
> > > <florian.bezdeka@siemens.com>:
> > >
> > > > On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai wrote:
> > > > > On 24.09.21 15:31, Henning Schild via Xenomai wrote:
> > > > > > Am Wed, 22 Sep 2021 16:21:54 +0200
> > > > > > schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
> > > > > >
> > > > > > > Am Wed, 22 Sep 2021 14:36:49 +0200
> > > > > > > schrieb Philippe Gerum <rpm@xenomai.org>:
> > > > > > >
> > > > > > > > Henning Schild via Xenomai <xenomai@xenomai.org> writes:
> > > > > > > >
> > > > > > > > > Hi,
> > > > > > > > >
> > > > > > > > > getting sick of maintaining a "small" kernel config i
> > > > > > > > > wanted to switch to a config derived from the debian11 5.10
> > > > > > > > > kernel. Basically that config plus the few switches coming
> > > > > > > > > in with dovetail.
> > > > > > > > >
> > > > > > > > > That passed all tests in qemu but on a real machine (big
> > > > > > > > > xeon with raid0) the "switchtest" has an issue.
> > > > > > > > >
> > > > > > > > > # /lib/xenomai/testsuite/switchtest
> > > > > > > > > == Testing FPU check routines...
> > > > > > > > > r0: 1 != 2
> > > > > > > > > r1: 1 != 2
> > > > > > > > > r2: 1 != 2
> > > > > > > > > r3: 1 != 2
> > > > > > > > > r4: 1 != 2
> > > > > > > > > r5: 1 != 2
> > > > > > > > > r6: 1 != 2
> > > > > > > > > r7: 1 != 2
> > > > > > > > > ymm0: 1/1 != 2/2
> > > > > > > > > ymm1: 1/1 != 2/2
> > > > > > > > > ymm2: 1/1 != 2/2
> > > > > > > > > ymm3: 1/1 != 2/2
> > > > > > > > > ymm4: 1/1 != 2/2
> > > > > > > > > ymm5: 1/1 != 2/2
> > > > > > > > > ymm6: 1/1 != 2/2
> > > > > > > > > ymm7: 1/1 != 2/2
> > > > > > > > > == FPU check routines: OK.
> > > > > > > > > == Threads: ... a lot of threads ...
> > > > > > > > > 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19
> > > > > > > > > rtuo_ufps30-20 rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22
> > > > > > > > > sleeper_ufpthread_create: Resource temporarily unavailable
> > > > > > > > > ps31-0 rtk31-1 rtk31-2 rtk_fp31-3 rtk_fp31-4
> > > > > > > > > rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
> > > > > > > > > rtup_ufpp31-9 rtup_ufpp31-10 rtus
> > > > > > > > >
> > > > > > > > > followed by only 0s
> > > > > > > > >
> > > > > > > > > RTH|---------cpu|ctx switches|-------total
> > > > > > > > > RTD| 0| 0| 0
> > > > > > > > > RTD| 1| 0| 0
> > > > > > > > > RTD| 2| 0| 0
> > > > > > > > > RTD| 3| 0| 0
> > > > > > > > > RTD| 4| 0| 0
> > > > > > > > > RTD| 5| 0| 0
> > > > > > > > > RTD| 6| 0| 0
> > > > > > > > >
> > > > > > > > > So it gets a
> > > > > > > > >
> > > > > > > > > sleeper_ufpthread_create: Resource temporarily unavailable
> > > > > > > > >
> > > > > > > > > but swallows that and keeps going. I think there might be a
> > > > > > > > > first issue with that error return not being dealt with.
> > > > > > > > >
> > > > > > > > > A second run get the "switchtest" stuck after crtl+c while
> > > > > > > > > the kernel starts complaining.
> > > > > > > > >
> > > > > > > > > [ 1229.072052] list_del corruption. prev->next should be
> > > > > > > > > ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
> > > > > > > > > ------------[ cut here ]------------ [ 1229.072054] kernel
> > > > > > > > > BUG at lib/list_debug.c:51! [ 1229.072054] invalid opcode:
> > > > > > > > > 0000 [#1] SMP PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID:
> > > > > > > > > 1857 Comm: switchtest Tainted: G E
> > > > > > > > > 5.10.61-xenomai-1 #1 [ 1229.072055] Hardware name: secret [
> > > > > > > > > 1229.072055] IRQ stage: Linux [ 1229.072055] RIP:
> > > > > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072056]
> > > > > > > > > Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> > > > > > > > > 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
> > > > > > > > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
> > > > > > > > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> > > > > > > > > 0000000000000000 [ 1229.072062] RDX: 0000000000000000 RSI:
> > > > > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072064] RBP:
> > > > > > > > > 0000000000000000 R08: 0000000000000001 R09:
> > > > > > > > > 000000000000000f [ 1229.072066] R10: 000000000000000f R11:
> > > > > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072069] R13:
> > > > > > > > > ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > > > > > > > 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
> > > > > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > > > > 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > > > > 0000000080050033 [ 1229.072076] CR2: 000055921bfa921c CR3:
> > > > > > > > > 00000001062fe002 CR4: 00000000001706e0 [ 1229.072078] Call
> > > > > > > > > Trace: [ 1229.072080] xntimer_destroy+0x81/0x150 [
> > > > > > > > > 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
> > > > > > > > > cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
> > > > > > > > > do_exit+0xe1/0xab0 [ 1229.072088] ?
> > > > > > > > > signal_wake_up_state+0x23/0x40 [ 1229.072090]
> > > > > > > > > do_group_exit+0x33/0xa0 [ 1229.072092]
> > > > > > > > > __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
> > > > > > > > > do_syscall_64+0x3f/0x90 [ 1229.072113]
> > > > > > > > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115]
> > > > > > > > > RIP: 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05
> > > > > > > > > f9 27 0f 00 be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00
> > > > > > > > > 00 89 0 [ 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS:
> > > > > > > > > 00000246 ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX:
> > > > > > > > > ffffffffffffffda RBX: 00007f57e6a3d610 RCX:
> > > > > > > > > 00007f57e6948699 [ 1229.072130] RDX: 000000000000003c RSI:
> > > > > > > > > 00000000000000e7 RDI: 0000000000000001 [ 1229.072132] RBP:
> > > > > > > > > 0000000000000001 R08: ffffffffffffff70 R09:
> > > > > > > > > 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
> > > > > > > > > 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
> > > > > > > > > 0000000000000002 R14: 00007f57e6a3dae8 R15:
> > > > > > > > > 0000000000000000 [ 1229.072138] Modules linked in: md4(E)
> > > > > > > > > sha512_ssse3(E) sha512_generic(E) cmac(E) nls_utf8(E) cifs)
> > > > > > > > > [ 1229.072169] mei(E) soundcore(E) sysimgblt(E) sg(E)
> > > > > > > > > evdev(E) ioatdma(E) joydev(E) watchdog(E) ac) [
> > > > > > > > > 1229.072185] ---[ end trace a1d1ac68468e74f0 ]--- [
> > > > > > > > > 1229.072186] RIP:
> > > > > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187]
> > > > > > > > > Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> > > > > > > > > 51 0d ff ff 0f 0b 48 89 b [ 1229.072187] RSP:
> > > > > > > > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072188] RAX:
> > > > > > > > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> > > > > > > > > 0000000000000000 [ 1229.072188] RDX: 0000000000000000 RSI:
> > > > > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072189] RBP:
> > > > > > > > > 0000000000000000 R08: 0000000000000001 R09:
> > > > > > > > > 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
> > > > > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
> > > > > > > > > ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > > > > > > > 0000000000000000 [ 1229.072190] FS: 00007f57e687bb80(0000)
> > > > > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > > > > 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > > > > 0000000080050033 [ 1229.072191] CR2: 000055921bfa921c CR3:
> > > > > > > > > 00000001062fe002 CR4: 00000000001706e0 [ 1229.072191]
> > > > > > > > > Fixing recursive fault but reboot is needed!
> > > > > > > > >
> > > > > > > > > I will look into that eventually. For now i just wanted to
> > > > > > > > > share what i have so far, maybe someone knows what is going
> > > > > > > > > on or can give a hint. function tracing was way too verbose
> > > > > > > > > to find the rootcause of that EBUSY.
> > > > > > > > >
> > > > > > > >
> > > > > > > > EAGAIN, switchtest triggers this when many CPUs are available
> > > > > > > > but the system heap is too small (not enough space there to
> > > > > > > > create thread TCBs and other core objects). Normally,
> > > > > > > > switchtest exits properly after a while.
> > > > > > >
> > > > > > > Ok maybe that changed kernel config did shrink the available
> > > > > > > heap, thanks for the hint.
> > > > > > >
> > > > > > > If it is an EAGAIN because of too little resources, maybe it
> > > > > > > should keep trying with less and less CPUs. And spit a warning
> > > > > > > like "could only run on 20 out of 32 cores".
> > > > > > > At least that would be my first idea for a patch in case it is
> > > > > > > that.
> > > > > >
> > > > > > The test runs just fine when reducing the number of cores to run
> > > > > > on. In fact it was one too many ;)
> > > > > >
> > > > > > good
> > > > > > ./switchtest -T 5 --cpu-affinity=0-30
> > > > > > bad (where affinity includes all cpus)
> > > > > > ./switchtest -T 5 --cpu-affinity=0-31
> > > > > >
> > > > > > > > The kernel splat looks like some issue on the error path
> > > > > > > > which might not have been observed yet (maybe triggered by ^C
> > > > > > > > while switchtest was unwinding).
> > > > > > >
> > > > > > > I saw exactly that in probably three attempts. First switchtest
> > > > > > > killed with ctrl+c when the 0s come ... never any fun kernel
> > > > > > > message. But always fun kernel message when the second run was
> > > > > > > interrupted. So i would be tempted to call that reproducible
> > > > > > > and not a one-time bad timing.
> > > > > >
> > > > > > But when running the bad case two times in a row, it will always
> > > > > >
> > > > > > kernel BUG at lib/list_debug.c:51!
> > > > > >
> > > > > > Even when none of the two runs was interrupted by ctrl+c.
> > > > > >
> > > > >
> > > > > So, the main issue was solved by increasing resources, but we still
> > > > > have a problem with handling errors gracefully - is that the
> > > > > correct summary of this issue? Or where are we standing with this?
> > >
> > > By reducing the number of threads, but yes that issue was "worked
> > > around". The crash is something that was found as well and is still
> > > open, in fact pretty easy to reproduce.
> > >
> >
> > How can I reproduce that?
>
> I tried it again on the system that Henning was using when reporting
> the problem. We increased CONFIG_XENO_OPT_DEBUG from 512 to 4096 in the
> meantime.
>
> Taken while switchtest is running on that system:
>
> # cat /proc/xenomai/registry/usage
> 523/4096
>
> So with the old 512 slots we would run into a exhaustion on such a big
> system. IMHO that should be the root cause.
>
> Configuration problem, no bug.
Correction: Maybe we have a problem in one of the error handling pathes
in switchtest?
>
> Henning, please correct me if you disagree.
>
> >
> > Jan
> >
> > > > Might that be related to a registry slot exhaustion? On the affected
> > > > system we changed CONFIG_XENO_OPT_DEBUG from 4096 back to its default
> > > > (512). Just an idea... ctrl+c might skip the resource cleanup.
> > >
> > > I have no which ressource was exhausted. We could just try that kernel
> > > with the bigger registry and compare with the smaller one. Thanks for
> > > the hint.
> > >
> > > Henning
> > >
> > > > Looking into /proc/xenomai/registry/usage might help in such case.
> > > >
> > > > >
> > > > > Jan
> > > > >
> > > >
> > >
> >
>
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-07 8:55 ` Bezdeka, Florian
@ 2021-10-07 9:05 ` Bezdeka, Florian
2021-10-07 12:45 ` Jan Kiszka
2021-10-07 13:29 ` Henning Schild
1 sibling, 1 reply; 15+ messages in thread
From: Bezdeka, Florian @ 2021-10-07 9:05 UTC (permalink / raw)
To: jan.kiszka, henning.schild; +Cc: xenomai
On Thu, 2021-10-07 at 08:55 +0000, Bezdeka, Florian via Xenomai wrote:
> On Thu, 2021-10-07 at 08:53 +0000, Bezdeka, Florian via Xenomai wrote:
> > On Thu, 2021-10-07 at 10:37 +0200, Jan Kiszka wrote:
> > > On 05.10.21 17:18, Henning Schild wrote:
> > > > Am Tue, 5 Oct 2021 16:38:12 +0200
> > > > schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
> > > > <florian.bezdeka@siemens.com>:
> > > >
> > > > > On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai wrote:
> > > > > > On 24.09.21 15:31, Henning Schild via Xenomai wrote:
> > > > > > > Am Wed, 22 Sep 2021 16:21:54 +0200
> > > > > > > schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
> > > > > > >
> > > > > > > > Am Wed, 22 Sep 2021 14:36:49 +0200
> > > > > > > > schrieb Philippe Gerum <rpm@xenomai.org>:
> > > > > > > >
> > > > > > > > > Henning Schild via Xenomai <xenomai@xenomai.org> writes:
> > > > > > > > >
> > > > > > > > > > Hi,
> > > > > > > > > >
> > > > > > > > > > getting sick of maintaining a "small" kernel config i
> > > > > > > > > > wanted to switch to a config derived from the debian11 5.10
> > > > > > > > > > kernel. Basically that config plus the few switches coming
> > > > > > > > > > in with dovetail.
> > > > > > > > > >
> > > > > > > > > > That passed all tests in qemu but on a real machine (big
> > > > > > > > > > xeon with raid0) the "switchtest" has an issue.
> > > > > > > > > >
> > > > > > > > > > # /lib/xenomai/testsuite/switchtest
> > > > > > > > > > == Testing FPU check routines...
> > > > > > > > > > r0: 1 != 2
> > > > > > > > > > r1: 1 != 2
> > > > > > > > > > r2: 1 != 2
> > > > > > > > > > r3: 1 != 2
> > > > > > > > > > r4: 1 != 2
> > > > > > > > > > r5: 1 != 2
> > > > > > > > > > r6: 1 != 2
> > > > > > > > > > r7: 1 != 2
> > > > > > > > > > ymm0: 1/1 != 2/2
> > > > > > > > > > ymm1: 1/1 != 2/2
> > > > > > > > > > ymm2: 1/1 != 2/2
> > > > > > > > > > ymm3: 1/1 != 2/2
> > > > > > > > > > ymm4: 1/1 != 2/2
> > > > > > > > > > ymm5: 1/1 != 2/2
> > > > > > > > > > ymm6: 1/1 != 2/2
> > > > > > > > > > ymm7: 1/1 != 2/2
> > > > > > > > > > == FPU check routines: OK.
> > > > > > > > > > == Threads: ... a lot of threads ...
> > > > > > > > > > 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19
> > > > > > > > > > rtuo_ufps30-20 rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22
> > > > > > > > > > sleeper_ufpthread_create: Resource temporarily unavailable
> > > > > > > > > > ps31-0 rtk31-1 rtk31-2 rtk_fp31-3 rtk_fp31-4
> > > > > > > > > > rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
> > > > > > > > > > rtup_ufpp31-9 rtup_ufpp31-10 rtus
> > > > > > > > > >
> > > > > > > > > > followed by only 0s
> > > > > > > > > >
> > > > > > > > > > RTH|---------cpu|ctx switches|-------total
> > > > > > > > > > RTD| 0| 0| 0
> > > > > > > > > > RTD| 1| 0| 0
> > > > > > > > > > RTD| 2| 0| 0
> > > > > > > > > > RTD| 3| 0| 0
> > > > > > > > > > RTD| 4| 0| 0
> > > > > > > > > > RTD| 5| 0| 0
> > > > > > > > > > RTD| 6| 0| 0
> > > > > > > > > >
> > > > > > > > > > So it gets a
> > > > > > > > > >
> > > > > > > > > > sleeper_ufpthread_create: Resource temporarily unavailable
> > > > > > > > > >
> > > > > > > > > > but swallows that and keeps going. I think there might be a
> > > > > > > > > > first issue with that error return not being dealt with.
> > > > > > > > > >
> > > > > > > > > > A second run get the "switchtest" stuck after crtl+c while
> > > > > > > > > > the kernel starts complaining.
> > > > > > > > > >
> > > > > > > > > > [ 1229.072052] list_del corruption. prev->next should be
> > > > > > > > > > ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
> > > > > > > > > > ------------[ cut here ]------------ [ 1229.072054] kernel
> > > > > > > > > > BUG at lib/list_debug.c:51! [ 1229.072054] invalid opcode:
> > > > > > > > > > 0000 [#1] SMP PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID:
> > > > > > > > > > 1857 Comm: switchtest Tainted: G E
> > > > > > > > > > 5.10.61-xenomai-1 #1 [ 1229.072055] Hardware name: secret [
> > > > > > > > > > 1229.072055] IRQ stage: Linux [ 1229.072055] RIP:
> > > > > > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072056]
> > > > > > > > > > Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> > > > > > > > > > 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
> > > > > > > > > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
> > > > > > > > > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> > > > > > > > > > 0000000000000000 [ 1229.072062] RDX: 0000000000000000 RSI:
> > > > > > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072064] RBP:
> > > > > > > > > > 0000000000000000 R08: 0000000000000001 R09:
> > > > > > > > > > 000000000000000f [ 1229.072066] R10: 000000000000000f R11:
> > > > > > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072069] R13:
> > > > > > > > > > ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > > > > > > > > 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
> > > > > > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > > > > > 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > > > > > 0000000080050033 [ 1229.072076] CR2: 000055921bfa921c CR3:
> > > > > > > > > > 00000001062fe002 CR4: 00000000001706e0 [ 1229.072078] Call
> > > > > > > > > > Trace: [ 1229.072080] xntimer_destroy+0x81/0x150 [
> > > > > > > > > > 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
> > > > > > > > > > cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
> > > > > > > > > > do_exit+0xe1/0xab0 [ 1229.072088] ?
> > > > > > > > > > signal_wake_up_state+0x23/0x40 [ 1229.072090]
> > > > > > > > > > do_group_exit+0x33/0xa0 [ 1229.072092]
> > > > > > > > > > __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
> > > > > > > > > > do_syscall_64+0x3f/0x90 [ 1229.072113]
> > > > > > > > > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115]
> > > > > > > > > > RIP: 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05
> > > > > > > > > > f9 27 0f 00 be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00
> > > > > > > > > > 00 89 0 [ 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS:
> > > > > > > > > > 00000246 ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX:
> > > > > > > > > > ffffffffffffffda RBX: 00007f57e6a3d610 RCX:
> > > > > > > > > > 00007f57e6948699 [ 1229.072130] RDX: 000000000000003c RSI:
> > > > > > > > > > 00000000000000e7 RDI: 0000000000000001 [ 1229.072132] RBP:
> > > > > > > > > > 0000000000000001 R08: ffffffffffffff70 R09:
> > > > > > > > > > 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
> > > > > > > > > > 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
> > > > > > > > > > 0000000000000002 R14: 00007f57e6a3dae8 R15:
> > > > > > > > > > 0000000000000000 [ 1229.072138] Modules linked in: md4(E)
> > > > > > > > > > sha512_ssse3(E) sha512_generic(E) cmac(E) nls_utf8(E) cifs)
> > > > > > > > > > [ 1229.072169] mei(E) soundcore(E) sysimgblt(E) sg(E)
> > > > > > > > > > evdev(E) ioatdma(E) joydev(E) watchdog(E) ac) [
> > > > > > > > > > 1229.072185] ---[ end trace a1d1ac68468e74f0 ]--- [
> > > > > > > > > > 1229.072186] RIP:
> > > > > > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187]
> > > > > > > > > > Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> > > > > > > > > > 51 0d ff ff 0f 0b 48 89 b [ 1229.072187] RSP:
> > > > > > > > > > 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072188] RAX:
> > > > > > > > > > 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> > > > > > > > > > 0000000000000000 [ 1229.072188] RDX: 0000000000000000 RSI:
> > > > > > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072189] RBP:
> > > > > > > > > > 0000000000000000 R08: 0000000000000001 R09:
> > > > > > > > > > 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
> > > > > > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
> > > > > > > > > > ffffa0ff488c7380 R14: 0000000000000000 R15:
> > > > > > > > > > 0000000000000000 [ 1229.072190] FS: 00007f57e687bb80(0000)
> > > > > > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > > > > > 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > > > > > 0000000080050033 [ 1229.072191] CR2: 000055921bfa921c CR3:
> > > > > > > > > > 00000001062fe002 CR4: 00000000001706e0 [ 1229.072191]
> > > > > > > > > > Fixing recursive fault but reboot is needed!
> > > > > > > > > >
> > > > > > > > > > I will look into that eventually. For now i just wanted to
> > > > > > > > > > share what i have so far, maybe someone knows what is going
> > > > > > > > > > on or can give a hint. function tracing was way too verbose
> > > > > > > > > > to find the rootcause of that EBUSY.
> > > > > > > > > >
> > > > > > > > >
> > > > > > > > > EAGAIN, switchtest triggers this when many CPUs are available
> > > > > > > > > but the system heap is too small (not enough space there to
> > > > > > > > > create thread TCBs and other core objects). Normally,
> > > > > > > > > switchtest exits properly after a while.
> > > > > > > >
> > > > > > > > Ok maybe that changed kernel config did shrink the available
> > > > > > > > heap, thanks for the hint.
> > > > > > > >
> > > > > > > > If it is an EAGAIN because of too little resources, maybe it
> > > > > > > > should keep trying with less and less CPUs. And spit a warning
> > > > > > > > like "could only run on 20 out of 32 cores".
> > > > > > > > At least that would be my first idea for a patch in case it is
> > > > > > > > that.
> > > > > > >
> > > > > > > The test runs just fine when reducing the number of cores to run
> > > > > > > on. In fact it was one too many ;)
> > > > > > >
> > > > > > > good
> > > > > > > ./switchtest -T 5 --cpu-affinity=0-30
> > > > > > > bad (where affinity includes all cpus)
> > > > > > > ./switchtest -T 5 --cpu-affinity=0-31
> > > > > > >
> > > > > > > > > The kernel splat looks like some issue on the error path
> > > > > > > > > which might not have been observed yet (maybe triggered by ^C
> > > > > > > > > while switchtest was unwinding).
> > > > > > > >
> > > > > > > > I saw exactly that in probably three attempts. First switchtest
> > > > > > > > killed with ctrl+c when the 0s come ... never any fun kernel
> > > > > > > > message. But always fun kernel message when the second run was
> > > > > > > > interrupted. So i would be tempted to call that reproducible
> > > > > > > > and not a one-time bad timing.
> > > > > > >
> > > > > > > But when running the bad case two times in a row, it will always
> > > > > > >
> > > > > > > kernel BUG at lib/list_debug.c:51!
> > > > > > >
> > > > > > > Even when none of the two runs was interrupted by ctrl+c.
> > > > > > >
> > > > > >
> > > > > > So, the main issue was solved by increasing resources, but we still
> > > > > > have a problem with handling errors gracefully - is that the
> > > > > > correct summary of this issue? Or where are we standing with this?
> > > >
> > > > By reducing the number of threads, but yes that issue was "worked
> > > > around". The crash is something that was found as well and is still
> > > > open, in fact pretty easy to reproduce.
> > > >
> > >
> > > How can I reproduce that?
> >
> > I tried it again on the system that Henning was using when reporting
> > the problem. We increased CONFIG_XENO_OPT_DEBUG from 512 to 4096 in the
> > meantime.
s/CONFIG_XENO_OPT_DEBUG/CONFIG_XENO_OPT_REGISTRY_NRSLOTS
> >
> > Taken while switchtest is running on that system:
> >
> > # cat /proc/xenomai/registry/usage
> > 523/4096
> >
> > So with the old 512 slots we would run into a exhaustion on such a big
> > system. IMHO that should be the root cause.
> >
> > Configuration problem, no bug.
>
> Correction: Maybe we have a problem in one of the error handling pathes
> in switchtest?
Correction 2: I just overlooked the BUG() above. So I assume we have a
problem, somewhere the registry exhaustion is not handled properly. The
answer to "how can I reproduce that" would be "decrease
CONFIG_XENO_OPT_REGISTRY_NRSLOTS and run switchtest".
>
> >
> > Henning, please correct me if you disagree.
> >
> > >
> > > Jan
> > >
> > > > > Might that be related to a registry slot exhaustion? On the affected
> > > > > system we changed CONFIG_XENO_OPT_DEBUG from 4096 back to its default
> > > > > (512). Just an idea... ctrl+c might skip the resource cleanup.
> > > >
> > > > I have no which ressource was exhausted. We could just try that kernel
> > > > with the bigger registry and compare with the smaller one. Thanks for
> > > > the hint.
> > > >
> > > > Henning
> > > >
> > > > > Looking into /proc/xenomai/registry/usage might help in such case.
> > > > >
> > > > > >
> > > > > > Jan
> > > > > >
> > > > >
> > > >
> > >
> >
>
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-07 9:05 ` Bezdeka, Florian
@ 2021-10-07 12:45 ` Jan Kiszka
0 siblings, 0 replies; 15+ messages in thread
From: Jan Kiszka @ 2021-10-07 12:45 UTC (permalink / raw)
To: Bezdeka, Florian (T RDA IOT SES-DE), Schild, Henning (T RDA IOT SES-DE)
Cc: xenomai
On 07.10.21 11:05, Bezdeka, Florian (T RDA IOT SES-DE) wrote:
> On Thu, 2021-10-07 at 08:55 +0000, Bezdeka, Florian via Xenomai wrote:
>> On Thu, 2021-10-07 at 08:53 +0000, Bezdeka, Florian via Xenomai wrote:
>>> On Thu, 2021-10-07 at 10:37 +0200, Jan Kiszka wrote:
>>>> On 05.10.21 17:18, Henning Schild wrote:
>>>>> Am Tue, 5 Oct 2021 16:38:12 +0200
>>>>> schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
>>>>> <florian.bezdeka@siemens.com>:
>>>>>
>>>>>> On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai wrote:
>>>>>>> On 24.09.21 15:31, Henning Schild via Xenomai wrote:
>>>>>>>> Am Wed, 22 Sep 2021 16:21:54 +0200
>>>>>>>> schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
>>>>>>>>
>>>>>>>>> Am Wed, 22 Sep 2021 14:36:49 +0200
>>>>>>>>> schrieb Philippe Gerum <rpm@xenomai.org>:
>>>>>>>>>
>>>>>>>>>> Henning Schild via Xenomai <xenomai@xenomai.org> writes:
>>>>>>>>>>
>>>>>>>>>>> Hi,
>>>>>>>>>>>
>>>>>>>>>>> getting sick of maintaining a "small" kernel config i
>>>>>>>>>>> wanted to switch to a config derived from the debian11 5.10
>>>>>>>>>>> kernel. Basically that config plus the few switches coming
>>>>>>>>>>> in with dovetail.
>>>>>>>>>>>
>>>>>>>>>>> That passed all tests in qemu but on a real machine (big
>>>>>>>>>>> xeon with raid0) the "switchtest" has an issue.
>>>>>>>>>>>
>>>>>>>>>>> # /lib/xenomai/testsuite/switchtest
>>>>>>>>>>> == Testing FPU check routines...
>>>>>>>>>>> r0: 1 != 2
>>>>>>>>>>> r1: 1 != 2
>>>>>>>>>>> r2: 1 != 2
>>>>>>>>>>> r3: 1 != 2
>>>>>>>>>>> r4: 1 != 2
>>>>>>>>>>> r5: 1 != 2
>>>>>>>>>>> r6: 1 != 2
>>>>>>>>>>> r7: 1 != 2
>>>>>>>>>>> ymm0: 1/1 != 2/2
>>>>>>>>>>> ymm1: 1/1 != 2/2
>>>>>>>>>>> ymm2: 1/1 != 2/2
>>>>>>>>>>> ymm3: 1/1 != 2/2
>>>>>>>>>>> ymm4: 1/1 != 2/2
>>>>>>>>>>> ymm5: 1/1 != 2/2
>>>>>>>>>>> ymm6: 1/1 != 2/2
>>>>>>>>>>> ymm7: 1/1 != 2/2
>>>>>>>>>>> == FPU check routines: OK.
>>>>>>>>>>> == Threads: ... a lot of threads ...
>>>>>>>>>>> 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19
>>>>>>>>>>> rtuo_ufps30-20 rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22
>>>>>>>>>>> sleeper_ufpthread_create: Resource temporarily unavailable
>>>>>>>>>>> ps31-0 rtk31-1 rtk31-2 rtk_fp31-3 rtk_fp31-4
>>>>>>>>>>> rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
>>>>>>>>>>> rtup_ufpp31-9 rtup_ufpp31-10 rtus
>>>>>>>>>>>
>>>>>>>>>>> followed by only 0s
>>>>>>>>>>>
>>>>>>>>>>> RTH|---------cpu|ctx switches|-------total
>>>>>>>>>>> RTD| 0| 0| 0
>>>>>>>>>>> RTD| 1| 0| 0
>>>>>>>>>>> RTD| 2| 0| 0
>>>>>>>>>>> RTD| 3| 0| 0
>>>>>>>>>>> RTD| 4| 0| 0
>>>>>>>>>>> RTD| 5| 0| 0
>>>>>>>>>>> RTD| 6| 0| 0
>>>>>>>>>>>
>>>>>>>>>>> So it gets a
>>>>>>>>>>>
>>>>>>>>>>> sleeper_ufpthread_create: Resource temporarily unavailable
>>>>>>>>>>>
>>>>>>>>>>> but swallows that and keeps going. I think there might be a
>>>>>>>>>>> first issue with that error return not being dealt with.
>>>>>>>>>>>
>>>>>>>>>>> A second run get the "switchtest" stuck after crtl+c while
>>>>>>>>>>> the kernel starts complaining.
>>>>>>>>>>>
>>>>>>>>>>> [ 1229.072052] list_del corruption. prev->next should be
>>>>>>>>>>> ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
>>>>>>>>>>> ------------[ cut here ]------------ [ 1229.072054] kernel
>>>>>>>>>>> BUG at lib/list_debug.c:51! [ 1229.072054] invalid opcode:
>>>>>>>>>>> 0000 [#1] SMP PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID:
>>>>>>>>>>> 1857 Comm: switchtest Tainted: G E
>>>>>>>>>>> 5.10.61-xenomai-1 #1 [ 1229.072055] Hardware name: secret [
>>>>>>>>>>> 1229.072055] IRQ stage: Linux [ 1229.072055] RIP:
>>>>>>>>>>> 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072056]
>>>>>>>>>>> Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
>>>>>>>>>>> 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
>>>>>>>>>>> 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
>>>>>>>>>>> 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
>>>>>>>>>>> 0000000000000000 [ 1229.072062] RDX: 0000000000000000 RSI:
>>>>>>>>>>> ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072064] RBP:
>>>>>>>>>>> 0000000000000000 R08: 0000000000000001 R09:
>>>>>>>>>>> 000000000000000f [ 1229.072066] R10: 000000000000000f R11:
>>>>>>>>>>> ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072069] R13:
>>>>>>>>>>> ffffa0ff488c7380 R14: 0000000000000000 R15:
>>>>>>>>>>> 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
>>>>>>>>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
>>>>>>>>>>> 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0:
>>>>>>>>>>> 0000000080050033 [ 1229.072076] CR2: 000055921bfa921c CR3:
>>>>>>>>>>> 00000001062fe002 CR4: 00000000001706e0 [ 1229.072078] Call
>>>>>>>>>>> Trace: [ 1229.072080] xntimer_destroy+0x81/0x150 [
>>>>>>>>>>> 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
>>>>>>>>>>> cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
>>>>>>>>>>> do_exit+0xe1/0xab0 [ 1229.072088] ?
>>>>>>>>>>> signal_wake_up_state+0x23/0x40 [ 1229.072090]
>>>>>>>>>>> do_group_exit+0x33/0xa0 [ 1229.072092]
>>>>>>>>>>> __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
>>>>>>>>>>> do_syscall_64+0x3f/0x90 [ 1229.072113]
>>>>>>>>>>> entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115]
>>>>>>>>>>> RIP: 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05
>>>>>>>>>>> f9 27 0f 00 be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00
>>>>>>>>>>> 00 89 0 [ 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS:
>>>>>>>>>>> 00000246 ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX:
>>>>>>>>>>> ffffffffffffffda RBX: 00007f57e6a3d610 RCX:
>>>>>>>>>>> 00007f57e6948699 [ 1229.072130] RDX: 000000000000003c RSI:
>>>>>>>>>>> 00000000000000e7 RDI: 0000000000000001 [ 1229.072132] RBP:
>>>>>>>>>>> 0000000000000001 R08: ffffffffffffff70 R09:
>>>>>>>>>>> 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
>>>>>>>>>>> 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
>>>>>>>>>>> 0000000000000002 R14: 00007f57e6a3dae8 R15:
>>>>>>>>>>> 0000000000000000 [ 1229.072138] Modules linked in: md4(E)
>>>>>>>>>>> sha512_ssse3(E) sha512_generic(E) cmac(E) nls_utf8(E) cifs)
>>>>>>>>>>> [ 1229.072169] mei(E) soundcore(E) sysimgblt(E) sg(E)
>>>>>>>>>>> evdev(E) ioatdma(E) joydev(E) watchdog(E) ac) [
>>>>>>>>>>> 1229.072185] ---[ end trace a1d1ac68468e74f0 ]--- [
>>>>>>>>>>> 1229.072186] RIP:
>>>>>>>>>>> 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187]
>>>>>>>>>>> Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
>>>>>>>>>>> 51 0d ff ff 0f 0b 48 89 b [ 1229.072187] RSP:
>>>>>>>>>>> 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072188] RAX:
>>>>>>>>>>> 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
>>>>>>>>>>> 0000000000000000 [ 1229.072188] RDX: 0000000000000000 RSI:
>>>>>>>>>>> ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072189] RBP:
>>>>>>>>>>> 0000000000000000 R08: 0000000000000001 R09:
>>>>>>>>>>> 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
>>>>>>>>>>> ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
>>>>>>>>>>> ffffa0ff488c7380 R14: 0000000000000000 R15:
>>>>>>>>>>> 0000000000000000 [ 1229.072190] FS: 00007f57e687bb80(0000)
>>>>>>>>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
>>>>>>>>>>> 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0:
>>>>>>>>>>> 0000000080050033 [ 1229.072191] CR2: 000055921bfa921c CR3:
>>>>>>>>>>> 00000001062fe002 CR4: 00000000001706e0 [ 1229.072191]
>>>>>>>>>>> Fixing recursive fault but reboot is needed!
>>>>>>>>>>>
>>>>>>>>>>> I will look into that eventually. For now i just wanted to
>>>>>>>>>>> share what i have so far, maybe someone knows what is going
>>>>>>>>>>> on or can give a hint. function tracing was way too verbose
>>>>>>>>>>> to find the rootcause of that EBUSY.
>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> EAGAIN, switchtest triggers this when many CPUs are available
>>>>>>>>>> but the system heap is too small (not enough space there to
>>>>>>>>>> create thread TCBs and other core objects). Normally,
>>>>>>>>>> switchtest exits properly after a while.
>>>>>>>>>
>>>>>>>>> Ok maybe that changed kernel config did shrink the available
>>>>>>>>> heap, thanks for the hint.
>>>>>>>>>
>>>>>>>>> If it is an EAGAIN because of too little resources, maybe it
>>>>>>>>> should keep trying with less and less CPUs. And spit a warning
>>>>>>>>> like "could only run on 20 out of 32 cores".
>>>>>>>>> At least that would be my first idea for a patch in case it is
>>>>>>>>> that.
>>>>>>>>
>>>>>>>> The test runs just fine when reducing the number of cores to run
>>>>>>>> on. In fact it was one too many ;)
>>>>>>>>
>>>>>>>> good
>>>>>>>> ./switchtest -T 5 --cpu-affinity=0-30
>>>>>>>> bad (where affinity includes all cpus)
>>>>>>>> ./switchtest -T 5 --cpu-affinity=0-31
>>>>>>>>
>>>>>>>>>> The kernel splat looks like some issue on the error path
>>>>>>>>>> which might not have been observed yet (maybe triggered by ^C
>>>>>>>>>> while switchtest was unwinding).
>>>>>>>>>
>>>>>>>>> I saw exactly that in probably three attempts. First switchtest
>>>>>>>>> killed with ctrl+c when the 0s come ... never any fun kernel
>>>>>>>>> message. But always fun kernel message when the second run was
>>>>>>>>> interrupted. So i would be tempted to call that reproducible
>>>>>>>>> and not a one-time bad timing.
>>>>>>>>
>>>>>>>> But when running the bad case two times in a row, it will always
>>>>>>>>
>>>>>>>> kernel BUG at lib/list_debug.c:51!
>>>>>>>>
>>>>>>>> Even when none of the two runs was interrupted by ctrl+c.
>>>>>>>>
>>>>>>>
>>>>>>> So, the main issue was solved by increasing resources, but we still
>>>>>>> have a problem with handling errors gracefully - is that the
>>>>>>> correct summary of this issue? Or where are we standing with this?
>>>>>
>>>>> By reducing the number of threads, but yes that issue was "worked
>>>>> around". The crash is something that was found as well and is still
>>>>> open, in fact pretty easy to reproduce.
>>>>>
>>>>
>>>> How can I reproduce that?
>>>
>>> I tried it again on the system that Henning was using when reporting
>>> the problem. We increased CONFIG_XENO_OPT_DEBUG from 512 to 4096 in the
>>> meantime.
>
> s/CONFIG_XENO_OPT_DEBUG/CONFIG_XENO_OPT_REGISTRY_NRSLOTS
>
>>>
>>> Taken while switchtest is running on that system:
>>>
>>> # cat /proc/xenomai/registry/usage
>>> 523/4096
>>>
>>> So with the old 512 slots we would run into a exhaustion on such a big
>>> system. IMHO that should be the root cause.
>>>
>>> Configuration problem, no bug.
>>
>> Correction: Maybe we have a problem in one of the error handling pathes
>> in switchtest?
>
> Correction 2: I just overlooked the BUG() above. So I assume we have a
> problem, somewhere the registry exhaustion is not handled properly. The
> answer to "how can I reproduce that" would be "decrease
> CONFIG_XENO_OPT_REGISTRY_NRSLOTS and run switchtest".
Confirmed. I even just reproduced it with a simple pthread_create loop,
without any switchtest involved. Debugging...
Jan
--
Siemens AG, T RDA IOT
Corporate Competence Center Embedded Linux
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-07 8:37 ` Jan Kiszka
2021-10-07 8:53 ` Bezdeka, Florian
@ 2021-10-07 13:17 ` Henning Schild
1 sibling, 0 replies; 15+ messages in thread
From: Henning Schild @ 2021-10-07 13:17 UTC (permalink / raw)
To: Jan Kiszka; +Cc: Bezdeka, Florian (T RDA IOT SES-DE), xenomai
Am Thu, 7 Oct 2021 10:37:19 +0200
schrieb Jan Kiszka <jan.kiszka@siemens.com>:
> On 05.10.21 17:18, Henning Schild wrote:
> > Am Tue, 5 Oct 2021 16:38:12 +0200
> > schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
> > <florian.bezdeka@siemens.com>:
> >
> >> On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai wrote:
> >>> On 24.09.21 15:31, Henning Schild via Xenomai wrote:
> >>>> Am Wed, 22 Sep 2021 16:21:54 +0200
> >>>> schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
> >>>>
> >>>>> Am Wed, 22 Sep 2021 14:36:49 +0200
> >>>>> schrieb Philippe Gerum <rpm@xenomai.org>:
> >>>>>
> >>>>>> Henning Schild via Xenomai <xenomai@xenomai.org> writes:
> >>>>>>
> >>>>>>> Hi,
> >>>>>>>
> >>>>>>> getting sick of maintaining a "small" kernel config i
> >>>>>>> wanted to switch to a config derived from the debian11 5.10
> >>>>>>> kernel. Basically that config plus the few switches coming
> >>>>>>> in with dovetail.
> >>>>>>>
> >>>>>>> That passed all tests in qemu but on a real machine (big
> >>>>>>> xeon with raid0) the "switchtest" has an issue.
> >>>>>>>
> >>>>>>> # /lib/xenomai/testsuite/switchtest
> >>>>>>> == Testing FPU check routines...
> >>>>>>> r0: 1 != 2
> >>>>>>> r1: 1 != 2
> >>>>>>> r2: 1 != 2
> >>>>>>> r3: 1 != 2
> >>>>>>> r4: 1 != 2
> >>>>>>> r5: 1 != 2
> >>>>>>> r6: 1 != 2
> >>>>>>> r7: 1 != 2
> >>>>>>> ymm0: 1/1 != 2/2
> >>>>>>> ymm1: 1/1 != 2/2
> >>>>>>> ymm2: 1/1 != 2/2
> >>>>>>> ymm3: 1/1 != 2/2
> >>>>>>> ymm4: 1/1 != 2/2
> >>>>>>> ymm5: 1/1 != 2/2
> >>>>>>> ymm6: 1/1 != 2/2
> >>>>>>> ymm7: 1/1 != 2/2
> >>>>>>> == FPU check routines: OK.
> >>>>>>> == Threads: ... a lot of threads ...
> >>>>>>> 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19
> >>>>>>> rtuo_ufps30-20 rtuo_ufpp_ufps30-21 rtuo_ufpp_ufps30-22
> >>>>>>> sleeper_ufpthread_create: Resource temporarily unavailable
> >>>>>>> ps31-0 rtk31-1 rtk31-2 rtk_fp31-3 rtk_fp31-4
> >>>>>>> rtk_fp_ufpp31-5 rtk_fp_ufpp31-6 rtup31-7 rtup31-8
> >>>>>>> rtup_ufpp31-9 rtup_ufpp31-10 rtus
> >>>>>>>
> >>>>>>> followed by only 0s
> >>>>>>>
> >>>>>>> RTH|---------cpu|ctx switches|-------total
> >>>>>>> RTD| 0| 0| 0
> >>>>>>> RTD| 1| 0| 0
> >>>>>>> RTD| 2| 0| 0
> >>>>>>> RTD| 3| 0| 0
> >>>>>>> RTD| 4| 0| 0
> >>>>>>> RTD| 5| 0| 0
> >>>>>>> RTD| 6| 0| 0
> >>>>>>>
> >>>>>>> So it gets a
> >>>>>>>
> >>>>>>> sleeper_ufpthread_create: Resource temporarily unavailable
> >>>>>>>
> >>>>>>> but swallows that and keeps going. I think there might be a
> >>>>>>> first issue with that error return not being dealt with.
> >>>>>>>
> >>>>>>> A second run get the "switchtest" stuck after crtl+c while
> >>>>>>> the kernel starts complaining.
> >>>>>>>
> >>>>>>> [ 1229.072052] list_del corruption. prev->next should be
> >>>>>>> ffffb24e46fb0548, but was ffffffff9a7356b0 [ 1229.072053]
> >>>>>>> ------------[ cut here ]------------ [ 1229.072054] kernel
> >>>>>>> BUG at lib/list_debug.c:51! [ 1229.072054] invalid opcode:
> >>>>>>> 0000 [#1] SMP PTI IRQ_PIPELINE [ 1229.072054] CPU: 31 PID:
> >>>>>>> 1857 Comm: switchtest Tainted: G E
> >>>>>>> 5.10.61-xenomai-1 #1 [ 1229.072055] Hardware name: secret [
> >>>>>>> 1229.072055] IRQ stage: Linux [ 1229.072055] RIP:
> >>>>>>> 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072056]
> >>>>>>> Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> >>>>>>> 51 0d ff ff 0f 0b 48 89 b [ 1229.072057] RSP:
> >>>>>>> 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072061] RAX:
> >>>>>>> 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> >>>>>>> 0000000000000000 [ 1229.072062] RDX: 0000000000000000 RSI:
> >>>>>>> ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072064] RBP:
> >>>>>>> 0000000000000000 R08: 0000000000000001 R09:
> >>>>>>> 000000000000000f [ 1229.072066] R10: 000000000000000f R11:
> >>>>>>> ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072069] R13:
> >>>>>>> ffffa0ff488c7380 R14: 0000000000000000 R15:
> >>>>>>> 0000000000000000 [ 1229.072072] FS: 00007f57e687bb80(0000)
> >>>>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> >>>>>>> 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0:
> >>>>>>> 0000000080050033 [ 1229.072076] CR2: 000055921bfa921c CR3:
> >>>>>>> 00000001062fe002 CR4: 00000000001706e0 [ 1229.072078] Call
> >>>>>>> Trace: [ 1229.072080] xntimer_destroy+0x81/0x150 [
> >>>>>>> 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [ 1229.072084]
> >>>>>>> cobalt_handle_taskexit_event+0x1d/0x40 [ 1229.072086]
> >>>>>>> do_exit+0xe1/0xab0 [ 1229.072088] ?
> >>>>>>> signal_wake_up_state+0x23/0x40 [ 1229.072090]
> >>>>>>> do_group_exit+0x33/0xa0 [ 1229.072092]
> >>>>>>> __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
> >>>>>>> do_syscall_64+0x3f/0x90 [ 1229.072113]
> >>>>>>> entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1229.072115]
> >>>>>>> RIP: 0033:0x7f57e6948699 [ 1229.072117] Code: 00 4c 8b 05
> >>>>>>> f9 27 0f 00 be e7 00 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00
> >>>>>>> 00 89 0 [ 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS:
> >>>>>>> 00000246 ORIG_RAX: 00000000000000e7 [ 1229.072128] RAX:
> >>>>>>> ffffffffffffffda RBX: 00007f57e6a3d610 RCX:
> >>>>>>> 00007f57e6948699 [ 1229.072130] RDX: 000000000000003c RSI:
> >>>>>>> 00000000000000e7 RDI: 0000000000000001 [ 1229.072132] RBP:
> >>>>>>> 0000000000000001 R08: ffffffffffffff70 R09:
> >>>>>>> 0000000000000001 [ 1229.072134] R10: 0000000000000005 R11:
> >>>>>>> 0000000000000246 R12: 00007f57e6a3d610 [ 1229.072136] R13:
> >>>>>>> 0000000000000002 R14: 00007f57e6a3dae8 R15:
> >>>>>>> 0000000000000000 [ 1229.072138] Modules linked in: md4(E)
> >>>>>>> sha512_ssse3(E) sha512_generic(E) cmac(E) nls_utf8(E) cifs)
> >>>>>>> [ 1229.072169] mei(E) soundcore(E) sysimgblt(E) sg(E)
> >>>>>>> evdev(E) ioatdma(E) joydev(E) watchdog(E) ac) [
> >>>>>>> 1229.072185] ---[ end trace a1d1ac68468e74f0 ]--- [
> >>>>>>> 1229.072186] RIP:
> >>>>>>> 0010:__list_del_entry_valid.cold+0x31/0x47 [ 1229.072187]
> >>>>>>> Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48 c7 c7 00 9a 32 9a e8
> >>>>>>> 51 0d ff ff 0f 0b 48 89 b [ 1229.072187] RSP:
> >>>>>>> 0018:ffffb24e4b5f7e30 EFLAGS: 00010046 [ 1229.072188] RAX:
> >>>>>>> 0000000000000057 RBX: ffffb24e46fb04b0 RCX:
> >>>>>>> 0000000000000000 [ 1229.072188] RDX: 0000000000000000 RSI:
> >>>>>>> ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [ 1229.072189] RBP:
> >>>>>>> 0000000000000000 R08: 0000000000000001 R09:
> >>>>>>> 000000000000000f [ 1229.072189] R10: 000000000000000f R11:
> >>>>>>> ffffa10e9fd97bd6 R12: 0000000000000000 [ 1229.072190] R13:
> >>>>>>> ffffa0ff488c7380 R14: 0000000000000000 R15:
> >>>>>>> 0000000000000000 [ 1229.072190] FS: 00007f57e687bb80(0000)
> >>>>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> >>>>>>> 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0:
> >>>>>>> 0000000080050033 [ 1229.072191] CR2: 000055921bfa921c CR3:
> >>>>>>> 00000001062fe002 CR4: 00000000001706e0 [ 1229.072191]
> >>>>>>> Fixing recursive fault but reboot is needed!
> >>>>>>>
> >>>>>>> I will look into that eventually. For now i just wanted to
> >>>>>>> share what i have so far, maybe someone knows what is going
> >>>>>>> on or can give a hint. function tracing was way too verbose
> >>>>>>> to find the rootcause of that EBUSY.
> >>>>>>>
> >>>>>>
> >>>>>> EAGAIN, switchtest triggers this when many CPUs are available
> >>>>>> but the system heap is too small (not enough space there to
> >>>>>> create thread TCBs and other core objects). Normally,
> >>>>>> switchtest exits properly after a while.
> >>>>>
> >>>>> Ok maybe that changed kernel config did shrink the available
> >>>>> heap, thanks for the hint.
> >>>>>
> >>>>> If it is an EAGAIN because of too little resources, maybe it
> >>>>> should keep trying with less and less CPUs. And spit a warning
> >>>>> like "could only run on 20 out of 32 cores".
> >>>>> At least that would be my first idea for a patch in case it is
> >>>>> that.
> >>>>
> >>>> The test runs just fine when reducing the number of cores to run
> >>>> on. In fact it was one too many ;)
> >>>>
> >>>> good
> >>>> ./switchtest -T 5 --cpu-affinity=0-30
> >>>> bad (where affinity includes all cpus)
> >>>> ./switchtest -T 5 --cpu-affinity=0-31
> >>>>
> >>>>>> The kernel splat looks like some issue on the error path
> >>>>>> which might not have been observed yet (maybe triggered by ^C
> >>>>>> while switchtest was unwinding).
> >>>>>
> >>>>> I saw exactly that in probably three attempts. First switchtest
> >>>>> killed with ctrl+c when the 0s come ... never any fun kernel
> >>>>> message. But always fun kernel message when the second run was
> >>>>> interrupted. So i would be tempted to call that reproducible
> >>>>> and not a one-time bad timing.
> >>>>
> >>>> But when running the bad case two times in a row, it will always
> >>>>
> >>>> kernel BUG at lib/list_debug.c:51!
> >>>>
> >>>> Even when none of the two runs was interrupted by ctrl+c.
> >>>>
> >>>
> >>> So, the main issue was solved by increasing resources, but we
> >>> still have a problem with handling errors gracefully - is that the
> >>> correct summary of this issue? Or where are we standing with
> >>> this?
> >
> > By reducing the number of threads, but yes that issue was "worked
> > around". The crash is something that was found as well and is still
> > open, in fact pretty easy to reproduce.
> >
>
> How can I reproduce that?
I could give access to a machine within Siemens that is "affected". You
seem to need high core counts and low CONFIG_XENO_OPT_REGISTRY_NRSLOTS
with 32 cores and CONFIG_XENO_OPT_REGISTRY_NRSLOTS=512 you will hit it,
but not with 31 cores
Not sure how things scale but my guess is that you can see it in qemu
with 4 cores if you go down to or below 64 SLOTS.
Henning
> Jan
>
> >> Might that be related to a registry slot exhaustion? On the
> >> affected system we changed CONFIG_XENO_OPT_DEBUG from 4096 back to
> >> its default (512). Just an idea... ctrl+c might skip the resource
> >> cleanup.
> >
> > I have no which ressource was exhausted. We could just try that
> > kernel with the bigger registry and compare with the smaller one.
> > Thanks for the hint.
> >
> > Henning
> >
> >> Looking into /proc/xenomai/registry/usage might help in such case.
> >>
> >>>
> >>> Jan
> >>>
> >>
> >
>
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-07 8:55 ` Bezdeka, Florian
2021-10-07 9:05 ` Bezdeka, Florian
@ 2021-10-07 13:29 ` Henning Schild
2021-10-07 17:28 ` Jan Kiszka
1 sibling, 1 reply; 15+ messages in thread
From: Henning Schild @ 2021-10-07 13:29 UTC (permalink / raw)
To: Bezdeka, Florian (T RDA IOT SES-DE); +Cc: Kiszka, Jan (T RDA IOT), xenomai
Am Thu, 7 Oct 2021 10:55:38 +0200
schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
<florian.bezdeka@siemens.com>:
> On Thu, 2021-10-07 at 08:53 +0000, Bezdeka, Florian via Xenomai wrote:
> > On Thu, 2021-10-07 at 10:37 +0200, Jan Kiszka wrote:
> > > On 05.10.21 17:18, Henning Schild wrote:
> > > > Am Tue, 5 Oct 2021 16:38:12 +0200
> > > > schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
> > > > <florian.bezdeka@siemens.com>:
> > > >
> > > > > On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai
> > > > > wrote:
> > > > > > On 24.09.21 15:31, Henning Schild via Xenomai wrote:
> > > > > > > Am Wed, 22 Sep 2021 16:21:54 +0200
> > > > > > > schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
> > > > > > >
> > > > > > > > Am Wed, 22 Sep 2021 14:36:49 +0200
> > > > > > > > schrieb Philippe Gerum <rpm@xenomai.org>:
> > > > > > > >
> > > > > > > > > Henning Schild via Xenomai <xenomai@xenomai.org>
> > > > > > > > > writes:
> > > > > > > > > > Hi,
> > > > > > > > > >
> > > > > > > > > > getting sick of maintaining a "small" kernel config
> > > > > > > > > > i wanted to switch to a config derived from the
> > > > > > > > > > debian11 5.10 kernel. Basically that config plus
> > > > > > > > > > the few switches coming in with dovetail.
> > > > > > > > > >
> > > > > > > > > > That passed all tests in qemu but on a real machine
> > > > > > > > > > (big xeon with raid0) the "switchtest" has an issue.
> > > > > > > > > >
> > > > > > > > > > # /lib/xenomai/testsuite/switchtest
> > > > > > > > > > == Testing FPU check routines...
> > > > > > > > > > r0: 1 != 2
> > > > > > > > > > r1: 1 != 2
> > > > > > > > > > r2: 1 != 2
> > > > > > > > > > r3: 1 != 2
> > > > > > > > > > r4: 1 != 2
> > > > > > > > > > r5: 1 != 2
> > > > > > > > > > r6: 1 != 2
> > > > > > > > > > r7: 1 != 2
> > > > > > > > > > ymm0: 1/1 != 2/2
> > > > > > > > > > ymm1: 1/1 != 2/2
> > > > > > > > > > ymm2: 1/1 != 2/2
> > > > > > > > > > ymm3: 1/1 != 2/2
> > > > > > > > > > ymm4: 1/1 != 2/2
> > > > > > > > > > ymm5: 1/1 != 2/2
> > > > > > > > > > ymm6: 1/1 != 2/2
> > > > > > > > > > ymm7: 1/1 != 2/2
> > > > > > > > > > == FPU check routines: OK.
> > > > > > > > > > == Threads: ... a lot of threads ...
> > > > > > > > > > 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19
> > > > > > > > > > rtuo_ufps30-20 rtuo_ufpp_ufps30-21
> > > > > > > > > > rtuo_ufpp_ufps30-22 sleeper_ufpthread_create:
> > > > > > > > > > Resource temporarily unavailable ps31-0 rtk31-1
> > > > > > > > > > rtk31-2 rtk_fp31-3 rtk_fp31-4 rtk_fp_ufpp31-5
> > > > > > > > > > rtk_fp_ufpp31-6 rtup31-7 rtup31-8 rtup_ufpp31-9
> > > > > > > > > > rtup_ufpp31-10 rtus
> > > > > > > > > >
> > > > > > > > > > followed by only 0s
> > > > > > > > > >
> > > > > > > > > > RTH|---------cpu|ctx switches|-------total
> > > > > > > > > > RTD| 0| 0| 0
> > > > > > > > > > RTD| 1| 0| 0
> > > > > > > > > > RTD| 2| 0| 0
> > > > > > > > > > RTD| 3| 0| 0
> > > > > > > > > > RTD| 4| 0| 0
> > > > > > > > > > RTD| 5| 0| 0
> > > > > > > > > > RTD| 6| 0| 0
> > > > > > > > > >
> > > > > > > > > > So it gets a
> > > > > > > > > >
> > > > > > > > > > sleeper_ufpthread_create: Resource temporarily
> > > > > > > > > > unavailable
> > > > > > > > > >
> > > > > > > > > > but swallows that and keeps going. I think there
> > > > > > > > > > might be a first issue with that error return not
> > > > > > > > > > being dealt with.
> > > > > > > > > >
> > > > > > > > > > A second run get the "switchtest" stuck after
> > > > > > > > > > crtl+c while the kernel starts complaining.
> > > > > > > > > >
> > > > > > > > > > [ 1229.072052] list_del corruption. prev->next
> > > > > > > > > > should be ffffb24e46fb0548, but was
> > > > > > > > > > ffffffff9a7356b0 [ 1229.072053] ------------[ cut
> > > > > > > > > > here ]------------ [ 1229.072054] kernel BUG at
> > > > > > > > > > lib/list_debug.c:51! [ 1229.072054] invalid opcode:
> > > > > > > > > > 0000 [#1] SMP PTI IRQ_PIPELINE [ 1229.072054] CPU:
> > > > > > > > > > 31 PID: 1857 Comm: switchtest Tainted: G
> > > > > > > > > > E 5.10.61-xenomai-1 #1 [ 1229.072055] Hardware
> > > > > > > > > > name: secret [ 1229.072055] IRQ stage: Linux [
> > > > > > > > > > 1229.072055] RIP:
> > > > > > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [
> > > > > > > > > > 1229.072056] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48
> > > > > > > > > > c7 c7 00 9a 32 9a e8 51 0d ff ff 0f 0b 48 89 b [
> > > > > > > > > > 1229.072057] RSP: 0018:ffffb24e4b5f7e30 EFLAGS:
> > > > > > > > > > 00010046 [ 1229.072061] RAX: 0000000000000057 RBX:
> > > > > > > > > > ffffb24e46fb04b0 RCX: 0000000000000000 [
> > > > > > > > > > 1229.072062] RDX: 0000000000000000 RSI:
> > > > > > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [
> > > > > > > > > > 1229.072064] RBP: 0000000000000000 R08:
> > > > > > > > > > 0000000000000001 R09: 000000000000000f [
> > > > > > > > > > 1229.072066] R10: 000000000000000f R11:
> > > > > > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [
> > > > > > > > > > 1229.072069] R13: ffffa0ff488c7380 R14:
> > > > > > > > > > 0000000000000000 R15: 0000000000000000 [
> > > > > > > > > > 1229.072072] FS: 00007f57e687bb80(0000)
> > > > > > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > > > > > 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > > > > > 0000000080050033 [ 1229.072076] CR2:
> > > > > > > > > > 000055921bfa921c CR3: 00000001062fe002 CR4:
> > > > > > > > > > 00000000001706e0 [ 1229.072078] Call Trace: [
> > > > > > > > > > 1229.072080] xntimer_destroy+0x81/0x150 [
> > > > > > > > > > 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [
> > > > > > > > > > 1229.072084] cobalt_handle_taskexit_event+0x1d/0x40
> > > > > > > > > > [ 1229.072086] do_exit+0xe1/0xab0 [ 1229.072088] ?
> > > > > > > > > > signal_wake_up_state+0x23/0x40 [ 1229.072090]
> > > > > > > > > > do_group_exit+0x33/0xa0 [ 1229.072092]
> > > > > > > > > > __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
> > > > > > > > > > do_syscall_64+0x3f/0x90 [ 1229.072113]
> > > > > > > > > > entry_SYSCALL_64_after_hwframe+0x44/0xa9 [
> > > > > > > > > > 1229.072115] RIP: 0033:0x7f57e6948699 [
> > > > > > > > > > 1229.072117] Code: 00 4c 8b 05 f9 27 0f 00 be e7 00
> > > > > > > > > > 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00 00 89 0 [
> > > > > > > > > > 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS:
> > > > > > > > > > 00000246 ORIG_RAX: 00000000000000e7 [ 1229.072128]
> > > > > > > > > > RAX: ffffffffffffffda RBX: 00007f57e6a3d610 RCX:
> > > > > > > > > > 00007f57e6948699 [ 1229.072130] RDX:
> > > > > > > > > > 000000000000003c RSI: 00000000000000e7 RDI:
> > > > > > > > > > 0000000000000001 [ 1229.072132] RBP:
> > > > > > > > > > 0000000000000001 R08: ffffffffffffff70 R09:
> > > > > > > > > > 0000000000000001 [ 1229.072134] R10:
> > > > > > > > > > 0000000000000005 R11: 0000000000000246 R12:
> > > > > > > > > > 00007f57e6a3d610 [ 1229.072136] R13:
> > > > > > > > > > 0000000000000002 R14: 00007f57e6a3dae8 R15:
> > > > > > > > > > 0000000000000000 [ 1229.072138] Modules linked in:
> > > > > > > > > > md4(E) sha512_ssse3(E) sha512_generic(E) cmac(E)
> > > > > > > > > > nls_utf8(E) cifs) [ 1229.072169] mei(E)
> > > > > > > > > > soundcore(E) sysimgblt(E) sg(E) evdev(E) ioatdma(E)
> > > > > > > > > > joydev(E) watchdog(E) ac) [ 1229.072185] ---[ end
> > > > > > > > > > trace a1d1ac68468e74f0 ]--- [ 1229.072186] RIP:
> > > > > > > > > > 0010:__list_del_entry_valid.cold+0x31/0x47 [
> > > > > > > > > > 1229.072187] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48
> > > > > > > > > > c7 c7 00 9a 32 9a e8 51 0d ff ff 0f 0b 48 89 b [
> > > > > > > > > > 1229.072187] RSP: 0018:ffffb24e4b5f7e30 EFLAGS:
> > > > > > > > > > 00010046 [ 1229.072188] RAX: 0000000000000057 RBX:
> > > > > > > > > > ffffb24e46fb04b0 RCX: 0000000000000000 [
> > > > > > > > > > 1229.072188] RDX: 0000000000000000 RSI:
> > > > > > > > > > ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [
> > > > > > > > > > 1229.072189] RBP: 0000000000000000 R08:
> > > > > > > > > > 0000000000000001 R09: 000000000000000f [
> > > > > > > > > > 1229.072189] R10: 000000000000000f R11:
> > > > > > > > > > ffffa10e9fd97bd6 R12: 0000000000000000 [
> > > > > > > > > > 1229.072190] R13: ffffa0ff488c7380 R14:
> > > > > > > > > > 0000000000000000 R15: 0000000000000000 [
> > > > > > > > > > 1229.072190] FS: 00007f57e687bb80(0000)
> > > > > > > > > > GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
> > > > > > > > > > 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0:
> > > > > > > > > > 0000000080050033 [ 1229.072191] CR2:
> > > > > > > > > > 000055921bfa921c CR3: 00000001062fe002 CR4:
> > > > > > > > > > 00000000001706e0 [ 1229.072191] Fixing recursive
> > > > > > > > > > fault but reboot is needed!
> > > > > > > > > >
> > > > > > > > > > I will look into that eventually. For now i just
> > > > > > > > > > wanted to share what i have so far, maybe someone
> > > > > > > > > > knows what is going on or can give a hint. function
> > > > > > > > > > tracing was way too verbose to find the rootcause
> > > > > > > > > > of that EBUSY.
> > > > > > > > >
> > > > > > > > > EAGAIN, switchtest triggers this when many CPUs are
> > > > > > > > > available but the system heap is too small (not
> > > > > > > > > enough space there to create thread TCBs and other
> > > > > > > > > core objects). Normally, switchtest exits properly
> > > > > > > > > after a while.
> > > > > > > >
> > > > > > > > Ok maybe that changed kernel config did shrink the
> > > > > > > > available heap, thanks for the hint.
> > > > > > > >
> > > > > > > > If it is an EAGAIN because of too little resources,
> > > > > > > > maybe it should keep trying with less and less CPUs.
> > > > > > > > And spit a warning like "could only run on 20 out of 32
> > > > > > > > cores". At least that would be my first idea for a
> > > > > > > > patch in case it is that.
> > > > > > >
> > > > > > > The test runs just fine when reducing the number of cores
> > > > > > > to run on. In fact it was one too many ;)
> > > > > > >
> > > > > > > good
> > > > > > > ./switchtest -T 5 --cpu-affinity=0-30
> > > > > > > bad (where affinity includes all cpus)
> > > > > > > ./switchtest -T 5 --cpu-affinity=0-31
> > > > > > >
> > > > > > > > > The kernel splat looks like some issue on the error
> > > > > > > > > path which might not have been observed yet (maybe
> > > > > > > > > triggered by ^C while switchtest was unwinding).
> > > > > > > >
> > > > > > > > I saw exactly that in probably three attempts. First
> > > > > > > > switchtest killed with ctrl+c when the 0s come ...
> > > > > > > > never any fun kernel message. But always fun kernel
> > > > > > > > message when the second run was interrupted. So i would
> > > > > > > > be tempted to call that reproducible and not a one-time
> > > > > > > > bad timing.
> > > > > > >
> > > > > > > But when running the bad case two times in a row, it will
> > > > > > > always
> > > > > > >
> > > > > > > kernel BUG at lib/list_debug.c:51!
> > > > > > >
> > > > > > > Even when none of the two runs was interrupted by ctrl+c.
> > > > > > >
> > > > > >
> > > > > > So, the main issue was solved by increasing resources, but
> > > > > > we still have a problem with handling errors gracefully -
> > > > > > is that the correct summary of this issue? Or where are we
> > > > > > standing with this?
> > > >
> > > > By reducing the number of threads, but yes that issue was
> > > > "worked around". The crash is something that was found as well
> > > > and is still open, in fact pretty easy to reproduce.
> > > >
> > >
> > > How can I reproduce that?
> >
> > I tried it again on the system that Henning was using when reporting
> > the problem. We increased CONFIG_XENO_OPT_DEBUG from 512 to 4096 in
> > the meantime.
> >
> > Taken while switchtest is running on that system:
> >
> > # cat /proc/xenomai/registry/usage
> > 523/4096
> >
> > So with the old 512 slots we would run into a exhaustion on such a
> > big system. IMHO that should be the root cause.
> >
> > Configuration problem, no bug.
>
> Correction: Maybe we have a problem in one of the error handling
> pathes in switchtest?
There is a bug. The switchtest starts running will all 0 even though it
failed to claim the ressources it needs ... maybe that is still OK. Not
sure what the return value was in that case ... but should not be 0.
The real problem is the BUG_ON on the second run. Probably some
leftovers from the first run that "failed" and did not clean up
properly.
But i personally see it as very low prio, which is also why i did not
do anything about it yet. It is a bug that gets triggered by an
artificial test that is "unusually stressy", and it can be worked
around by making that test less stressy or increasing the slot nr.
Henning
> >
> > Henning, please correct me if you disagree.
> >
> > >
> > > Jan
> > >
> > > > > Might that be related to a registry slot exhaustion? On the
> > > > > affected system we changed CONFIG_XENO_OPT_DEBUG from 4096
> > > > > back to its default (512). Just an idea... ctrl+c might skip
> > > > > the resource cleanup.
> > > >
> > > > I have no which ressource was exhausted. We could just try that
> > > > kernel with the bigger registry and compare with the smaller
> > > > one. Thanks for the hint.
> > > >
> > > > Henning
> > > >
> > > > > Looking into /proc/xenomai/registry/usage might help in such
> > > > > case.
> > > > > >
> > > > > > Jan
> > > > > >
> > > > >
> > > >
> > >
> >
>
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: "switchtest" problem with recent 5.10 dovetail and distro-like kernel config
2021-10-07 13:29 ` Henning Schild
@ 2021-10-07 17:28 ` Jan Kiszka
0 siblings, 0 replies; 15+ messages in thread
From: Jan Kiszka @ 2021-10-07 17:28 UTC (permalink / raw)
To: Henning Schild, Bezdeka, Florian (T RDA IOT SES-DE); +Cc: xenomai
On 07.10.21 15:29, Henning Schild wrote:
> Am Thu, 7 Oct 2021 10:55:38 +0200
> schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
> <florian.bezdeka@siemens.com>:
>
>> On Thu, 2021-10-07 at 08:53 +0000, Bezdeka, Florian via Xenomai wrote:
>>> On Thu, 2021-10-07 at 10:37 +0200, Jan Kiszka wrote:
>>>> On 05.10.21 17:18, Henning Schild wrote:
>>>>> Am Tue, 5 Oct 2021 16:38:12 +0200
>>>>> schrieb "Bezdeka, Florian (T RDA IOT SES-DE)"
>>>>> <florian.bezdeka@siemens.com>:
>>>>>
>>>>>> On Tue, 2021-10-05 at 16:29 +0200, Jan Kiszka via Xenomai
>>>>>> wrote:
>>>>>>> On 24.09.21 15:31, Henning Schild via Xenomai wrote:
>>>>>>>> Am Wed, 22 Sep 2021 16:21:54 +0200
>>>>>>>> schrieb Henning Schild via Xenomai <xenomai@xenomai.org>:
>>>>>>>>
>>>>>>>>> Am Wed, 22 Sep 2021 14:36:49 +0200
>>>>>>>>> schrieb Philippe Gerum <rpm@xenomai.org>:
>>>>>>>>>
>>>>>>>>>> Henning Schild via Xenomai <xenomai@xenomai.org>
>>>>>>>>>> writes:
>>>>>>>>>>> Hi,
>>>>>>>>>>>
>>>>>>>>>>> getting sick of maintaining a "small" kernel config
>>>>>>>>>>> i wanted to switch to a config derived from the
>>>>>>>>>>> debian11 5.10 kernel. Basically that config plus
>>>>>>>>>>> the few switches coming in with dovetail.
>>>>>>>>>>>
>>>>>>>>>>> That passed all tests in qemu but on a real machine
>>>>>>>>>>> (big xeon with raid0) the "switchtest" has an issue.
>>>>>>>>>>>
>>>>>>>>>>> # /lib/xenomai/testsuite/switchtest
>>>>>>>>>>> == Testing FPU check routines...
>>>>>>>>>>> r0: 1 != 2
>>>>>>>>>>> r1: 1 != 2
>>>>>>>>>>> r2: 1 != 2
>>>>>>>>>>> r3: 1 != 2
>>>>>>>>>>> r4: 1 != 2
>>>>>>>>>>> r5: 1 != 2
>>>>>>>>>>> r6: 1 != 2
>>>>>>>>>>> r7: 1 != 2
>>>>>>>>>>> ymm0: 1/1 != 2/2
>>>>>>>>>>> ymm1: 1/1 != 2/2
>>>>>>>>>>> ymm2: 1/1 != 2/2
>>>>>>>>>>> ymm3: 1/1 != 2/2
>>>>>>>>>>> ymm4: 1/1 != 2/2
>>>>>>>>>>> ymm5: 1/1 != 2/2
>>>>>>>>>>> ymm6: 1/1 != 2/2
>>>>>>>>>>> ymm7: 1/1 != 2/2
>>>>>>>>>>> == FPU check routines: OK.
>>>>>>>>>>> == Threads: ... a lot of threads ...
>>>>>>>>>>> 30-16 rtuo_ufpp30-17 rtuo_ufpp30-18 rtuo_ufps30-19
>>>>>>>>>>> rtuo_ufps30-20 rtuo_ufpp_ufps30-21
>>>>>>>>>>> rtuo_ufpp_ufps30-22 sleeper_ufpthread_create:
>>>>>>>>>>> Resource temporarily unavailable ps31-0 rtk31-1
>>>>>>>>>>> rtk31-2 rtk_fp31-3 rtk_fp31-4 rtk_fp_ufpp31-5
>>>>>>>>>>> rtk_fp_ufpp31-6 rtup31-7 rtup31-8 rtup_ufpp31-9
>>>>>>>>>>> rtup_ufpp31-10 rtus
>>>>>>>>>>>
>>>>>>>>>>> followed by only 0s
>>>>>>>>>>>
>>>>>>>>>>> RTH|---------cpu|ctx switches|-------total
>>>>>>>>>>> RTD| 0| 0| 0
>>>>>>>>>>> RTD| 1| 0| 0
>>>>>>>>>>> RTD| 2| 0| 0
>>>>>>>>>>> RTD| 3| 0| 0
>>>>>>>>>>> RTD| 4| 0| 0
>>>>>>>>>>> RTD| 5| 0| 0
>>>>>>>>>>> RTD| 6| 0| 0
>>>>>>>>>>>
>>>>>>>>>>> So it gets a
>>>>>>>>>>>
>>>>>>>>>>> sleeper_ufpthread_create: Resource temporarily
>>>>>>>>>>> unavailable
>>>>>>>>>>>
>>>>>>>>>>> but swallows that and keeps going. I think there
>>>>>>>>>>> might be a first issue with that error return not
>>>>>>>>>>> being dealt with.
>>>>>>>>>>>
>>>>>>>>>>> A second run get the "switchtest" stuck after
>>>>>>>>>>> crtl+c while the kernel starts complaining.
>>>>>>>>>>>
>>>>>>>>>>> [ 1229.072052] list_del corruption. prev->next
>>>>>>>>>>> should be ffffb24e46fb0548, but was
>>>>>>>>>>> ffffffff9a7356b0 [ 1229.072053] ------------[ cut
>>>>>>>>>>> here ]------------ [ 1229.072054] kernel BUG at
>>>>>>>>>>> lib/list_debug.c:51! [ 1229.072054] invalid opcode:
>>>>>>>>>>> 0000 [#1] SMP PTI IRQ_PIPELINE [ 1229.072054] CPU:
>>>>>>>>>>> 31 PID: 1857 Comm: switchtest Tainted: G
>>>>>>>>>>> E 5.10.61-xenomai-1 #1 [ 1229.072055] Hardware
>>>>>>>>>>> name: secret [ 1229.072055] IRQ stage: Linux [
>>>>>>>>>>> 1229.072055] RIP:
>>>>>>>>>>> 0010:__list_del_entry_valid.cold+0x31/0x47 [
>>>>>>>>>>> 1229.072056] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48
>>>>>>>>>>> c7 c7 00 9a 32 9a e8 51 0d ff ff 0f 0b 48 89 b [
>>>>>>>>>>> 1229.072057] RSP: 0018:ffffb24e4b5f7e30 EFLAGS:
>>>>>>>>>>> 00010046 [ 1229.072061] RAX: 0000000000000057 RBX:
>>>>>>>>>>> ffffb24e46fb04b0 RCX: 0000000000000000 [
>>>>>>>>>>> 1229.072062] RDX: 0000000000000000 RSI:
>>>>>>>>>>> ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [
>>>>>>>>>>> 1229.072064] RBP: 0000000000000000 R08:
>>>>>>>>>>> 0000000000000001 R09: 000000000000000f [
>>>>>>>>>>> 1229.072066] R10: 000000000000000f R11:
>>>>>>>>>>> ffffa10e9fd97bd6 R12: 0000000000000000 [
>>>>>>>>>>> 1229.072069] R13: ffffa0ff488c7380 R14:
>>>>>>>>>>> 0000000000000000 R15: 0000000000000000 [
>>>>>>>>>>> 1229.072072] FS: 00007f57e687bb80(0000)
>>>>>>>>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
>>>>>>>>>>> 1229.072074] CS: 0010 DS: 0000 ES: 0000 CR0:
>>>>>>>>>>> 0000000080050033 [ 1229.072076] CR2:
>>>>>>>>>>> 000055921bfa921c CR3: 00000001062fe002 CR4:
>>>>>>>>>>> 00000000001706e0 [ 1229.072078] Call Trace: [
>>>>>>>>>>> 1229.072080] xntimer_destroy+0x81/0x150 [
>>>>>>>>>>> 1229.072082] __xnthread_cleanup+0x1e/0x2a0 [
>>>>>>>>>>> 1229.072084] cobalt_handle_taskexit_event+0x1d/0x40
>>>>>>>>>>> [ 1229.072086] do_exit+0xe1/0xab0 [ 1229.072088] ?
>>>>>>>>>>> signal_wake_up_state+0x23/0x40 [ 1229.072090]
>>>>>>>>>>> do_group_exit+0x33/0xa0 [ 1229.072092]
>>>>>>>>>>> __x64_sys_exit_group+0x14/0x20 [ 1229.072111]
>>>>>>>>>>> do_syscall_64+0x3f/0x90 [ 1229.072113]
>>>>>>>>>>> entry_SYSCALL_64_after_hwframe+0x44/0xa9 [
>>>>>>>>>>> 1229.072115] RIP: 0033:0x7f57e6948699 [
>>>>>>>>>>> 1229.072117] Code: 00 4c 8b 05 f9 27 0f 00 be e7 00
>>>>>>>>>>> 00 00 ba 3c 00 00 00 eb 12 0f 1f 44 00 00 89 0 [
>>>>>>>>>>> 1229.072119] RSP: 002b:00007ffcfbda0078 EFLAGS:
>>>>>>>>>>> 00000246 ORIG_RAX: 00000000000000e7 [ 1229.072128]
>>>>>>>>>>> RAX: ffffffffffffffda RBX: 00007f57e6a3d610 RCX:
>>>>>>>>>>> 00007f57e6948699 [ 1229.072130] RDX:
>>>>>>>>>>> 000000000000003c RSI: 00000000000000e7 RDI:
>>>>>>>>>>> 0000000000000001 [ 1229.072132] RBP:
>>>>>>>>>>> 0000000000000001 R08: ffffffffffffff70 R09:
>>>>>>>>>>> 0000000000000001 [ 1229.072134] R10:
>>>>>>>>>>> 0000000000000005 R11: 0000000000000246 R12:
>>>>>>>>>>> 00007f57e6a3d610 [ 1229.072136] R13:
>>>>>>>>>>> 0000000000000002 R14: 00007f57e6a3dae8 R15:
>>>>>>>>>>> 0000000000000000 [ 1229.072138] Modules linked in:
>>>>>>>>>>> md4(E) sha512_ssse3(E) sha512_generic(E) cmac(E)
>>>>>>>>>>> nls_utf8(E) cifs) [ 1229.072169] mei(E)
>>>>>>>>>>> soundcore(E) sysimgblt(E) sg(E) evdev(E) ioatdma(E)
>>>>>>>>>>> joydev(E) watchdog(E) ac) [ 1229.072185] ---[ end
>>>>>>>>>>> trace a1d1ac68468e74f0 ]--- [ 1229.072186] RIP:
>>>>>>>>>>> 0010:__list_del_entry_valid.cold+0x31/0x47 [
>>>>>>>>>>> 1229.072187] Code: 99 32 9a e8 5f 0d ff ff 0f 0b 48
>>>>>>>>>>> c7 c7 00 9a 32 9a e8 51 0d ff ff 0f 0b 48 89 b [
>>>>>>>>>>> 1229.072187] RSP: 0018:ffffb24e4b5f7e30 EFLAGS:
>>>>>>>>>>> 00010046 [ 1229.072188] RAX: 0000000000000057 RBX:
>>>>>>>>>>> ffffb24e46fb04b0 RCX: 0000000000000000 [
>>>>>>>>>>> 1229.072188] RDX: 0000000000000000 RSI:
>>>>>>>>>>> ffffa10e9fd9bba0 RDI: ffffa10e9fd97b68 [
>>>>>>>>>>> 1229.072189] RBP: 0000000000000000 R08:
>>>>>>>>>>> 0000000000000001 R09: 000000000000000f [
>>>>>>>>>>> 1229.072189] R10: 000000000000000f R11:
>>>>>>>>>>> ffffa10e9fd97bd6 R12: 0000000000000000 [
>>>>>>>>>>> 1229.072190] R13: ffffa0ff488c7380 R14:
>>>>>>>>>>> 0000000000000000 R15: 0000000000000000 [
>>>>>>>>>>> 1229.072190] FS: 00007f57e687bb80(0000)
>>>>>>>>>>> GS:ffffa10e9fd80000(0000) knlGS:0000000000000000 [
>>>>>>>>>>> 1229.072190] CS: 0010 DS: 0000 ES: 0000 CR0:
>>>>>>>>>>> 0000000080050033 [ 1229.072191] CR2:
>>>>>>>>>>> 000055921bfa921c CR3: 00000001062fe002 CR4:
>>>>>>>>>>> 00000000001706e0 [ 1229.072191] Fixing recursive
>>>>>>>>>>> fault but reboot is needed!
>>>>>>>>>>>
>>>>>>>>>>> I will look into that eventually. For now i just
>>>>>>>>>>> wanted to share what i have so far, maybe someone
>>>>>>>>>>> knows what is going on or can give a hint. function
>>>>>>>>>>> tracing was way too verbose to find the rootcause
>>>>>>>>>>> of that EBUSY.
>>>>>>>>>>
>>>>>>>>>> EAGAIN, switchtest triggers this when many CPUs are
>>>>>>>>>> available but the system heap is too small (not
>>>>>>>>>> enough space there to create thread TCBs and other
>>>>>>>>>> core objects). Normally, switchtest exits properly
>>>>>>>>>> after a while.
>>>>>>>>>
>>>>>>>>> Ok maybe that changed kernel config did shrink the
>>>>>>>>> available heap, thanks for the hint.
>>>>>>>>>
>>>>>>>>> If it is an EAGAIN because of too little resources,
>>>>>>>>> maybe it should keep trying with less and less CPUs.
>>>>>>>>> And spit a warning like "could only run on 20 out of 32
>>>>>>>>> cores". At least that would be my first idea for a
>>>>>>>>> patch in case it is that.
>>>>>>>>
>>>>>>>> The test runs just fine when reducing the number of cores
>>>>>>>> to run on. In fact it was one too many ;)
>>>>>>>>
>>>>>>>> good
>>>>>>>> ./switchtest -T 5 --cpu-affinity=0-30
>>>>>>>> bad (where affinity includes all cpus)
>>>>>>>> ./switchtest -T 5 --cpu-affinity=0-31
>>>>>>>>
>>>>>>>>>> The kernel splat looks like some issue on the error
>>>>>>>>>> path which might not have been observed yet (maybe
>>>>>>>>>> triggered by ^C while switchtest was unwinding).
>>>>>>>>>
>>>>>>>>> I saw exactly that in probably three attempts. First
>>>>>>>>> switchtest killed with ctrl+c when the 0s come ...
>>>>>>>>> never any fun kernel message. But always fun kernel
>>>>>>>>> message when the second run was interrupted. So i would
>>>>>>>>> be tempted to call that reproducible and not a one-time
>>>>>>>>> bad timing.
>>>>>>>>
>>>>>>>> But when running the bad case two times in a row, it will
>>>>>>>> always
>>>>>>>>
>>>>>>>> kernel BUG at lib/list_debug.c:51!
>>>>>>>>
>>>>>>>> Even when none of the two runs was interrupted by ctrl+c.
>>>>>>>>
>>>>>>>
>>>>>>> So, the main issue was solved by increasing resources, but
>>>>>>> we still have a problem with handling errors gracefully -
>>>>>>> is that the correct summary of this issue? Or where are we
>>>>>>> standing with this?
>>>>>
>>>>> By reducing the number of threads, but yes that issue was
>>>>> "worked around". The crash is something that was found as well
>>>>> and is still open, in fact pretty easy to reproduce.
>>>>>
>>>>
>>>> How can I reproduce that?
>>>
>>> I tried it again on the system that Henning was using when reporting
>>> the problem. We increased CONFIG_XENO_OPT_DEBUG from 512 to 4096 in
>>> the meantime.
>>>
>>> Taken while switchtest is running on that system:
>>>
>>> # cat /proc/xenomai/registry/usage
>>> 523/4096
>>>
>>> So with the old 512 slots we would run into a exhaustion on such a
>>> big system. IMHO that should be the root cause.
>>>
>>> Configuration problem, no bug.
>>
>> Correction: Maybe we have a problem in one of the error handling
>> pathes in switchtest?
>
> There is a bug. The switchtest starts running will all 0 even though it
> failed to claim the ressources it needs ... maybe that is still OK. Not
> sure what the return value was in that case ... but should not be 0.
The return value is non-zero, at least that is fine.
I think the issue of some thread starting to run is simply that there is
no common kick-off after all threads have been created but rather an
immediate start of each new thread - not really an issue.
>
> The real problem is the BUG_ON on the second run. Probably some
> leftovers from the first run that "failed" and did not clean up
> properly.
>
> But i personally see it as very low prio, which is also why i did not
> do anything about it yet. It is a bug that gets triggered by an
> artificial test that is "unusually stressy", and it can be worked
> around by making that test less stressy or increasing the slot nr.
That real bug is fixed now - fortunately as it was not a switchtest problem.
Jan
--
Siemens AG, T RDA IOT
Corporate Competence Center Embedded Linux
^ permalink raw reply [flat|nested] 15+ messages in thread
end of thread, other threads:[~2021-10-07 17:28 UTC | newest]
Thread overview: 15+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-09-22 10:25 "switchtest" problem with recent 5.10 dovetail and distro-like kernel config Henning Schild
2021-09-22 12:36 ` Philippe Gerum
2021-09-22 14:21 ` Henning Schild
2021-09-24 13:31 ` Henning Schild
2021-10-05 14:29 ` Jan Kiszka
2021-10-05 14:38 ` Bezdeka, Florian
2021-10-05 15:18 ` Henning Schild
2021-10-07 8:37 ` Jan Kiszka
2021-10-07 8:53 ` Bezdeka, Florian
2021-10-07 8:55 ` Bezdeka, Florian
2021-10-07 9:05 ` Bezdeka, Florian
2021-10-07 12:45 ` Jan Kiszka
2021-10-07 13:29 ` Henning Schild
2021-10-07 17:28 ` Jan Kiszka
2021-10-07 13:17 ` Henning Schild
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.