Re: BUG: scheduling while atomic with PREEMPT_RT=y and bpf selftests

Bert Karwatzki
2025-05-26T09:23:30Z

Am Sonntag, dem 25.05.2025 um 18:32 -0700 schrieb Alexei Starovoitov:
> On Sun, May 25, 2025 at 3:48 PM Bert Karwatzki <spasswolf@web.de> wrote:
> >
> > [ T2916] rtlock_slowlock_locked+0x635/0x1d00
> > [ T2916] ? srso_alias_return_thunk+0x5/0xfbef5
> > [ T2916] ? lock_acquire+0xca/0x300
> > [ T2916] rt_spin_lock+0x99/0x190
> > [ T2916] task_get_cgroup1+0xe8/0x340
> > [ T2916] bpf_task_get_cgroup1+0xe/0x20
>
> Known issue.
> Please trim your emails.

Narrowed it down to single tests:

Running (in tools/testing/selftests/bpf):
./test_progs -a cgrp_local_storage/cgrp1_tp_btf

results in this warning:
[ 4782.072921] [ T17037] BUG: sleeping function called from invalid context at kernel/locking/spinlock_rt.c:48
[ 4782.072925] [ T17037] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 17037, name: test_progs
[ 4782.072927] [ T17037] preempt_count: 1, expected: 0
[ 4782.072928] [ T17037] RCU nest depth: 2, expected: 2
[ 4782.072929] [ T17037] INFO: lockdep is turned off.
[ 4782.072930] [ T17037] Preemption disabled at:
[ 4782.072930] [ T17037] [<ffffffff97790acd>] fd_install+0x3d/0x360
[ 4782.072942] [ T17037] CPU: 11 UID: 0 PID: 17037 Comm: test_progs Tainted: G W O 6.15.0-rc7-next-20250523-gcc-dirty #4 PREEMPT_{RT,(full)}
[ 4782.072945] [ T17037] Tainted: [W]=WARN, [O]=OOT_MODULE
[ 4782.072946] [ T17037] Hardware name: Micro-Star International Co., Ltd. Alpha 15 B5EEK/MS-158L, BIOS E158LAMS.10F 11/11/2024
[ 4782.072948] [ T17037] Call Trace:
[ 4782.072950] [ T17037] <TASK>
[ 4782.072953] [ T17037] dump_stack_lvl+0x6d/0xb0
[ 4782.072957] [ T17037] __might_resched.cold+0xfa/0x135
[ 4782.072961] [ T17037] rt_spin_lock+0x5f/0x190
[ 4782.072964] [ T17037] ? task_get_cgroup1+0xe8/0x340
[ 4782.072967] [ T17037] task_get_cgroup1+0xe8/0x340
[ 4782.072969] [ T17037] bpf_task_get_cgroup1+0xe/0x20
[ 4782.072973] [ T17037] bpf_prog_8d22669ef1ee8049_on_enter+0x62/0x1d4
[ 4782.072975] [ T17037] bpf_trace_run2+0xd3/0x260
[ 4782.072978] [ T17037] ? srso_alias_return_thunk+0x5/0xfbef5
[ 4782.072982] [ T17037] __bpf_trace_sys_enter+0x37/0x60
[ 4782.072986] [ T17037] syscall_trace_enter+0x1c7/0x260
[ 4782.072989] [ T17037] do_syscall_64+0x395/0xfa0
[ 4782.072991] [ T17037] ? srso_alias_return_thunk+0x5/0xfbef5
[ 4782.072994] [ T17037] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 4782.072996] [ T17037] RIP: 0033:0x7f731eb12779
[ 4782.073014] [ T17037] Code: ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05
<48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 4f 86 0d 00 f7 d8 64 89 01 48
[ 4782.073015] [ T17037] RSP: 002b:00007fff6713da78 EFLAGS: 00000202 ORIG_RAX: 0000000000000141
[ 4782.073017] [ T17037] RAX: ffffffffffffffda RBX: 00007fff6713e208 RCX: 00007f731eb12779
[ 4782.073019] [ T17037] RDX: 0000000000000040 RSI: 00007fff6713daf0 RDI: 000000000000001c
[ 4782.073020] [ T17037] RBP: 00007fff6713da90 R08: 0000000000000001 R09: 00007fff6713daf0
[ 4782.073021] [ T17037] R10: 00007f731ebebac0 R11: 0000000000000202 R12: 0000000000000000
[ 4782.073022] [ T17037] R13: 00007fff6713e228 R14: 00007f731f147000 R15: 0000558d31b9b890
[ 4782.073029] [ T17037] </TASK>

Running
./test_progs -a cgrp_local_storage/cgrp1_recursion
gives a similar warning as above but also additional
[ 5185.074482] [ T1419] BUG: scheduling while atomic: Xorg:cs0/1419/0x00000002
[...]
[ 5185.077594] [ T1163] BUG: scheduling while atomic: in:imklog/1163/0x00000002
[...]
[ 5185.077852] [ T1165] BUG: scheduling while atomic: rs:main Q:Reg/1165/0x00000002
[...]
[ 5185.078004] [ T5845] BUG: scheduling while atomic: dmesg/5845/0x00000002
[...]
messages.