Kernel Deadlock while using uprobes

[Negreanu Marius]

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
-------------- next part --------------



[  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