* [RT] sysrq Z: sleeping function called from invalid context
@ 2011-12-02 23:08 Frank Rowand
2011-12-02 23:49 ` Steven Rostedt
0 siblings, 1 reply; 3+ messages in thread
From: Frank Rowand @ 2011-12-02 23:08 UTC (permalink / raw)
To: Steven Rostedt; +Cc: linux-kernel, linux-rt-users
Hi Steve,
I get a "sleeping function called from invalid context" when I invoke sysrq Z.
I get this both with CONFIG_MAGIC_SYSRQ_FORCE_PRINTK enabled and disabled.
3.0.12-rt29
ARM Pandaboard
I have not tried this on 3.2-rc4-rt5.
[ 900.963226] SysRq : Dump ftrace buffer
[ 900.967163] Dumping ftrace buffer:
[ 900.970733] BUG: sleeping function called from invalid context at kernel/rtmutex.c:645
[ 900.985137] in_atomic(): 0, irqs_disabled(): 128, pid: 563, name: irq/106-OMAP UA
[ 900.992980] 2 locks held by irq/106-OMAP UA/563:
[ 900.997833] #0: (&port_lock_key){+.+...}, at: [<c02d8b14>] serial_omap_irq+0x4c/0x7dc
[ 901.006286] #1: (sysrq_key_table_lock){+.+...}, at: [<c02c13a0>] __handle_sysrq+0x20/0x18c
[ 901.015167] irq event stamp: 45345
[ 901.018737] hardirqs last enabled at (45344): [<c0482f68>] _raw_spin_unlock_irq+0x24/0x4c
[ 901.027435] hardirqs last disabled at (45345): [<c00fb854>] ftrace_dump+0x14/0x23c
[ 901.035400] softirqs last enabled at (0): [<c009dca8>] copy_process+0x364/0xf84
[ 901.043182] softirqs last disabled at (0): [< (null)>] (null)
[ 901.049499] [<c00681b8>] (unwind_backtrace+0x0/0xf0) from [<c04824d0>] (rt_spin_lock+0x24/0x5c)
[ 901.058654] [<c04824d0>] (rt_spin_lock+0x24/0x5c) from [<c00f3b34>] (read_buffer_lock+0x4c/0x6c)
[ 901.067871] [<c00f3b34>] (read_buffer_lock+0x4c/0x6c) from [<c00f5908>] (ring_buffer_empty_cpu+0x50/0x7c)
[ 901.077911] [<c00f5908>] (ring_buffer_empty_cpu+0x50/0x7c) from [<c00fa3cc>] (trace_empty+0x58/0xd8)
[ 901.087524] [<c00fa3cc>] (trace_empty+0x58/0xd8) from [<c00fb9f8>] (ftrace_dump+0x1b8/0x23c)
[ 901.096374] [<c00fb9f8>] (ftrace_dump+0x1b8/0x23c) from [<c02c1428>] (__handle_sysrq+0xa8/0x18c)
[ 901.105621] [<c02c1428>] (__handle_sysrq+0xa8/0x18c) from [<c02d90cc>] (serial_omap_irq+0x604/0x7dc)
[ 901.115203] [<c02d90cc>] (serial_omap_irq+0x604/0x7dc) from [<c00eb934>] (irq_forced_thread_fn+0x20/0x40)
[ 901.125244] [<c00eb934>] (irq_forced_thread_fn+0x20/0x40) from [<c00eb7dc>] (irq_thread+0x144/0x1e4)
[ 901.134887] [<c00eb7dc>] (irq_thread+0x144/0x1e4) from [<c00c094c>] (kthread+0x7c/0x84)
[ 901.143310] [<c00c094c>] (kthread+0x7c/0x84) from [<c0061e30>] (kernel_thread_exit+0x0/0x8)
[ 901.152496] (ftrace buffer empty)
-Frank
^ permalink raw reply [flat|nested] 3+ messages in thread* Re: [RT] sysrq Z: sleeping function called from invalid context
2011-12-02 23:08 [RT] sysrq Z: sleeping function called from invalid context Frank Rowand
@ 2011-12-02 23:49 ` Steven Rostedt
2011-12-03 0:27 ` Frank Rowand
0 siblings, 1 reply; 3+ messages in thread
From: Steven Rostedt @ 2011-12-02 23:49 UTC (permalink / raw)
To: frank.rowand; +Cc: linux-kernel, linux-rt-users
On Fri, 2011-12-02 at 15:08 -0800, Frank Rowand wrote:
> Hi Steve,
>
> I get a "sleeping function called from invalid context" when I invoke sysrq Z.
>
> I get this both with CONFIG_MAGIC_SYSRQ_FORCE_PRINTK enabled and disabled.
Patient: Hey doctor, it hurts when I do this
Doctor: Don't do that.
>
> 3.0.12-rt29
> ARM Pandaboard
>
> I have not tried this on 3.2-rc4-rt5.
>
> [ 900.963226] SysRq : Dump ftrace buffer
> [ 900.967163] Dumping ftrace buffer:
> [ 900.970733] BUG: sleeping function called from invalid context at kernel/rtmutex.c:645
> [ 900.985137] in_atomic(): 0, irqs_disabled(): 128, pid: 563, name: irq/106-OMAP UA
> [ 900.992980] 2 locks held by irq/106-OMAP UA/563:
> [ 900.997833] #0: (&port_lock_key){+.+...}, at: [<c02d8b14>] serial_omap_irq+0x4c/0x7dc
> [ 901.006286] #1: (sysrq_key_table_lock){+.+...}, at: [<c02c13a0>] __handle_sysrq+0x20/0x18c
> [ 901.015167] irq event stamp: 45345
> [ 901.018737] hardirqs last enabled at (45344): [<c0482f68>] _raw_spin_unlock_irq+0x24/0x4c
> [ 901.027435] hardirqs last disabled at (45345): [<c00fb854>] ftrace_dump+0x14/0x23c
> [ 901.035400] softirqs last enabled at (0): [<c009dca8>] copy_process+0x364/0xf84
> [ 901.043182] softirqs last disabled at (0): [< (null)>] (null)
> [ 901.049499] [<c00681b8>] (unwind_backtrace+0x0/0xf0) from [<c04824d0>] (rt_spin_lock+0x24/0x5c)
> [ 901.058654] [<c04824d0>] (rt_spin_lock+0x24/0x5c) from [<c00f3b34>] (read_buffer_lock+0x4c/0x6c)
> [ 901.067871] [<c00f3b34>] (read_buffer_lock+0x4c/0x6c) from [<c00f5908>] (ring_buffer_empty_cpu+0x50/0x7c)
Grumble. I really don't want to make the read_buffer_lock a real spin
lock. I'll have to see what else is called when its held. I you could
try to make it into a raw_spin_lock() if you want and see if it causes
any more issues.
I guess the other question is, what disabled interrupts?
Oh, it's in the lockdep splat above :-p
It's the ftrace_dump code that disables interrupts.
Oh! looking into the ring_buffer code, could you add this:
(totally untested)
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 2467714..2ffbb9d 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -1045,7 +1045,7 @@ static inline int ok_to_lock(void)
if (in_nmi())
return 0;
#ifdef CONFIG_PREEMPT_RT_FULL
- if (in_atomic())
+ if (in_atomic() || irqs_disabled())
return 0;
#endif
return 1;
> [ 901.077911] [<c00f5908>] (ring_buffer_empty_cpu+0x50/0x7c) from [<c00fa3cc>] (trace_empty+0x58/0xd8)
> [ 901.087524] [<c00fa3cc>] (trace_empty+0x58/0xd8) from [<c00fb9f8>] (ftrace_dump+0x1b8/0x23c)
> [ 901.096374] [<c00fb9f8>] (ftrace_dump+0x1b8/0x23c) from [<c02c1428>] (__handle_sysrq+0xa8/0x18c)
> [ 901.105621] [<c02c1428>] (__handle_sysrq+0xa8/0x18c) from [<c02d90cc>] (serial_omap_irq+0x604/0x7dc)
> [ 901.115203] [<c02d90cc>] (serial_omap_irq+0x604/0x7dc) from [<c00eb934>] (irq_forced_thread_fn+0x20/0x40)
> [ 901.125244] [<c00eb934>] (irq_forced_thread_fn+0x20/0x40) from [<c00eb7dc>] (irq_thread+0x144/0x1e4)
> [ 901.134887] [<c00eb7dc>] (irq_thread+0x144/0x1e4) from [<c00c094c>] (kthread+0x7c/0x84)
> [ 901.143310] [<c00c094c>] (kthread+0x7c/0x84) from [<c0061e30>] (kernel_thread_exit+0x0/0x8)
> [ 901.152496] (ftrace buffer empty)
>
> -Frank
^ permalink raw reply related [flat|nested] 3+ messages in thread* Re: [RT] sysrq Z: sleeping function called from invalid context
2011-12-02 23:49 ` Steven Rostedt
@ 2011-12-03 0:27 ` Frank Rowand
0 siblings, 0 replies; 3+ messages in thread
From: Frank Rowand @ 2011-12-03 0:27 UTC (permalink / raw)
To: Steven Rostedt
Cc: Rowand, Frank, linux-kernel@vger.kernel.org,
linux-rt-users@vger.kernel.org
On 12/02/11 15:49, Steven Rostedt wrote:
> On Fri, 2011-12-02 at 15:08 -0800, Frank Rowand wrote:
>> Hi Steve,
>>
>> I get a "sleeping function called from invalid context" when I invoke sysrq Z.
>>
>> I get this both with CONFIG_MAGIC_SYSRQ_FORCE_PRINTK enabled and disabled.
>
> Patient: Hey doctor, it hurts when I do this
>
> Doctor: Don't do that.
I had similar thoughts as I was writing my email.
< snip >
>
> Oh! looking into the ring_buffer code, could you add this:
> (totally untested)
>
> diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
> index 2467714..2ffbb9d 100644
> --- a/kernel/trace/ring_buffer.c
> +++ b/kernel/trace/ring_buffer.c
> @@ -1045,7 +1045,7 @@ static inline int ok_to_lock(void)
> if (in_nmi())
> return 0;
> #ifdef CONFIG_PREEMPT_RT_FULL
> - if (in_atomic())
> + if (in_atomic() || irqs_disabled())
> return 0;
> #endif
> return 1;
I would say the result is good with the patch applied.
If CONFIG_MAGIC_SYSRQ_FORCE_PRINTK is disabled then the splat does not occur
and the ftrace buffer is printed on the console.
If CONFIG_MAGIC_SYSRQ_FORCE_PRINTK is enabled, then the splat does not occur
and the ftrace buffer sometimes is printed on the console. I think that
this is good enough, given that sysrq when CONFIG_PREEMPT_RT_FULL is enabled
is somewhat dicey to begin with.
-Frank
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2011-12-03 0:33 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2011-12-02 23:08 [RT] sysrq Z: sleeping function called from invalid context Frank Rowand
2011-12-02 23:49 ` Steven Rostedt
2011-12-03 0:27 ` Frank Rowand
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.