Re: [PATCH] tick/rcu: fix false positive "softirq work is pending" messages on RT

[Frederic Weisbecker]

Le Mon, Aug 21, 2023 at 03:03:10PM -0700, Paul E. McKenney a écrit :
> On Mon, Aug 21, 2023 at 01:23:15AM +0800, Wen Yang wrote:
> > 
> > On 2023/8/19 04:07, paul.gortmaker@xxxxxxxxxxxxx wrote:
> > > From: Paul Gortmaker <paul.gortmaker@xxxxxxxxxxxxx>
> > > 
> > > In commit 0345691b24c0 ("tick/rcu: Stop allowing RCU_SOFTIRQ in idle")
> > > the new function report_idle_softirq() was created by breaking code out
> > > of the existing can_stop_idle_tick() for kernels v5.18 and newer.
> > > 
> > > In doing so, the code essentially went from a one conditional:
> > > 
> > > 	if (a && b && c)
> > > 		warn();
> > > 
> > > to a three conditional:
> > > 
> > > 	if (!a)
> > > 		return;
> > > 	if (!b)
> > > 		return;
> > > 	if (!c)
> > > 		return;
> > > 	warn();
> > > 
> > > However, it seems one of the conditionals didn't get a "!" removed.
> > > Compare the instance of local_bh_blocked() in the old code:
> > > 
> > > -               if (ratelimit < 10 && !local_bh_blocked() &&
> > > -                   (local_softirq_pending() & SOFTIRQ_STOP_IDLE_MASK)) {
> > > -                       pr_warn("NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #%02x!!!\n",
> > > -                               (unsigned int) local_softirq_pending());
> > > -                       ratelimit++;
> > > -               }
> > > 
> > > ...to the usage in the new (5.18+) code:
> > > 
> > > +       /* On RT, softirqs handling may be waiting on some lock */
> > > +       if (!local_bh_blocked())
> > > +               return false;
> > > 
> > > It seems apparent that the "!" should be removed from the new code.
> > > 
> > > This issue lay dormant until another fixup for the same commit was added
> > > in commit a7e282c77785 ("tick/rcu: Fix bogus ratelimit condition").
> > > This commit realized the ratelimit was essentially set to zero instead
> > > of ten, and hence *no* softirq pending messages would ever be issued.
> > > 
> > > Once this commit was backported via linux-stable, both the v6.1 and v6.4
> > > preempt-rt kernels started printing out 10 instances of this at boot:
> > > 
> > >    NOHZ tick-stop error: local softirq work is pending, handler #80!!!
> > > 
> > > Just to double check my understanding of things, I confirmed that the
> > > v5.18-rt did print the pending-80 messages with a cherry pick of the
> > > ratelimit fix, and then confirmed no pending softirq messages were
> > > printed with a revert of mainline's 034569 on a v5.18-rt baseline.
> > > 
> > > Finally I confirmed it fixed the issue on v6.1-rt and v6.4-rt, and
> > > also didn't break anything on a defconfig of mainline master of today.
> > > 
> > > Fixes: 0345691b24c0 ("tick/rcu: Stop allowing RCU_SOFTIRQ in idle")
> > > Cc: Wen Yang <wenyang.linux@xxxxxxxxxxx>
> > > Cc: Thomas Gleixner <tglx@xxxxxxxxxxxxx>
> > > Cc: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
> > > Cc: Paul E. McKenney <paulmck@xxxxxxxxxx>
> > > Cc: Frederic Weisbecker <frederic@xxxxxxxxxx>
> > > Signed-off-by: Paul Gortmaker <paul.gortmaker@xxxxxxxxxxxxx>
> > > 
> > > diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
> > > index 2b865cb77feb..b52e1861b913 100644
> > > --- a/kernel/time/tick-sched.c
> > > +++ b/kernel/time/tick-sched.c
> > > @@ -1050,7 +1050,7 @@ static bool report_idle_softirq(void)
> > >   		return false;
> > >   	/* On RT, softirqs handling may be waiting on some lock */
> > > -	if (!local_bh_blocked())
> > > +	if (local_bh_blocked())
> > >   		return false;
> > >   	pr_warn("NOHZ tick-stop error: local softirq work is pending, handler #%02x!!!\n",
> > 
> > Good catch!
> > 
> > Reviewed-by: Wen Yang <wenyang.linux@xxxxxxxxxxx>
> 
> Frederic would normally take this, but he appears to be out.  So I am
> (probably only temporarily) queueing this in -rcu for more testing
> coverage.

I'm back, I should relay this to Thomas to avoid conflicts with
timers changes.

Thanks all of you, clearly I wasn't thinking much the day I wrote this
patch.