Re: [PATCH v4 3/3] rcu: Use _full() API to debug synchronize_rcu()

From: Joel Fernandes
Date: Wed Mar 05 2025 - 10:25:06 EST

Next message: Jie Gan: "Re: [PATCH v15 02/10] Coresight: Add trace_id function to retrieving the trace ID"
Previous message: Yury Norov: "Re: [PATCH v4 3/8] bits: introduce fixed-type genmasks"
In reply to: Joel Fernandes: "Re: [PATCH v4 3/3] rcu: Use _full() API to debug synchronize_rcu()"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On 3/3/2025 10:23 PM, Boqun Feng wrote:
> On Sun, Mar 02, 2025 at 07:15:07PM -0500, Joel Fernandes wrote:
>> On Fri, Feb 28, 2025 at 05:08:49PM -0800, Paul E. McKenney wrote:
>>> On Fri, Feb 28, 2025 at 11:59:55AM -0800, Paul E. McKenney wrote:
>>>> On Fri, Feb 28, 2025 at 08:12:51PM +0100, Uladzislau Rezki wrote:
>>>>> Hello, Paul!
>>>>>
>>>>>>>>>>
>>>>>>>>>> Except that I got this from overnight testing of rcu/dev on the shared
>>>>>>>>>> RCU tree:
>>>>>>>>>>
>>>>>>>>>> WARNING: CPU: 5 PID: 14 at kernel/rcu/tree.c:1636 rcu_sr_normal_complete+0x5c/0x80
>>>>>>>>>>
>>>>>>>>>> I see this only on TREE05. Which should not be too surprising, given
>>>>>>>>>> that this is the scenario that tests it. It happened within five minutes
>>>>>>>>>> on all 14 of the TREE05 runs.
>>>>>>>>>>
>>>>>>>>> Hm.. This is not fun. I tested this on my system and i did not manage to
>>>>>>>>> trigger this whereas you do. Something is wrong.
>>>>>>>>
>>>>>>>> If you have a debug patch, I would be happy to give it a go.
>>>>>>>>
>>>>>>> I can trigger it. But.
>>>>>>>
>>>>>>> Some background. I tested those patches during many hours on the stable
>>>>>>> kernel which is 6.13. On that kernel i was not able to trigger it. Running
>>>>>>> the rcutorture on the our shared "dev" tree, which i did now, triggers this
>>>>>>> right away.
>>>>>>
>>>>>> Bisection? (Hey, you knew that was coming!)
>>>>>>
>>>>> Looks like this: rcu: Fix get_state_synchronize_rcu_full() GP-start detection
>>>>>
>>>>> After revert in the dev, rcutorture passes TREE05, 16 instances.
>>>>
>>>> Huh. We sure don't get to revert that one...
>>>>
>>>> Do we have a problem with the ordering in rcu_gp_init() between the calls
>>>> to rcu_seq_start() and portions of rcu_sr_normal_gp_init()? For example,
>>>> do we need to capture the relevant portion of the list before the call
>>>> to rcu_seq_start(), and do the grace-period-start work afterwards?
>>>
>>> I tried moving the call to rcu_sr_normal_gp_init() before the call to
>>> rcu_seq_start() and got no failures in a one-hour run of 200*TREE05.
>>> Which does not necessarily mean that this is the correct fix, but I
>>> figured that it might at least provide food for thought.
>>>
>>> Thanx, Paul
>>>
>>> ------------------------------------------------------------------------
>>>
>>> diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
>>> index 48384fa2eaeb8..d3efeff7740e7 100644
>>> --- a/kernel/rcu/tree.c
>>> +++ b/kernel/rcu/tree.c
>>> @@ -1819,10 +1819,10 @@ static noinline_for_stack bool rcu_gp_init(void)
>>>
>>> /* Advance to a new grace period and initialize state. */
>>> record_gp_stall_check_time();
>>> + start_new_poll = rcu_sr_normal_gp_init();
>>> /* Record GP times before starting GP, hence rcu_seq_start(). */
>>> rcu_seq_start(&rcu_state.gp_seq);
>>> ASSERT_EXCLUSIVE_WRITER(rcu_state.gp_seq);
>>> - start_new_poll = rcu_sr_normal_gp_init();
>>> trace_rcu_grace_period(rcu_state.name, rcu_state.gp_seq, TPS("start"));
>>
>> Oh... so the bug is this? Good catch...
>>
>>
>> CPU 0 CPU 1
>>
>> rcu_gp_init()
>> rcu_seq_start(rcu_state.gp_seq)
>> sychronize_rcu_normal()
>> rs.head.func
>> = (void *) get_state_synchronize_rcu();
>> // save rcu_state.gp_seq
>> rcu_sr_normal_add_req() ->
>> llist_add(rcu_state.srs_next)
>> (void) start_poll_synchronize_rcu();
>>
>>
>
> This means synchronize_rcu_normal() got the new state of gp_seq, but
> its wait request was inserted before the new wait_head, therefore..
>
>> sr_normal_gp_init()
>> llist_add(wait_head, &rcu_state.srs_next);
>> // pick up the
>> // injected WH
>> rcu_state.srs_wait_tail = wait_head;
>>
>> rcu_gp_cleanup()
>> rcu_seq_end(&rcu_state.gp_seq);
>> sr_normal_complete()
>
> at rcu_gp_cleanup() time, rcu_sr_normal_complete() complete the
> corresponding wait request, however, the sychronize_rcu_normal()
> observed the new gp_seq, its poll state will expect the next gp, hence
> the WARN_ONCE().
>
> Yes, I believe this is the scenario for the bug.
>
>> WARN_ONCE(IS_ENABLED(CONFIG_PROVE_RCU) &&
>> !poll_state_synchronize_rcu(oldstate),
>>
>> Where as reordering sr_normal_gp_init() prevents this:
>>
>> rcu_gp_init()
>>
>> sr_normal_gp_init()
>> // WH has not
>> // been injected
>> // so nothing to
>> // wait on
>>
>
> I don't quite get the comment above, the fix I believe is that wait_head
> was inserted with a llist_add() which is a fully ordered cmpxchg(), so
> we have:
>
> llist_add(wait_head, ..)
> // ^ provding the ordering againt
> // the seq change below
>
> , which means if...
>
>> rcu_seq_start(rcu_state.gp_seq)
>> sychronize_rcu_normal()
>> rs.head.func
>> = (void *) get_state_synchronize_rcu();
>> // save rcu_state.gp_seq
>
> ... the synchronize_rcu_normal() observes the new gp_seq, then...
>
>> rcu_sr_normal_add_req() ->
>> llist_add(rcu_state.srs_next)
>
> ... when its corresponding wait request gets queued, the above wait_head
> must be already in the llist...

Correct exactly!

>
>> (void) start_poll_synchronize_rcu();
>>
>> rcu_gp_cleanup()
>> rcu_seq_end(&rcu_state.gp_seq);
>
> ... hence, as the comment below said, won't do anything.
>
>> // sr_normal_complete()
>> // wont do anything so
>> // no warning
>>
>> Did I get that right?
>>
>
> Other than I'm unable to follow what do you mean "WH has not been
> injected, so nothing to wait on", maybe because I am missing some
> terminology from you ;-) I think it's a good analysis, thank you!

