All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH v4] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
@ 2022-04-25  1:04 Zqiang
  2022-04-25 15:45 ` Paul E. McKenney
  0 siblings, 1 reply; 6+ messages in thread
From: Zqiang @ 2022-04-25  1:04 UTC (permalink / raw)
  To: paulmck, frederic; +Cc: rcu, linux-kernel

If the rcutree.use_softirq is configured, when RCU Stall event
happened, dump status of all rcuc kthreads who due to starvation
prevented grace period ends on CPUs that not report quiescent
state.

Signed-off-by: Zqiang <qiang1.zhang@intel.com>
---
 v1->v2:
 rework rcuc_kthread_dump function
 v2->v3:
 merge this rcuc-stalled information into print_cpu_stall_info()
 v3->v4:
 print rcuc info only when rcuc kthread is starved

 kernel/rcu/tree_stall.h | 49 ++++++++++++++++++-----------------------
 1 file changed, 21 insertions(+), 28 deletions(-)

diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h
index d7956c03edbd..a3d33c471cbb 100644
--- a/kernel/rcu/tree_stall.h
+++ b/kernel/rcu/tree_stall.h
@@ -407,7 +407,19 @@ static bool rcu_is_gp_kthread_starving(unsigned long *jp)
 
 static bool rcu_is_rcuc_kthread_starving(struct rcu_data *rdp, unsigned long *jp)
 {
-	unsigned long j = jiffies - READ_ONCE(rdp->rcuc_activity);
+	int cpu;
+	struct task_struct *rcuc;
+	unsigned long j;
+
+	rcuc = rdp->rcu_cpu_kthread_task;
+	if (!rcuc)
+		return false;
+
+	cpu = task_cpu(rcuc);
+	if (cpu_is_offline(cpu) || idle_cpu(cpu))
+		return false;
+
+	j = jiffies - READ_ONCE(rdp->rcuc_activity);
 
 	if (jp)
 		*jp = j;
@@ -432,6 +444,9 @@ static void print_cpu_stall_info(int cpu)
 	struct rcu_data *rdp = per_cpu_ptr(&rcu_data, cpu);
 	char *ticks_title;
 	unsigned long ticks_value;
+	bool rcuc_starved;
+	unsigned long j;
+	char buf[32];
 
 	/*
 	 * We could be printing a lot while holding a spinlock.  Avoid
@@ -449,7 +464,10 @@ static void print_cpu_stall_info(int cpu)
 	delta = rcu_seq_ctr(rdp->mynode->gp_seq - rdp->rcu_iw_gp_seq);
 	falsepositive = rcu_is_gp_kthread_starving(NULL) &&
 			rcu_dynticks_in_eqs(rcu_dynticks_snap(rdp));
-	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld %s\n",
+	rcuc_starved = rcu_is_rcuc_kthread_starving(rdp, &j);
+	if (rcuc_starved)
+		sprintf(buf, "rcuc=%ld jiffies(starved)", j);
+	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld %s %s\n",
 	       cpu,
 	       "O."[!!cpu_online(cpu)],
 	       "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)],
@@ -462,32 +480,10 @@ static void print_cpu_stall_info(int cpu)
 	       rdp->dynticks_nesting, rdp->dynticks_nmi_nesting,
 	       rdp->softirq_snap, kstat_softirqs_cpu(RCU_SOFTIRQ, cpu),
 	       data_race(rcu_state.n_force_qs) - rcu_state.n_force_qs_gpstart,
+	       rcuc_starved ? buf : "",
 	       falsepositive ? " (false positive?)" : "");
 }
 
-static void rcuc_kthread_dump(struct rcu_data *rdp)
-{
-	int cpu;
-	unsigned long j;
-	struct task_struct *rcuc;
-
-	rcuc = rdp->rcu_cpu_kthread_task;
-	if (!rcuc)
-		return;
-
-	cpu = task_cpu(rcuc);
-	if (cpu_is_offline(cpu) || idle_cpu(cpu))
-		return;
-
-	if (!rcu_is_rcuc_kthread_starving(rdp, &j))
-		return;
-
-	pr_err("%s kthread starved for %ld jiffies\n", rcuc->comm, j);
-	sched_show_task(rcuc);
-	if (!trigger_single_cpu_backtrace(cpu))
-		dump_cpu_task(cpu);
-}
-
 /* Complain about starvation of grace-period kthread.  */
 static void rcu_check_gp_kthread_starvation(void)
 {
@@ -659,9 +655,6 @@ static void print_cpu_stall(unsigned long gps)
 	rcu_check_gp_kthread_expired_fqs_timer();
 	rcu_check_gp_kthread_starvation();
 
-	if (!use_softirq)
-		rcuc_kthread_dump(rdp);
-
 	rcu_dump_cpu_stacks();
 
 	raw_spin_lock_irqsave_rcu_node(rnp, flags);
-- 
2.25.1


^ permalink raw reply related	[flat|nested] 6+ messages in thread

* Re: [PATCH v4] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
  2022-04-25  1:04 [PATCH v4] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state Zqiang
@ 2022-04-25 15:45 ` Paul E. McKenney
  2022-04-26  6:44   ` Zhang, Qiang1
  0 siblings, 1 reply; 6+ messages in thread
From: Paul E. McKenney @ 2022-04-25 15:45 UTC (permalink / raw)
  To: Zqiang; +Cc: frederic, rcu, linux-kernel

On Mon, Apr 25, 2022 at 09:04:04AM +0800, Zqiang wrote:
> If the rcutree.use_softirq is configured, when RCU Stall event
> happened, dump status of all rcuc kthreads who due to starvation
> prevented grace period ends on CPUs that not report quiescent
> state.
> 
> Signed-off-by: Zqiang <qiang1.zhang@intel.com>
> ---
>  v1->v2:
>  rework rcuc_kthread_dump function
>  v2->v3:
>  merge this rcuc-stalled information into print_cpu_stall_info()
>  v3->v4:
>  print rcuc info only when rcuc kthread is starved
> 
>  kernel/rcu/tree_stall.h | 49 ++++++++++++++++++-----------------------
>  1 file changed, 21 insertions(+), 28 deletions(-)

I have queued this for testing and further review, thank you!

I did the usual wordsmithing, plus I got rid of a couple of space
characters that are extraneous in the common case (one of yours and one
pre-existing instance).

Could you please generate an actual stall of this type?  You might
need to add a delay to the rcuc code, but other than that, please see
the rcutorture blog series [1] and in particular the post on forcing
stall warnings [2].

							Thanx, Paul

[1] https://paulmck.livejournal.com/61432.html
[2] https://paulmck.livejournal.com/58077.html

------------------------------------------------------------------------

commit 66226e2acda8b31b60137b1ae71244df68541a01
Author: Zqiang <qiang1.zhang@intel.com>
Date:   Mon Apr 25 09:04:04 2022 +0800

    rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
    
    If the rcutree.use_softirq kernel boot parameter is disabled, then it is
    possible that a RCU CPU stall is due to the rcuc kthreads being starved of
    CPU time.  There is currently no easy way to infer this from the RCU CPU
    stall warning output.  This commit therefore adds a string of the form "
    rcuc=%ld jiffies(starved)" to a given CPU's output if the corresponding
    rcuc kthread has been starved for more than two seconds.
    
    [ paulmck: Eliminate extraneous space characters. ]
    
    Signed-off-by: Zqiang <qiang1.zhang@intel.com>
    Signed-off-by: Paul E. McKenney <paulmck@kernel.org>

diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h
index d7956c03edbd4..0a25a4ea6eef8 100644
--- a/kernel/rcu/tree_stall.h
+++ b/kernel/rcu/tree_stall.h
@@ -407,7 +407,19 @@ static bool rcu_is_gp_kthread_starving(unsigned long *jp)
 
 static bool rcu_is_rcuc_kthread_starving(struct rcu_data *rdp, unsigned long *jp)
 {
-	unsigned long j = jiffies - READ_ONCE(rdp->rcuc_activity);
+	int cpu;
+	struct task_struct *rcuc;
+	unsigned long j;
+
+	rcuc = rdp->rcu_cpu_kthread_task;
+	if (!rcuc)
+		return false;
+
+	cpu = task_cpu(rcuc);
+	if (cpu_is_offline(cpu) || idle_cpu(cpu))
+		return false;
+
+	j = jiffies - READ_ONCE(rdp->rcuc_activity);
 
 	if (jp)
 		*jp = j;
@@ -432,6 +444,9 @@ static void print_cpu_stall_info(int cpu)
 	struct rcu_data *rdp = per_cpu_ptr(&rcu_data, cpu);
 	char *ticks_title;
 	unsigned long ticks_value;
+	bool rcuc_starved;
+	unsigned long j;
+	char buf[32];
 
 	/*
 	 * We could be printing a lot while holding a spinlock.  Avoid
@@ -449,7 +464,10 @@ static void print_cpu_stall_info(int cpu)
 	delta = rcu_seq_ctr(rdp->mynode->gp_seq - rdp->rcu_iw_gp_seq);
 	falsepositive = rcu_is_gp_kthread_starving(NULL) &&
 			rcu_dynticks_in_eqs(rcu_dynticks_snap(rdp));
-	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld %s\n",
+	rcuc_starved = rcu_is_rcuc_kthread_starving(rdp, &j);
+	if (rcuc_starved)
+		sprintf(buf, " rcuc=%ld jiffies(starved)", j);
+	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld%s%s\n",
 	       cpu,
 	       "O."[!!cpu_online(cpu)],
 	       "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)],
@@ -462,32 +480,10 @@ static void print_cpu_stall_info(int cpu)
 	       rdp->dynticks_nesting, rdp->dynticks_nmi_nesting,
 	       rdp->softirq_snap, kstat_softirqs_cpu(RCU_SOFTIRQ, cpu),
 	       data_race(rcu_state.n_force_qs) - rcu_state.n_force_qs_gpstart,
+	       rcuc_starved ? buf : "",
 	       falsepositive ? " (false positive?)" : "");
 }
 
-static void rcuc_kthread_dump(struct rcu_data *rdp)
-{
-	int cpu;
-	unsigned long j;
-	struct task_struct *rcuc;
-
-	rcuc = rdp->rcu_cpu_kthread_task;
-	if (!rcuc)
-		return;
-
-	cpu = task_cpu(rcuc);
-	if (cpu_is_offline(cpu) || idle_cpu(cpu))
-		return;
-
-	if (!rcu_is_rcuc_kthread_starving(rdp, &j))
-		return;
-
-	pr_err("%s kthread starved for %ld jiffies\n", rcuc->comm, j);
-	sched_show_task(rcuc);
-	if (!trigger_single_cpu_backtrace(cpu))
-		dump_cpu_task(cpu);
-}
-
 /* Complain about starvation of grace-period kthread.  */
 static void rcu_check_gp_kthread_starvation(void)
 {
@@ -659,9 +655,6 @@ static void print_cpu_stall(unsigned long gps)
 	rcu_check_gp_kthread_expired_fqs_timer();
 	rcu_check_gp_kthread_starvation();
 
-	if (!use_softirq)
-		rcuc_kthread_dump(rdp);
-
 	rcu_dump_cpu_stacks();
 
 	raw_spin_lock_irqsave_rcu_node(rnp, flags);

^ permalink raw reply related	[flat|nested] 6+ messages in thread

* RE: [PATCH v4] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
  2022-04-25 15:45 ` Paul E. McKenney
