All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH] rcu-tasks: Inspect stalled task's trc state in locked state
@ 2021-11-09 11:22 Neeraj Upadhyay
  2021-11-09 14:52 ` Paul E. McKenney
  0 siblings, 1 reply; 4+ messages in thread
From: Neeraj Upadhyay @ 2021-11-09 11:22 UTC (permalink / raw)
  To: paulmck, josh, rostedt, mathieu.desnoyers, jiangshanlai, joel
  Cc: rcu, linux-kernel, urezki, frederic, boqun.feng, Neeraj Upadhyay

On RCU tasks trace stall, inspect the RCU-tasks-trace specific
states of stalled task in locked down state, using try_invoke_
on_locked_down_task(), to get reliable trc state of a non-running
stalled task.

Signed-off-by: Neeraj Upadhyay <quic_neeraju@quicinc.com>
---
 kernel/rcu/tasks.h | 43 ++++++++++++++++++++++++++++++++++---------
 1 file changed, 34 insertions(+), 9 deletions(-)

diff --git a/kernel/rcu/tasks.h b/kernel/rcu/tasks.h
index e4a32db9f712..4e49b847971b 100644
--- a/kernel/rcu/tasks.h
+++ b/kernel/rcu/tasks.h
@@ -1073,25 +1073,50 @@ static void rcu_tasks_trace_postscan(struct list_head *hop)
 	// Any tasks that exit after this point will set ->trc_reader_checked.
 }
 
+/* Communicate task state back to the RCU tasks trace stall warning request. */
+struct trc_stall_chk_rdr {
+	int nesting;
+	int ipi_to_cpu;
+	u8 needqs;
+};
+
+static bool trc_check_slow_task(struct task_struct *t, void *arg)
+{
+	struct trc_stall_chk_rdr *trc_rdrp = arg;
+
+	if (task_curr(t))
+		return false; // It is running, so decline to inspect it.
+	trc_rdrp->nesting = READ_ONCE(t->trc_reader_nesting);
+	trc_rdrp->ipi_to_cpu = READ_ONCE(t->trc_ipi_to_cpu);
+	trc_rdrp->needqs = READ_ONCE(t->trc_reader_special.b.need_qs);
+	return true;
+}
+
 /* Show the state of a task stalling the current RCU tasks trace GP. */
 static void show_stalled_task_trace(struct task_struct *t, bool *firstreport)
 {
 	int cpu;
+	struct trc_stall_chk_rdr trc_rdr;
+	bool is_idle_tsk = is_idle_task(t);
 
 	if (*firstreport) {
 		pr_err("INFO: rcu_tasks_trace detected stalls on tasks:\n");
 		*firstreport = false;
 	}
-	// FIXME: This should attempt to use try_invoke_on_nonrunning_task().
 	cpu = task_cpu(t);
-	pr_alert("P%d: %c%c%c nesting: %d%c cpu: %d\n",
-		 t->pid,
-		 ".I"[READ_ONCE(t->trc_ipi_to_cpu) >= 0],
-		 ".i"[is_idle_task(t)],
-		 ".N"[cpu >= 0 && tick_nohz_full_cpu(cpu)],
-		 READ_ONCE(t->trc_reader_nesting),
-		 " N"[!!READ_ONCE(t->trc_reader_special.b.need_qs)],
-		 cpu);
+	if (!try_invoke_on_locked_down_task(t, trc_check_slow_task, &trc_rdr))
+		pr_alert("P%d: %c\n",
+			 t->pid,
+			 ".i"[is_idle_tsk]);
+	else
+		pr_alert("P%d: %c%c%c nesting: %d%c cpu: %d\n",
+			 t->pid,
+			 ".I"[trc_rdr.ipi_to_cpu >= 0],
+			 ".i"[is_idle_tsk],
+			 ".N"[cpu >= 0 && tick_nohz_full_cpu(cpu)],
+			 trc_rdr.nesting,
+			 " N"[!!trc_rdr.needqs],
+			 cpu);
 	sched_show_task(t);
 }
 
-- 
2.17.1


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

* Re: [PATCH] rcu-tasks: Inspect stalled task's trc state in locked state
  2021-11-09 11:22 [PATCH] rcu-tasks: Inspect stalled task's trc state in locked state Neeraj Upadhyay
@ 2021-11-09 14:52 ` Paul E. McKenney
  2021-11-10  4:40   ` quic_neeraju
  0 siblings, 1 reply; 4+ messages in thread
From: Paul E. McKenney @ 2021-11-09 14:52 UTC (permalink / raw)
  To: Neeraj Upadhyay
  Cc: josh, rostedt, mathieu.desnoyers, jiangshanlai, joel, rcu,
	linux-kernel, urezki, frederic, boqun.feng

On Tue, Nov 09, 2021 at 04:52:14PM +0530, Neeraj Upadhyay wrote:
> On RCU tasks trace stall, inspect the RCU-tasks-trace specific
> states of stalled task in locked down state, using try_invoke_
> on_locked_down_task(), to get reliable trc state of a non-running
> stalled task.
> 
> Signed-off-by: Neeraj Upadhyay <quic_neeraju@quicinc.com>

Queued for further review and testing, thank you!

Along those lines, what did you do to test this?  I would like to
add that to the commit message.  (The usual approach is to use the
rcutorture.stall_cpu module parameter, in case I have not yet passed
that along.)

							Thanx, Paul

> ---
>  kernel/rcu/tasks.h | 43 ++++++++++++++++++++++++++++++++++---------
>  1 file changed, 34 insertions(+), 9 deletions(-)
> 
> diff --git a/kernel/rcu/tasks.h b/kernel/rcu/tasks.h
> index e4a32db9f712..4e49b847971b 100644
> --- a/kernel/rcu/tasks.h
> +++ b/kernel/rcu/tasks.h
> @@ -1073,25 +1073,50 @@ static void rcu_tasks_trace_postscan(struct list_head *hop)
>  	// Any tasks that exit after this point will set ->trc_reader_checked.
>  }
>  
> +/* Communicate task state back to the RCU tasks trace stall warning request. */
> +struct trc_stall_chk_rdr {
> +	int nesting;
> +	int ipi_to_cpu;
> +	u8 needqs;
> +};
> +
> +static bool trc_check_slow_task(struct task_struct *t, void *arg)
> +{
> +	struct trc_stall_chk_rdr *trc_rdrp = arg;
> +
> +	if (task_curr(t))
> +		return false; // It is running, so decline to inspect it.
> +	trc_rdrp->nesting = READ_ONCE(t->trc_reader_nesting);
> +	trc_rdrp->ipi_to_cpu = READ_ONCE(t->trc_ipi_to_cpu);
> +	trc_rdrp->needqs = READ_ONCE(t->trc_reader_special.b.need_qs);
> +	return true;
> +}
> +
>  /* Show the state of a task stalling the current RCU tasks trace GP. */
>  static void show_stalled_task_trace(struct task_struct *t, bool *firstreport)
>  {
>  	int cpu;
> +	struct trc_stall_chk_rdr trc_rdr;
> +	bool is_idle_tsk = is_idle_task(t);
>  
>  	if (*firstreport) {
>  		pr_err("INFO: rcu_tasks_trace detected stalls on tasks:\n");
>  		*firstreport = false;
>  	}
> -	// FIXME: This should attempt to use try_invoke_on_nonrunning_task().
>  	cpu = task_cpu(t);
> -	pr_alert("P%d: %c%c%c nesting: %d%c cpu: %d\n",
> -		 t->pid,
> -		 ".I"[READ_ONCE(t->trc_ipi_to_cpu) >= 0],
> -		 ".i"[is_idle_task(t)],
> -		 ".N"[cpu >= 0 && tick_nohz_full_cpu(cpu)],
> -		 READ_ONCE(t->trc_reader_nesting),
> -		 " N"[!!READ_ONCE(t->trc_reader_special.b.need_qs)],
> -		 cpu);
> +	if (!try_invoke_on_locked_down_task(t, trc_check_slow_task, &trc_rdr))
> +		pr_alert("P%d: %c\n",
> +			 t->pid,
> +			 ".i"[is_idle_tsk]);
> +	else
> +		pr_alert("P%d: %c%c%c nesting: %d%c cpu: %d\n",
> +			 t->pid,
> +			 ".I"[trc_rdr.ipi_to_cpu >= 0],
> +			 ".i"[is_idle_tsk],
> +			 ".N"[cpu >= 0 && tick_nohz_full_cpu(cpu)],
> +			 trc_rdr.nesting,
> +			 " N"[!!trc_rdr.needqs],
> +			 cpu);
>  	sched_show_task(t);
>  }
>  
> -- 
> 2.17.1
> 

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

* Re: [PATCH] rcu-tasks: Inspect stalled task's trc state in locked state
  2021-11-09 14:52 ` Paul E. McKenney
