Question about KCSAN, rcu_read_lock_trace(), and rcu_read_unlock_trace()

[Paul E. McKenney]

Hello!

KCSAN complains about data races between lines 14 and 25 in the code
below, presumably when one function is invoked in an interrupt handler
that interrupted the other running in task context:

1 static inline void rcu_read_lock_trace(void)
2 {
3 int n;
4 struct task_struct *t = current;
5
6 rcu_try_lock_acquire(&rcu_tasks_trace_srcu_struct.dep_map);
7 n = READ_ONCE(t->trc_reader_nesting);
8 WRITE_ONCE(t->trc_reader_nesting, n + 1);
9 if (n) {
10 // In case we interrupted a Tasks Trace RCU reader.
11 return;
12 }
13 barrier(); // nesting before scp to protect against interrupt handler.
14 t->trc_reader_scp = __srcu_read_lock_fast(&rcu_tasks_trace_srcu_struct);
15 if (!IS_ENABLED(CONFIG_TASKS_TRACE_RCU_NO_MB))
16 smp_mb(); // Placeholder for more selective ordering
17 }
18
19 static inline void rcu_read_unlock_trace(void)
20 {
21 int n;
22 struct srcu_ctr __percpu *scp;
23 struct task_struct *t = current;
24
25 scp = t->trc_reader_scp;
26 barrier(); // scp before nesting to protect against interrupt handler.
27 n = READ_ONCE(t->trc_reader_nesting) - 1;
28 WRITE_ONCE(t->trc_reader_nesting, n);
29 if (!n) {
30 if (!IS_ENABLED(CONFIG_TASKS_TRACE_RCU_NO_MB))
31 smp_mb(); // Placeholder for more selective ordering
32 __srcu_read_unlock_fast(&rcu_tasks_trace_srcu_struct, scp);
33 }
34 srcu_lock_release(&rcu_tasks_trace_srcu_struct.dep_map);
35 }

It appears to me that the updates to and checks of >trc_reader_nesting
should prevent this data race.

Except that I don't see any KCSAN on barrier(). Is there something I
need to do to convince KCSAN that the code before and after a call to
barrier() cannot be reordered with respect to interrupt handlers?

Or is there some real bug in this code that I am blind to?

Thanx, Paul

[Marco Elver]

On Sat, 18 Jul 2026 at 01:49, Paul E. McKenney <pau...@kernel.org> wrote:
>
> Hello!
>
> KCSAN complains about data races between lines 14 and 25 in the code
> below, presumably when one function is invoked in an interrupt handler
> that interrupted the other running in task context:

The data race reported is on t->trc_reader_scp, right?

Can you share the data race report? Is one of the stack traces from
within an NMI?

Thanks,
-- Marco

[Paul E. McKenney]

On Sun, Jul 19, 2026 at 11:59:09PM +0200, Marco Elver wrote:
> On Sat, 18 Jul 2026 at 01:49, Paul E. McKenney <pau...@kernel.org> wrote:
> >
> > Hello!
> >
> > KCSAN complains about data races between lines 14 and 25 in the code
> > below, presumably when one function is invoked in an interrupt handler
> > that interrupted the other running in task context:
>
> The data race reported is on t->trc_reader_scp, right?

Yes.

Here you go!

One of them is from a softirq handler, specifically a timer handler.
The other was from task level.

I used gdb to map to the actual function. And rcu_read_lock_trace()
was inlined into tasks_tracing_torture_read_lock(), plus
rcu_read_unlock_trace() into tasks_tracing_torture_read_unlock().

Thoughts?

Thanx, Paul

------------------------------------------------------------------------

