On Wed, Nov 09, 2022 at 04:46:01PM +0800, Leizhen (ThunderTown) wrote: > > > On 2022/11/9 10:09, Leizhen (ThunderTown) wrote: > > > > > > On 2022/11/9 4:46, Paul E. McKenney wrote: > >> On Mon, Nov 07, 2022 at 11:29:35PM +0800, Zhen Lei wrote: > >>> Describes how to quickly determine the RCU stall fault type based on the > >>> extra output information during CONFIG_RCU_CPU_STALL_CPUTIME=y. > >>> > >>> Signed-off-by: Zhen Lei <thunder.leizhen@xxxxxxxxxx> > >> > >> Hearing no objections, I queued the following for further review. > >> > >> This commit might of course need to change based on your ongoing > >> discussion with Robert. I that case, please feel free to send me a > >> replacment patch or to send me an incremental patch that I can fold into > >> this patch. Either way works. > > > > I'll issue incremental patches on the basis of your adjustment! This will > > make it clearer and save your time in reviewing. > > I found that Patch 4/4 had one line of description that needed to be changed, > so I had to switch to method 1. Sounds good! I will drop what I have (five patches) and take the next series with Frederic's feedback addressed. Thanx, Paul > > Thanks for your help. I really admire your verbal skills. Your improved > > description is much better than mine. > > > >> > >> Thanx, Paul > >> > >> ------------------------------------------------------------------------ > >> > >> commit b05c2a06ff8a1267b7e8dc812e3944119535d6b6 > >> Author: Zhen Lei <thunder.leizhen@xxxxxxxxxx> > >> Date: Mon Nov 7 23:29:35 2022 +0800 > >> > >> doc: Document CONFIG_RCU_CPU_STALL_CPUTIME=y stall information > >> > >> This commit doucments how to quickly determine the bug causing a given > >> RCU CPU stall fault warning based on the output information provided > >> by CONFIG_RCU_CPU_STALL_CPUTIME=y. > >> > >> [ paulmck: Apply wordsmithing. ] > >> > >> Signed-off-by: Zhen Lei <thunder.leizhen@xxxxxxxxxx> > >> Signed-off-by: Paul E. McKenney <paulmck@xxxxxxxxxx> > >> > >> diff --git a/Documentation/RCU/stallwarn.rst b/Documentation/RCU/stallwarn.rst > >> index dfa4db8c0931e..bd8cf6c640984 100644 > >> --- a/Documentation/RCU/stallwarn.rst > >> +++ b/Documentation/RCU/stallwarn.rst > >> @@ -390,3 +390,82 @@ for example, "P3421". > >> > >> It is entirely possible to see stall warnings from normal and from > >> expedited grace periods at about the same time during the same run. > >> + > >> +RCU_CPU_STALL_CPUTIME > >> +===================== > >> + > >> +In kernels built with CONFIG_RCU_CPU_STALL_CPUTIME=y or booted with > >> +rcupdate.rcu_cpu_stall_cputime=1, the following additional information > >> +is supplied with each RCU CPU stall warning:: > >> + > >> +rcu: hardirqs softirqs csw/system > >> +rcu: number: 624 45 0 > >> +rcu: cputime: 69 1 2425 ==> 2500(ms) > >> + > >> +These statistics are collected during the second half of the rcu stall > >> +timeout. The values in row "number:" are the number of hard interrupts, > >> +number of soft interrupts, and number of context switches on the stalled > >> +CPU. The first three values in row "cputime:" indicate the CPU time in > >> +milliseconds consumed by hard interrupts, soft interrupts, and tasks > >> +on the stalled CPU. The last number is the measurement interval, again > >> +in milliseconds. Because user-mode tasks normally do not cause RCU CPU > >> +stalls, these tasks are typically kernel tasks, which is why only the > >> +system CPU time are considered. > >> + > >> +The following describes four typical scenarios: > >> + > >> +1. A CPU looping with interrupts disabled.:: > >> + > >> + rcu: hardirqs softirqs csw/system > >> + rcu: number: 0 0 0 > >> + rcu: cputime: 0 0 0 ==> 2500(ms) > >> + > >> + Because interrupts have been disabled throughout the measurement > >> + interval, there are no interrupts and no context switches. > >> + Furthermore, because CPU time consumption was measured using interrupt > >> + handlers, the system CPU consumption is misleadingly measured as zero. > >> + This scenario will normally also have "(0 ticks this GP)" printed on > >> + this CPU's summary line. > >> + > >> +2. A CPU looping with bottom halves disabled. > >> + > >> + This is similar to the previous example, but with non-zero number of > >> + and CPU time consumed by hard interrupts, along with non-zero CPU > >> + time consumed by in-kernel execution.:: > >> + > >> + rcu: hardirqs softirqs csw/system > >> + rcu: number: 624 0 0 > >> + rcu: cputime: 49 0 2446 ==> 2500(ms) > >> + > >> + The fact that there are zero softirqs gives a hint that these were > >> + disabled, perhaps via local_bh_disable(). It is of course possible > >> + that there were no softirqs, perhaps because all events that would > >> + result in softirq execution are confined to other CPUs. In this case, > >> + the diagnosis should continue as shown in the next example. > >> + > >> +3. A CPU looping with preemption disabled. > >> + > >> + Here, only the number of context switches is zero.:: > >> + > >> + rcu: hardirqs softirqs csw/system > >> + rcu: number: 624 45 0 > >> + rcu: cputime: 69 1 2425 ==> 2500(ms) > >> + > >> + This situation hints that the stalled CPU was looping with preemption > >> + disabled. > >> + > >> +4. No looping, but massive hard and soft interrupts.:: > >> + > >> + rcu: hardirqs softirqs csw/system > >> + rcu: number: xx xx 0 > >> + rcu: cputime: xx xx 0 ==> 2500(ms) > >> + > >> + Here, the number and CPU time of hard interrupts are all non-zero, > >> + but the number of context switches and the in-kernel CPU time consumed > >> + are zero. The number and cputime of soft interrupts will usually be > >> + non-zero, but could be zero, for example, if the CPU was spinning > >> + within a single hard interrupt handler. > >> + > >> + If this type of RCU CPU stall warning can be reproduced, you can > >> + narrow it down by looking at /proc/interrupts or by writing code to > >> + trace each interrupt, for example, by referring to show_interrupts(). > >> . > >> > > > > -- > Regards, > Zhen Lei
