rcu_preempt detected stalls related to ebpf

rcu_preempt detected stalls related to ebpf

[Zac Ecob]

[-- Attachment #1: Type: text/plain, Size: 5375 bytes --]

Hi,

I am receiving an error from the RCU stall detector when using ebpf. 

I have managed to reproduce it on the 6.9.4 kernel (running inside qemu_system_x86-64), using the files attached.

The exact output is:

[   21.742355] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[   21.742643] rcu: 	(detected by 0, t=21002 jiffies, g=-1039, q=8 ncpus=1)
[   21.742899] rcu: All QSes seen, last rcu_preempt kthread activity 21002 (4294688977-4294667975), jiffies_till_next_fqs=3, root ->qsmask 0x0
[   21.743358] rcu: rcu_preempt kthread starved for 21002 jiffies! g-1039 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
[   21.743738] rcu: 	Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
[   21.744074] rcu: RCU grace-period kthread stack dump:
[   21.744263] task:rcu_preempt     state:R  running task     stack:15544 pid:15    tgid:15    ppid:2      flags:0x00004000
[   21.744677] Call Trace:
[   21.744778]  <TASK>
[   21.744866]  __schedule+0x309/0x890
[   21.745018]  ? __pfx_rcu_gp_kthread+0x10/0x10
[   21.745194]  schedule+0x2b/0xe0
[   21.745323]  schedule_timeout+0x86/0x160
[   21.745466]  ? __pfx_process_timeout+0x10/0x10
[   21.745626]  rcu_gp_fqs_loop+0x113/0x670
[   21.745767]  rcu_gp_kthread+0x19b/0x240
[   21.745904]  kthread+0xd2/0x100
[   21.746019]  ? __pfx_kthread+0x10/0x10
[   21.746153]  ret_from_fork+0x2f/0x50
[   21.746283]  ? __pfx_kthread+0x10/0x10
[   21.746416]  ret_from_fork_asm+0x1a/0x30
[   21.746559]  </TASK>
[   21.746640] rcu: Stack dump where RCU GP kthread last ran:
[   21.746833] CPU: 0 PID: 56 Comm: exploit Not tainted 6.9.4 #1
[   21.747035] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.14.0-2 04/01/2014
[   21.747335] RIP: 0010:___bpf_prog_run+0x29/0x20a0
[   21.747524] Code: 90 41 55 41 54 45 31 e4 55 48 89 fd 53 48 89 f3 0f b6 33 40 0f b6 d6 89 f0 48 8b 14 d5 00 7f 41 a0 e9 eb e9 da 00 f3 0f 1e fa <f3> 0f 1e fa 8b 53 04 83 fa 51 0f 84 07 1f 00 00 0f 8f 62 16 00 00
[   21.748243] RSP: 0018:ffff9252801bfa68 EFLAGS: 00000213
[   21.748450] RAX: 00000000000000c3 RBX: ffff9252800350b0 RCX: 00000000ffffff8d
[   21.748732] RDX: ffffffff9edd48d9 RSI: 00000000000000c3 RDI: ffff9252801bfa90
[   21.749012] RBP: ffff9252801bfa90 R08: ffff8dc381261e00 R09: ffff8dc381261e00
[   21.749292] R10: ffff8dc381bbe000 R11: ffff8dc3811f0000 R12: 0000000000000000
[   21.749572] R13: 0000000000000001 R14: ffff8dc381bbe400 R15: 0000000000000001
[   21.749854] FS:  00007fb818a03680(0000) GS:ffff8dc3fd800000(0000) knlGS:0000000000000000
[   21.750170] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   21.750397] CR2: 0000564d89dca2a8 CR3: 0000000001bbc000 CR4: 00000000000006f0
[   21.750678] Call Trace:
[   21.750779]  <IRQ>
[   21.750864]  ? rcu_check_gp_kthread_starvation+0x108/0x1a0
[   21.751082]  ? rcu_sched_clock_irq+0xc47/0xf50
[   21.751260]  ? timekeeping_update+0xab/0x280
[   21.751433]  ? timekeeping_advance+0x372/0x590
[   21.751612]  ? update_process_times+0x68/0xa0
[   21.751786]  ? tick_nohz_handler+0x110/0x190
[   21.751958]  ? __pfx_tick_nohz_handler+0x10/0x10
[   21.752143]  ? __hrtimer_run_queues+0x10d/0x2a0
[   21.752324]  ? hrtimer_interrupt+0xfe/0x240
[   21.752491]  ? __sysvec_apic_timer_interrupt+0x53/0x140
[   21.752702]  ? sysvec_apic_timer_interrupt+0x6b/0x80
[   21.752901]  </IRQ>
[   21.752989]  <TASK>
[   21.753077]  ? asm_sysvec_apic_timer_interrupt+0x1a/0x20
[   21.753287]  ? ___bpf_prog_run+0x29/0x20a0
[   21.753451]  ? ___bpf_prog_run+0x29/0x20a0
[   21.753614]  ? ___bpf_prog_run+0x29/0x20a0
[   21.753778]  __bpf_prog_run448+0x46/0x70
[   21.753936]  ? place_entity+0x14/0xf0
[   21.754085]  ? __alloc_pages+0x1bb/0x1020
[   21.754247]  ? kmem_cache_alloc_node+0x45/0x260
[   21.754429]  ? wakeup_preempt+0x5c/0x70
[   21.754583]  ? kmalloc_reserve+0x89/0xe0
[   21.754741]  ? kmalloc_reserve+0x89/0xe0
[   21.754898]  ? __alloc_skb+0xd7/0x1a0
[   21.755046]  ? security_sock_rcv_skb+0x29/0x40
[   21.755225]  sk_filter_trim_cap+0xaf/0x200
[   21.755389]  ? skb_copy_datagram_from_iter+0x59/0x1e0
[   21.755590]  unix_dgram_sendmsg+0x392/0xba0
[   21.755759]  ? remove_wait_queue+0x11/0x50
[   21.755923]  sock_write_iter+0x18f/0x1a0
[   21.756081]  vfs_write+0x37e/0x430
[   21.756222]  ksys_write+0xaa/0xe0
[   21.756354]  do_syscall_64+0xa8/0x1b0
[   21.756502]  entry_SYSCALL_64_after_hwframe+0x77/0x7f
[   21.756706] RIP: 0033:0x7fb81891c4e0
[   21.756851] Code: 69 0d 00 64 c7 00 16 00 00 00 b8 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 80 3d 89 ee 0d 00 00 74 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 48 83 ec 28 48 89
[   21.757571] RSP: 002b:00007ffd045da728 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[   21.757867] RAX: ffffffffffffffda RBX: 00007ffd045da978 RCX: 00007fb81891c4e0
[   21.758147] RDX: 0000000000000001 RSI: 00007ffd045da73f RDI: 0000000000000005
[   21.758427] RBP: 00007ffd045da860 R08: 000000000000ee08 R09: 0000000000000001
[   21.758706] R10: 00007fb818828278 R11: 0000000000000202 R12: 0000000000000000
[   21.758986] R13: 00007ffd045da988 R14: 00007fb818a3c000 R15: 0000564d75188dd8
[   21.759266]  </TASK>