@ 2021-11-10  4:40   ` quic_neeraju
  2021-11-10 19:55     ` Paul E. McKenney
  0 siblings, 1 reply; 4+ messages in thread
From: quic_neeraju @ 2021-11-10  4:40 UTC (permalink / raw)
  To: paulmck
  Cc: josh, rostedt, mathieu.desnoyers, jiangshanlai, joel, rcu,
	linux-kernel, urezki, frederic, boqun.feng

Hi Paul,


On 11/9/2021 8:22 PM, Paul E. McKenney wrote:
> On Tue, Nov 09, 2021 at 04:52:14PM +0530, Neeraj Upadhyay wrote:
>> On RCU tasks trace stall, inspect the RCU-tasks-trace specific
>> states of stalled task in locked down state, using try_invoke_
>> on_locked_down_task(), to get reliable trc state of a non-running
>> stalled task.
>>
>> Signed-off-by: Neeraj Upadhyay <quic_neeraju@quicinc.com>
> 
> Queued for further review and testing, thank you!
> 
> Along those lines, what did you do to test this?  I would like to
> add that to the commit message.  (The usual approach is to use the
> rcutorture.stall_cpu module parameter, in case I have not yet passed
> that along.)
> 

Before sending the patch, I had tested with TRACE01 and adding long 
delay before rcu_read_unlock_trace() in tasks_tracing_torture_read_unlock()

