linux-kernel - Re: BUG: scheduling while atomic with PREEMPT

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <0b1f48ba715a16c4d4874ae65bc01914de4d5a90.camel@web.de>
Date: Sun, 08 Jun 2025 10:45:36 +0200
From: Bert Karwatzki <spasswolf@....de>
To: Sebastian Andrzej Siewior <bigeasy@...utronix.de>, Steven Rostedt
	 <rostedt@...dmis.org>
Cc: linux-kernel@...r.kernel.org, linux-next@...r.kernel.org, 
	bpf@...r.kernel.org, linux-rt-users@...r.kernel.org, 
	linux-rt-devel@...ts.linux.dev, Thomas Gleixner <tglx@...utronix.de>,
 Alexei Starovoitov <alexei.starovoitov@...il.com>, spasswolf@....de
Subject: Re: BUG: scheduling while atomic with PREEMPT_RT=y and bpf selftests

Am Donnerstag, dem 05.06.2025 um 14:51 +0200 schrieb Sebastian Andrzej Siewior:
> On 2025-06-05 08:48:38 [-0400], Steven Rostedt wrote:
> > On Thu,  5 Jun 2025 11:19:03 +0200
> > Bert Karwatzki <spasswolf@....de> wrote:
> > 
> > > This patch seems to create so much output that the orginal error message and
> > > backtrace often get lost, so I needed several runs to get a meaningful message
> > > when running
> > 
> > Are you familiar with preempt count tracing?
> 
> I have an initial set of patches to tackle this problem, I'm going to
> send them after the merge window.
> 
> Sebastian

I've found the reason for the "mysterious" increase of preempt_count:

[   70.821750] [   T2746] bpf_link_settle calling fd_install() preemt_count = 0
[   70.821751] [   T2746] preempt_count_add 5898: preempt_count = 0x0 counter = 0x1b232c
[   70.821752] [   T2746] preempt_count_add 5900: preempt_count = 0x1 counter = 0x1b232d
[   70.821754] [   T2746] preempt_count_sub 5966: preempt_count = 0x1 counter = 0x1b232e
[   70.821755] [   T2746] preempt_count_sub 5968: preempt_count = 0x0 counter = 0x1b232f
[   70.821761] [   T2746] __bpf_trace_sys_enter 18: preempt_count = 0x0
[   70.821762] [   T2746] __bpf_trace_sys_enter 18: preempt_count = 0x1
[   70.821764] [   T2746] __bpf_trace_run: preempt_count = 1
[   70.821765] [   T2746] bpf_prog_run: preempt_count = 1
[   70.821766] [   T2746] __bpf_prog_run: preempt_count = 1

It's caused by this macro from include/trace/bpf_probe.h (with my pr_err()):

#define __BPF_DECLARE_TRACE_SYSCALL(call, proto, args) \
static notrace void \
__bpf_trace_##call(void *__data, proto) \
{ \
 might_fault(); \
 if (!strcmp(get_current()->comm, "test_progs")) \
 pr_err("%s %d: preempt_count = 0x%x", __func__, __LINE__, preempt_count());\
 preempt_disable_notrace(); \
 if (!strcmp(get_current()->comm, "test_progs")) \
 pr_err("%s %d: preempt_count = 0x%x", __func__, __LINE__, preempt_count());\
 CONCATENATE(bpf_trace_run, COUNT_ARGS(args))(__data, CAST_TO_U64(args)); \
 preempt_enable_notrace(); \
}

The preempt_{en,dis}able_notrace were introduced in
commit 4aadde89d81f ("tracing/bpf: disable preemption in syscall probe")
This commit is present in v6.14 and v6.15, but the bug already appears in
v6.12 so in that case preemption is disable somewhere else. 

Bert Karwatzki