@ 2022-04-26  6:44   ` Zhang, Qiang1
  2022-04-26 13:48     ` Paul E. McKenney
  0 siblings, 1 reply; 6+ messages in thread
From: Zhang, Qiang1 @ 2022-04-26  6:44 UTC (permalink / raw)
  To: paulmck; +Cc: frederic, rcu, linux-kernel


On Mon, Apr 25, 2022 at 09:04:04AM +0800, Zqiang wrote:
> If the rcutree.use_softirq is configured, when RCU Stall event 
> happened, dump status of all rcuc kthreads who due to starvation 
> prevented grace period ends on CPUs that not report quiescent state.
> 
> Signed-off-by: Zqiang <qiang1.zhang@intel.com>
> ---
>  v1->v2:
>  rework rcuc_kthread_dump function
>  v2->v3:
>  merge this rcuc-stalled information into print_cpu_stall_info()
>  v3->v4:
>  print rcuc info only when rcuc kthread is starved
> 
>  kernel/rcu/tree_stall.h | 49 
> ++++++++++++++++++-----------------------
>  1 file changed, 21 insertions(+), 28 deletions(-)

>I have queued this for testing and further review, thank you!
>
>I did the usual wordsmithing, plus I got rid of a couple of space characters that are extraneous in the common case (one of yours and one pre-existing instance).
>
>Could you please generate an actual stall of this type?  You might need to add a delay to the rcuc code, but other than that, please see the rcutorture blog series [1] and in particular the post on forcing stall warnings [2].
>
>							Thanx, Paul
>
>[1] https://paulmck.livejournal.com/61432.html
>[2] https://paulmck.livejournal.com/58077.html