static void tasks_tracing_torture_read_unlock(int idx)
{
         rcu_read_unlock_trace();
}

I retested with below commandline (without adding delay in 
tasks_tracing_torture_read_unlock()):

tools/testing/selftests/rcutorture/bin/kvm.sh --cpus 8 --configs TRACE01 
--bootargs "rcutorture.torture_type=tasks-tracing 
rcutorture.stall_cpu=10 rcutorture.stall_cpu_block=1 
rcupdate.rcu_task_stall_timeout=100" --trust-make

With this, I can see stalls for both RUNNING and WAITING state task:

[   21.520291] INFO: rcu_tasks_trace detected stalls on tasks:
[   21.521292] P85: ... nesting: 1N cpu: 2
[   21.521966] task:rcu_torture_sta state:D stack:15080 pid:   85 ppid: 
     2 flags:0x00004000
[   21.523384] Call Trace:
[   21.523808]  __schedule+0x273/0x6e0
[   21.524428]  schedule+0x35/0xa0
[   21.524971]  schedule_timeout+0x1ed/0x270
[   21.525690]  ? del_timer_sync+0x30/0x30
[   21.526371]  ? rcu_torture_writer+0x720/0x720
[   21.527106]  rcu_torture_stall+0x24a/0x270
[   21.527816]  kthread+0x115/0x140
[   21.528401]  ? set_kthread_struct+0x40/0x40
[   21.529136]  ret_from_fork+0x22/0x30
[   21.529766]  1 holdouts
[   21.632300] INFO: rcu_tasks_trace detected stalls on tasks:
[   21.632345] rcu_torture_stall end.
[   21.633293] P85: .
[   21.633294] task:rcu_torture_sta state:R  running task 
stack:15080 pid:   85 ppid:     2 flags:0x00004000
[   21.633299] Call Trace:
[   21.633301]  ? vprintk_emit+0xab/0x180
[   21.633306]  ? vprintk_emit+0x11a/0x180
[   21.633308]  ? _printk+0x4d/0x69
[   21.633311]  ? __default_send_IPI_shortcut+0x1f/0x40



