From: Richard Genoud <richard.genoud@gmail.com>
To: Stanislaw Gruszka <sgruszka@redhat.com>
Cc: Helmut Schaa <helmut.schaa@googlemail.com>,
"linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>,
linux-wireless@vger.kernel.org
Subject: Re: Soft lockup in rt2x00usb_work_rxdone()
Date: Tue, 07 Nov 2017 12:01:23 +0100 [thread overview]
Message-ID: <1510052483.24015.1.camel@gmail.com> (raw)
In-Reply-To: <20171107101320.GA12140@redhat.com>
Le mardi 07 novembre 2017 à 11:13 +0100, Stanislaw Gruszka a écrit :
> On Tue, Nov 07, 2017 at 11:06:39AM +0100, Richard Genoud wrote:
> > > 3 short articles how to configure and use ftrace are here:
> > > https://lwn.net/Articles/365835/
> > > https://lwn.net/Articles/366796/
> > > https://lwn.net/Articles/370423/
> > >
> >
> > I tried with ftrace, but I don't think there's a way to dump the
> > trace
> > when there's a soft lock-up
> > (I can't do anything after the unbind, even the heartbeat led
> > stopped blinking).
> > I saw the /proc/sys/kernel/ftrace_dump_on_oops file, but there's no
> > /proc/sys/kernel/ftrace_dump_on_soft_lock-up file :)
>
> You should configure function trace with rt2x* functions. After that
> start tracing, unbind the device, then stop tracing and provide trace
> output.
Ok, I found a way to display the trace (after the unbind, the board is
frozen and I can't type anything).
Adding
CONFIG_SOFTLOCKUP_DETECTOR=y
CONFIG_BOOTPARAM_SOFTLOCKUP_PANIC=y
along with echo 1 > /proc/sys/kernel/ftrace_dump_on_oops does the trick
(trace is after the stack dump)
# cd /sys/kernel/debug/tracing/
# echo 1 > /proc/sys/kernel/ftrace_dump_on_oops
#
# echo rt2x00usb* > set_ftrace_filter
# echo 0 > tracing_on
# echo function > current_tracer
# echo 1 > tracing_on
# echo 1-2.2 > /sys/bus/usb/drivers/usb/unbind
[board frozen]
watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [kworker/u2:3:188]
CPU: 0 PID: 188 Comm: kworker/u2:3 Not tainted 4.14.0-rc8-00040-g53fb1fe423ba #13
Hardware name: Atmel AT91SAM9
Workqueue: phy0 rt2x00usb_work_rxdone
task: c7b34400 task.stack: c7b4e000
PC is at rb_commit+0x1a8/0x2e4
LR is at ring_buffer_unlock_commit+0x20/0xa4
pc : [<c006c694>] lr : [<c006d724>] psr: 80000013
sp : c7b4fda8 ip : 00000000 fp : c7b4fdc4
r10: c664ee34 r9 : c7b2ed18 r8 : 60000013
r7 : 001c4851 r6 : c780a0e0 r5 : c7319340 r4 : 00008a48
r3 : c7319340 r2 : c664e000 r1 : 00000e38 r0 : 00000e24
Flags: Nzcv IRQs on FIQs on Mode SVC_32 ISA ARM Segment none
Control: 0005317f Table: 27270000 DAC: 00000053
CPU: 0 PID: 188 Comm: kworker/u2:3 Not tainted 4.14.0-rc8-00040-g53fb1fe423ba #13
Hardware name: Atmel AT91SAM9
Workqueue: phy0 rt2x00usb_work_rxdone
[<c000fe00>] (unwind_backtrace) from [<c000dd94>] (show_stack+0x20/0x24)
[<c000dd94>] (show_stack) from [<c05a55e0>] (dump_stack+0x20/0x28)
[<c05a55e0>] (dump_stack) from [<c000b03c>] (show_regs+0x1c/0x20)
[<c000b03c>] (show_regs) from [<c0064c90>] (watchdog_timer_fn+0x148/0x1ac)
[<c0064c90>] (watchdog_timer_fn) from [<c0051dec>] (hrtimer_run_queues+0x128/0x250)
[<c0051dec>] (hrtimer_run_queues) from [<c00512e8>] (run_local_timers+0x18/0x68)
[<c00512e8>] (run_local_timers) from [<c0051370>] (update_process_times+0x38/0x6c)
[<c0051370>] (update_process_times) from [<c005e1c0>] (tick_nohz_handler+0xc0/0x10c)
[<c005e1c0>] (tick_nohz_handler) from [<c03a756c>] (ch2_irq+0x30/0x38)
[<c03a756c>] (ch2_irq) from [<c0046b00>] (__handle_irq_event_percpu+0x74/0x1dc)
[<c0046b00>] (__handle_irq_event_percpu) from [<c0046c94>] (handle_irq_event_percpu+0x2c/0x68)
[<c0046c94>] (handle_irq_event_percpu) from [<c0046d08>] (handle_irq_event+0x38/0x4c)
[<c0046d08>] (handle_irq_event) from [<c0049f54>] (handle_fasteoi_irq+0xa0/0x114)
[<c0049f54>] (handle_fasteoi_irq) from [<c0046320>] (generic_handle_irq+0x28/0x38)
[<c0046320>] (generic_handle_irq) from [<c00463c0>] (__handle_domain_irq+0x90/0xb8)
[<c00463c0>] (__handle_domain_irq) from [<c00094a4>] (aic_handle+0xb0/0xb8)
[<c00094a4>] (aic_handle) from [<c000ea68>] (__irq_svc+0x68/0x84)
Exception stack(0xc7b4fd58 to 0xc7b4fda0)
fd40: 00000e24 00000e38
fd60: c664e000 c7319340 00008a48 c7319340 c780a0e0 001c4851 60000013 c7b2ed18
fd80: c664ee34 c7b4fdc4 00000000 c7b4fda8 c006d724 c006c694 80000013 ffffffff
[<c000ea68>] (__irq_svc) from [<c006c694>] (rb_commit+0x1a8/0x2e4)
[<c006c694>] (rb_commit) from [<c006d724>] (ring_buffer_unlock_commit+0x20/0xa4)
[<c006d724>] (ring_buffer_unlock_commit) from [<c00756f4>] (trace_function+0xe0/0xf0)
[<c00756f4>] (trace_function) from [<c007c794>] (function_trace_call+0xbc/0x11c)
[<c007c794>] (function_trace_call) from [<c000f12c>] (ftrace_graph_call+0x0/0xc)
[<c000f12c>] (ftrace_graph_call) from [<c0337780>] (rt2x00usb_kick_rx_entry+0x14/0x118)
[<c0337780>] (rt2x00usb_kick_rx_entry) from [<c033834c>] (rt2x00usb_clear_entry+0x30/0x34)
[<c033834c>] (rt2x00usb_clear_entry) from [<c0332b10>] (rt2x00lib_rxdone+0x58c/0x5b8)
[<c0332b10>] (rt2x00lib_rxdone) from [<c03376ec>] (rt2x00usb_work_rxdone+0x60/0x7c)
[<c03376ec>] (rt2x00usb_work_rxdone) from [<c002ca64>] (process_one_work+0x1e4/0x3a0)
[<c002ca64>] (process_one_work) from [<c002cf28>] (worker_thread+0x2c8/0x45c)
[<c002cf28>] (worker_thread) from [<c0031f68>] (kthread+0x114/0x130)
[<c0031f68>] (kthread) from [<c000a4c8>] (ret_from_fork+0x14/0x2c)
Kernel panic - not syncing: softlockup: hung tasks
CPU: 0 PID: 188 Comm: kworker/u2:3 Tainted: G L 4.14.0-rc8-00040-g53fb1fe423ba #13
Hardware name: Atmel AT91SAM9
Workqueue: phy0 rt2x00usb_work_rxdone
[<c000fe00>] (unwind_backtrace) from [<c000dd94>] (show_stack+0x20/0x24)
[<c000dd94>] (show_stack) from [<c05a55e0>] (dump_stack+0x20/0x28)
[<c05a55e0>] (dump_stack) from [<c00187d0>] (panic+0xc8/0x260)
[<c00187d0>] (panic) from [<c0064cc8>] (watchdog_timer_fn+0x180/0x1ac)
[<c0064cc8>] (watchdog_timer_fn) from [<c0051dec>] (hrtimer_run_queues+0x128/0x250)
[<c0051dec>] (hrtimer_run_queues) from [<c00512e8>] (run_local_timers+0x18/0x68)
[<c00512e8>] (run_local_timers) from [<c0051370>] (update_process_times+0x38/0x6c)
[<c0051370>] (update_process_times) from [<c005e1c0>] (tick_nohz_handler+0xc0/0x10c)
[<c005e1c0>] (tick_nohz_handler) from [<c03a756c>] (ch2_irq+0x30/0x38)
[<c03a756c>] (ch2_irq) from [<c0046b00>] (__handle_irq_event_percpu+0x74/0x1dc)
[<c0046b00>] (__handle_irq_event_percpu) from [<c0046c94>] (handle_irq_event_percpu+0x2c/0x68)
[<c0046c94>] (handle_irq_event_percpu) from [<c0046d08>] (handle_irq_event+0x38/0x4c)
[<c0046d08>] (handle_irq_event) from [<c0049f54>] (handle_fasteoi_irq+0xa0/0x114)
[<c0049f54>] (handle_fasteoi_irq) from [<c0046320>] (generic_handle_irq+0x28/0x38)
[<c0046320>] (generic_handle_irq) from [<c00463c0>] (__handle_domain_irq+0x90/0xb8)
[<c00463c0>] (__handle_domain_irq) from [<c00094a4>] (aic_handle+0xb0/0xb8)
[<c00094a4>] (aic_handle) from [<c000ea68>] (__irq_svc+0x68/0x84)
Exception stack(0xc7b4fd58 to 0xc7b4fda0)
fd40: 00000e24 00000e38
fd60: c664e000 c7319340 00008a48 c7319340 c780a0e0 001c4851 60000013 c7b2ed18
fd80: c664ee34 c7b4fdc4 00000000 c7b4fda8 c006d724 c006c694 80000013 ffffffff
[<c000ea68>] (__irq_svc) from [<c006c694>] (rb_commit+0x1a8/0x2e4)
[<c006c694>] (rb_commit) from [<c006d724>] (ring_buffer_unlock_commit+0x20/0xa4)
[<c006d724>] (ring_buffer_unlock_commit) from [<c00756f4>] (trace_function+0xe0/0xf0)
[<c00756f4>] (trace_function) from [<c007c794>] (function_trace_call+0xbc/0x11c)
[<c007c794>] (function_trace_call) from [<c000f12c>] (ftrace_graph_call+0x0/0xc)
[<c000f12c>] (ftrace_graph_call) from [<c0337780>] (rt2x00usb_kick_rx_entry+0x14/0x118)
[<c0337780>] (rt2x00usb_kick_rx_entry) from [<c033834c>] (rt2x00usb_clear_entry+0x30/0x34)
[<c033834c>] (rt2x00usb_clear_entry) from [<c0332b10>] (rt2x00lib_rxdone+0x58c/0x5b8)
[<c0332b10>] (rt2x00lib_rxdone) from [<c03376ec>] (rt2x00usb_work_rxdone+0x60/0x7c)
[<c03376ec>] (rt2x00usb_work_rxdone) from [<c002ca64>] (process_one_work+0x1e4/0x3a0)
[<c002ca64>] (process_one_work) from [<c002cf28>] (worker_thread+0x2c8/0x45c)
[<c002cf28>] (worker_thread) from [<c0031f68>] (kthread+0x114/0x130)
[<c0031f68>] (kthread) from [<c000a4c8>] (ret_from_fork+0x14/0x2c)
Dumping ftrace buffer:
---------------------------------
CPU:0 [LOST 1781327 EVENTS]
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
kworker/-188 0.n.. 24110000us : rt2x00usb_kick_rx_entry <-rt2x00usb_clear_entry
kworker/-188 0.n.. 24110000us : rt2x00usb_clear_entry <-rt2x00lib_rxdone
[forever]
> Thanks
> Stanislaw
Thanks,
Richard
next prev parent reply other threads:[~2017-11-07 11:01 UTC|newest]
Thread overview: 11+ messages / expand[flat|nested] mbox.gz Atom feed top
2017-11-06 15:57 Soft lockup in rt2x00usb_work_rxdone() Richard Genoud
2017-11-07 8:53 ` Stanislaw Gruszka
2017-11-07 10:06 ` Richard Genoud
2017-11-07 10:13 ` Stanislaw Gruszka
2017-11-07 11:01 ` Richard Genoud [this message]
2017-11-08 10:37 ` Stanislaw Gruszka
2017-11-08 11:07 ` Richard Genoud
2017-11-08 11:35 ` Stanislaw Gruszka
2017-11-09 10:54 ` Stanislaw Gruszka
2017-11-07 11:13 ` Richard Genoud
2017-11-08 10:41 ` Stanislaw Gruszka
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=1510052483.24015.1.camel@gmail.com \
--to=richard.genoud@gmail.com \
--cc=helmut.schaa@googlemail.com \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-wireless@vger.kernel.org \
--cc=sgruszka@redhat.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;
as well as URLs for NNTP newsgroup(s).