On Mon, 6 Jul 2026 10:57:15 -0400 Steven Rostedt <[email protected]> wrote:
> On Mon, 6 Jul 2026 17:54:45 +0800 > Yuanhe Shu <[email protected]> wrote: > > > When the function tracer's func_stack_trace option and the function graph > > profiler (function_profile_enabled) are both active, a recursive ftrace > > reentrance can occur, leading to a hard lockup. This was observed during > > ftrace selftest (ftracetest-ktap) execution: > > > > watchdog: Watchdog detected hard LOCKUP on cpu 204 > > RIP: profile_graph_entry+0xa0/0x160 > > Call Trace: > > function_graph_enter+0xc9/0x120 > > arch_ftrace_ops_list_func+0x112/0x230 > > ftrace_call+0x5/0x44 > > unwind_next_frame+0x5/0x870 <-- traced by ftrace > > arch_stack_walk+0x88/0xf0 > > stack_trace_save+0x4b/0x70 > > __ftrace_trace_stack+0x12e/0x170 > > function_stack_trace_call+0x7c/0xa0 > > arch_ftrace_ops_list_func+0x112/0x230 > > ftrace_call+0x5/0x44 > > irqtime_account_irq+0x5/0xb0 > > __irq_exit_rcu+0x12/0xc0 > > ... > > > > The root cause is a recursive ftrace reentrance: > > function_stack_trace_call() invokes __trace_stack() -> > > arch_stack_walk() -> unwind_next_frame() to capture a backtrace. > > Since the unwinder functions (__unwind_start(), > > unwind_next_frame(), unwind_get_return_address(), > > unwind_get_return_address_ptr()) are not marked notrace, the > > function graph tracer instruments them, re-entering the ftrace > > infrastructure from within an ftrace callback. This results in a > > hard lockup with interrupts disabled, detected by the watchdog NMI. > > I'm fine with this change, but I'm wondering why the recursion protection > didn't catch this. There may be a missing check somewhere. I'll ack this > change, but I also want to add the check that would have prevented this > lockup. I tried to reproduce it, but it appears to be a case where things slow down so much that it triggers a lockup when it's not really locked up, but is moving so slow that the watchdog triggers. The recursive protection *is* working, but it still allows one recursion to take place (there's an unrelated reason for that). Thus what we have is that every time the function profiler does a stack trace, the function tracer recurses the unwind functions and it too does a stack trace. This just slows things down a lot more. With CONFIG_FTRACE_RECORD_RECURSION enabled, I get the following: # echo 1 > /sys/kernel/tracing/function_profile_enabled # trace-cmd start -p function -l 'unwind_*' --func-stack # cat /sys/kernel/tracing/recursed_functions __unwind_start+0x3c3/0x7e0: unwind_next_frame+0x4/0x2220 arch_stack_walk+0xb7/0x100: unwind_get_return_address+0x4/0xe0 Thus unwind_next_frame and unwind_get_return_address both had recursion from just tracing functions that started with "unwind_". It would be much worse if you traced more. Since function stack tracing is known to cause slowdowns and is even documented as possibly locking up the machine, this is *not* a fix nor belongs in stable. But it is OK to be added in the next merge window. x86 maintainers, feel free to take this with my ack, but you can remove the fixes and stable tags. -- Steve