Thanks
Neeraj

> 							Thanx, Paul
> 
>> ---
>>   kernel/rcu/tasks.h | 43 ++++++++++++++++++++++++++++++++++---------
>>   1 file changed, 34 insertions(+), 9 deletions(-)
>>
>> diff --git a/kernel/rcu/tasks.h b/kernel/rcu/tasks.h
>> index e4a32db9f712..4e49b847971b 100644
>> --- a/kernel/rcu/tasks.h
>> +++ b/kernel/rcu/tasks.h
>> @@ -1073,25 +1073,50 @@ static void rcu_tasks_trace_postscan(struct list_head *hop)
>>   	// Any tasks that exit after this point will set ->trc_reader_checked.
>>   }
>>   
>> +/* Communicate task state back to the RCU tasks trace stall warning request. */
>> +struct trc_stall_chk_rdr {
>> +	int nesting;
>> +	int ipi_to_cpu;
>> +	u8 needqs;
>> +};
>> +
>> +static bool trc_check_slow_task(struct task_struct *t, void *arg)
>> +{
>> +	struct trc_stall_chk_rdr *trc_rdrp = arg;
>> +
>> +	if (task_curr(t))
>> +		return false; // It is running, so decline to inspect it.
>> +	trc_rdrp->nesting = READ_ONCE(t->trc_reader_nesting);
>> +	trc_rdrp->ipi_to_cpu = READ_ONCE(t->trc_ipi_to_cpu);
>> +	trc_rdrp->needqs = READ_ONCE(t->trc_reader_special.b.need_qs);
>> +	return true;
>> +}
>> +
>>   /* Show the state of a task stalling the current RCU tasks trace GP. */
>>   static void show_stalled_task_trace(struct task_struct *t, bool *firstreport)
>>   {
>>   	int cpu;
>> +	struct trc_stall_chk_rdr trc_rdr;
>> +	bool is_idle_tsk = is_idle_task(t);
>>   
>>   	if (*firstreport) {
>>   		pr_err("INFO: rcu_tasks_trace detected stalls on tasks:\n");
>>   		*firstreport = false;
>>   	}
>> -	// FIXME: This should attempt to use try_invoke_on_nonrunning_task().
>>   	cpu = task_cpu(t);
>> -	pr_alert("P%d: %c%c%c nesting: %d%c cpu: %d\n",
>> -		 t->pid,
>> -		 ".I"[READ_ONCE(t->trc_ipi_to_cpu) >= 0],
>> -		 ".i"[is_idle_task(t)],
>> -		 ".N"[cpu >= 0 && tick_nohz_full_cpu(cpu)],
>> -		 READ_ONCE(t->trc_reader_nesting),
>> -		 " N"[!!READ_ONCE(t->trc_reader_special.b.need_qs)],
>> -		 cpu);
>> +	if (!try_invoke_on_locked_down_task(t, trc_check_slow_task, &trc_rdr))
>> +		pr_alert("P%d: %c\n",
>> +			 t->pid,
>> +			 ".i"[is_idle_tsk]);
>> +	else
>> +		pr_alert("P%d: %c%c%c nesting: %d%c cpu: %d\n",
>> +			 t->pid,
>> +			 ".I"[trc_rdr.ipi_to_cpu >= 0],
>> +			 ".i"[is_idle_tsk],
>> +			 ".N"[cpu >= 0 && tick_nohz_full_cpu(cpu)],
>> +			 trc_rdr.nesting,
>> +			 " N"[!!trc_rdr.needqs],
>> +			 cpu);
>>   	sched_show_task(t);
>>   }
>>   
>> -- 
>> 2.17.1
>>

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