Apologies if this is not a relevant bug that needs fixing, and any mistakes in etiquette. Please let me know any additional information needed.

Thanks

[-- Attachment #2: repro.tar.xz --]
[-- Type: application/x-xz, Size: 2548 bytes --]

Re: rcu_preempt detected stalls related to ebpf

[Alexei Starovoitov]

On Thu, Jun 13, 2024 at 10:55 PM Zac Ecob <zacecob@protonmail.com> wrote:
>
> Hi,
>
> I am receiving an error from the RCU stall detector when using ebpf.

Thanks for the report. I reduced the reproducer to the following:
0: R1=ctx() R10=fp0
0: (71) r3 = *(u8 *)(r10 -387)        ;
R3_w=scalar(smin=smin32=0,smax=umax=smax32=umax32=255,var_off=(0x0;
0xff)) R10=fp0
1: (bc) w7 = (s8)w3                   ;
R3_w=scalar(smin=smin32=0,smax=umax=smax32=umax32=255,var_off=(0x0;
0xff)) R7_w=scalar(smin=smin32=0,smax=umax=smax32=umax32=127,var_off=(0x0;
0x7f))
2: (36) if w7 >= 0x2533823b goto pc-3
mark_precise: frame0: last_idx 2 first_idx 0 subseq_idx -1
mark_precise: frame0: regs=r7 stack= before 1: (bc) w7 = (s8)w3
mark_precise: frame0: regs=r3 stack= before 0: (71) r3 = *(u8 *)(r10 -387)
2: R7_w=scalar(smin=smin32=0,smax=umax=smax32=umax32=127,var_off=(0x0; 0x7f))
3: (b4) w0 = 0                        ; R0_w=0
4: (95) exit
processed 5 insns (limit 1000000) max_states_per_insn 0 total_states 0
peak_states 0 mark_read 0

The verifier doesn't process (s8) insn correctly.

Yonghong,
please take a look.

Re: rcu_preempt detected stalls related to ebpf

[Zac Ecob]

> I reduced the reproducer to the following:

Thank you for minimising the repro - I didn't think to do it myself. Apologies.

> The verifier doesn't process the (s8) instruction correctly.

I took a further look out of curiosity and managed to properly crash the kernel. I think it might have security implications? 
I haven't attached a repro for this because of such (though I could perhaps email it directly?). 

Not sure how best to precede?

Thanks

Re: rcu_preempt detected stalls related to ebpf

[Alexei Starovoitov]

On Sat, Jun 15, 2024 at 12:09 AM Zac Ecob <zacecob@protonmail.com> wrote:
>
> > I reduced the reproducer to the following:
>
> Thank you for minimising the repro - I didn't think to do it myself. Apologies.
>
> > The verifier doesn't process the (s8) instruction correctly.
>
> I took a further look out of curiosity and managed to properly crash the kernel. I think it might have security implications?
> I haven't attached a repro for this because of such (though I could perhaps email it directly?).
>
> Not sure how best to precede?

Pls focus your efforts on fixing the bug.

Re: rcu_preempt detected stalls related to ebpf

[Yonghong Song]

On 6/15/24 9:59 AM, Alexei Starovoitov wrote:
> On Sat, Jun 15, 2024 at 12:09 AM Zac Ecob <zacecob@protonmail.com> wrote:
>>> I reduced the reproducer to the following:
>> Thank you for minimising the repro - I didn't think to do it myself. Apologies.
>>
>>> The verifier doesn't process the (s8) instruction correctly.
>> I took a further look out of curiosity and managed to properly crash the kernel. I think it might have security implications?
>> I haven't attached a repro for this because of such (though I could perhaps email it directly?).
>>
>> Not sure how best to precede?
> Pls focus your efforts on fixing the bug.

This is the fix: https://lore.kernel.org/bpf/20240615174621.3994321-1-yonghong.song@linux.dev/

Zac, could you test it in your environment?