I followed the instructions, add " rcutorture.stall_cpu=22 rcutorture.fwd_progress=0"  and
" rcutree.use_softirq=0"to bootargs, can trigger  RCU CPU stall warning:

root@qemux86-64:/# dmesg
[   37.556435] rcu: INFO: rcu_preempt self-detected stall on CPU
[   37.556437] rcu:     3-....: (1 GPs behind) idle=269/1/0x4000000000000000 softirq=0/0 fqs=5631 rcuc=26004 jiffies(starved)
[   37.556440]  (t=26000 jiffies g=3589 q=35403)
[   37.556441] NMI backtrace for cpu 3
[   37.556442] CPU: 3 PID: 117 Comm: rcu_torture_sta Tainted: G             L    5.17.0-yoctodev-standard #16 7fe7533e7466875b0801ac148f921afcf57d38bc
[   37.556443] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014
[   37.556444] Call Trace:
[   37.556445]  <IRQ>
[   37.556446]  dump_stack_lvl+0x5b/0x82
[   37.556449]  dump_stack+0x10/0x12
[   37.556451]  nmi_cpu_backtrace.cold+0x32/0x8a
[   37.556452]  ? lapic_can_unplug_cpu+0x80/0x80
[   37.556454]  nmi_trigger_cpumask_backtrace+0xce/0xe0
[   37.556456]  arch_trigger_cpumask_backtrace+0x19/0x20
[   37.556458]  rcu_dump_cpu_stacks+0xcd/0x140
[   37.556460]  rcu_sched_clock_irq.cold+0x7a/0x3ba
[   37.556463]  ? debug_smp_processor_id+0x17/0x20
[   37.556466]  update_process_times+0x9b/0xd0
[   37.556467]  tick_sched_handle.isra.0+0x25/0x50
[   37.556469]  tick_sched_timer+0x79/0x90
[   37.556470]  ? tick_sched_do_timer+0x60/0x60
[   37.556471]  __hrtimer_run_queues+0x1d1/0x4c0
[   37.556473]  hrtimer_interrupt+0x114/0x230
[   37.556475]  ? rcu_read_lock_held_common+0x12/0x50
[   37.556489]  __sysvec_apic_timer_interrupt+0xa4/0x280
[   37.556491]  sysvec_apic_timer_interrupt+0x95/0xc0
[   37.556492]  </IRQ>


Thanks
Zqiang

>
------------------------------------------------------------------------

commit 66226e2acda8b31b60137b1ae71244df68541a01
Author: Zqiang <qiang1.zhang@intel.com>
Date:   Mon Apr 25 09:04:04 2022 +0800

    rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
    
    If the rcutree.use_softirq kernel boot parameter is disabled, then it is
    possible that a RCU CPU stall is due to the rcuc kthreads being starved of
    CPU time.  There is currently no easy way to infer this from the RCU CPU
    stall warning output.  This commit therefore adds a string of the form "
    rcuc=%ld jiffies(starved)" to a given CPU's output if the corresponding
    rcuc kthread has been starved for more than two seconds.
    
    [ paulmck: Eliminate extraneous space characters. ]
    
    Signed-off-by: Zqiang <qiang1.zhang@intel.com>
    Signed-off-by: Paul E. McKenney <paulmck@kernel.org>

diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h index d7956c03edbd4..0a25a4ea6eef8 100644
--- a/kernel/rcu/tree_stall.h
+++ b/kernel/rcu/tree_stall.h
@@ -407,7 +407,19 @@ static bool rcu_is_gp_kthread_starving(unsigned long *jp)
 
 static bool rcu_is_rcuc_kthread_starving(struct rcu_data *rdp, unsigned long *jp)  {
-	unsigned long j = jiffies - READ_ONCE(rdp->rcuc_activity);
+	int cpu;
+	struct task_struct *rcuc;
+	unsigned long j;
+
+	rcuc = rdp->rcu_cpu_kthread_task;
+	if (!rcuc)
+		return false;
+
+	cpu = task_cpu(rcuc);
+	if (cpu_is_offline(cpu) || idle_cpu(cpu))
+		return false;
+
+	j = jiffies - READ_ONCE(rdp->rcuc_activity);
 
 	if (jp)
 		*jp = j;
@@ -432,6 +444,9 @@ static void print_cpu_stall_info(int cpu)
 	struct rcu_data *rdp = per_cpu_ptr(&rcu_data, cpu);
 	char *ticks_title;
 	unsigned long ticks_value;
+	bool rcuc_starved;
+	unsigned long j;
+	char buf[32];
 
 	/*
 	 * We could be printing a lot while holding a spinlock.  Avoid @@ -449,7 +464,10 @@ static void print_cpu_stall_info(int cpu)
 	delta = rcu_seq_ctr(rdp->mynode->gp_seq - rdp->rcu_iw_gp_seq);
 	falsepositive = rcu_is_gp_kthread_starving(NULL) &&
 			rcu_dynticks_in_eqs(rcu_dynticks_snap(rdp));
-	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld %s\n",
+	rcuc_starved = rcu_is_rcuc_kthread_starving(rdp, &j);
+	if (rcuc_starved)
+		sprintf(buf, " rcuc=%ld jiffies(starved)", j);
+	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u 
+fqs=%ld%s%s\n",
 	       cpu,
 	       "O."[!!cpu_online(cpu)],
 	       "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)], @@ -462,32 +480,10 @@ static void print_cpu_stall_info(int cpu)
 	       rdp->dynticks_nesting, rdp->dynticks_nmi_nesting,
 	       rdp->softirq_snap, kstat_softirqs_cpu(RCU_SOFTIRQ, cpu),
 	       data_race(rcu_state.n_force_qs) - rcu_state.n_force_qs_gpstart,
+	       rcuc_starved ? buf : "",
 	       falsepositive ? " (false positive?)" : "");  }
 
-static void rcuc_kthread_dump(struct rcu_data *rdp) -{
-	int cpu;
-	unsigned long j;
-	struct task_struct *rcuc;
-
-	rcuc = rdp->rcu_cpu_kthread_task;
-	if (!rcuc)
-		return;
-
-	cpu = task_cpu(rcuc);
-	if (cpu_is_offline(cpu) || idle_cpu(cpu))
-		return;
-
-	if (!rcu_is_rcuc_kthread_starving(rdp, &j))
-		return;
-
-	pr_err("%s kthread starved for %ld jiffies\n", rcuc->comm, j);
-	sched_show_task(rcuc);
-	if (!trigger_single_cpu_backtrace(cpu))
-		dump_cpu_task(cpu);
-}
-
 /* Complain about starvation of grace-period kthread.  */  static void rcu_check_gp_kthread_starvation(void)
 {
@@ -659,9 +655,6 @@ static void print_cpu_stall(unsigned long gps)
 	rcu_check_gp_kthread_expired_fqs_timer();
 	rcu_check_gp_kthread_starvation();
 
-	if (!use_softirq)
-		rcuc_kthread_dump(rdp);
-
 	rcu_dump_cpu_stacks();
 
 	raw_spin_lock_irqsave_rcu_node(rnp, flags);

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [PATCH v4] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
  2022-04-26  6:44   ` Zhang, Qiang1
@ 2022-04-26 13:48     ` Paul E. McKenney
  2022-04-26 14:38       ` Zhang, Qiang1
  0 siblings, 1 reply; 6+ messages in thread
From: Paul E. McKenney @ 2022-04-26 13:48 UTC (permalink / raw)
  To: Zhang, Qiang1; +Cc: frederic, rcu, linux-kernel

On Tue, Apr 26, 2022 at 06:44:46AM +0000, Zhang, Qiang1 wrote:
> 
> On Mon, Apr 25, 2022 at 09:04:04AM +0800, Zqiang wrote:
> > If the rcutree.use_softirq is configured, when RCU Stall event 
> > happened, dump status of all rcuc kthreads who due to starvation 
> > prevented grace period ends on CPUs that not report quiescent state.
> > 
> > Signed-off-by: Zqiang <qiang1.zhang@intel.com>
> > ---
> >  v1->v2:
> >  rework rcuc_kthread_dump function
> >  v2->v3:
> >  merge this rcuc-stalled information into print_cpu_stall_info()
> >  v3->v4:
> >  print rcuc info only when rcuc kthread is starved
> > 
> >  kernel/rcu/tree_stall.h | 49 
> > ++++++++++++++++++-----------------------
> >  1 file changed, 21 insertions(+), 28 deletions(-)
> 
> >I have queued this for testing and further review, thank you!
> >
> >I did the usual wordsmithing, plus I got rid of a couple of space characters that are extraneous in the common case (one of yours and one pre-existing instance).
> >
> >Could you please generate an actual stall of this type?  You might need to add a delay to the rcuc code, but other than that, please see the rcutorture blog series [1] and in particular the post on forcing stall warnings [2].
> >
> >							Thanx, Paul
> >
> >[1] https://paulmck.livejournal.com/61432.html
> >[2] https://paulmck.livejournal.com/58077.html
> 
> I followed the instructions, add " rcutorture.stall_cpu=22 rcutorture.fwd_progress=0"  and
> " rcutree.use_softirq=0"to bootargs, can trigger  RCU CPU stall warning:
> 
> root@qemux86-64:/# dmesg
> [   37.556435] rcu: INFO: rcu_preempt self-detected stall on CPU
> [   37.556437] rcu:     3-....: (1 GPs behind) idle=269/1/0x4000000000000000 softirq=0/0 fqs=5631 rcuc=26004 jiffies(starved)
> [   37.556440]  (t=26000 jiffies g=3589 q=35403)
> [   37.556441] NMI backtrace for cpu 3
> [   37.556442] CPU: 3 PID: 117 Comm: rcu_torture_sta Tainted: G             L    5.17.0-yoctodev-standard #16 7fe7533e7466875b0801ac148f921afcf57d38bc
> [   37.556443] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014
> [   37.556444] Call Trace:
> [   37.556445]  <IRQ>
> [   37.556446]  dump_stack_lvl+0x5b/0x82
> [   37.556449]  dump_stack+0x10/0x12
> [   37.556451]  nmi_cpu_backtrace.cold+0x32/0x8a
> [   37.556452]  ? lapic_can_unplug_cpu+0x80/0x80
> [   37.556454]  nmi_trigger_cpumask_backtrace+0xce/0xe0
> [   37.556456]  arch_trigger_cpumask_backtrace+0x19/0x20
> [   37.556458]  rcu_dump_cpu_stacks+0xcd/0x140
> [   37.556460]  rcu_sched_clock_irq.cold+0x7a/0x3ba
> [   37.556463]  ? debug_smp_processor_id+0x17/0x20
> [   37.556466]  update_process_times+0x9b/0xd0
> [   37.556467]  tick_sched_handle.isra.0+0x25/0x50
> [   37.556469]  tick_sched_timer+0x79/0x90
> [   37.556470]  ? tick_sched_do_timer+0x60/0x60
> [   37.556471]  __hrtimer_run_queues+0x1d1/0x4c0
> [   37.556473]  hrtimer_interrupt+0x114/0x230
> [   37.556475]  ? rcu_read_lock_held_common+0x12/0x50
> [   37.556489]  __sysvec_apic_timer_interrupt+0xa4/0x280
> [   37.556491]  sysvec_apic_timer_interrupt+0x95/0xc0
> [   37.556492]  </IRQ>

Excellent, thank you!!!

Now could you please do the same thing for a use_softirq kernel to
verify that it prints correctly when that message is not supposed
to be shown?

							Thanx, Paul

> Thanks
> Zqiang
> 
> >
> ------------------------------------------------------------------------
> 
> commit 66226e2acda8b31b60137b1ae71244df68541a01
> Author: Zqiang <qiang1.zhang@intel.com>
> Date:   Mon Apr 25 09:04:04 2022 +0800
> 
>     rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
>     
>     If the rcutree.use_softirq kernel boot parameter is disabled, then it is
>     possible that a RCU CPU stall is due to the rcuc kthreads being starved of
>     CPU time.  There is currently no easy way to infer this from the RCU CPU
>     stall warning output.  This commit therefore adds a string of the form "
>     rcuc=%ld jiffies(starved)" to a given CPU's output if the corresponding
>     rcuc kthread has been starved for more than two seconds.
>     
>     [ paulmck: Eliminate extraneous space characters. ]
>     
>     Signed-off-by: Zqiang <qiang1.zhang@intel.com>
>     Signed-off-by: Paul E. McKenney <paulmck@kernel.org>
> 
> diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h index d7956c03edbd4..0a25a4ea6eef8 100644
> --- a/kernel/rcu/tree_stall.h
> +++ b/kernel/rcu/tree_stall.h
> @@ -407,7 +407,19 @@ static bool rcu_is_gp_kthread_starving(unsigned long *jp)
>  
>  static bool rcu_is_rcuc_kthread_starving(struct rcu_data *rdp, unsigned long *jp)  {
> -	unsigned long j = jiffies - READ_ONCE(rdp->rcuc_activity);
> +	int cpu;
> +	struct task_struct *rcuc;
> +	unsigned long j;
> +
> +	rcuc = rdp->rcu_cpu_kthread_task;
> +	if (!rcuc)
> +		return false;
> +
> +	cpu = task_cpu(rcuc);
> +	if (cpu_is_offline(cpu) || idle_cpu(cpu))
> +		return false;
> +
> +	j = jiffies - READ_ONCE(rdp->rcuc_activity);
>  
>  	if (jp)
>  		*jp = j;
> @@ -432,6 +444,9 @@ static void print_cpu_stall_info(int cpu)
>  	struct rcu_data *rdp = per_cpu_ptr(&rcu_data, cpu);
>  	char *ticks_title;
>  	unsigned long ticks_value;
> +	bool rcuc_starved;
> +	unsigned long j;
> +	char buf[32];
>  
>  	/*
>  	 * We could be printing a lot while holding a spinlock.  Avoid @@ -449,7 +464,10 @@ static void print_cpu_stall_info(int cpu)
>  	delta = rcu_seq_ctr(rdp->mynode->gp_seq - rdp->rcu_iw_gp_seq);
>  	falsepositive = rcu_is_gp_kthread_starving(NULL) &&
>  			rcu_dynticks_in_eqs(rcu_dynticks_snap(rdp));
> -	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld %s\n",
> +	rcuc_starved = rcu_is_rcuc_kthread_starving(rdp, &j);
> +	if (rcuc_starved)
> +		sprintf(buf, " rcuc=%ld jiffies(starved)", j);
> +	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u 
> +fqs=%ld%s%s\n",
>  	       cpu,
>  	       "O."[!!cpu_online(cpu)],
>  	       "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)], @@ -462,32 +480,10 @@ static void print_cpu_stall_info(int cpu)
>  	       rdp->dynticks_nesting, rdp->dynticks_nmi_nesting,
>  	       rdp->softirq_snap, kstat_softirqs_cpu(RCU_SOFTIRQ, cpu),
>  	       data_race(rcu_state.n_force_qs) - rcu_state.n_force_qs_gpstart,
> +	       rcuc_starved ? buf : "",
>  	       falsepositive ? " (false positive?)" : "");  }
>  
> -static void rcuc_kthread_dump(struct rcu_data *rdp) -{
> -	int cpu;
> -	unsigned long j;
> -	struct task_struct *rcuc;
> -
> -	rcuc = rdp->rcu_cpu_kthread_task;
> -	if (!rcuc)
> -		return;
> -
> -	cpu = task_cpu(rcuc);
> -	if (cpu_is_offline(cpu) || idle_cpu(cpu))
> -		return;
> -
> -	if (!rcu_is_rcuc_kthread_starving(rdp, &j))
> -		return;
> -
> -	pr_err("%s kthread starved for %ld jiffies\n", rcuc->comm, j);
> -	sched_show_task(rcuc);
> -	if (!trigger_single_cpu_backtrace(cpu))
> -		dump_cpu_task(cpu);
> -}
> -
>  /* Complain about starvation of grace-period kthread.  */  static void rcu_check_gp_kthread_starvation(void)
>  {
> @@ -659,9 +655,6 @@ static void print_cpu_stall(unsigned long gps)
>  	rcu_check_gp_kthread_expired_fqs_timer();
>  	rcu_check_gp_kthread_starvation();
>  
> -	if (!use_softirq)
> -		rcuc_kthread_dump(rdp);
> -
>  	rcu_dump_cpu_stacks();
>  
>  	raw_spin_lock_irqsave_rcu_node(rnp, flags);

^ permalink raw reply	[flat|nested] 6+ messages in thread

* RE: [PATCH v4] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
  2022-04-26 13:48     ` Paul E. McKenney
@ 2022-04-26 14:38       ` Zhang, Qiang1
  2022-04-26 16:15         ` Paul E. McKenney
  0 siblings, 1 reply; 6+ messages in thread
From: Zhang, Qiang1 @ 2022-04-26 14:38 UTC (permalink / raw)
  To: paulmck; +Cc: frederic, rcu, linux-kernel


On Tue, Apr 26, 2022 at 06:44:46AM +0000, Zhang, Qiang1 wrote:
> 
> On Mon, Apr 25, 2022 at 09:04:04AM +0800, Zqiang wrote:
> > If the rcutree.use_softirq is configured, when RCU Stall event 
> > happened, dump status of all rcuc kthreads who due to starvation 
> > prevented grace period ends on CPUs that not report quiescent state.
> > 
> > Signed-off-by: Zqiang <qiang1.zhang@intel.com>
> > ---
> >  v1->v2:
> >  rework rcuc_kthread_dump function
> >  v2->v3:
> >  merge this rcuc-stalled information into print_cpu_stall_info()
> >  v3->v4:
> >  print rcuc info only when rcuc kthread is starved
> > 
> >  kernel/rcu/tree_stall.h | 49
> > ++++++++++++++++++-----------------------
> >  1 file changed, 21 insertions(+), 28 deletions(-)
> 
> >I have queued this for testing and further review, thank you!
> >
> >I did the usual wordsmithing, plus I got rid of a couple of space characters that are extraneous in the common case (one of yours and one pre-existing instance).
> >
> >Could you please generate an actual stall of this type?  You might need to add a delay to the rcuc code, but other than that, please see the rcutorture blog series [1] and in particular the post on forcing stall warnings [2].
> >
> >							Thanx, Paul
> >
> >[1] https://paulmck.livejournal.com/61432.html
> >[2] https://paulmck.livejournal.com/58077.html
> 
> I followed the instructions, add " rcutorture.stall_cpu=22 
> rcutorture.fwd_progress=0"  and " rcutree.use_softirq=0"to bootargs, can trigger  RCU CPU stall warning:
> 
> root@qemux86-64:/# dmesg
> [   37.556435] rcu: INFO: rcu_preempt self-detected stall on CPU
> [   37.556437] rcu:     3-....: (1 GPs behind) idle=269/1/0x4000000000000000 softirq=0/0 fqs=5631 rcuc=26004 jiffies(starved)
> [   37.556440]  (t=26000 jiffies g=3589 q=35403)
> [   37.556441] NMI backtrace for cpu 3
> [   37.556442] CPU: 3 PID: 117 Comm: rcu_torture_sta Tainted: G             L    5.17.0-yoctodev-standard #16 7fe7533e7466875b0801ac148f921afcf57d38bc
> [   37.556443] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014
> [   37.556444] Call Trace:
> [   37.556445]  <IRQ>
> [   37.556446]  dump_stack_lvl+0x5b/0x82
> [   37.556449]  dump_stack+0x10/0x12
> [   37.556451]  nmi_cpu_backtrace.cold+0x32/0x8a
> [   37.556452]  ? lapic_can_unplug_cpu+0x80/0x80
> [   37.556454]  nmi_trigger_cpumask_backtrace+0xce/0xe0
> [   37.556456]  arch_trigger_cpumask_backtrace+0x19/0x20
> [   37.556458]  rcu_dump_cpu_stacks+0xcd/0x140
> [   37.556460]  rcu_sched_clock_irq.cold+0x7a/0x3ba
> [   37.556463]  ? debug_smp_processor_id+0x17/0x20
> [   37.556466]  update_process_times+0x9b/0xd0
> [   37.556467]  tick_sched_handle.isra.0+0x25/0x50
> [   37.556469]  tick_sched_timer+0x79/0x90
> [   37.556470]  ? tick_sched_do_timer+0x60/0x60
> [   37.556471]  __hrtimer_run_queues+0x1d1/0x4c0
> [   37.556473]  hrtimer_interrupt+0x114/0x230
> [   37.556475]  ? rcu_read_lock_held_common+0x12/0x50
> [   37.556489]  __sysvec_apic_timer_interrupt+0xa4/0x280
> [   37.556491]  sysvec_apic_timer_interrupt+0x95/0xc0
> [   37.556492]  </IRQ>

>Excellent, thank you!!!
>
>Now could you please do the same thing for a use_softirq kernel to verify that it prints correctly when that message is not supposed to be shown?

The use_softirq is not set zero, log follow:

rcu: INFO: rcu_preempt self-detected stall on CPU	
[   32.388910] rcu:     3-....: (20847 ticks this GP) idle=733/1/0x4000000000000000 softirq=4565/4565 fqs=4655
[   32.388913]  (t=21000 jiffies g=8113 q=12547)
[   32.388914] NMI backtrace for cpu 3
[   32.388914] CPU: 3 PID: 73 Comm: rcu_torture_sta Tainted: G             L    5.17.0-yoctodev-standard #2 05f26dfea00beb93d9714ba8d61bb77646676403
[   32.388915] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014
[   32.388916] Call Trace:
[   32.388916]  <IRQ>
[   32.388917]  dump_stack_lvl+0x5b/0x82

Thanks
Zqiang

>
>							Thanx, Paul

> Thanks
> Zqiang
> 
> >
> ----------------------------------------------------------------------
> --
> 
> commit 66226e2acda8b31b60137b1ae71244df68541a01
> Author: Zqiang <qiang1.zhang@intel.com>
> Date:   Mon Apr 25 09:04:04 2022 +0800
> 
>     rcu: Dump all rcuc kthreads status for CPUs that not report 
> quiescent state
>     
>     If the rcutree.use_softirq kernel boot parameter is disabled, then it is
>     possible that a RCU CPU stall is due to the rcuc kthreads being starved of
>     CPU time.  There is currently no easy way to infer this from the RCU CPU
>     stall warning output.  This commit therefore adds a string of the form "
>     rcuc=%ld jiffies(starved)" to a given CPU's output if the corresponding
>     rcuc kthread has been starved for more than two seconds.
>     
>     [ paulmck: Eliminate extraneous space characters. ]
>     
>     Signed-off-by: Zqiang <qiang1.zhang@intel.com>
>     Signed-off-by: Paul E. McKenney <paulmck@kernel.org>
> 
> diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h index 
> d7956c03edbd4..0a25a4ea6eef8 100644
> --- a/kernel/rcu/tree_stall.h
> +++ b/kernel/rcu/tree_stall.h
> @@ -407,7 +407,19 @@ static bool rcu_is_gp_kthread_starving(unsigned 
> long *jp)
>  
>  static bool rcu_is_rcuc_kthread_starving(struct rcu_data *rdp, unsigned long *jp)  {
> -	unsigned long j = jiffies - READ_ONCE(rdp->rcuc_activity);
> +	int cpu;
> +	struct task_struct *rcuc;
> +	unsigned long j;
> +
> +	rcuc = rdp->rcu_cpu_kthread_task;
> +	if (!rcuc)
> +		return false;
> +
> +	cpu = task_cpu(rcuc);
> +	if (cpu_is_offline(cpu) || idle_cpu(cpu))
> +		return false;
> +
> +	j = jiffies - READ_ONCE(rdp->rcuc_activity);
>  
>  	if (jp)
>  		*jp = j;
> @@ -432,6 +444,9 @@ static void print_cpu_stall_info(int cpu)
>  	struct rcu_data *rdp = per_cpu_ptr(&rcu_data, cpu);
>  	char *ticks_title;
>  	unsigned long ticks_value;
> +	bool rcuc_starved;
> +	unsigned long j;
> +	char buf[32];
>  
>  	/*
>  	 * We could be printing a lot while holding a spinlock.  Avoid @@ -449,7 +464,10 @@ static void print_cpu_stall_info(int cpu)
>  	delta = rcu_seq_ctr(rdp->mynode->gp_seq - rdp->rcu_iw_gp_seq);
>  	falsepositive = rcu_is_gp_kthread_starving(NULL) &&
>  			rcu_dynticks_in_eqs(rcu_dynticks_snap(rdp));
> -	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld %s\n",
> +	rcuc_starved = rcu_is_rcuc_kthread_starving(rdp, &j);
> +	if (rcuc_starved)
> +		sprintf(buf, " rcuc=%ld jiffies(starved)", j);
> +	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u 
> +fqs=%ld%s%s\n",
>  	       cpu,
>  	       "O."[!!cpu_online(cpu)],
>  	       "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)], @@ -462,32 +480,10 @@ static void print_cpu_stall_info(int cpu)
>  	       rdp->dynticks_nesting, rdp->dynticks_nmi_nesting,
>  	       rdp->softirq_snap, kstat_softirqs_cpu(RCU_SOFTIRQ, cpu),
>  	       data_race(rcu_state.n_force_qs) - 
> rcu_state.n_force_qs_gpstart,
> +	       rcuc_starved ? buf : "",
>  	       falsepositive ? " (false positive?)" : "");  }
>  
> -static void rcuc_kthread_dump(struct rcu_data *rdp) -{
> -	int cpu;
> -	unsigned long j;
> -	struct task_struct *rcuc;
> -
> -	rcuc = rdp->rcu_cpu_kthread_task;
> -	if (!rcuc)
> -		return;
> -
> -	cpu = task_cpu(rcuc);
> -	if (cpu_is_offline(cpu) || idle_cpu(cpu))
> -		return;
> -
> -	if (!rcu_is_rcuc_kthread_starving(rdp, &j))
> -		return;
> -
> -	pr_err("%s kthread starved for %ld jiffies\n", rcuc->comm, j);
> -	sched_show_task(rcuc);
> -	if (!trigger_single_cpu_backtrace(cpu))
> -		dump_cpu_task(cpu);
> -}
> -
>  /* Complain about starvation of grace-period kthread.  */  static 
> void rcu_check_gp_kthread_starvation(void)
>  {
> @@ -659,9 +655,6 @@ static void print_cpu_stall(unsigned long gps)
>  	rcu_check_gp_kthread_expired_fqs_timer();
>  	rcu_check_gp_kthread_starvation();
>  
> -	if (!use_softirq)
> -		rcuc_kthread_dump(rdp);
> -
>  	rcu_dump_cpu_stacks();
>  
>  	raw_spin_lock_irqsave_rcu_node(rnp, flags);

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [PATCH v4] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
  2022-04-26 14:38       ` Zhang, Qiang1
@ 2022-04-26 16:15         ` Paul E. McKenney
  0 siblings, 0 replies; 6+ messages in thread
From: Paul E. McKenney @ 2022-04-26 16:15 UTC (permalink / raw)
  To: Zhang, Qiang1; +Cc: frederic, rcu, linux-kernel

On Tue, Apr 26, 2022 at 02:38:20PM +0000, Zhang, Qiang1 wrote:
> 
> On Tue, Apr 26, 2022 at 06:44:46AM +0000, Zhang, Qiang1 wrote:
> > 
> > On Mon, Apr 25, 2022 at 09:04:04AM +0800, Zqiang wrote:
> > > If the rcutree.use_softirq is configured, when RCU Stall event 
> > > happened, dump status of all rcuc kthreads who due to starvation 
> > > prevented grace period ends on CPUs that not report quiescent state.
> > > 
> > > Signed-off-by: Zqiang <qiang1.zhang@intel.com>
> > > ---
> > >  v1->v2:
> > >  rework rcuc_kthread_dump function
> > >  v2->v3:
> > >  merge this rcuc-stalled information into print_cpu_stall_info()
> > >  v3->v4:
> > >  print rcuc info only when rcuc kthread is starved
> > > 
> > >  kernel/rcu/tree_stall.h | 49
> > > ++++++++++++++++++-----------------------
> > >  1 file changed, 21 insertions(+), 28 deletions(-)
> > 
> > >I have queued this for testing and further review, thank you!
> > >
> > >I did the usual wordsmithing, plus I got rid of a couple of space characters that are extraneous in the common case (one of yours and one pre-existing instance).
> > >
> > >Could you please generate an actual stall of this type?  You might need to add a delay to the rcuc code, but other than that, please see the rcutorture blog series [1] and in particular the post on forcing stall warnings [2].
> > >
> > >							Thanx, Paul
> > >
> > >[1] https://paulmck.livejournal.com/61432.html
> > >[2] https://paulmck.livejournal.com/58077.html
> > 
> > I followed the instructions, add " rcutorture.stall_cpu=22 
> > rcutorture.fwd_progress=0"  and " rcutree.use_softirq=0"to bootargs, can trigger  RCU CPU stall warning:
> > 
> > root@qemux86-64:/# dmesg
> > [   37.556435] rcu: INFO: rcu_preempt self-detected stall on CPU
> > [   37.556437] rcu:     3-....: (1 GPs behind) idle=269/1/0x4000000000000000 softirq=0/0 fqs=5631 rcuc=26004 jiffies(starved)
> > [   37.556440]  (t=26000 jiffies g=3589 q=35403)
> > [   37.556441] NMI backtrace for cpu 3
> > [   37.556442] CPU: 3 PID: 117 Comm: rcu_torture_sta Tainted: G             L    5.17.0-yoctodev-standard #16 7fe7533e7466875b0801ac148f921afcf57d38bc
> > [   37.556443] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014
> > [   37.556444] Call Trace:
> > [   37.556445]  <IRQ>
> > [   37.556446]  dump_stack_lvl+0x5b/0x82
> > [   37.556449]  dump_stack+0x10/0x12
> > [   37.556451]  nmi_cpu_backtrace.cold+0x32/0x8a
> > [   37.556452]  ? lapic_can_unplug_cpu+0x80/0x80
> > [   37.556454]  nmi_trigger_cpumask_backtrace+0xce/0xe0
> > [   37.556456]  arch_trigger_cpumask_backtrace+0x19/0x20
> > [   37.556458]  rcu_dump_cpu_stacks+0xcd/0x140
> > [   37.556460]  rcu_sched_clock_irq.cold+0x7a/0x3ba
> > [   37.556463]  ? debug_smp_processor_id+0x17/0x20
> > [   37.556466]  update_process_times+0x9b/0xd0
> > [   37.556467]  tick_sched_handle.isra.0+0x25/0x50
> > [   37.556469]  tick_sched_timer+0x79/0x90
> > [   37.556470]  ? tick_sched_do_timer+0x60/0x60
> > [   37.556471]  __hrtimer_run_queues+0x1d1/0x4c0
> > [   37.556473]  hrtimer_interrupt+0x114/0x230
> > [   37.556475]  ? rcu_read_lock_held_common+0x12/0x50
> > [   37.556489]  __sysvec_apic_timer_interrupt+0xa4/0x280
> > [   37.556491]  sysvec_apic_timer_interrupt+0x95/0xc0
> > [   37.556492]  </IRQ>
> 
> >Excellent, thank you!!!
> >
> >Now could you please do the same thing for a use_softirq kernel to verify that it prints correctly when that message is not supposed to be shown?
> 
> The use_softirq is not set zero, log follow:
> 
> rcu: INFO: rcu_preempt self-detected stall on CPU	
> [   32.388910] rcu:     3-....: (20847 ticks this GP) idle=733/1/0x4000000000000000 softirq=4565/4565 fqs=4655
> [   32.388913]  (t=21000 jiffies g=8113 q=12547)
> [   32.388914] NMI backtrace for cpu 3
> [   32.388914] CPU: 3 PID: 73 Comm: rcu_torture_sta Tainted: G             L    5.17.0-yoctodev-standard #2 05f26dfea00beb93d9714ba8d61bb77646676403
> [   32.388915] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014
> [   32.388916] Call Trace:
> [   32.388916]  <IRQ>
> [   32.388917]  dump_stack_lvl+0x5b/0x82

Again excellent, and again, thank you!

							Thanx, Paul

> Thanks
> Zqiang
> 
> >
> >							Thanx, Paul
> 
> > Thanks
> > Zqiang
> > 
> > >
> > ----------------------------------------------------------------------
> > --
> > 
> > commit 66226e2acda8b31b60137b1ae71244df68541a01
> > Author: Zqiang <qiang1.zhang@intel.com>
> > Date:   Mon Apr 25 09:04:04 2022 +0800
> > 
> >     rcu: Dump all rcuc kthreads status for CPUs that not report 
> > quiescent state
> >     
> >     If the rcutree.use_softirq kernel boot parameter is disabled, then it is
> >     possible that a RCU CPU stall is due to the rcuc kthreads being starved of
> >     CPU time.  There is currently no easy way to infer this from the RCU CPU
> >     stall warning output.  This commit therefore adds a string of the form "
> >     rcuc=%ld jiffies(starved)" to a given CPU's output if the corresponding
> >     rcuc kthread has been starved for more than two seconds.
> >     
> >     [ paulmck: Eliminate extraneous space characters. ]
> >     
> >     Signed-off-by: Zqiang <qiang1.zhang@intel.com>
> >     Signed-off-by: Paul E. McKenney <paulmck@kernel.org>
> > 
> > diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h index 
> > d7956c03edbd4..0a25a4ea6eef8 100644
> > --- a/kernel/rcu/tree_stall.h
> > +++ b/kernel/rcu/tree_stall.h
> > @@ -407,7 +407,19 @@ static bool rcu_is_gp_kthread_starving(unsigned 
> > long *jp)
> >  
> >  static bool rcu_is_rcuc_kthread_starving(struct rcu_data *rdp, unsigned long *jp)  {
> > -	unsigned long j = jiffies - READ_ONCE(rdp->rcuc_activity);
> > +	int cpu;
> > +	struct task_struct *rcuc;
> > +	unsigned long j;
> > +
> > +	rcuc = rdp->rcu_cpu_kthread_task;
> > +	if (!rcuc)
> > +		return false;
> > +
> > +	cpu = task_cpu(rcuc);
> > +	if (cpu_is_offline(cpu) || idle_cpu(cpu))
> > +		return false;
> > +
> > +	j = jiffies - READ_ONCE(rdp->rcuc_activity);
> >  
> >  	if (jp)
> >  		*jp = j;
> > @@ -432,6 +444,9 @@ static void print_cpu_stall_info(int cpu)
> >  	struct rcu_data *rdp = per_cpu_ptr(&rcu_data, cpu);
> >  	char *ticks_title;
> >  	unsigned long ticks_value;
> > +	bool rcuc_starved;
> > +	unsigned long j;
> > +	char buf[32];
> >  
> >  	/*
> >  	 * We could be printing a lot while holding a spinlock.  Avoid @@ -449,7 +464,10 @@ static void print_cpu_stall_info(int cpu)
> >  	delta = rcu_seq_ctr(rdp->mynode->gp_seq - rdp->rcu_iw_gp_seq);
> >  	falsepositive = rcu_is_gp_kthread_starving(NULL) &&
> >  			rcu_dynticks_in_eqs(rcu_dynticks_snap(rdp));
> > -	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld %s\n",
> > +	rcuc_starved = rcu_is_rcuc_kthread_starving(rdp, &j);
> > +	if (rcuc_starved)
> > +		sprintf(buf, " rcuc=%ld jiffies(starved)", j);
> > +	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u 
> > +fqs=%ld%s%s\n",
> >  	       cpu,
> >  	       "O."[!!cpu_online(cpu)],
> >  	       "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)], @@ -462,32 +480,10 @@ static void print_cpu_stall_info(int cpu)
> >  	       rdp->dynticks_nesting, rdp->dynticks_nmi_nesting,
> >  	       rdp->softirq_snap, kstat_softirqs_cpu(RCU_SOFTIRQ, cpu),
> >  	       data_race(rcu_state.n_force_qs) - 
> > rcu_state.n_force_qs_gpstart,
> > +	       rcuc_starved ? buf : "",
> >  	       falsepositive ? " (false positive?)" : "");  }
> >  
> > -static void rcuc_kthread_dump(struct rcu_data *rdp) -{
> > -	int cpu;
> > -	unsigned long j;
> > -	struct task_struct *rcuc;
> > -
> > -	rcuc = rdp->rcu_cpu_kthread_task;
> > -	if (!rcuc)
> > -		return;
> > -
> > -	cpu = task_cpu(rcuc);
> > -	if (cpu_is_offline(cpu) || idle_cpu(cpu))
> > -		return;
> > -
> > -	if (!rcu_is_rcuc_kthread_starving(rdp, &j))
> > -		return;
> > -
> > -	pr_err("%s kthread starved for %ld jiffies\n", rcuc->comm, j);
> > -	sched_show_task(rcuc);
> > -	if (!trigger_single_cpu_backtrace(cpu))
> > -		dump_cpu_task(cpu);
> > -}
> > -
> >  /* Complain about starvation of grace-period kthread.  */  static 
> > void rcu_check_gp_kthread_starvation(void)
> >  {
> > @@ -659,9 +655,6 @@ static void print_cpu_stall(unsigned long gps)
> >  	rcu_check_gp_kthread_expired_fqs_timer();
> >  	rcu_check_gp_kthread_starvation();
> >  
> > -	if (!use_softirq)
> > -		rcuc_kthread_dump(rdp);
> > -
> >  	rcu_dump_cpu_stacks();
> >  
> >  	raw_spin_lock_irqsave_rcu_node(rnp, flags);

^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2022-04-26 16:15 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-04-25  1:04 [PATCH v4] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state Zqiang
2022-04-25 15:45 ` Paul E. McKenney
2022-04-26  6:44   ` Zhang, Qiang1
2022-04-26 13:48     ` Paul E. McKenney
2022-04-26 14:38       ` Zhang, Qiang1
2022-04-26 16:15         ` Paul E. McKenney

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.