linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v3] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
@ 2022-04-24  4:17 Zqiang
  2022-04-24 16:06 ` Paul E. McKenney
  2022-04-25 13:23 ` Dan Carpenter
  0 siblings, 2 replies; 3+ messages in thread
From: Zqiang @ 2022-04-24  4:17 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()

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

diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h
index d7956c03edbd..3482e37d2e3e 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,8 @@ 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;
 
 	/*
 	 * We could be printing a lot while holding a spinlock.  Avoid
@@ -449,7 +463,8 @@ 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);
+	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld rcuc=%ld jiffies(%s) %s\n",
 	       cpu,
 	       "O."[!!cpu_online(cpu)],
 	       "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)],
@@ -462,32 +477,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,
+	       j, rcuc_starved ? "starved" : "",
 	       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 +652,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] 3+ messages in thread

* Re: [PATCH v3] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
  2022-04-24  4:17 [PATCH v3] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state Zqiang
@ 2022-04-24 16:06 ` Paul E. McKenney
  2022-04-25 13:23 ` Dan Carpenter
  1 sibling, 0 replies; 3+ messages in thread
From: Paul E. McKenney @ 2022-04-24 16:06 UTC (permalink / raw)
  To: Zqiang; +Cc: frederic, rcu, linux-kernel

On Sun, Apr 24, 2022 at 12:17:47PM +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>

Much, much better, thank you!

A few more comments below.

							Thanx, Paul

> ---
>  v1->v2:
>  rework rcuc_kthread_dump function
>  v2->v3:
>  merge this rcuc-stalled information into print_cpu_stall_info()
> 
>  kernel/rcu/tree_stall.h | 46 ++++++++++++++++-------------------------
>  1 file changed, 18 insertions(+), 28 deletions(-)
> 
> diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h
> index d7956c03edbd..3482e37d2e3e 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);

Localizing this logic is a good improvement, thank you!

>  	if (jp)
>  		*jp = j;
> @@ -432,6 +444,8 @@ 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;
>  
>  	/*
>  	 * We could be printing a lot while holding a spinlock.  Avoid
> @@ -449,7 +463,8 @@ 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);
> +	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld rcuc=%ld jiffies(%s) %s\n",

The trick here is to sprintf() to format the "rcuc=%ld jiffies" part of
the message, then just have "%s" instead of the "rcuc=%ld jiffies(%s)",
and then ...

>  	       cpu,
>  	       "O."[!!cpu_online(cpu)],
>  	       "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)],
> @@ -462,32 +477,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,
> +	       j, rcuc_starved ? "starved" : "",

... here have:

	       rcu_starved ? buf : "",

Where "buf" is the place you sprintf()ed into.  This is especially
important for kernels that don't have rcuc kthreads in the first place.
We don't need the poor CPU-stalled systems administrator wasting time
wondering what an rcuc is an why anyone would care.  ;-)

>  	       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 +652,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	[flat|nested] 3+ messages in thread

* Re: [PATCH v3] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
  2022-04-24  4:17 [PATCH v3] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state Zqiang
  2022-04-24 16:06 ` Paul E. McKenney
@ 2022-04-25 13:23 ` Dan Carpenter
  1 sibling, 0 replies; 3+ messages in thread
From: Dan Carpenter @ 2022-04-25 13:23 UTC (permalink / raw)
  To: kbuild, Zqiang, paulmck, frederic; +Cc: lkp, kbuild-all, rcu, linux-kernel

Hi Zqiang,

url:    https://github.com/intel-lab-lkp/linux/commits/Zqiang/rcu-Dump-all-rcuc-kthreads-status-for-CPUs-that-not-report-quiescent-state/20220424-121850
base:   https://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git dev
config: i386-randconfig-m021 (https://download.01.org/0day-ci/archive/20220424/202204241503.imwh5SqZ-lkp@intel.com/config)
compiler: gcc-11 (Debian 11.2.0-20) 11.2.0

If you fix the issue, kindly add following tag as appropriate
Reported-by: kernel test robot <lkp@intel.com>
Reported-by: Dan Carpenter <dan.carpenter@oracle.com>

smatch warnings:
kernel/rcu/tree_stall.h:467 print_cpu_stall_info() error: uninitialized symbol 'j'.

vim +/j +467 kernel/rcu/tree_stall.h

59b73a27681c58 Paul E. McKenney 2019-01-11  440  static void print_cpu_stall_info(int cpu)
59b73a27681c58 Paul E. McKenney 2019-01-11  441  {
59b73a27681c58 Paul E. McKenney 2019-01-11  442  	unsigned long delta;
88375825171c7d Paul E. McKenney 2020-03-31  443  	bool falsepositive;
59b73a27681c58 Paul E. McKenney 2019-01-11  444  	struct rcu_data *rdp = per_cpu_ptr(&rcu_data, cpu);
59b73a27681c58 Paul E. McKenney 2019-01-11  445  	char *ticks_title;
59b73a27681c58 Paul E. McKenney 2019-01-11  446  	unsigned long ticks_value;
17d9de741a1aaf Zqiang           2022-04-24  447  	bool rcuc_starved;
17d9de741a1aaf Zqiang           2022-04-24  448  	unsigned long j;
59b73a27681c58 Paul E. McKenney 2019-01-11  449  
59b73a27681c58 Paul E. McKenney 2019-01-11  450  	/*
59b73a27681c58 Paul E. McKenney 2019-01-11  451  	 * We could be printing a lot while holding a spinlock.  Avoid
59b73a27681c58 Paul E. McKenney 2019-01-11  452  	 * triggering hard lockup.
59b73a27681c58 Paul E. McKenney 2019-01-11  453  	 */
59b73a27681c58 Paul E. McKenney 2019-01-11  454  	touch_nmi_watchdog();
59b73a27681c58 Paul E. McKenney 2019-01-11  455  
59b73a27681c58 Paul E. McKenney 2019-01-11  456  	ticks_value = rcu_seq_ctr(rcu_state.gp_seq - rdp->gp_seq);
59b73a27681c58 Paul E. McKenney 2019-01-11  457  	if (ticks_value) {
59b73a27681c58 Paul E. McKenney 2019-01-11  458  		ticks_title = "GPs behind";
59b73a27681c58 Paul E. McKenney 2019-01-11  459  	} else {
59b73a27681c58 Paul E. McKenney 2019-01-11  460  		ticks_title = "ticks this GP";
59b73a27681c58 Paul E. McKenney 2019-01-11  461  		ticks_value = rdp->ticks_this_gp;
59b73a27681c58 Paul E. McKenney 2019-01-11  462  	}
59b73a27681c58 Paul E. McKenney 2019-01-11  463  	delta = rcu_seq_ctr(rdp->mynode->gp_seq - rdp->rcu_iw_gp_seq);
88375825171c7d Paul E. McKenney 2020-03-31  464  	falsepositive = rcu_is_gp_kthread_starving(NULL) &&
88375825171c7d Paul E. McKenney 2020-03-31  465  			rcu_dynticks_in_eqs(rcu_dynticks_snap(rdp));
17d9de741a1aaf Zqiang           2022-04-24  466  	rcuc_starved = rcu_is_rcuc_kthread_starving(rdp, &j);