* Re: [PATCH] rcu-tasks: Inspect stalled task's trc state in locked state
  2021-11-10  4:40   ` quic_neeraju
@ 2021-11-10 19:55     ` Paul E. McKenney
  0 siblings, 0 replies; 4+ messages in thread
From: Paul E. McKenney @ 2021-11-10 19:55 UTC (permalink / raw)
  To: quic_neeraju
  Cc: josh, rostedt, mathieu.desnoyers, jiangshanlai, joel, rcu,
	linux-kernel, urezki, frederic, boqun.feng

On Wed, Nov 10, 2021 at 10:10:27AM +0530, quic_neeraju wrote:
> Hi Paul,
> 
> 
> On 11/9/2021 8:22 PM, Paul E. McKenney wrote:
> > On Tue, Nov 09, 2021 at 04:52:14PM +0530, Neeraj Upadhyay wrote:
> > > On RCU tasks trace stall, inspect the RCU-tasks-trace specific
> > > states of stalled task in locked down state, using try_invoke_
> > > on_locked_down_task(), to get reliable trc state of a non-running
> > > stalled task.
> > > 
> > > Signed-off-by: Neeraj Upadhyay <quic_neeraju@quicinc.com>
> > 
> > Queued for further review and testing, thank you!
> > 
> > Along those lines, what did you do to test this?  I would like to
> > add that to the commit message.  (The usual approach is to use the
> > rcutorture.stall_cpu module parameter, in case I have not yet passed
> > that along.)
> > 
> 
> Before sending the patch, I had tested with TRACE01 and adding long delay
> before rcu_read_unlock_trace() in tasks_tracing_torture_read_unlock()
> 
> static void tasks_tracing_torture_read_unlock(int idx)
> {
>         rcu_read_unlock_trace();
> }
> 
> I retested with below commandline (without adding delay in
> tasks_tracing_torture_read_unlock()):
> 
> tools/testing/selftests/rcutorture/bin/kvm.sh --cpus 8 --configs TRACE01
> --bootargs "rcutorture.torture_type=tasks-tracing rcutorture.stall_cpu=10
> rcutorture.stall_cpu_block=1 rcupdate.rcu_task_stall_timeout=100"
> --trust-make
> 
> With this, I can see stalls for both RUNNING and WAITING state task:

Applied, thank you!

							Thanx, Paul