[15101.116015] BUG: KCSAN: data-race in tasks_tracing_torture_read_lock / tasks_tracing_torture_read_unlock
[15101.116033]
[15101.116036] read to 0xffff0000065c3948 of 8 bytes by interrupt on cpu 0:
[15101.116043] tasks_tracing_torture_read_unlock+0xd8/0x198
[15101.116054] rcutorture_one_extend+0x4a4/0x654
[15101.116065] rcu_torture_one_read_end+0x3e4/0x69c
[15101.116072] rcu_torture_one_read+0x2bc/0x434
[15101.116083] rcu_torture_timer+0x98/0x158
[15101.116093] call_timer_fn+0xdc/0x6cc
[15101.116104] __run_timer_base+0x2a8/0x368
[15101.116113] run_timer_softirq+0x44/0x78
[15101.116122] handle_softirqs+0x16c/0x55c
[15101.116133] __do_softirq+0x14/0x20
[15101.116141] ____do_softirq+0x1c/0x2c
[15101.116151] call_on_irq_stack+0x30/0x48
[15101.116160] do_softirq_own_stack+0x28/0x38
[15101.116170] __irq_exit_rcu+0xd4/0x18c
[15101.116180] irq_exit_rcu+0x10/0x34
[15101.116189] el1_interrupt+0x40/0x60
[15101.116198] el1h_64_irq_handler+0x18/0x24
[15101.116205] el1h_64_irq+0x6c/0x70
[15101.116211] __tsan_unaligned_volatile_write4+0x1c/0x274
[15101.116223] __udelay+0x4c/0x60
[15101.116232] kcsan_setup_watchpoint+0x39c/0x7f4
[15101.116239] __tsan_read8+0x228/0x26c
[15101.116249] __delay+0x2c4/0x378
[15101.116257] __udelay+0x4c/0x60
[15101.116266] kcsan_setup_watchpoint+0x39c/0x7f4
[15101.116274] __tsan_unaligned_write8+0x228/0x26c
[15101.116284] tasks_tracing_torture_read_lock+0x108/0x1d4
[15101.116295] rcutorture_one_extend+0x258/0x654
[15101.116306] rcu_torture_one_read+0xc0/0x434
[15101.116316] rcu_torture_reader+0x328/0x470
[15101.116326] kthread+0x1d8/0x204
[15101.116335] ret_from_fork+0x10/0x20
[15101.116344]
[15101.116348] write to 0xffff0000065c3948 of 8 bytes by task 69 on cpu 0:
[15101.116353] tasks_tracing_torture_read_lock+0x108/0x1d4
[15101.116365] rcutorture_one_extend+0x258/0x654
[15101.116375] rcu_torture_one_read+0xc0/0x434
[15101.116390] rcu_torture_reader+0x328/0x470
[15101.116399] kthread+0x1d8/0x204
[15101.116407] ret_from_fork+0x10/0x20
[15101.116417]
[15101.116420] 1 lock held by rcu_torture_rea/69:
[15101.116425] #0: ffffd671cefba830 (rcu_tasks_trace_srcu_struct){....}-{0:0}, at: tasks_tracing_torture_read_lock+0x5c/0x1d4
[15101.116449] irq event stamp: 449296300
[15101.129146] hardirqs last enabled at (449296300): [<ffffd671cd184bb0>] _raw_spin_unlock_irq+0x3c/0x90
[15101.129721] hardirqs last disabled at (449296299): [<ffffd671cd184978>] _raw_spin_lock_irq+0x38/0xa0
[15101.130273] softirqs last enabled at (449295042): [<ffffd671cb573a40>] handle_softirqs+0x508/0x55c
[15101.130827] softirqs last disabled at (449296297): [<ffffd671cb410b4c>] __do_softirq+0x14/0x20
[15101.131352]
[15101.131355] Reported by Kernel Concurrency Sanitizer on:
[15101.131361] CPU: 0 UID: 0 PID: 69 Comm: rcu_torture_rea Not tainted 7.2.0-rc3-00070-ga4256b0f69da #13383 PREEMPTLAZY
[15101.131371] Hardware name: linux,dummy-virt (DT)
[15101.131376] ==================================================================

[Marco Elver]

Should the nesting check be before read of scp?

> > > 28 WRITE_ONCE(t->trc_reader_nesting, n);
> > > 29 if (!n) {
> > > 30 if (!IS_ENABLED(CONFIG_TASKS_TRACE_RCU_NO_MB))
> > > 31 smp_mb(); // Placeholder for more selective ordering
> > > 32 __srcu_read_unlock_fast(&rcu_tasks_trace_srcu_struct, scp);
> > > 33 }
> > > 34 srcu_lock_release(&rcu_tasks_trace_srcu_struct.dep_map);
> > > 35 }
> > >
> > > It appears to me that the updates to and checks of >trc_reader_nesting
> > > should prevent this data race.
> > >
> > > Except that I don't see any KCSAN on barrier(). Is there something I
> > > need to do to convince KCSAN that the code before and after a call to
> > > barrier() cannot be reordered with respect to interrupt handlers?
> > >
> > > Or is there some real bug in this code that I am blind to?
> >
> > Can you share the data race report? Is one of the stack traces from
> > within an NMI?
>
> Here you go!
>
> One of them is from a softirq handler, specifically a timer handler.
> The other was from task level.
>
> I used gdb to map to the actual function. And rcu_read_lock_trace()
> was inlined into tasks_tracing_torture_read_lock(), plus
> rcu_read_unlock_trace() into tasks_tracing_torture_read_unlock().
>
> Thoughts?

