Re: [PATCH v2] tracing: Add mutex to trace_parser to fix concurrent write races

On Wed, 15 Jul 2026 08:19:37 +0000
Tengda Wu <[email protected]> wrote:

> The trace_parser structure is allocated and initialized when a trace
> file is opened, and is subsequently used in the write handler to parse
> user input. If userspace opens a trace file descriptor and shares it
> across multiple threads, concurrent write calls will race on the
> parser's internal state, specifically the idx, cont, and buffer fields,
> leading to corrupted input or undefined behavior.
> 
> Fix this by embedding a mutex directly in struct trace_parser. The mutex
> is initialized in trace_parser_get_init() and destroyed in
> trace_parser_put(). All write-side users that access parser state
> (trace_get_user() followed by checking trace_parser_loaded() /
> trace_parser_cont() against the buffer) now hold the mutex across the
> full critical section, avoiding any TOCTOU gap between the parse and the
> subsequent consumption of parser->buffer.
> 
> Fixes: e704eff3ff51 ("ftrace: Have set_graph_function handle multiple functions in one write")
> Fixes: 689fd8b65d66 ("tracing: trace parser support for function and graph")
> Cc: [email protected]
> Signed-off-by: Tengda Wu <[email protected]>
> ---
> v2: Add proper lockdep assertions to enforce that the parser lock is
>     held by all callers (Steven).
> v1: https://lore.kernel.org/all/[email protected]/

This triggered a lockdep splat:

