* [PATCH 0/3] rcu: Add RCU stall diagnosis information
@ 2022-10-17 10:01 Zhen Lei
2022-10-17 10:01 ` [PATCH 1/3] sched: Add helper kstat_cpu_softirqs_sum() Zhen Lei
` (3 more replies)
0 siblings, 4 replies; 8+ messages in thread
From: Zhen Lei @ 2022-10-17 10:01 UTC (permalink / raw)
To: Paul E . McKenney, Frederic Weisbecker, Neeraj Upadhyay,
Josh Triplett, Steven Rostedt, Mathieu Desnoyers, Lai Jiangshan,
Joel Fernandes, rcu, linux-kernel
Cc: Zhen Lei
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.
Zhen Lei (3):
sched: Add helper kstat_cpu_softirqs_sum()
sched: Add helper nr_context_switches_cpu()
rcu: Add RCU stall diagnosis information
include/linux/kernel_stat.h | 12 +++++++++++
kernel/rcu/tree.h | 11 ++++++++++
kernel/rcu/tree_stall.h | 40 +++++++++++++++++++++++++++++++++++++
kernel/sched/core.c | 5 +++++
4 files changed, 68 insertions(+)
--
2.25.1
^ permalink raw reply [flat|nested] 8+ messages in thread* [PATCH 1/3] sched: Add helper kstat_cpu_softirqs_sum() 2022-10-17 10:01 [PATCH 0/3] rcu: Add RCU stall diagnosis information Zhen Lei @ 2022-10-17 10:01 ` Zhen Lei 2022-10-17 10:01 ` [PATCH 2/3] sched: Add helper nr_context_switches_cpu() Zhen Lei ` (2 subsequent siblings) 3 siblings, 0 replies; 8+ messages in thread From: Zhen Lei @ 2022-10-17 10:01 UTC (permalink / raw) To: Paul E . McKenney, Frederic Weisbecker, Neeraj Upadhyay, Josh Triplett, Steven Rostedt, Mathieu Desnoyers, Lai Jiangshan, Joel Fernandes, rcu, linux-kernel Cc: Zhen Lei Similar to kstat_cpu_irqs_sum(), it counts the sum of all software interrupts on a specified CPU. Signed-off-by: Zhen Lei <thunder.leizhen@huawei.com> --- include/linux/kernel_stat.h | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/include/linux/kernel_stat.h b/include/linux/kernel_stat.h index ddb5a358fd829f4..61d427c1962bf1c 100644 --- a/include/linux/kernel_stat.h +++ b/include/linux/kernel_stat.h @@ -67,6 +67,17 @@ static inline unsigned int kstat_softirqs_cpu(unsigned int irq, int cpu) return kstat_cpu(cpu).softirqs[irq]; } +static inline unsigned int kstat_cpu_softirqs_sum(int cpu) +{ + int i; + unsigned int sum = 0; + + for (i = 0; i < NR_SOFTIRQS; i++) + sum += kstat_softirqs_cpu(i, cpu); + + return sum; +} + /* * Number of interrupts per specific IRQ source, since bootup */ -- 2.25.1 ^ permalink raw reply related [flat|nested] 8+ messages in thread
* [PATCH 2/3] sched: Add helper nr_context_switches_cpu() 2022-10-17 10:01 [PATCH 0/3] rcu: Add RCU stall diagnosis information Zhen Lei 2022-10-17 10:01 ` [PATCH 1/3] sched: Add helper kstat_cpu_softirqs_sum() Zhen Lei @ 2022-10-17 10:01 ` Zhen Lei 2022-10-17 10:01 ` [PATCH 3/3] rcu: Add RCU stall diagnosis information Zhen Lei 2022-10-20 23:13 ` [PATCH 0/3] " Paul E. McKenney 3 siblings, 0 replies; 8+ messages in thread From: Zhen Lei @ 2022-10-17 10:01 UTC (permalink / raw) To: Paul E . McKenney, Frederic Weisbecker, Neeraj Upadhyay, Josh Triplett, Steven Rostedt, Mathieu Desnoyers, Lai Jiangshan, Joel Fernandes, rcu, linux-kernel Cc: Zhen Lei Returns the number of context switches on the specified CPU, which can be used to diagnose rcu stall. Signed-off-by: Zhen Lei <thunder.leizhen@huawei.com> --- include/linux/kernel_stat.h | 1 + kernel/sched/core.c | 5 +++++ 2 files changed, 6 insertions(+) diff --git a/include/linux/kernel_stat.h b/include/linux/kernel_stat.h index 61d427c1962bf1c..ac4f9302b559c9d 100644 --- a/include/linux/kernel_stat.h +++ b/include/linux/kernel_stat.h @@ -52,6 +52,7 @@ DECLARE_PER_CPU(struct kernel_cpustat, kernel_cpustat); #define kstat_cpu(cpu) per_cpu(kstat, cpu) #define kcpustat_cpu(cpu) per_cpu(kernel_cpustat, cpu) +extern unsigned long long nr_context_switches_cpu(int cpu); extern unsigned long long nr_context_switches(void); extern unsigned int kstat_irqs_cpu(unsigned int irq, int cpu); diff --git a/kernel/sched/core.c b/kernel/sched/core.c index 5800b0623ff3068..a0d19f67f2046d9 100644 --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @@ -5229,6 +5229,11 @@ bool single_task_running(void) } EXPORT_SYMBOL(single_task_running); +unsigned long long nr_context_switches_cpu(int cpu) +{ + return cpu_rq(cpu)->nr_switches; +} + unsigned long long nr_context_switches(void) { int i; -- 2.25.1 ^ permalink raw reply related [flat|nested] 8+ messages in thread
* [PATCH 3/3] rcu: Add RCU stall diagnosis information 2022-10-17 10:01 [PATCH 0/3] rcu: Add RCU stall diagnosis information Zhen Lei 2022-10-17 10:01 ` [PATCH 1/3] sched: Add helper kstat_cpu_softirqs_sum() Zhen Lei 2022-10-17 10:01 ` [PATCH 2/3] sched: Add helper nr_context_switches_cpu() Zhen Lei @ 2022-10-17 10:01 ` Zhen Lei 2022-10-20 23:13 ` [PATCH 0/3] " Paul E. McKenney 3 siblings, 0 replies; 8+ messages in thread From: Zhen Lei @ 2022-10-17 10:01 UTC (permalink / raw) To: Paul E . McKenney, Frederic Weisbecker, Neeraj Upadhyay, Josh Triplett, Steven Rostedt, Mathieu Desnoyers, Lai Jiangshan, Joel Fernandes, rcu, linux-kernel Cc: Zhen Lei 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. For example: rcu: INFO: rcu_preempt self-detected stall on CPU rcu: 0-....: (1250 ticks this GP) <omitted> rcu: hardirqs softirqs csw/system rcu: number: 624 45 0 rcu: cputime: 69 1 2425 ==> 2500(ms) The example above shows that the number of hard and soft interrupts is small, there is zero context switching, and the system takes up a lot of time. We can quickly conclude that the current task is infinitely looped with preempt_disable(). The impact on system performance is negligible because snapshot is recorded only one time after 1/2 CPU stall timeout. Signed-off-by: Zhen Lei <thunder.leizhen@huawei.com> --- kernel/rcu/tree.h | 11 +++++++++++ kernel/rcu/tree_stall.h | 40 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 51 insertions(+) diff --git a/kernel/rcu/tree.h b/kernel/rcu/tree.h index d4a97e40ea9c3e2..fb3121d15cca6f8 100644 --- a/kernel/rcu/tree.h +++ b/kernel/rcu/tree.h @@ -158,6 +158,16 @@ union rcu_noqs { u16 s; /* Set of bits, aggregate OR here. */ }; +struct rcu_snap_record { + unsigned long gp_seq; + u64 cputime_irq; + u64 cputime_softirq; + u64 cputime_system; + unsigned int nr_hardirqs; + unsigned int nr_softirqs; + unsigned long long nr_csw; +}; + /* Per-CPU data for read-copy update. */ struct rcu_data { /* 1) quiescent-state and grace-period handling : */ @@ -262,6 +272,7 @@ struct rcu_data { short rcu_onl_gp_flags; /* ->gp_flags at last online. */ unsigned long last_fqs_resched; /* Time of last rcu_resched(). */ unsigned long last_sched_clock; /* Jiffies of last rcu_sched_clock_irq(). */ + struct rcu_snap_record snap_record; int cpu; }; diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h index 5653560573e22d6..08cfcf526f7d245 100644 --- a/kernel/rcu/tree_stall.h +++ b/kernel/rcu/tree_stall.h @@ -211,8 +211,10 @@ static void rcu_stall_kick_kthreads(void) */ static void rcu_iw_handler(struct irq_work *iwp) { + int cpu = smp_processor_id(); struct rcu_data *rdp; struct rcu_node *rnp; + struct rcu_snap_record *r; rdp = container_of(iwp, struct rcu_data, rcu_iw); rnp = rdp->mynode; @@ -222,6 +224,16 @@ static void rcu_iw_handler(struct irq_work *iwp) rdp->rcu_iw_pending = false; } raw_spin_unlock_rcu_node(rnp); + + r = &rdp->snap_record; + r->cputime_irq = kcpustat_this_cpu->cpustat[CPUTIME_IRQ]; + r->cputime_softirq = kcpustat_this_cpu->cpustat[CPUTIME_SOFTIRQ]; + r->cputime_system = kcpustat_this_cpu->cpustat[CPUTIME_SYSTEM]; + r->nr_hardirqs = kstat_cpu_irqs_sum(cpu); + r->nr_softirqs = kstat_cpu_softirqs_sum(cpu); + r->nr_csw = nr_context_switches_cpu(cpu); + barrier(); + r->gp_seq = rdp->gp_seq; } ////////////////////////////////////////////////////////////////////////////// @@ -428,6 +440,32 @@ static bool rcu_is_rcuc_kthread_starving(struct rcu_data *rdp, unsigned long *jp return j > 2 * HZ; } +static void print_cpu_stat_info(int cpu) +{ + u64 *cpustat; + unsigned long half_timeout; + struct rcu_snap_record *r; + struct rcu_data *rdp = per_cpu_ptr(&rcu_data, cpu); + + r = &rdp->snap_record; + if (r->gp_seq != rdp->gp_seq) + return; + + cpustat = kcpustat_this_cpu->cpustat; + half_timeout = rcu_jiffies_till_stall_check() / 2; + + pr_err(" hardirqs softirqs csw/system\n"); + pr_err(" number: %8d %10d %12lld\n", + kstat_cpu_irqs_sum(cpu) - r->nr_hardirqs, + kstat_cpu_softirqs_sum(cpu) - r->nr_softirqs, + nr_context_switches_cpu(cpu) - r->nr_csw); + pr_err("cputime: %8lld %10lld %12lld ==> %lld(ms)\n", + div_u64(cpustat[CPUTIME_IRQ] - r->cputime_irq, NSEC_PER_MSEC), + div_u64(cpustat[CPUTIME_SOFTIRQ] - r->cputime_softirq, NSEC_PER_MSEC), + div_u64(cpustat[CPUTIME_SYSTEM] - r->cputime_system, NSEC_PER_MSEC), + jiffies64_to_msecs(half_timeout)); +} + /* * Print out diagnostic information for the specified stalled CPU. * @@ -484,6 +522,8 @@ static void print_cpu_stall_info(int cpu) data_race(rcu_state.n_force_qs) - rcu_state.n_force_qs_gpstart, rcuc_starved ? buf : "", falsepositive ? " (false positive?)" : ""); + + print_cpu_stat_info(cpu); } /* Complain about starvation of grace-period kthread. */ -- 2.25.1 ^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [PATCH 0/3] rcu: Add RCU stall diagnosis information 2022-10-17 10:01 [PATCH 0/3] rcu: Add RCU stall diagnosis information Zhen Lei ` (2 preceding siblings ...) 2022-10-17 10:01 ` [PATCH 3/3] rcu: Add RCU stall diagnosis information Zhen Lei @ 2022-10-20 23:13 ` Paul E. McKenney 2022-10-21 8:07 ` Leizhen (ThunderTown) 3 siblings, 1 reply; 8+ messages in thread From: Paul E. McKenney @ 2022-10-20 23:13 UTC (permalink / raw) To: Zhen Lei Cc: Frederic Weisbecker, Neeraj Upadhyay, Josh Triplett, Steven Rostedt, Mathieu Desnoyers, Lai Jiangshan, Joel Fernandes, rcu, linux-kernel On Mon, Oct 17, 2022 at 06:01:05PM +0800, Zhen Lei wrote: > 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. > > Zhen Lei (3): > sched: Add helper kstat_cpu_softirqs_sum() > sched: Add helper nr_context_switches_cpu() > rcu: Add RCU stall diagnosis information Interesting approach, thank you! I have pulled this in for testing and review, having rescued it from my spam folder. Some questions that might come up include: (1) Can the addition of things like cond_resched() make RCU happier with the I/O pressure test? (2) Should there be a way to turn this off for environments with slow consoles? (3) If this information shows heavy CPU usage, what debug and fix approach should be used? For an example of #1, if a CPU is flooded with softirq activity, one might hope that the call to rcu_softirq_qs() would prevent the RCU CPU stall warning, at least for kernels built with CONFIG_PREEMPT_RT=n. Similarly, if there are huge numbers of context switches, one might hope that the rcu_note_context_switch() would report a quiescent state sooner rather than later. Thoughts? Thanx, Paul > include/linux/kernel_stat.h | 12 +++++++++++ > kernel/rcu/tree.h | 11 ++++++++++ > kernel/rcu/tree_stall.h | 40 +++++++++++++++++++++++++++++++++++++ > kernel/sched/core.c | 5 +++++ > 4 files changed, 68 insertions(+) > > -- > 2.25.1 > ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH 0/3] rcu: Add RCU stall diagnosis information 2022-10-20 23:13 ` [PATCH 0/3] " Paul E. McKenney @ 2022-10-21 8:07 ` Leizhen (ThunderTown) 2022-10-21 19:15 ` Paul E. McKenney 0 siblings, 1 reply; 8+ messages in thread From: Leizhen (ThunderTown) @ 2022-10-21 8:07 UTC (permalink / raw) To: paulmck Cc: Frederic Weisbecker, Neeraj Upadhyay, Josh Triplett, Steven Rostedt, Mathieu Desnoyers, Lai Jiangshan, Joel Fernandes, rcu, linux-kernel On 2022/10/21 7:13, Paul E. McKenney wrote: > On Mon, Oct 17, 2022 at 06:01:05PM +0800, Zhen Lei wrote: >> 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. >> >> Zhen Lei (3): >> sched: Add helper kstat_cpu_softirqs_sum() >> sched: Add helper nr_context_switches_cpu() >> rcu: Add RCU stall diagnosis information > > Interesting approach, thank you! > > I have pulled this in for testing and review, having rescued it from my > spam folder. Thanks. My company's mail system has been having some problems lately. Also, I need to apologize that yesterday I found out there was a mistake in patch 3/3. Yesterday, I finally got to print_other_cpu_stall() by forcing a stub. diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h index 08cfcf526f7d245..caaee5f4ee091df 100644 --- a/kernel/rcu/tree_stall.h +++ b/kernel/rcu/tree_stall.h @@ -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; half_timeout = rcu_jiffies_till_stall_check() / 2; pr_err(" hardirqs softirqs csw/system\n"); > > Some questions that might come up include: (1) Can the addition of > things like cond_resched() make RCU happier with the I/O pressure test? > (2) Should there be a way to turn this off for environments with slow > consoles? (3) If this information shows heavy CPU usage, what debug > and fix approach should be used? If the CPU usage is high due to busy services, I think it is excusable to report RCU stall warning. When users see RCU stall, they are most worried about whether there are unrecoverable errors, such as dead loop. If the cause is known to be the CPU usage, the I/O performance has reached its peak, this is probably what people want to see. (1) This needs to be considered by the business task itself. As far as I know some drivers' data processing is done in an interrupt context. (2) Do you mean to suppress such new debugging information that I added? or the whole RCU stall information? (3) The statistics can be accurate to a single hard interrupt, software interrupt, or task. However, the price will be higher. Users can recall what they did at the time, then reproduce it. Maybe we can get this code ready, add a new debugging option, and turn it on when needed. > > For an example of #1, if a CPU is flooded with softirq activity, one > might hope that the call to rcu_softirq_qs() would prevent the RCU CPU > stall warning, at least for kernels built with CONFIG_PREEMPT_RT=n. > Similarly, if there are huge numbers of context switches, one might hope > that the rcu_note_context_switch() would report a quiescent state sooner > rather than later. Good idea. I'm going to dig deeper. How about dynamically extending the stall timeout if the CPU usage is too high? > > Thoughts? > > Thanx, Paul > >> include/linux/kernel_stat.h | 12 +++++++++++ >> kernel/rcu/tree.h | 11 ++++++++++ >> kernel/rcu/tree_stall.h | 40 +++++++++++++++++++++++++++++++++++++ >> kernel/sched/core.c | 5 +++++ >> 4 files changed, 68 insertions(+) >> >> -- >> 2.25.1 >> > . > -- Regards, Zhen Lei ^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [PATCH 0/3] rcu: Add RCU stall diagnosis information 2022-10-21 8:07 ` Leizhen (ThunderTown) @ 2022-10-21 19:15 ` Paul E. McKenney 2022-10-24 9:23 ` Leizhen (ThunderTown) 0 siblings, 1 reply; 8+ messages in thread From: Paul E. McKenney @ 2022-10-21 19:15 UTC (permalink / raw) To: Leizhen (ThunderTown) Cc: Frederic Weisbecker, Neeraj Upadhyay, Josh Triplett, Steven Rostedt, Mathieu Desnoyers, Lai Jiangshan, Joel Fernandes, rcu, linux-kernel On Fri, Oct 21, 2022 at 04:07:43PM +0800, Leizhen (ThunderTown) wrote: > > > On 2022/10/21 7:13, Paul E. McKenney wrote: > > On Mon, Oct 17, 2022 at 06:01:05PM +0800, Zhen Lei wrote: > >> 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. > >> > >> Zhen Lei (3): > >> sched: Add helper kstat_cpu_softirqs_sum() > >> sched: Add helper nr_context_switches_cpu() > >> rcu: Add RCU stall diagnosis information > > > > Interesting approach, thank you! > > > > I have pulled this in for testing and review, having rescued it from my > > spam folder. > > Thanks. My company's mail system has been having some problems lately. > > Also, I need to apologize that yesterday I found out there was a mistake > in patch 3/3. Yesterday, I finally got to print_other_cpu_stall() by forcing > a stub. OK, I done dropped your three patches for the time being. Please feel free to submit v2 whenever you are ready to do so. > diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h > index 08cfcf526f7d245..caaee5f4ee091df 100644 > --- a/kernel/rcu/tree_stall.h > +++ b/kernel/rcu/tree_stall.h > @@ -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; > half_timeout = rcu_jiffies_till_stall_check() / 2; > > pr_err(" hardirqs softirqs csw/system\n"); > > > > > Some questions that might come up include: (1) Can the addition of > > things like cond_resched() make RCU happier with the I/O pressure test? > > (2) Should there be a way to turn this off for environments with slow > > consoles? (3) If this information shows heavy CPU usage, what debug > > and fix approach should be used? > > If the CPU usage is high due to busy services, I think it is excusable > to report RCU stall warning. Not so much. RCU CPU stall warning usually means that there is some overly long loop in the kernel. > When users see RCU stall, they are most > worried about whether there are unrecoverable errors, such as dead loop. > If the cause is known to be the CPU usage, the I/O performance has > reached its peak, this is probably what people want to see. You have a workload that can be carried out entirely in interrupt handlers? If not, the kernel code really should be updated to avoid the RCU CPU stall warnings. > (1) This needs to be considered by the business task itself. As far as I > know some drivers' data processing is done in an interrupt context. You are seeing an entire CPU being consumed by interrupt handlers? If so, is the CPU being carefully placed in the idle loop beforehand? If not, how do you keep the long delays in the interrupted processing from causing problems? > (2) Do you mean to suppress such new debugging information that I added? > or the whole RCU stall information? Only the new debugging information. I already get complaints about RCU CPU stall warnings producing more output than people like. > (3) The statistics can be accurate to a single hard interrupt, software > interrupt, or task. However, the price will be higher. Users can > recall what they did at the time, then reproduce it. Maybe we can get > this code ready, add a new debugging option, and turn it on when needed. Let me ask this a different way. What combination of numbers would lead you to believe that a given RCU CPU stall warning can safely be ignored? > > For an example of #1, if a CPU is flooded with softirq activity, one > > might hope that the call to rcu_softirq_qs() would prevent the RCU CPU > > stall warning, at least for kernels built with CONFIG_PREEMPT_RT=n. > > Similarly, if there are huge numbers of context switches, one might hope > > that the rcu_note_context_switch() would report a quiescent state sooner > > rather than later. > > Good idea. I'm going to dig deeper. > > How about dynamically extending the stall timeout if the CPU usage is too high? Let's first work out why the RCU CPU stalls are happening. After all, if there is a particular case that is truly harmless, it would be better to arrange that stalls not be printed at all in that case. It is better to just not have false positives, right? Thanx, Paul > > Thoughts? > > > > Thanx, Paul > > > >> include/linux/kernel_stat.h | 12 +++++++++++ > >> kernel/rcu/tree.h | 11 ++++++++++ > >> kernel/rcu/tree_stall.h | 40 +++++++++++++++++++++++++++++++++++++ > >> kernel/sched/core.c | 5 +++++ > >> 4 files changed, 68 insertions(+) > >> > >> -- > >> 2.25.1 > >> > > . > > > > -- > Regards, > Zhen Lei ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH 0/3] rcu: Add RCU stall diagnosis information 2022-10-21 19:15 ` Paul E. McKenney @ 2022-10-24 9:23 ` Leizhen (ThunderTown) 0 siblings, 0 replies; 8+ messages in thread From: Leizhen (ThunderTown) @ 2022-10-24 9:23 UTC (permalink / raw) To: paulmck Cc: Frederic Weisbecker, Neeraj Upadhyay, Josh Triplett, Steven Rostedt, Mathieu Desnoyers, Lai Jiangshan, Joel Fernandes, rcu, linux-kernel On 2022/10/22 3:15, Paul E. McKenney wrote: > On Fri, Oct 21, 2022 at 04:07:43PM +0800, Leizhen (ThunderTown) wrote: >> >> >> On 2022/10/21 7:13, Paul E. McKenney wrote: >>> On Mon, Oct 17, 2022 at 06:01:05PM +0800, Zhen Lei wrote: >>>> 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. >>>> >>>> Zhen Lei (3): >>>> sched: Add helper kstat_cpu_softirqs_sum() >>>> sched: Add helper nr_context_switches_cpu() >>>> rcu: Add RCU stall diagnosis information >>> >>> Interesting approach, thank you! >>> >>> I have pulled this in for testing and review, having rescued it from my >>> spam folder. >> >> Thanks. My company's mail system has been having some problems lately. >> >> Also, I need to apologize that yesterday I found out there was a mistake >> in patch 3/3. Yesterday, I finally got to print_other_cpu_stall() by forcing >> a stub. > > OK, I done dropped your three patches for the time being. > > Please feel free to submit v2 whenever you are ready to do so. > >> diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h >> index 08cfcf526f7d245..caaee5f4ee091df 100644 >> --- a/kernel/rcu/tree_stall.h >> +++ b/kernel/rcu/tree_stall.h >> @@ -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; >> half_timeout = rcu_jiffies_till_stall_check() / 2; >> >> pr_err(" hardirqs softirqs csw/system\n"); >> >>> >>> Some questions that might come up include: (1) Can the addition of >>> things like cond_resched() make RCU happier with the I/O pressure test? >>> (2) Should there be a way to turn this off for environments with slow >>> consoles? (3) If this information shows heavy CPU usage, what debug >>> and fix approach should be used? >> >> If the CPU usage is high due to busy services, I think it is excusable >> to report RCU stall warning. > > Not so much. RCU CPU stall warning usually means that there is some > overly long loop in the kernel. Yes, so the added statistics are helpful. Low count means long loop may exist. > >> When users see RCU stall, they are most >> worried about whether there are unrecoverable errors, such as dead loop. >> If the cause is known to be the CPU usage, the I/O performance has >> reached its peak, this is probably what people want to see. > > You have a workload that can be carried out entirely in interrupt > handlers? If not, the kernel code really should be updated to avoid > the RCU CPU stall warnings. > >> (1) This needs to be considered by the business task itself. As far as I >> know some drivers' data processing is done in an interrupt context. > > You are seeing an entire CPU being consumed by interrupt handlers? > If so, is the CPU being carefully placed in the idle loop beforehand? > If not, how do you keep the long delays in the interrupted processing > from causing problems? Some chips with poor implementation may respond to interrupts on only a few cores. However, I didn't actually see. After all, these process information, if not specifically recorded, will not be seen again. > >> (2) Do you mean to suppress such new debugging information that I added? >> or the whole RCU stall information? > > Only the new debugging information. I already get complaints about RCU > CPU stall warnings producing more output than people like. OK, I got it. Perhaps we can consider recording the RCU stall information in the buffer and printing the following brief information. Warning: RCU stall id=%d Then, the user-mode process accesses the new added RCU attribute file and queries detailed information based on the ID. Or delay printing until the new GP or panic. > >> (3) The statistics can be accurate to a single hard interrupt, software >> interrupt, or task. However, the price will be higher. Users can >> recall what they did at the time, then reproduce it. Maybe we can get >> this code ready, add a new debugging option, and turn it on when needed. > > Let me ask this a different way. What combination of numbers would lead > you to believe that a given RCU CPU stall warning can safely be ignored? > >>> For an example of #1, if a CPU is flooded with softirq activity, one >>> might hope that the call to rcu_softirq_qs() would prevent the RCU CPU >>> stall warning, at least for kernels built with CONFIG_PREEMPT_RT=n. >>> Similarly, if there are huge numbers of context switches, one might hope >>> that the rcu_note_context_switch() would report a quiescent state sooner >>> rather than later. >> >> Good idea. I'm going to dig deeper. >> >> How about dynamically extending the stall timeout if the CPU usage is too high? > > Let's first work out why the RCU CPU stalls are happening. After all, if OK > there is a particular case that is truly harmless, it would be better to > arrange that stalls not be printed at all in that case. It is better to > just not have false positives, right? Yes. > > Thanx, Paul > >>> Thoughts? >>> >>> Thanx, Paul >>> >>>> include/linux/kernel_stat.h | 12 +++++++++++ >>>> kernel/rcu/tree.h | 11 ++++++++++ >>>> kernel/rcu/tree_stall.h | 40 +++++++++++++++++++++++++++++++++++++ >>>> kernel/sched/core.c | 5 +++++ >>>> 4 files changed, 68 insertions(+) >>>> >>>> -- >>>> 2.25.1 >>>> >>> . >>> >> >> -- >> Regards, >> Zhen Lei > . > -- Regards, Zhen Lei ^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2022-10-24 9:23 UTC | newest] Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2022-10-17 10:01 [PATCH 0/3] rcu: Add RCU stall diagnosis information Zhen Lei 2022-10-17 10:01 ` [PATCH 1/3] sched: Add helper kstat_cpu_softirqs_sum() Zhen Lei 2022-10-17 10:01 ` [PATCH 2/3] sched: Add helper nr_context_switches_cpu() Zhen Lei 2022-10-17 10:01 ` [PATCH 3/3] rcu: Add RCU stall diagnosis information Zhen Lei 2022-10-20 23:13 ` [PATCH 0/3] " Paul E. McKenney 2022-10-21 8:07 ` Leizhen (ThunderTown) 2022-10-21 19:15 ` Paul E. McKenney 2022-10-24 9:23 ` Leizhen (ThunderTown)
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).