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

Steven Rostedt
2025-06-06T13:56:00Z

On Fri, 06 Jun 2025 15:13:05 +0200
Bert Karwatzki <spasswolf@web.de> wrote:

> I tried this and first thought my kernel did not have the right configuration as
>
> # trace-cmd record -e preempt_disable -e preempt_enable
>
> seemed to do nothing in particular, but it turns out it takes a long time to start
> (~1min) when the kernel is compiled with CONFIG_LOCKDEP=y. (on the standard debian

Yeah, that's a recent regression in the code which I'm currently testing a
fix for:

https://lore.kernel.org/linux-trace-kernel/20250605161701.35f7989a@gandalf.local.home

> kernel starting to record takes less time, but it does not have CONFIG_PREEMPT_TRACER.)
>
> So after the trace-cmd was running I ran the bpf example and got a trace.dat:
>
> # ls -lh trace.dat
> -rw-r--r-- 1 root root 152M 6. Jun 14:41 trace.dat
>
> turning this into a report with
>
> # trace-cmd report > preemp_trace.rep
>
> gives a rather unwieldly large file

Of course, it's recording every time preemption is enabled and disabled ;-)

I usually run it with a test:

# trace-cmd record -e preempt_disable -e preempt_enable ./myprog

Where it will stop when ./myprog is done.

>
> # ls -lh preempt_trace.rep
> -rw-rw-r-- 1 root root 7,4G 6. Jun 14:46 preempt_trace.rep
>
> This file has about 61 million lines
>
> # wc -l preempt_trace.rep
> 61627360 preempt_trace.rep
>
> but only 742104 corresponding to the bpf example program "test_progs"
>
> # grep test_progs preempt_trace.rep | wc -l
> 742104

# trace-cmd record -e preempt_disable -e preempt_enable -F ./test_progs

where "-F" means "follow" and will only record when "./test_progs" is running.
Add "-c" to also trace its children.

>
> Is it possible to filter the preempt_{en,dis}able events by task name (i.e.
> get_current()->comm)?
>
> I tried this (from https://code.tools/man/1/trace-cmd-report/) but it
> fails with an error message:
> # trace-cmd record -e preempt_enable -F '.*:COMM == "test_progs"' -e preempt_disable -F '.*:COMM == "test_progs"'

-F means to execute. The -F in trace-cmd report is filter (that's because
-f was already taken :-p)

-- Steve

>
> ********************
> Unable to exec .*:COMM == "test_progs"
> ********************
> trace-cmd: No such file or directory
> Failed to exec .*:COMM == "test_progs"
> libtracecmd: No such file or directory
> can not stat 'trace.dat.cpu0'
>
>
> Bert Karwatzki