On Fri, 27 Mar 2026 16:25:08 -0400
Steven Rostedt <[email protected]> wrote:

> Also, I noticed that there's nothing that reads the RB_MISSING as I thought
> it might. I'll have to look into how to pass that info to the trace output.

And when I cat 
/sys/kernel/tracing/instances/ptracingtest/per_cpu/cpuX/trace_pipe

   (where X is the failed buffer)

It triggered an infinite loop of:

[  206.549217] ------------[ cut here ]------------
[  206.550907] WARNING: kernel/trace/ring_buffer.c:5751 at 
__rb_get_reader_page+0xa6b/0x1040, CPU#2: cat/1197
[  206.554111] Modules linked in:
[  206.555331] CPU: 2 UID: 0 PID: 1197 Comm: cat Tainted: G        W           
7.0.0-rc4-test-00028-g7b37f48b2c57-dirty #276 PREEMPT(full) 
[  206.559048] Tainted: [W]=WARN
[  206.560244] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 
1.17.0-debian-1.17.0-1 04/01/2014
[  206.563212] RIP: 0010:__rb_get_reader_page+0xa6b/0x1040
[  206.564964] Code: ff df 48 c1 ea 03 80 3c 02 00 0f 85 4a 05 00 00 48 8b 43 
10 be 04 00 00 00 4c 8d 60 08 4c 89 e7 e8 9a 2d 63 00 f0 41 ff 04 24 <0f> 0b e9 
36 fb ff ff e8 29 39 05 00 fb 0f 1f 44 00 00 4d 85 f6 0f
[  206.572295] RSP: 0018:ffff888112a77938 EFLAGS: 00010006
[  206.574095] RAX: 0000000000000001 RBX: ffff888100d6e000 RCX: 0000000000000001
[  206.576458] RDX: 0000000000000001 RSI: 0000000000000004 RDI: ffff88810027b808
[  206.578749] RBP: 1ffff1102254ef34 R08: ffffffff909a1556 R09: ffffed102004f701
[  206.581020] R10: ffffed102004f702 R11: ffff88823443a000 R12: ffff88810027b808
[  206.583312] R13: ffff888100f65f00 R14: ffff888100f65f00 R15: dffffc0000000000
[  206.585647] FS:  00007f98e4d80780(0000) GS:ffff88829e3c2000(0000) 
knlGS:0000000000000000
[  206.588246] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  206.590179] CR2: 00007f98e4d3e000 CR3: 000000012272e006 CR4: 0000000000172ef0
[  206.592444] Call Trace:
[  206.593518]  <TASK>
[  206.594436]  ? __pfx___rb_get_reader_page+0x10/0x10
[  206.596148]  ? lock_acquire+0x1b2/0x340
[  206.597599]  rb_buffer_peek+0x37e/0x520
[  206.598954]  ring_buffer_peek+0xe9/0x310
[  206.601956]  peek_next_entry+0x15a/0x280
[  206.603420]  __find_next_entry+0x39f/0x530
[  206.604918]  ? __pfx___mutex_lock+0x10/0x10
[  206.606474]  ? rcu_is_watching+0x15/0xb0
[  206.616049]  ? __pfx___find_next_entry+0x10/0x10
[  206.617741]  ? preempt_count_sub+0x10c/0x1c0
[  206.619242]  ? __pfx_down_read+0x10/0x10
[  206.620687]  trace_find_next_entry_inc+0x2f/0x240
[  206.622351]  tracing_read_pipe+0x4e7/0xc60
[  206.623852]  ? rw_verify_area+0x353/0x5f0
[  206.625325]  vfs_read+0x171/0xb20
[  206.626592]  ? __lock_acquire+0x487/0x2220
[  206.628135]  ? __pfx___handle_mm_fault+0x10/0x10
[  206.629784]  ? __pfx_vfs_read+0x10/0x10
[  206.632696]  ? __pfx_css_rstat_updated+0x10/0x10
[  206.634351]  ? rcu_is_watching+0x15/0xb0
[  206.635835]  ? trace_preempt_on+0x126/0x160
[  206.637362]  ? preempt_count_sub+0x10c/0x1c0
[  206.638880]  ? count_memcg_events+0x10a/0x4b0
[  206.640455]  ? find_held_lock+0x2b/0x80
[  206.641908]  ? rcu_read_unlock+0x17/0x60
[  206.643340]  ? lock_release+0x1ab/0x320
[  206.644812]  ksys_read+0xff/0x200
[  206.646127]  ? __pfx_ksys_read+0x10/0x10
[  206.647651]  do_syscall_64+0x117/0x16c0
[  206.649035]  ? irqentry_exit+0xd9/0x690
[  206.650548]  entry_SYSCALL_64_after_hwframe+0x76/0x7e
[  206.652331] RIP: 0033:0x7f98e4e14eb2
[  206.653743] 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
[  206.659364] RSP: 002b:00007ffdc0a8d930 EFLAGS: 00000202 ORIG_RAX: 
0000000000000000
[  206.663251] RAX: ffffffffffffffda RBX: 0000000000040000 RCX: 00007f98e4e14eb2
[  206.665614] RDX: 0000000000040000 RSI: 00007f98e4d3f000 RDI: 0000000000000003
[  206.668022] RBP: 0000000000040000 R08: 0000000000000000 R09: 0000000000000000
[  206.670306] R10: 0000000000000000 R11: 0000000000000202 R12: 00007f98e4d3f000
[  206.672624] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000040000
[  206.674941]  </TASK>
[  206.675927] irq event stamp: 7898
[  206.677154] hardirqs last  enabled at (7897): [<ffffffff90991f6f>] 
ring_buffer_empty_cpu+0x19f/0x2f0
[  206.680088] hardirqs last disabled at (7898): [<ffffffff909a277d>] 
ring_buffer_peek+0x17d/0x310
[  206.682881] softirqs last  enabled at (7888): [<ffffffff9056cffc>] 
handle_softirqs+0x5bc/0x7c0
[  206.685710] softirqs last disabled at (7879): [<ffffffff9056d322>] 
__irq_exit_rcu+0x112/0x230
[  206.688483] ---[ end trace 0000000000000000 ]---

OK, that RB_MISSED_EVENTS is causing an issue. Something else we need to
look into. The warning is that __rb_get_reader_page() is trying more than 3
times. Thus I think it's constantly swapping the head page and the reader
page. Something to investigate.

So, I'm holding off pulling in these patches. I may take the first one
though.

-- Steve

Reply via email to