[  214.921782] ======================================================
[  214.924654] WARNING: possible circular locking dependency detected
[  214.927502] 7.2.0-rc4-test-00009-gdf004e09835f-dirty #25 Not tainted
[  214.930417] ------------------------------------------------------
[  214.933274] ftrace-test-mco/3440 is trying to acquire lock:
[  214.935879] ffffffff9c3f3a00 (ftrace_lock){+.+.}-{4:4}, at: register_ftrace_function_probe+0x46/0x580
[  214.939970] 
[  214.939970] but task is already holding lock:
[  214.942531] ffffffff9c3f3440 (ftrace_cmd_mutex){+.+.}-{4:4}, at: ftrace_process_regex.isra.0+0x68/0x120
[  214.946327] 
[  214.946327] which lock already depends on the new lock.
[  214.946327] 
[  214.949491] 
[  214.949491] the existing dependency chain (in reverse order) is:
[  214.952351] 
[  214.952351] -> #2 (ftrace_cmd_mutex){+.+.}-{4:4}:
[  214.954682]        __mutex_lock+0xdb/0x10a0
[  214.956466]        ftrace_process_regex.isra.0+0x68/0x120
[  214.958555]        ftrace_regex_write.part.0.isra.0+0xc5/0x150
[  214.960767]        vfs_write+0xd0/0x5a0
[  214.962311]        ksys_write+0x79/0xf0
[  214.963871]        do_syscall_64+0x7e/0x7d0
[  214.965444]        entry_SYSCALL_64_after_hwframe+0x76/0x7e
[  214.967425] 
[  214.967425] -> #1 (&parser->lock){+.+.}-{4:4}:
[  214.969537]        __mutex_lock+0xdb/0x10a0
[  214.971054]        trace_pid_write+0x105/0x2d0
[  214.972666]        pid_write.isra.0+0xc0/0x360
[  214.974263]        vfs_write+0xd0/0x5a0
[  214.975699]        ksys_write+0x79/0xf0
[  214.977119]        do_syscall_64+0x7e/0x7d0
[  214.978633]        entry_SYSCALL_64_after_hwframe+0x76/0x7e
[  214.980544] 
[  214.980544] -> #0 (ftrace_lock){+.+.}-{4:4}:
[  214.982584]        __lock_acquire+0x1496/0x23b0
[  214.984211]        lock_acquire+0xdb/0x310
[  214.985702]        __mutex_lock+0xdb/0x10a0
[  214.987220]        register_ftrace_function_probe+0x46/0x580
[  214.989169]        ftrace_trace_probe_callback.isra.0+0x76/0xe0
[  214.991168]        ftrace_process_regex.isra.0+0xb2/0x120
[  214.993036]        ftrace_regex_write.part.0.isra.0+0xc5/0x150
[  214.995018]        vfs_write+0xd0/0x5a0
[  214.996448]        ksys_write+0x79/0xf0
[  214.997873]        do_syscall_64+0x7e/0x7d0
[  214.999399]        entry_SYSCALL_64_after_hwframe+0x76/0x7e
[  215.001301] 
[  215.001301] other info that might help us debug this:
[  215.001301] 
[  215.004055] Chain exists of:
[  215.004055]   ftrace_lock --> &parser->lock --> ftrace_cmd_mutex
[  215.004055] 
[  215.007461]  Possible unsafe locking scenario:
[  215.007461] 
[  215.009549]        CPU0                    CPU1
[  215.011160]        ----                    ----
[  215.012790]   lock(ftrace_cmd_mutex);
[  215.014161]                                lock(&parser->lock);
[  215.016174]                                lock(ftrace_cmd_mutex);
[  215.018247]   lock(ftrace_lock);
[  215.019513] 
[  215.019513]  *** DEADLOCK ***
[  215.019513] 
[  215.021679] 3 locks held by ftrace-test-mco/3440:
[  215.023342]  #0: ffff8bf9c16d5450 (sb_writers#14){.+.+}-{0:0}, at: ksys_write+0x79/0xf0
[  215.026030]  #1: ffff8bf9c44108b0 (&parser->lock){+.+.}-{4:4}, at: ftrace_regex_write.part.0.isra.0+0x47/0x150
[  215.029259]  #2: ffffffff9c3f3440 (ftrace_cmd_mutex){+.+.}-{4:4}, at: ftrace_process_regex.isra.0+0x68/0x120
[  215.032448] 
[  215.032448] stack backtrace:
[  215.034100] CPU: 1 UID: 0 PID: 3440 Comm: ftrace-test-mco Not tainted 7.2.0-rc4-test-00009-gdf004e09835f-dirty #25 PREEMPT(lazy) 
[  215.034104] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.17.0-debian-1.17.0-1 04/01/2014
[  215.034105] Call Trace:
[  215.034107]  <TASK>
[  215.034109]  dump_stack_lvl+0x6e/0xa0
[  215.034118]  print_circular_bug.cold+0x185/0x1d0
[  215.034125]  check_noncircular+0x148/0x170
[  215.034130]  __lock_acquire+0x1496/0x23b0
[  215.034133]  ? save_trace+0x53/0x360
[  215.034140]  lock_acquire+0xdb/0x310
[  215.034142]  ? register_ftrace_function_probe+0x46/0x580
[  215.034149]  __mutex_lock+0xdb/0x10a0
[  215.034153]  ? register_ftrace_function_probe+0x46/0x580
[  215.034156]  ? ftrace_process_regex.isra.0+0x68/0x120
[  215.034159]  ? register_ftrace_function_probe+0x46/0x580
[  215.034162]  ? lock_acquire+0xeb/0x310
[  215.034167]  ? register_ftrace_function_probe+0x46/0x580
[  215.034170]  register_ftrace_function_probe+0x46/0x580
[  215.034174]  ? ftrace_process_regex.isra.0+0x68/0x120
[  215.034176]  ? __might_fault+0x44/0xa0
[  215.034182]  ftrace_trace_probe_callback.isra.0+0x76/0xe0
[  215.034187]  ftrace_process_regex.isra.0+0xb2/0x120
[  215.034191]  ftrace_regex_write.part.0.isra.0+0xc5/0x150
[  215.034195]  vfs_write+0xd0/0x5a0
[  215.034200]  ? rcu_is_watching+0x11/0x50
[  215.034206]  ? fput_close_sync+0x79/0xe0
[  215.034211]  ksys_write+0x79/0xf0
[  215.034214]  do_syscall_64+0x7e/0x7d0
[  215.034218]  ? trace_hardirqs_off+0xd/0x30
[  215.034222]  entry_SYSCALL_64_after_hwframe+0x76/0x7e
[  215.034224] RIP: 0033:0x7feefb1a17d2
[  215.034228] Code: 18 41 8b 93 08 03 00 00 59 5e 48 83 f8 fc 75 1a 83 e2 39 83 fa 08 75 12 e8 2b ff ff ff 0f 1f 00 49 89 ca 48 8b 44 24 20 0f 05 <48> 83 c4 18 c3 66 0f 1f 84 00 00 00 00 00 48 83 ec 10 ff 74 24 18
[  215.034230] RSP: 002b:00007ffe0dae2bc0 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[  215.034233] RAX: ffffffffffffffda RBX: 00007feefb2f95c0 RCX: 00007feefb1a17d2
[  215.034235] RDX: 0000000000000014 RSI: 000055d4f7f6d5d0 RDI: 0000000000000001
[  215.034237] RBP: 0000000000000014 R08: 0000000000000000 R09: 0000000000000000
[  215.034238] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000014
[  215.034240] R13: 000055d4f7f6d5d0 R14: 000055d4f7f6f3f0 R15: 0000000000000008
[  215.034245]  </TASK>

Your original patch doesn't have this issue. But I still hate the fact
that the lock is part of the parser. I would say let's make a global
mutex for the parsing in the ftrace code (parser_lock) and replace all
the mutex_lock(&parser->lock) with mutex_lock(&parser_lock).

Also add a comment to explain what the lock is protecting by the
declaration of the lock.

Thanks,

-- Steve