That tree has some new returns in rcu_is_rcuc_kthread_starving() where
*jp is not set.

17d9de741a1aaf Zqiang           2022-04-24 @467  	pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld rcuc=%ld jiffies(%s) %s\n",
59b73a27681c58 Paul E. McKenney 2019-01-11  468  	       cpu,
59b73a27681c58 Paul E. McKenney 2019-01-11  469  	       "O."[!!cpu_online(cpu)],
59b73a27681c58 Paul E. McKenney 2019-01-11  470  	       "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)],
59b73a27681c58 Paul E. McKenney 2019-01-11  471  	       "N."[!!(rdp->grpmask & rdp->mynode->qsmaskinitnext)],
59b73a27681c58 Paul E. McKenney 2019-01-11  472  	       !IS_ENABLED(CONFIG_IRQ_WORK) ? '?' :
59b73a27681c58 Paul E. McKenney 2019-01-11  473  			rdp->rcu_iw_pending ? (int)min(delta, 9UL) + '0' :
59b73a27681c58 Paul E. McKenney 2019-01-11  474  				"!."[!delta],
59b73a27681c58 Paul E. McKenney 2019-01-11  475  	       ticks_value, ticks_title,
59b73a27681c58 Paul E. McKenney 2019-01-11  476  	       rcu_dynticks_snap(rdp) & 0xfff,
59b73a27681c58 Paul E. McKenney 2019-01-11  477  	       rdp->dynticks_nesting, rdp->dynticks_nmi_nesting,
59b73a27681c58 Paul E. McKenney 2019-01-11  478  	       rdp->softirq_snap, kstat_softirqs_cpu(RCU_SOFTIRQ, cpu),
88375825171c7d Paul E. McKenney 2020-03-31  479  	       data_race(rcu_state.n_force_qs) - rcu_state.n_force_qs_gpstart,
17d9de741a1aaf Zqiang           2022-04-24  480  	       j, rcuc_starved ? "starved" : "",
88375825171c7d Paul E. McKenney 2020-03-31  481  	       falsepositive ? " (false positive?)" : "");
59b73a27681c58 Paul E. McKenney 2019-01-11  482  }

-- 
0-DAY CI Kernel Test Service
https://01.org/lkp


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

end of thread, other threads:[~2022-04-25 13:24 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-04-24  4:17 [PATCH v3] rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state Zqiang
2022-04-24 16:06 ` Paul E. McKenney
2022-04-25 13:23 ` Dan Carpenter

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).