Re: [PATCH] tracing/snapshot: Avoid CPU buffer swap during reserve/commit
From: Tengda Wu <hidden>
Date: 2026-07-31 01:15:12
Also in:
lkml
On 2026/7/30 19:11, Steven Rostedt wrote:
quoted hunk ↗ jump to hunk
On Thu, 30 Jul 2026 12:10:18 +0800 Tengda Wu [off-list ref] wrote:quoted
On 2026/7/30 10:04, Steven Rostedt wrote:quoted
On Thu, 30 Jul 2026 01:19:12 +0000 Tengda Wu [off-list ref] wrote:quoted
Commit 3163f635b20e ("tracing: Fix race issue between cpu buffer write and swap") fixed most of the race conditions between snapshot's ring_buffer_swap_cpu and ring_buffer_lock_{reserve, commit}. It achieved this by replacing the asynchronous swap with smp_call_function_single to trigger an interrupt on the target CPU to handle the swap.I'm curious. How did you discover this race?Just run the POC provided in commit 3163f635b20e [1] day after day, and the issue occurs. The call trace points out that the problem happens when tracing the function: [1] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=3163f635b20e9e1fb4659e74f47918c9dddfe64e [ 55.864661] ------------[ cut here ]------------ [ 55.865536] WARNING: CPU: 0 PID: 1451 at kernel/trace/ring_buffer.c:3096 rb_commit.constprop.0+0x367/0x820 [ 55.866993] Modules linked in: binfmt_misc rpcrdma rdma_cm iw_cm ib_cm ib_core nfsd auth_rpcgss nfs_acl lockd grace sunrpc [ 55.869583] CPU: 0 PID: 1451 Comm: DTS202602110403 Not tainted 5.10.0+ #1 [ 55.871729] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 55.874671] RIP: 0010:rb_commit.constprop.0+0x367/0x820 [ 55.871729] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/0 1/2014 [ 55.874671] RIP: 0010:rb_commit.constprop.0+0x367/0x820 [ 55.875637] Code: 8d 7f 10 48 89 f9 48 c1 e9 03 80 3c 01 00 0f 85 af 03 00 00 49 8b 5f 10 be 04 00 00 00 48 8d 7b 08 e8 dd a0 41 00 f0 ff 43 08 <0f> 0b 48 83 c4 60 5b 5d 41 5c 41 5d 41 5e 41 5f e9 54 58 2e 02 be [ 55.878367] RSP: 0018:ffffc90000b57a30 EFLAGS: 00010202 [ 55.879227] RAX: 0000000000000001 RBX: ffff88800105ec00 RCX: ffffffff9e11db33 [ 55.880366] RDX: ffffed100020bd82 RSI: 0000000000000004 RDI: ffff88800105ec08 [ 55.881470] RBP: ffff88800105ec00 R08: 0000000000000001 R09: ffff88800105ec0b [ 55.882563] R10: ffffed100020bd81 R11: 0000000000000001 R12: ffff8880010520a0 [ 55.883681] R13: ffff88800105ec40 R14: 0000000000000000 R15: ffff888001052000 [ 55.884761] FS: 00007f6be3c5d740(0000) GS:ffff888065200000(0000) knlGS:0000000000000000 [ 55.885980] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 55.886876] CR2: 000055d8257879e0 CR3: 0000000005c78003 CR4: 0000000000770ef0 [ 55.887994] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 55.889113] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 55.890232] PKRU: 55555554 [ 55.890740] Call Trace: [ 55.891221] ? s_show+0x2f0/0x2f0 [ 55.891815] ? kallsyms_lookup_size_offset+0x130/0x130 [ 55.892684] ring_buffer_unlock_commit+0x68/0x510 [ 55.893490] ? kallsyms_lookup_size_offset+0x130/0x130 [ 55.894341] ? seq_print_sym+0x13d/0x1a0 [ 55.895024] function_trace_call+0x266/0x370 [ 55.895754] ? ring_buffer_iter_advance+0x2f/0x80 [ 55.896584] 0xffffffffc037406a [ 55.897180] ? ring_buffer_iter_advance+0x2f/0x80 [ 55.897966] ? kallsyms_lookup+0x5/0x260 [ 55.898640] ? _raw_write_unlock_irqrestore+0x60/0x60 [ 55.899481] kallsyms_lookup+0x5/0x260 The vmcore indicates that the buffer in CPU 0 was swapped: * array_buffer->buffers: cpu 0, ffff888001052000, committing = 0, entries = 10010687, commits = 10010686 cpu 1, ffff888001fa4400, committing = 0, entries = 18780536, commits = 18780536 cpu 2, ffff888100110400, committing = 0, entries = 20905896, commits = 20905896 cpu 3, ffff888100111c00, committing = 0, entries = 20825484, commits = 20825484 * max_buffer->buffers: cpu 0, ffff888001052400, committing = 1, entries = 9768877, commits = 9768878 cpu 1, ffff888001fa6400, committing = 0, entries = 0, commits = 0 cpu 2, ffff888100112400, committing = 0, entries = 0, commits = 0 cpu 3, ffff888100112800, committing = 0, entries = 0, commits = 0 We first checked if the problem could occur before rb_start_commit, but we just couldn't get past the 'READ_ONCE(cpu_buffer->buffer) != buffer' check. So we turned our attention to what happens after rb_start_commit, to see if the committing counter might drop to 0 and then get incremented again. In the end, we found that only rb_move_tail could cause this. Honestly, it was a pretty tough journey.I bet. Thanks for doing that work.quoted
The work_on_cpu approach does not fix the issue inside the ring buffer itself. However, as far as the current codebase is concerned, the snapshot operation is the only path that triggers a CPU buffer swap. This fix has minimal impact and does not expose users to the internal intermediate state of the ring buffer when they echo to snapshot, thus avoiding the confusion of hitting an -EBUSY error.I admit it is a way to avoid the -EBUSY, which is a separate issue and one that always existed. Your patch can be added to solve that for this specific use case. But then it would not be a fix, just an enhancement.quoted
If we were to fix this from within the ring buffer, we might need to introduce a new flag (e.g., a local_t variable similar to committing) to detect such race windows. Based on the current analysis, this race only occurs during a very brief window in rb_move_tail. Adding a new flag for this seems unnecessary. Alternatively, we could simply remove both rb_end_commit(cpu_buffer) and local_inc(&cpu_buffer->committing) inside rb_move_tail, thereby eliminating the 1-0-1 transition of committing and preventing such a race window from existing in the first place. In principle, committing should remain non-zero from the moment rb_start_commit is called until the commit is finished.Actually there already exists something that can be used: cpu_buffer->current_context It is set to prevent recursion in the ring buffer when the commit starts, and is cleared after the commit is finished. If it is anything other than 0, it means a commit is in progress and the swap should return -EBUSY. This is not affected by the move to next page. Something like this should fix it:diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c index 804ccae694d2..ce195bc4136a 100644 --- a/kernel/trace/ring_buffer.c +++ b/kernel/trace/ring_buffer.c@@ -6850,7 +6850,7 @@ int ring_buffer_swap_cpu(struct trace_buffer *buffer_a, { struct ring_buffer_per_cpu *cpu_buffer_a; struct ring_buffer_per_cpu *cpu_buffer_b; - int ret = -EINVAL; + int ret = -EBUSY; if (!cpumask_test_cpu(cpu, buffer_a->cpumask) || !cpumask_test_cpu(cpu, buffer_b->cpumask))@@ -6891,10 +6891,10 @@ int ring_buffer_swap_cpu(struct trace_buffer *buffer_a, atomic_inc(&cpu_buffer_a->record_disabled); atomic_inc(&cpu_buffer_b->record_disabled); - ret = -EBUSY; - if (local_read(&cpu_buffer_a->committing)) + /* Do not swap if either buffer is in the process of writing */ + if (cpu_buffer_a->current_context) goto out_dec; - if (local_read(&cpu_buffer_b->committing)) + if (cpu_buffer_b->current_context) goto out_dec; /*Care to send both patches? One with the above to fix the problem, and this current patch to make the swap not return -EBUSY. The first would go to stable, the latter would go in the next merge window. -- Steve
Certainly, I'd be happy to send both patches. Thank you very much for the detailed analysis and for providing a concrete fix. I really appreciate the guidance. I'll make sure to include proper commit messages and tags. I'll send them out shortly. Thanks, Tengda