public inbox for systemtap@sourceware.org
 help / color / mirror / Atom feed
* Kernel Deadlock while using uprobes
@ 2012-04-09 12:30 Negreanu Marius
  2012-04-09 17:48 ` Josh Stone
  0 siblings, 1 reply; 3+ messages in thread
From: Negreanu Marius @ 2012-04-09 12:30 UTC (permalink / raw)
  To: systemtap

[-- Attachment #1: Type: text/plain, Size: 535 bytes --]

I managed to get a 3.0 kernel patched with uprobes from here[1].
The kernel probing works fine as far as disktop.stp can test that.

But, when I'm trying to insert a uprobe, the kernel detects a deadlock.
The script I'm using is:
echo 'probe process("/bin/ping").function("main") { print($$parms) }'
> /tmp/cfg/test.stp
and the deadlock is the one attached.

Do you have any pointers on this one ?

Thanks,
Marius


1:  http://repos.fedorapeople.org/repos/jistone/kernel-uprobes/fedora-15/SRPMS/kernel-2.6.40.4-6.uprobes2.fc15.src.rpm

[-- Attachment #2: dmesg.txt --]
[-- Type: text/plain, Size: 4854 bytes --]




[  173.575760]
[  173.575765] =================================
[  173.581601] [ INFO: inconsistent lock state ]
[  173.585946] 3.0.22-mid26-00008-g48ae378-dirty #10
[  173.590690] ---------------------------------
[  173.595033] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
[  173.601086] migration/1/7 [HC0[0]:SC1[1]:HE1:SE0] takes:
[  173.606382]  (task_utrace_lock){?.-...}, at: [<f6e13cfd>] spin_lock+0xd/0xf [test]
[  173.613996] {IN-HARDIRQ-W} state was registered at:
[  173.618857]   [<c10693db>] __lock_acquire+0x244/0xc31
[  173.623950]   [<c106a327>] lock_acquire+0x12d/0x167
[  173.628807]   [<c15541e1>] _raw_spin_lock+0x43/0x51
[  173.633675]   [<f6e13cfd>] spin_lock+0xd/0xf [test]
[  173.638590]   [<f6e13efc>] task_utrace_struct+0x15/0x2d [test]
[  173.644417]   [<f6e15af0>] utrace_report_exec+0x1d/0xd5 [test]
[  173.650285]   [<c1091af7>] ftrace_ops_list_func+0x99/0xdf
[  173.655675]   [<c155a3af>] ftrace_call+0x5/0x8
[  173.660148]   [<c101459b>] smp_apic_timer_interrupt+0x6b/0x7d
[  173.665946]   [<c155514a>] apic_timer_interrupt+0x36/0x3c
[  173.671465]   [<c1080743>] cpu_stopper_thread+0xbf/0x17b
[  173.676822]   [<c1055bd2>] kthread+0x68/0x6d
[  173.681207]   [<c155a382>] kernel_thread_helper+0x6/0x10
[  173.686564] irq event stamp: 290
[  173.689807] hardirqs last  enabled at (290): [<c104060a>] __do_softirq+0x51/0x1f4
[  173.697415] hardirqs last disabled at (288): [<c1555143>] apic_timer_interrupt+0x2f/0x3c
[  173.705623] softirqs last  enabled at (250): [<c1040798>] __do_softirq+0x1df/0x1f4
[  173.713239] softirqs last disabled at (289): [<c1003aad>] do_softirq+0x58/0xa7
[  173.720589]
[  173.720591] other info that might help us debug this:
[  173.727234]  Possible unsafe locking scenario:
[  173.727237]
[  173.733192]        CPU0
[  173.735655]        ----
[  173.738192]   lock(task_utrace_lock);
[  173.741912]   <Interrupt>
[  173.744550]     lock(task_utrace_lock);
[  173.748440]
[  173.748443]  *** DEADLOCK ***
[  173.748446]
[  173.754496] no locks held by migration/1/7.
[  173.758693]
[  173.758695] stack backtrace:
[  173.763165] Pid: 7, comm: migration/1 Tainted: G        WC  3.0.22-mid26-00008-g48ae378-dirty #10
[  173.772061] Call Trace:
[  173.774532]  [<c106807f>] valid_state+0x1e2/0x1ef
[  173.779271]  [<c1068180>] mark_lock+0xf4/0x21a
[  173.783818]  [<c124b59c>] ? cpumask_next_and+0x23/0x2f
[  173.788985]  [<c1068b56>] ? check_usage_forwards+0x69/0x69
[  173.794501]  [<c1069449>] __lock_acquire+0x2b2/0xc31
[  173.799575]  [<c1069db9>] ? __lock_acquire+0xc22/0xc31
[  173.804749]  [<f6e13cfd>] ? spin_lock+0xd/0xf [test]
[  173.809815]  [<c106a327>] lock_acquire+0x12d/0x167
[  173.814637]  [<f6e13cfd>] ? spin_lock+0xd/0xf [test]
[  173.819708]  [<c15541e1>] _raw_spin_lock+0x43/0x51
[  173.824530]  [<f6e13cfd>] ? spin_lock+0xd/0xf [test]
[  173.829525]  [<f6e13cfd>] spin_lock+0xd/0xf [test]
[  173.834347]  [<f6e13efc>] task_utrace_struct+0x15/0x2d [test]
[  173.840129]  [<f6e15af0>] utrace_report_exec+0x1d/0xd5 [test]
[  173.845985]  [<c1091af7>] ftrace_ops_list_func+0x99/0xdf
[  173.851324]  [<c104069a>] ? __do_softirq+0xe1/0x1f4
[  173.856304]  [<c104755d>] ? run_timer_softirq+0xa/0x2f3
[  173.861559]  [<c155a3af>] ftrace_call+0x5/0x8
[  173.866015]  [<c1047562>] ? run_timer_softirq+0xf/0x2f3
[  173.871268]  [<c109166b>] ? rcu_read_lock_held+0x1d/0x1f
[  173.876684]  [<c1091b08>] ? ftrace_ops_list_func+0xaa/0xdf
[  173.882195]  [<c10405dc>] ? __do_softirq+0x23/0x1f4
[  173.887170]  [<c10402a5>] ? __local_bh_disable+0x6/0x86
[  173.892421]  [<c104060a>] ? __do_softirq+0x51/0x1f4
[  173.897322]  [<c10405b9>] ? irq_enter+0x5f/0x5f
[  173.901951]  [<c104069a>] __do_softirq+0xe1/0x1f4
[  173.906682]  [<c10405b9>] ? irq_enter+0x5f/0x5f
[  173.911310]  <IRQ>  [<c1040407>] ? irq_exit+0x46/0xb1
[  173.916416]  [<c10145a0>] ? smp_apic_timer_interrupt+0x70/0x7d
[  173.922353]  [<c1253b30>] ? trace_hardirqs_off_thunk+0xc/0x10
[  173.928128]  [<c155514a>] ? apic_timer_interrupt+0x36/0x3c
[  173.933722]  [<c10808b7>] ? stop_machine_cpu_stop+0xa2/0xa9
[  173.939324]  [<c1080743>] ? cpu_stopper_thread+0xbf/0x17b
[  173.944828]  [<c1557400>] ? sub_preempt_count+0x8b/0x98
[  173.950080]  [<c155296e>] ? __schedule+0x72a/0x757
[  173.954895]  [<c1080815>] ? cpumask_weight+0x16/0x16
[  173.959965]  [<c1554a0a>] ? _raw_spin_unlock_irqrestore+0x3b/0x5e
[  173.966089]  [<c15529c5>] ? preempt_schedule+0x2a/0x41
[  173.971330]  [<c1554a29>] ? _raw_spin_unlock_irqrestore+0x5a/0x5e
[  173.977453]  [<c102d2ec>] ? complete+0x48/0x4f
[  173.982000]  [<c1080684>] ? res_counter_init+0x43/0x43
[  173.987165]  [<c1055bd2>] ? kthread+0x68/0x6d
[  173.991629]  [<c1055b6a>] ? __init_kthread_worker+0x4d/0x4d
[  173.997231]  [<c155a382>] ? kernel_thread_helper+0x6/0x10


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

* Re: Kernel Deadlock while using uprobes
  2012-04-09 12:30 Kernel Deadlock while using uprobes Negreanu Marius
@ 2012-04-09 17:48 ` Josh Stone
  2012-04-12 18:32   ` Negreanu Marius
  0 siblings, 1 reply; 3+ messages in thread
From: Josh Stone @ 2012-04-09 17:48 UTC (permalink / raw)
  To: SystemTap, groleo; +Cc: David Smith

On 04/09/2012 05:30 AM, Negreanu Marius wrote:
> I managed to get a 3.0 kernel patched with uprobes from here[1].
> The kernel probing works fine as far as disktop.stp can test that.
> 
> But, when I'm trying to insert a uprobe, the kernel detects a deadlock.
> The script I'm using is:
> echo 'probe process("/bin/ping").function("main") { print($$parms) }'
>> /tmp/cfg/test.stp
> and the deadlock is the one attached.

> [  173.733192]        CPU0
> [  173.735655]        ----
> [  173.738192]   lock(task_utrace_lock);
> [  173.741912]   <Interrupt>
> [  173.744550]     lock(task_utrace_lock);
> [  173.748440]
> [  173.748443]  *** DEADLOCK ***

Hmm, looks like we have inconsistent interrupt state while taking that
lock.  We either need to disable interrupts while holding it, or make
sure that it's never attempted within any interrupt.  This is dsmith's
utrace port, hopefully he can take a closer look.

> 1:  http://repos.fedorapeople.org/repos/jistone/kernel-uprobes/fedora-15/SRPMS/kernel-2.6.40.4-6.uprobes2.fc15.src.rpm

Do note that this new uprobes is still under heavy development, and I
haven't been keeping that repo up to date.  Anton Arapov has much newer
builds available here:
http://repos.fedorapeople.org/repos/aarapov/kernel-uprobes/

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

* Re: Kernel Deadlock while using uprobes
  2012-04-09 17:48 ` Josh Stone