Sorry I should have clarified, you are right the wait_head is inserted (via
sr_normal_gp_init() -> llist_add(wait_head, &rcu_state.srs_next)) always; but
since per the fix it is done BEFORE the rcu_seq_start(), it means that:

IF synchronize_rcu_normal() saved the gp_seq via (which is required condition
for the WARN)

rs.head.func
= (void *) get_state_synchronize_rcu();
// save rcu_state.gp_seq

then, that also means that this path.. :
sychronize_rcu_normal() ->
rcu_sr_normal_add_req() ->
llist_add(rcu_state.srs_next)

.. will NOT be picked up (have its request serviced) by the end of the current
grace period, because rcu_sr_normal_add_req() happened AFTER sr_normal_gp_init()
due to the reordering in the fix.

Thus making the bug impossible.

Does that make sense or did I miss something?

>> I think this is a real bug AFAICS, hoping all the memory barriers are in
>> place to make sure the code reordering also correctly orders the accesses.
>> I'll double check that.
>>
>> I also feel its 'theoretical', because as long as rcu_gp_init() and
>> rcu_gp_cleanup() are properly ordered WRT pre-existing readers, then
>> synchronize_rcu_normal() still waits for pre-existing readers even though its
>> a bit confused about the value of the cookies.
>>
>> For the fix,
>> Reviewed-by: Joel Fernandes (Google) <joel@xxxxxxxxxxxxxxxxx>
>>
>> (If possible, include a Link: to my (this) post so that the sequence of
>> events is further clarified.)
>>
>
> Will add the tag (with the email you really want ;-)) and a link to this
> email to the patch. Thanks!
Awesome, thanks!

- Joel

Next message: Jie Gan: "Re: [PATCH v15 02/10] Coresight: Add trace_id function to retrieving the trace ID"
Previous message: Yury Norov: "Re: [PATCH v4 3/8] bits: introduce fixed-type genmasks"
In reply to: Joel Fernandes: "Re: [PATCH v4 3/3] rcu: Use _full() API to debug synchronize_rcu()"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]