From: "Elliott, Robert (Servers)" <elliott@hpe.com>
To: "Leizhen (ThunderTown)" <thunder.leizhen@huawei.com>,
"paulmck@kernel.org" <paulmck@kernel.org>
Cc: Frederic Weisbecker <frederic@kernel.org>,
Neeraj Upadhyay <quic_neeraju@quicinc.com>,
Josh Triplett <josh@joshtriplett.org>,
"Steven Rostedt" <rostedt@goodmis.org>,
Mathieu Desnoyers <mathieu.desnoyers@efficios.com>,
Lai Jiangshan <jiangshanlai@gmail.com>,
Joel Fernandes <joel@joelfernandes.org>,
"rcu@vger.kernel.org" <rcu@vger.kernel.org>,
"linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>
Subject: RE: [PATCH v4 4/4] rcu: Add RCU stall diagnosis information
Date: Mon, 7 Nov 2022 20:38:01 +0000 [thread overview]
Message-ID: <MW5PR84MB18427CB2FF17CE0D91BE9944AB3C9@MW5PR84MB1842.NAMPRD84.PROD.OUTLOOK.COM> (raw)
In-Reply-To: <5133bd4b-c17f-f5ed-eae2-fe2d199dc5db@huawei.com>
> > Maybe this shouldn't be a table? Make it grep-friendly:
> > [ 1816.719922] rcu: half-timeout counts: hardirq =5 softirq=10 csw=0
> > [ 1816.725643] rcu: half_timeout cputimes (ms): time=1500 hardirq=3
> softirq=0 system=1492
>
> I prefer the table. Table look clearer and easier to compare.
Here's an example where it also triggers expedited stalls. The
self-detected stall prints including the new table can end up
interleaved with the expedited stall prints.
(the table is expanded a bit here to experiment with adding more info,
and I included the \t prefixes)
[ 933.728032] tcrypt: rcu testing - kernel_fpu_disable for rude 6 s
[ 938.038278] rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 46-.... } 4 jiffies s: 521 root: 0x8/.
[ 938.049151] rcu: blocking rcu_node structures (internal RCU debug): l=1:42-55:0x10/.
[ 938.057236] Sending NMI from CPU 35 to CPUs 46:
[ 938.062048] NMI backtrace for cpu 46
[ 938.062050] CPU: 46 PID: 44184 Comm: modprobe Not tainted 6.0.0+ #11
[ 938.062052] Hardware name: HPE ProLiant DL360 Gen10/ProLiant DL360 Gen10, BIOS U32 03/08/2022
[ 938.062053] RIP: 0010:rude_sleep_cycles+0x13/0x27 [tcrypt]
...
[ 938.062151] </TASK>
[ 938.073277] rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 46-.... } 289 jiffies s: 521 root: 0x8/.
[ 938.334292] rcu: blocking rcu_node structures (internal RCU debug): l=1:42-55:0x10/.
[ 938.342289] Sending NMI from CPU 35 to CPUs 46:
[ 938.347049] NMI backtrace for cpu 46
[ 938.347050] CPU: 46 PID: 44184 Comm: modprobe Not tainted 6.0.0+ #11
[ 938.347051] Hardware name: HPE ProLiant DL360 Gen10/ProLiant DL360 Gen10, BIOS U32 03/08/2022
[ 938.347052] RIP: 0010:rude_sleep_cycles+0x13/0x27 [tcrypt]
...
[ 938.347121] </TASK>
[ 938.358275] rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 46-.... } 573 jiffies s: 521 root: 0x8/.
[ 938.619182] rcu: blocking rcu_node structures (internal RCU debug): l=1:42-55:0x10/.
[ 938.627179] Sending NMI from CPU 35 to CPUs 46:
[ 938.631939] NMI backtrace for cpu 46
[ 938.631939] CPU: 46 PID: 44184 Comm: modprobe Not tainted 6.0.0+ #11
[ 938.631941] Hardware name: HPE ProLiant DL360 Gen10/ProLiant DL360 Gen10, BIOS U32 03/08/2022
[ 938.631942] RIP: 0010:rude_sleep_cycles+0x13/0x27 [tcrypt]
...
[ 938.631997] </TASK>
[ 938.643272] rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: {
[ 938.734267] rcu: INFO: rcu_preempt self-detected stall on CPU
[ 938.740111] 46-....
[ 938.747282] rcu: 46-....: (4948 ticks this GP) idle=a9cc/1/0x4000000000000000 softirq=7598/7598 fqs=1253
[ 938.747285] rcu: hardirqs softirqs csw system cond_resched
[ 938.747286] rcu: number: 0 0 0 0
[ 938.754461] } 720 jiffies s: 521 root: 0x8/.
[ 938.757178] rcu: cputime: 62 0 2436 ==> 2500 (ms)
[ 938.757179] rcu: current: in_kernel_fpu_begin=1 this_cpu_preemptible=0
[ 938.757181] (t=5023 jiffies g=61053 q=704 ncpus=56)
[ 938.759640] rcu: blocking rcu_node structures (internal RCU debug):
The first "46-" line is from the expedited stall.
The second "46-" line is from the self-detected stall.
The table lines are from the self-detected stall.
The "} 720" line is from the expedited stall.
The "(t=5023" line is from the self-detected stall.
The "blocking" line is from the expedited stall.
[ 938.761745] CPU: 46 PID: 44184 Comm: modprobe Not tainted 6.0.0+ #11
[ 938.761747] Hardware name: HPE ProLiant DL360 Gen10/ProLiant DL360 Gen10, BIOS U32 03/08/2022
[ 938.982118] RIP: 0010:rude_sleep_cycles+0x13/0x27 [tcrypt]
...
[ 939.221833] </TASK>
[ 939.224239] l=1:42-55:0x10/.
[ 939.227440] Sending NMI from CPU 35 to CPUs 46:
[ 939.232204] NMI backtrace for cpu 46
[ 939.232205] CPU: 46 PID: 44184 Comm: modprobe Not tainted 6.0.0+ #11
[ 939.232206] Hardware name: HPE ProLiant DL360 Gen10/ProLiant DL360 Gen10, BIOS U32 03/08/2022
[ 939.232207] RIP: 0010:rude_sleep_cycles+0x13/0x27 [tcrypt]
...
[ 939.232262] </TASK>
[ 939.243264] rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 46-.... } 1458 jiffies s: 521 root: 0x8/.
[ 939.503926] rcu: blocking rcu_node structures (internal RCU debug): l=1:42-55:0x10/.
[ 939.511920] Sending NMI from CPU 35 to CPUs 46:
[ 939.516678] NMI backtrace for cpu 46
[ 939.516679] CPU: 46 PID: 44184 Comm: modprobe Not tainted 6.0.0+ #11
[ 939.516680] Hardware name: HPE ProLiant DL360 Gen10/ProLiant DL360 Gen10, BIOS U32 03/08/2022
[ 939.516680] RIP: 0010:rude_sleep_cycles+0x13/0x27 [tcrypt]
...
[ 939.516732] </TASK>
[ 939.528263] rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: {
[ 939.748586] initcall tcrypt_mod_init+0x0/0x1000 [tcrypt] returned -11 after 6020623 usecs
[ 939.753200] 46-.... } 1718 jiffies s: 521 root: 0x8/.
[ 939.791580] rcu: blocking rcu_node structures (internal RCU debug):
next prev parent reply other threads:[~2022-11-07 20:38 UTC|newest]
Thread overview: 21+ messages / expand[flat|nested] mbox.gz Atom feed top
2022-11-04 2:12 [PATCH v4 0/4] " Zhen Lei
2022-11-04 2:12 ` [PATCH v4 1/4] genirq: Fix the return type of kstat_cpu_irqs_sum() Zhen Lei
2022-11-04 2:12 ` [PATCH v4 2/4] sched: Add helper kstat_cpu_softirqs_sum() Zhen Lei
2022-11-04 2:12 ` [PATCH v4 3/4] sched: Add helper nr_context_switches_cpu() Zhen Lei
2022-11-04 2:12 ` [PATCH v4 4/4] rcu: Add RCU stall diagnosis information Zhen Lei
2022-11-04 3:12 ` Leizhen (ThunderTown)
2022-11-04 13:43 ` Paul E. McKenney
2022-11-05 1:58 ` Elliott, Robert (Servers)
2022-11-05 7:03 ` Leizhen (ThunderTown)
2022-11-05 20:32 ` Paul E. McKenney
2022-11-07 3:20 ` Leizhen (ThunderTown)
2022-11-05 20:06 ` Paul E. McKenney
2022-11-07 2:10 ` Elliott, Robert (Servers)
2022-11-07 11:49 ` Leizhen (ThunderTown)
2022-11-07 20:38 ` Elliott, Robert (Servers) [this message]
2022-11-07 21:57 ` Elliott, Robert (Servers)
2022-11-08 3:06 ` Leizhen (ThunderTown)
2022-11-08 5:53 ` Elliott, Robert (Servers)
2022-11-08 6:41 ` Leizhen (ThunderTown)
2022-11-08 19:29 ` Elliott, Robert (Servers)
2022-11-08 3:18 ` Leizhen (ThunderTown)
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=MW5PR84MB18427CB2FF17CE0D91BE9944AB3C9@MW5PR84MB1842.NAMPRD84.PROD.OUTLOOK.COM \
--to=elliott@hpe.com \
--cc=frederic@kernel.org \
--cc=jiangshanlai@gmail.com \
--cc=joel@joelfernandes.org \
--cc=josh@joshtriplett.org \
--cc=linux-kernel@vger.kernel.org \
--cc=mathieu.desnoyers@efficios.com \
--cc=paulmck@kernel.org \
--cc=quic_neeraju@quicinc.com \
--cc=rcu@vger.kernel.org \
--cc=rostedt@goodmis.org \
--cc=thunder.leizhen@huawei.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
all inboxes | Powered by JetHome®