@ 2012-04-12 18:32   ` Negreanu Marius
  0 siblings, 0 replies; 3+ messages in thread
From: Negreanu Marius @ 2012-04-12 18:32 UTC (permalink / raw)
  To: Josh Stone; +Cc: SystemTap, David Smith

I disabled lockdep since it wasn't helping much.
This resulted in a different looking deadlock(see below).
From the code, I can't find a way so that task_utrace_lock is held
twice by the same task unless STAPCONF_UTRACE_VIA_FTRACE has
something to do with it.

I'm thinking maybe ftrace is tracing the tracing code in systemtap, thus
leading to a deadlock if the systemtap callback is called by ftrace.
The deadlock doesn't happen when using STAPCONF_UTRACE_VIA_TRACEPOINTS .



[   52.207772] =============================================
[   52.214703] [ INFO: possible recursive locking detected ]
[   52.220090] 3.0.22-mid26-00008-g48ae378-dirty #14
[   52.224813] ---------------------------------------------
[   52.230305] stapio/3210 is trying to acquire lock:
[   52.235116]  (task_utrace_lock){-.-...}, at: [<f6680ebd>]
task_utrace_struct+0x16/0x33 [test]
[   52.243808]
[   52.243811] but task is already holding lock:
[   52.249754]  (task_utrace_lock){-.-...}, at: [<f6680ebd>]
task_utrace_struct+0x16/0x33 [test]
[   52.258380]
[   52.258383] other info that might help us debug this:
[   52.265017]  Possible unsafe locking scenario:
[   52.265020]
[   52.270972]        CPU0
[   52.273511]        ----
[   52.275968]   lock(task_utrace_lock);
[   52.279679]   lock(task_utrace_lock);

On Mon, Apr 9, 2012 at 8:48 PM, Josh Stone <jistone@redhat.com> wrote:
> On 04/09/2012 05:30 AM, Negreanu Marius wrote:
>> I managed to get a 3.0 kernel patched with uprobes from here[1].
>> The kernel probing works fine as far as disktop.stp can test that.
>>
>> But, when I'm trying to insert a uprobe, the kernel detects a deadlock.
>> The script I'm using is:
>> echo 'probe process("/bin/ping").function("main") { print($$parms) }'
>>> /tmp/cfg/test.stp
>> and the deadlock is the one attached.
>
>> [  173.733192]        CPU0
>> [  173.735655]        ----
>> [  173.738192]   lock(task_utrace_lock);
>> [  173.741912]   <Interrupt>
>> [  173.744550]     lock(task_utrace_lock);
>> [  173.748440]
>> [  173.748443]  *** DEADLOCK ***
>
> Hmm, looks like we have inconsistent interrupt state while taking that
> lock.  We either need to disable interrupts while holding it, or make
> sure that it's never attempted within any interrupt.  This is dsmith's
> utrace port, hopefully he can take a closer look.
>
>> 1:  http://repos.fedorapeople.org/repos/jistone/kernel-uprobes/fedora-15/SRPMS/kernel-2.6.40.4-6.uprobes2.fc15.src.rpm
>
> Do note that this new uprobes is still under heavy development, and I
> haven't been keeping that repo up to date.  Anton Arapov has much newer
> builds available here:
> http://repos.fedorapeople.org/repos/aarapov/kernel-uprobes/



-- 
Regards!
http://groleo.wordpress.com

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

end of thread, other threads:[~2012-04-12 18:32 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-04-09 12:30 Kernel Deadlock while using uprobes Negreanu Marius
2012-04-09 17:48 ` Josh Stone
2012-04-12 18:32   ` Negreanu Marius

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 read-only IMAP folder(s) and NNTP newsgroup(s).