Looks like a real data race (also no simulated reordering involved).
There's nothing preventing rcu_read_unlock_trace() from running when
the rcu_read_lock_trace() is writing t->trc_reader_scp, and because
rcu_read_unlock_trace() does 'scp = t->trc_reader_scp' unconditionally
on entry we get this data race. So the interleaving is:

> 1 rcu_read_lock_trace
> ....

> 14 t->trc_reader_scp = __srcu_read_lock_fast(&rcu_tasks_trace_srcu_struct);

> <interrupt>
> 19 rcu_read_unlock_trace
> < ... var decls only ... >

> 25 scp = t->trc_reader_scp;

Or of course reversed.

[Paul E. McKenney]

Right you are!!! A big "thank you" to both you and to KCSAN!

> > > > 28 WRITE_ONCE(t->trc_reader_nesting, n);
> > > > 29 if (!n) {
> > > > 30 if (!IS_ENABLED(CONFIG_TASKS_TRACE_RCU_NO_MB))
> > > > 31 smp_mb(); // Placeholder for more selective ordering
> > > > 32 __srcu_read_unlock_fast(&rcu_tasks_trace_srcu_struct, scp);
> > > > 33 }
> > > > 34 srcu_lock_release(&rcu_tasks_trace_srcu_struct.dep_map);
> > > > 35 }
> > > >
> > > > It appears to me that the updates to and checks of >trc_reader_nesting
> > > > should prevent this data race.
> > > >
> > > > Except that I don't see any KCSAN on barrier(). Is there something I
> > > > need to do to convince KCSAN that the code before and after a call to
> > > > barrier() cannot be reordered with respect to interrupt handlers?
> > > >
> > > > Or is there some real bug in this code that I am blind to?

And the answer to this question was clearly "yes". ;-)

> > > Can you share the data race report? Is one of the stack traces from
> > > within an NMI?
> >
> > Here you go!
> >
> > One of them is from a softirq handler, specifically a timer handler.
> > The other was from task level.
> >
> > I used gdb to map to the actual function. And rcu_read_lock_trace()
> > was inlined into tasks_tracing_torture_read_lock(), plus
> > rcu_read_unlock_trace() into tasks_tracing_torture_read_unlock().
> >
> > Thoughts?
>
> Looks like a real data race (also no simulated reordering involved).
> There's nothing preventing rcu_read_unlock_trace() from running when
> the rcu_read_lock_trace() is writing t->trc_reader_scp, and because
> rcu_read_unlock_trace() does 'scp = t->trc_reader_scp' unconditionally
> on entry we get this data race. So the interleaving is:
>
> > 1 rcu_read_lock_trace
> > ....
> > 14 t->trc_reader_scp = __srcu_read_lock_fast(&rcu_tasks_trace_srcu_struct);
> > <interrupt>
> > 19 rcu_read_unlock_trace
> > < ... var decls only ... >
> > 25 scp = t->trc_reader_scp;
>
> Or of course reversed.

Again, thank you!

Alleged fix below, which I will be feeding to KCSAN later today.

Thanx, Paul

------------------------------------------------------------------------

diff --git a/include/linux/rcupdate_trace.h b/include/linux/rcupdate_trace.h
index f54d37b6fd142a..273c59a032512e 100644
--- a/include/linux/rcupdate_trace.h
+++ b/include/linux/rcupdate_trace.h
@@ -126,11 +126,13 @@ static inline void rcu_read_unlock_trace(void)
struct srcu_ctr __percpu *scp;

struct task_struct *t = current;

- scp = t->trc_reader_scp;
- barrier(); // scp before nesting to protect against interrupt handler.

n = READ_ONCE(t->trc_reader_nesting) - 1;

- WRITE_ONCE(t->trc_reader_nesting, n);
- if (!n) {
+ if (n) {
+ WRITE_ONCE(t->trc_reader_nesting, n);
+ } else {
+ scp = t->trc_reader_scp; // Compiler cannot hoist load due to data raciness.
+ barrier(); // scp before nesting to protect against interrupt handler.
+ WRITE_ONCE(t->trc_reader_nesting, n);
if (!IS_ENABLED(CONFIG_TASKS_TRACE_RCU_NO_MB))

smp_mb(); // Placeholder for more selective ordering

__srcu_read_unlock_fast(&rcu_tasks_trace_srcu_struct, scp);

[Marco Elver]

On Mon, 20 Jul 2026 at 17:24, Paul E. McKenney <pau...@kernel.org> wrote:
[...]

> Again, thank you!
>
> Alleged fix below, which I will be feeding to KCSAN later today.

Glad this helped. The fix looks reasonable, but KCSAN will be better
at judging it.

Thanks,
-- Marco