> [   21.520291] INFO: rcu_tasks_trace detected stalls on tasks:
> [   21.521292] P85: ... nesting: 1N cpu: 2
> [   21.521966] task:rcu_torture_sta state:D stack:15080 pid:   85 ppid:
> 2 flags:0x00004000
> [   21.523384] Call Trace:
> [   21.523808]  __schedule+0x273/0x6e0
> [   21.524428]  schedule+0x35/0xa0
> [   21.524971]  schedule_timeout+0x1ed/0x270
> [   21.525690]  ? del_timer_sync+0x30/0x30
> [   21.526371]  ? rcu_torture_writer+0x720/0x720
> [   21.527106]  rcu_torture_stall+0x24a/0x270
> [   21.527816]  kthread+0x115/0x140
> [   21.528401]  ? set_kthread_struct+0x40/0x40
> [   21.529136]  ret_from_fork+0x22/0x30
> [   21.529766]  1 holdouts
> [   21.632300] INFO: rcu_tasks_trace detected stalls on tasks:
> [   21.632345] rcu_torture_stall end.
> [   21.633293] P85: .
> [   21.633294] task:rcu_torture_sta state:R  running task stack:15080 pid:
> 85 ppid:     2 flags:0x00004000
> [   21.633299] Call Trace:
> [   21.633301]  ? vprintk_emit+0xab/0x180
> [   21.633306]  ? vprintk_emit+0x11a/0x180
> [   21.633308]  ? _printk+0x4d/0x69
> [   21.633311]  ? __default_send_IPI_shortcut+0x1f/0x40
> 
> 
> 
> Thanks
> Neeraj
> 
> > 							Thanx, Paul
> > 
> > > ---
> > >   kernel/rcu/tasks.h | 43 ++++++++++++++++++++++++++++++++++---------
> > >   1 file changed, 34 insertions(+), 9 deletions(-)
> > > 
> > > diff --git a/kernel/rcu/tasks.h b/kernel/rcu/tasks.h
> > > index e4a32db9f712..4e49b847971b 100644
> > > --- a/kernel/rcu/tasks.h
> > > +++ b/kernel/rcu/tasks.h
> > > @@ -1073,25 +1073,50 @@ static void rcu_tasks_trace_postscan(struct list_head *hop)
> > >   	// Any tasks that exit after this point will set ->trc_reader_checked.
> > >   }
> > > +/* Communicate task state back to the RCU tasks trace stall warning request. */
> > > +struct trc_stall_chk_rdr {
> > > +	int nesting;
> > > +	int ipi_to_cpu;
> > > +	u8 needqs;
> > > +};
> > > +
> > > +static bool trc_check_slow_task(struct task_struct *t, void *arg)
> > > +{
> > > +	struct trc_stall_chk_rdr *trc_rdrp = arg;
> > > +
> > > +	if (task_curr(t))
> > > +		return false; // It is running, so decline to inspect it.
> > > +	trc_rdrp->nesting = READ_ONCE(t->trc_reader_nesting);
> > > +	trc_rdrp->ipi_to_cpu = READ_ONCE(t->trc_ipi_to_cpu);
> > > +	trc_rdrp->needqs = READ_ONCE(t->trc_reader_special.b.need_qs);
> > > +	return true;
> > > +}
> > > +
> > >   /* Show the state of a task stalling the current RCU tasks trace GP. */
> > >   static void show_stalled_task_trace(struct task_struct *t, bool *firstreport)
> > >   {
> > >   	int cpu;
> > > +	struct trc_stall_chk_rdr trc_rdr;
> > > +	bool is_idle_tsk = is_idle_task(t);
> > >   	if (*firstreport) {
> > >   		pr_err("INFO: rcu_tasks_trace detected stalls on tasks:\n");
> > >   		*firstreport = false;
> > >   	}
> > > -	// FIXME: This should attempt to use try_invoke_on_nonrunning_task().
> > >   	cpu = task_cpu(t);
> > > -	pr_alert("P%d: %c%c%c nesting: %d%c cpu: %d\n",
> > > -		 t->pid,
> > > -		 ".I"[READ_ONCE(t->trc_ipi_to_cpu) >= 0],
> > > -		 ".i"[is_idle_task(t)],
> > > -		 ".N"[cpu >= 0 && tick_nohz_full_cpu(cpu)],
> > > -		 READ_ONCE(t->trc_reader_nesting),
> > > -		 " N"[!!READ_ONCE(t->trc_reader_special.b.need_qs)],
> > > -		 cpu);
> > > +	if (!try_invoke_on_locked_down_task(t, trc_check_slow_task, &trc_rdr))
> > > +		pr_alert("P%d: %c\n",
> > > +			 t->pid,
> > > +			 ".i"[is_idle_tsk]);
> > > +	else
> > > +		pr_alert("P%d: %c%c%c nesting: %d%c cpu: %d\n",
> > > +			 t->pid,
> > > +			 ".I"[trc_rdr.ipi_to_cpu >= 0],
> > > +			 ".i"[is_idle_tsk],
> > > +			 ".N"[cpu >= 0 && tick_nohz_full_cpu(cpu)],
> > > +			 trc_rdr.nesting,
> > > +			 " N"[!!trc_rdr.needqs],
> > > +			 cpu);
> > >   	sched_show_task(t);
> > >   }
> > > -- 
> > > 2.17.1
> > > 

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

end of thread, other threads:[~2021-11-10 19:55 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-11-09 11:22 [PATCH] rcu-tasks: Inspect stalled task's trc state in locked state Neeraj Upadhyay
2021-11-09 14:52 ` Paul E. McKenney
2021-11-10  4:40   ` quic_neeraju
2021-11-10 19:55     ` 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.