Re: [PATCH v6 0/2] rcu: Add RCU stall diagnosis information

Paul E. McKenney
2022-11-12T18:59:52Z

On Thu, Nov 10, 2022 at 10:27:44AM +0800, Leizhen (ThunderTown) wrote:
> On 2022/11/10 1:22, Paul E. McKenney wrote:
> > On Wed, Nov 09, 2022 at 06:03:17PM +0100, Frederic Weisbecker wrote:
> >> On Wed, Nov 09, 2022 at 07:59:01AM -0800, Paul E. McKenney wrote:
> >>> On Wed, Nov 09, 2022 at 04:26:21PM +0100, Frederic Weisbecker wrote:
> >>>> Hi Zhen Lei,
> >>>>
> >>>> On Wed, Nov 09, 2022 at 05:37:36PM +0800, Zhen Lei wrote:
> >>>>> v5 --> v6:
> >>>>> 1. When there are more than two continuous RCU stallings, correctly handle the
> >>>>> value of the second and subsequent sampling periods. Update comments and
> >>>>> document.
> >>>>> Thanks to Elliott, Robert for the test.
> >>>>> 2. Change "rcu stall" to "RCU stall".
> >>>>>
> >>>>> v4 --> v5:
> >>>>> 1. Resolve a git am conflict. No code change.
> >>>>>
> >>>>> v3 --> v4:
> >>>>> 1. Rename rcu_cpu_stall_deep_debug to rcu_cpu_stall_cputime.
> >>>>>
> >>>>> v2 --> v3:
> >>>>> 1. Fix the return type of kstat_cpu_irqs_sum()
> >>>>> 2. Add Kconfig option CONFIG_RCU_CPU_STALL_DEEP_DEBUG and boot parameter
> >>>>> rcupdate.rcu_cpu_stall_deep_debug.
> >>>>> 3. Add comments and normalize local variable name
> >>>>>
> >>>>>
> >>>>> v1 --> v2:
> >>>>> 1. Fixed a bug in the code. If the rcu stall is detected by another CPU,
> >>>>> kcpustat_this_cpu cannot be used.
> >>>>> @@ -451,7 +451,7 @@ static void print_cpu_stat_info(int cpu)
> >>>>> if (r->gp_seq != rdp->gp_seq)
> >>>>> return;
> >>>>>
> >>>>> - cpustat = kcpustat_this_cpu->cpustat;
> >>>>> + cpustat = kcpustat_cpu(cpu).cpustat;
> >>>>> 2. Move the start point of statistics from rcu_stall_kick_kthreads() to
> >>>>> rcu_implicit_dynticks_qs(), removing the dependency on irq_work.
> >>>>>
> >>>>> v1:
> >>>>> In some extreme cases, such as the I/O pressure test, the CPU usage may
> >>>>> be 100%, causing RCU stall. In this case, the printed information about
> >>>>> current is not useful. Displays the number and usage of hard interrupts,
> >>>>> soft interrupts, and context switches that are generated within half of
> >>>>> the CPU stall timeout, can help us make a general judgment. In other
> >>>>> cases, we can preliminarily determine whether an infinite loop occurs
> >>>>> when local_irq, local_bh or preempt is disabled.
> >>>>
> >>>> That looks useful but I have to ask: what does it bring that the softlockup
> >>>> and hardlockup watchdog can not already solve?
> >>>
> >>> This is a good point. One possible benefit is putting the needed information
> >>> in one spot, for example, in cases where the soft/hard lockup timeouts are
> >>> significantly different than the RCU CPU stall warning timeout.
> >>
> >> Arguably, the hardlockup/softlockup detectors usually trigger after RCU stall,
> >> unless all CPUs are caught into a hardlockup, in which case only the hardlockup
> >> detector has a chance.
> >>
> >> Anyway I would say that in this case just lower the delay for the lockup
> >> detectors to consider the situation is a lockup?
> >
> > Try it both ways and see how it works? The rcutorture module parameters
> > stall_cpu and stall_cpu_irqsoff are easy ways to generate these sorts
> > of scenarios.
> >
> > Actually, that does remind me of something. Back when I was chasing
> > that interrupt storm, would this patch have helped me? In that case, the
>
> Yes, this patch series originally addressed an RCU stall issue caused by an
> interruption storm. The serial port driver written by another project team
> failed to write the register in a specific condition. As a result, interrupts
> were repeatedly reported.

Very good!

> > half-way point would have been reached while all online CPUs were spinning
> > with interrupts disabled and the incoming CPU was getting hammered with
> > continual scheduling-clock interrupts. So I suspect that the answer is
> > "no" because the incoming CPU was not blocking the grace period.
> >
> > Instead of being snapshot halfway to the RCU CPU stall warning, should
> > the values be snapshot when the CPU notices the beginning or end of an
> > RCU grace period and when a CPU goes offline?
>
> This won't work. Those normal counts that occurred before the failure
> have an impact on our analysis. For example, some software interrupts
> may have been generated before local_bh_disable() is called.

Fair enough, and thank you for considering this option. But please be
prepared to adjust (somehow or another) as needed to accommodate other
failure scenarios as they arise.

Thanx, Paul

> > But that would not suffice, because detailed information would not have
> > been dumped for the incoming CPU.
> >
> > However, the lack of context switches and interrupts on the rest of the
> > CPUs would likely have been a big cluebat, so there is that. It might
> > be better to rework the warning at the beginning of rcu_sched_clock_irq()
> > to complain if more than (say) 10 scheduling-clock interrupts occur on
> > a given CPU during a single jiffy.
> >
> > Independent of Zhen Lei patch.
> >
> > Thoughts?
> >
> > Thanx, Paul
> >
> >> Thanks.
> >>
> >>
> >>>
> >>> Thoughts?
> >>>
> >>> Thanx, Paul
> >>>
> >>>> Thanks.
> >>>>
> >>>>>
> >>>>> Zhen Lei (2):
> >>>>> rcu: Add RCU stall diagnosis information
> >>>>> doc: Document CONFIG_RCU_CPU_STALL_CPUTIME=y stall information
> >>>>>
> >>>>> Documentation/RCU/stallwarn.rst | 88 +++++++++++++++++++
> >>>>> .../admin-guide/kernel-parameters.txt | 6 ++
> >>>>> kernel/rcu/Kconfig.debug | 11 +++
> >>>>> kernel/rcu/rcu.h | 1 +
> >>>>> kernel/rcu/tree.c | 17 ++++
> >>>>> kernel/rcu/tree.h | 19 ++++
> >>>>> kernel/rcu/tree_stall.h | 29 ++++++
> >>>>> kernel/rcu/update.c | 2 +
> >>>>> 8 files changed, 173 insertions(+)
> >>>>>
> >>>>> --
> >>>>> 2.25.1
> >>>>>
> > .
> >
>
> --
> Regards,
> Zhen Lei