* regression 3.11-rc1: rmmod hangs after tracing module
@ 2013-07-23 18:07 Arend van Spriel
2013-07-23 18:44 ` Steven Rostedt
0 siblings, 1 reply; 3+ messages in thread
From: Arend van Spriel @ 2013-07-23 18:07 UTC (permalink / raw)
To: Steven Rostedt, linux-kernel
[-- Attachment #1: Type: text/plain, Size: 309 bytes --]
Hi Steven,
During testing of our brcmfmac wireless driver I had a trace-cmd running
along (trace-cmd record -e brcmfmac:*). After the test I stopped the
trace, unplugged my usb device and did a rmmod resulting in the attached
lockdep splat. Hope you have an idea what is going wrong here.
Regards,
Arend
[-- Attachment #2: lockdep-splat.log --]
[-- Type: text/plain, Size: 8128 bytes --]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.298412] usbcore: deregistering interface driver brcmfmac
Jul 23 16:05:00 arend-lp-dev kernel: [23055.304526]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.306019] =============================================
Jul 23 16:05:00 arend-lp-dev kernel: [23055.311417] [ INFO: possible recursive locking detected ]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.316812] 3.11.0-rc1-wl-testing-lockdep-00002-g41cc093-dirty #1 Tainted: G W O
Jul 23 16:05:00 arend-lp-dev kernel: [23055.324893] ---------------------------------------------
Jul 23 16:05:00 arend-lp-dev kernel: [23055.330289] rmmod/3345 is trying to acquire lock:
Jul 23 16:05:00 arend-lp-dev kernel: [23055.334989] (trace_types_lock){+.+.+.}, at: [<c10df3a0>] tracing_reset_all_online_cpus+0x10/0x50
Jul 23 16:05:00 arend-lp-dev kernel: [23055.343921]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.343921] but task is already holding lock:
Jul 23 16:05:00 arend-lp-dev kernel: [23055.349751] (trace_types_lock){+.+.+.}, at: [<c10ef799>] trace_module_notify+0x19/0x270
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353445]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353445] other info that might help us debug this:
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353446] Possible unsafe locking scenario:
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353446]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353447] CPU0
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353448] ----
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353450] lock(trace_types_lock);
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353451] lock(trace_types_lock);
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353452]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353452] *** DEADLOCK ***
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353452]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353453] May be due to missing lock nesting notation
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353453]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353454] 3 locks held by rmmod/3345:
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353464] #0: ((module_notify_list).rwsem){.+.+.+}, at: [<c10683da>] __blocking_notifier_call_chain+0x2a/0x70
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353469] #1: (trace_types_lock){+.+.+.}, at: [<c10ef799>] trace_module_notify+0x19/0x270
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353474] #2: (event_mutex){+.+.+.}, at: [<c10ef7a5>] trace_module_notify+0x25/0x270
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353475]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353475] stack backtrace:
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353479] CPU: 3 PID: 3345 Comm: rmmod Tainted: G W O 3.11.0-rc1-wl-testing-lockdep-00002-g41cc093-dirty #1
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353480] Hardware name: Dell Inc. Latitude E6410/07XJP9, BIOS A07 02/15/2011
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353486] 00000000 00000000 e2659dd4 c1522e3d c1a3b010 e2659e50 c109ee33 c16b70b5
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353492] e1603890 00000d11 c1a3d320 e1603a50 bc1d806f 00000003 e1603a80 00011781
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353497] bc1d806f c18d8e00 00000000 c1a3b010 00000000 00011781 e16035a0 e16035a0
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353498] Call Trace:
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353504] [<c1522e3d>] dump_stack+0x4b/0x66
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353510] [<c109ee33>] __lock_acquire+0x14a3/0x19d0
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353515] [<c10a0038>] ? mark_held_locks+0x68/0x110
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353518] [<c10a0038>] ? mark_held_locks+0x68/0x110
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353522] [<c109f8b9>] lock_acquire+0x79/0x110
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353526] [<c10df3a0>] ? tracing_reset_all_online_cpus+0x10/0x50
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353531] [<c1524b06>] mutex_lock_nested+0x66/0x350
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353535] [<c10df3a0>] ? tracing_reset_all_online_cpus+0x10/0x50
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353540] [<c113e2df>] ? kfree+0x18f/0x1a0
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353543] [<c10ef9dc>] ? trace_module_notify+0x25c/0x270
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353547] [<c10df3a0>] tracing_reset_all_online_cpus+0x10/0x50
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353550] [<c10ef9eb>] trace_module_notify+0x26b/0x270
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353555] [<c152d655>] notifier_call_chain+0x45/0x60
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353559] [<c10683f3>] __blocking_notifier_call_chain+0x43/0x70
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353576] [<f8667140>] ? brcmf_usb_ctlwrite_complete+0x90/0x90 [brcmfmac]
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353580] [<c106843f>] blocking_notifier_call_chain+0x1f/0x30
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353585] [<c10a894e>] SyS_delete_module+0x14e/0x200
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353590] [<c1529b46>] ? restore_all+0xf/0xf
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353593] [<c152d600>] ? __do_page_fault+0x4d0/0x4d0
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353597] [<c10a01cc>] ? trace_hardirqs_on_caller+0xec/0x1b0
Jul 23 16:05:00 arend-lp-dev kernel: [23055.353601] [<c1531061>] sysenter_do_call+0x12/0x32
Jul 23 16:07:12 arend-lp-dev kernel: [23187.532144] INFO: task rmmod:3345 blocked for more than 120 seconds.
Jul 23 16:07:12 arend-lp-dev kernel: [23187.538557] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 23 16:07:12 arend-lp-dev kernel: [23187.546429] rmmod D c12bbdc8 0 3345 3344 0x00000000
Jul 23 16:07:12 arend-lp-dev kernel: [23187.552900] e2659e80 00000096 e2658000 c12bbdc8 e16035a0 f4ccc780 c1865da0 c1865da0
Jul 23 16:07:12 arend-lp-dev kernel: [23187.560839] fe29af00 000014f7 f53d7da0 e16035a0 e15f0000 e2659e90 e16035a0 c10a007b
Jul 23 16:07:12 arend-lp-dev kernel: [23187.568781] 0000007b 000000d8 c17700e0 ffffff10 c109f8cd 00000060 00000246 00000000
Jul 23 16:07:12 arend-lp-dev kernel: [23187.576715] Call Trace:
Jul 23 16:07:12 arend-lp-dev kernel: [23187.579169] [<c12bbdc8>] ? trace_hardirqs_on_thunk+0xc/0x10
Jul 23 16:07:12 arend-lp-dev kernel: [23187.584877] [<c10a007b>] ? mark_held_locks+0xab/0x110
Jul 23 16:07:12 arend-lp-dev kernel: [23187.590058] [<c109f8cd>] ? lock_acquire+0x8d/0x110
Jul 23 16:07:12 arend-lp-dev kernel: [23187.594988] [<c10df3a0>] ? tracing_reset_all_online_cpus+0x10/0x50
Jul 23 16:07:12 arend-lp-dev kernel: [23187.601302] [<c1527d73>] schedule+0x23/0x60
Jul 23 16:07:12 arend-lp-dev kernel: [23187.605580] [<c1528048>] schedule_preempt_disabled+0x18/0x30
Jul 23 16:07:12 arend-lp-dev kernel: [23187.611370] [<c1524bf5>] mutex_lock_nested+0x155/0x350
Jul 23 16:07:12 arend-lp-dev kernel: [23187.616640] [<c10df3a0>] ? tracing_reset_all_online_cpus+0x10/0x50
Jul 23 16:07:12 arend-lp-dev kernel: [23187.622954] [<c10df3a0>] tracing_reset_all_online_cpus+0x10/0x50
Jul 23 16:07:12 arend-lp-dev kernel: [23187.629098] [<c10ef9eb>] trace_module_notify+0x26b/0x270
Jul 23 16:07:12 arend-lp-dev kernel: [23187.634540] [<c152d655>] notifier_call_chain+0x45/0x60
Jul 23 16:07:12 arend-lp-dev kernel: [23187.639819] [<c10683f3>] __blocking_notifier_call_chain+0x43/0x70
Jul 23 16:07:12 arend-lp-dev kernel: [23187.646065] [<f8667140>] ? brcmf_usb_ctlwrite_complete+0x90/0x90 [brcmfmac]
Jul 23 16:07:12 arend-lp-dev kernel: [23187.653161] [<c106843f>] blocking_notifier_call_chain+0x1f/0x30
Jul 23 16:07:12 arend-lp-dev kernel: [23187.659227] [<c10a894e>] SyS_delete_module+0x14e/0x200
Jul 23 16:07:12 arend-lp-dev kernel: [23187.664508] [<c1529b46>] ? restore_all+0xf/0xf
Jul 23 16:07:12 arend-lp-dev kernel: [23187.669093] [<c152d600>] ? __do_page_fault+0x4d0/0x4d0
Jul 23 16:07:12 arend-lp-dev kernel: [23187.674373] [<c10a01cc>] ? trace_hardirqs_on_caller+0xec/0x1b0
Jul 23 16:07:12 arend-lp-dev kernel: [23187.680317] [<c1531061>] sysenter_do_call+0x12/0x32
Jul 23 16:07:12 arend-lp-dev kernel: [23187.685331] INFO: lockdep is turned off.
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: regression 3.11-rc1: rmmod hangs after tracing module
2013-07-23 18:07 regression 3.11-rc1: rmmod hangs after tracing module Arend van Spriel
@ 2013-07-23 18:44 ` Steven Rostedt
2013-07-25 8:32 ` Arend van Spriel
0 siblings, 1 reply; 3+ messages in thread
From: Steven Rostedt @ 2013-07-23 18:44 UTC (permalink / raw)
To: Arend van Spriel; +Cc: linux-kernel, Oleg Nesterov, Masami Hiramatsu
On Tue, 2013-07-23 at 20:07 +0200, Arend van Spriel wrote:
> Hi Steven,
>
> During testing of our brcmfmac wireless driver I had a trace-cmd running
> along (trace-cmd record -e brcmfmac:*). After the test I stopped the
> trace, unplugged my usb device and did a rmmod resulting in the attached
> lockdep splat. Hope you have an idea what is going wrong here.
Thanks for the report!
Does this fix you bug?
-- Steve
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 69cba47..882ec1d 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -1224,18 +1224,17 @@ void tracing_reset_current(int cpu)
tracing_reset(&global_trace.trace_buffer, cpu);
}
+/* Must have trace_types_lock held */
void tracing_reset_all_online_cpus(void)
{
struct trace_array *tr;
- mutex_lock(&trace_types_lock);
list_for_each_entry(tr, &ftrace_trace_arrays, list) {
tracing_reset_online_cpus(&tr->trace_buffer);
#ifdef CONFIG_TRACER_MAX_TRACE
tracing_reset_online_cpus(&tr->max_buffer);
#endif
}
- mutex_unlock(&trace_types_lock);
}
#define SAVED_CMDLINES 128
^ permalink raw reply related [flat|nested] 3+ messages in thread
* Re: regression 3.11-rc1: rmmod hangs after tracing module
2013-07-23 18:44 ` Steven Rostedt
@ 2013-07-25 8:32 ` Arend van Spriel
0 siblings, 0 replies; 3+ messages in thread
From: Arend van Spriel @ 2013-07-25 8:32 UTC (permalink / raw)
To: Steven Rostedt; +Cc: linux-kernel, Oleg Nesterov, Masami Hiramatsu
On 07/23/2013 08:44 PM, Steven Rostedt wrote:
> On Tue, 2013-07-23 at 20:07 +0200, Arend van Spriel wrote:
>> Hi Steven,
>>
>> During testing of our brcmfmac wireless driver I had a trace-cmd running
>> along (trace-cmd record -e brcmfmac:*). After the test I stopped the
>> trace, unplugged my usb device and did a rmmod resulting in the attached
>> lockdep splat. Hope you have an idea what is going wrong here.
>
> Thanks for the report!
>
> Does this fix you bug?
Thanks Steve,
Tested your patch and it indeed fixes my deadlock.
Regards,
Arend
> -- Steve
>
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 69cba47..882ec1d 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -1224,18 +1224,17 @@ void tracing_reset_current(int cpu)
> tracing_reset(&global_trace.trace_buffer, cpu);
> }
>
> +/* Must have trace_types_lock held */
> void tracing_reset_all_online_cpus(void)
> {
> struct trace_array *tr;
>
> - mutex_lock(&trace_types_lock);
> list_for_each_entry(tr, &ftrace_trace_arrays, list) {
> tracing_reset_online_cpus(&tr->trace_buffer);
> #ifdef CONFIG_TRACER_MAX_TRACE
> tracing_reset_online_cpus(&tr->max_buffer);
> #endif
> }
> - mutex_unlock(&trace_types_lock);
> }
>
> #define SAVED_CMDLINES 128
>
>
>
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2013-07-25 8:32 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2013-07-23 18:07 regression 3.11-rc1: rmmod hangs after tracing module Arend van Spriel
2013-07-23 18:44 ` Steven Rostedt
2013-07-25 8:32 ` Arend van Spriel
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.