xen-devel
[Xen-devel] xenstored unsafe lock order detected, xlate_proc_name, evtc
Hello,
I just tried the latest xen/stable-2.6.32.x kernel, ie. 2.6.32.15, with Xen
4.0.0,
and I got this:
http://pasik.reaktio.net/xen/pv_ops-dom0-debug/log-2.6.32.15-pvops-dom0-xen-stable-x86_64.txt
Jun 5 20:28:46 f13 kernel: device vif1.0 entered promiscuous mode
Jun 5 20:28:46 f13 kernel: virbr0: topology change detected, propagating
Jun 5 20:28:46 f13 kernel: virbr0: port 1(vif1.0) entering forwarding state
Jun 5 20:28:47 f13 avahi-daemon[1384]: Registering new address record for
fe80::fcff:ffff:feff:ffff on vif1.0.*.
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel:
======================================================
Jun 5 20:29:28 f13 kernel: [ INFO: HARDIRQ-safe -> HARDIRQ-unsafe lock order
detected ]
Jun 5 20:29:28 f13 kernel: 2.6.32.15 #2
Jun 5 20:29:28 f13 kernel:
------------------------------------------------------
Jun 5 20:29:28 f13 kernel: xenstored/1508 [HC0[0]:SC0[0]:HE0:SE1] is trying to
acquire:
Jun 5 20:29:28 f13 kernel: (proc_subdir_lock){+.+...}, at:
[<ffffffff8117bd76>] xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel: and this task is already holding:
Jun 5 20:29:28 f13 kernel: (&port_user_lock){-.-...}, at: [<ffffffffa015a390>]
evtchn_ioctl+0x1ae/0x2c7 [xen_evtchn]
Jun 5 20:29:28 f13 kernel: which would create a new lock dependency:
Jun 5 20:29:28 f13 kernel: (&port_user_lock){-.-...} ->
(proc_subdir_lock){+.+...}
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel: but this new dependency connects a HARDIRQ-irq-safe
lock:
Jun 5 20:29:28 f13 kernel: (&port_user_lock){-.-...}
Jun 5 20:29:28 f13 kernel: ... which became HARDIRQ-irq-safe at:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108c2e8>] __lock_acquire+0x2d6/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>] lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>] _spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a815>] evtchn_interrupt+0x2b/0x119
[xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffff810b80f4>] handle_IRQ_event+0x53/0x119
Jun 5 20:29:28 f13 kernel: [<ffffffff810ba096>] handle_level_irq+0x7d/0xdf
Jun 5 20:29:28 f13 kernel: [<ffffffff812b72bd>]
__xen_evtchn_do_upcall+0xe7/0x168
Jun 5 20:29:28 f13 kernel: [<ffffffff812b7820>] xen_evtchn_do_upcall+0x37/0x4c
Jun 5 20:29:28 f13 kernel: [<ffffffff81013f3e>]
xen_do_hypervisor_callback+0x1e/0x30
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel: to a HARDIRQ-irq-unsafe lock:
Jun 5 20:29:28 f13 kernel: (proc_subdir_lock){+.+...}
Jun 5 20:29:28 f13 kernel: ... which became HARDIRQ-irq-unsafe at:
Jun 5 20:29:28 f13 kernel: ... [<ffffffff8108c35c>] __lock_acquire+0x34a/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>] lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>] _spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffff8117bd76>] xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel: [<ffffffff8117c8ef>] __proc_create+0x44/0x125
Jun 5 20:29:28 f13 kernel: [<ffffffff8117cc05>] proc_symlink+0x30/0xa3
Jun 5 20:29:28 f13 kernel: [<ffffffff819b8fde>] proc_root_init+0x62/0xb9
Jun 5 20:29:28 f13 kernel: [<ffffffff81995d49>] start_kernel+0x400/0x433
Jun 5 20:29:28 f13 kernel: [<ffffffff819952c1>]
x86_64_start_reservations+0xac/0xb0
Jun 5 20:29:28 f13 kernel: [<ffffffff819990f3>] xen_start_kernel+0x659/0x660
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel: other info that might help us debug this:
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel: 2 locks held by xenstored/1508:
Jun 5 20:29:28 f13 kernel: #0: (&u->bind_mutex){+.+.+.}, at:
[<ffffffffa015a20b>] evtchn_ioctl+0x29/0x2c7 [xen_evtchn]
Jun 5 20:29:28 f13 kernel: #1: (&port_user_lock){-.-...}, at:
[<ffffffffa015a390>] evtchn_ioctl+0x1ae/0x2c7 [xen_evtchn]
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel: the dependencies between HARDIRQ-irq-safe lock and
the holding lock:
Jun 5 20:29:28 f13 kernel: -> (&port_user_lock){-.-...} ops: 0 {
Jun 5 20:29:28 f13 kernel: IN-HARDIRQ-W at:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108c2e8>]
__lock_acquire+0x2d6/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>]
lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>]
_spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a815>]
evtchn_interrupt+0x2b/0x119 [xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffff810b80f4>]
handle_IRQ_event+0x53/0x119
Jun 5 20:29:28 f13 kernel: [<ffffffff810ba096>]
handle_level_irq+0x7d/0xdf
Jun 5 20:29:28 f13 kernel: [<ffffffff812b72bd>]
__xen_evtchn_do_upcall+0xe7/0x168
Jun 5 20:29:28 f13 kernel: [<ffffffff812b7820>]
xen_evtchn_do_upcall+0x37/0x4c
Jun 5 20:29:28 f13 kernel: [<ffffffff81013f3e>]
xen_do_hypervisor_callback+0x1e/0x30
Jun 5 20:29:28 f13 kernel: IN-SOFTIRQ-W at:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108c309>]
__lock_acquire+0x2f7/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>]
lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>]
_spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a815>]
evtchn_interrupt+0x2b/0x119 [xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffff810b80f4>]
handle_IRQ_event+0x53/0x119
Jun 5 20:29:28 f13 kernel: [<ffffffff810ba096>]
handle_level_irq+0x7d/0xdf
Jun 5 20:29:28 f13 kernel: [<ffffffff812b72bd>]
__xen_evtchn_do_upcall+0xe7/0x168
Jun 5 20:29:28 f13 kernel: [<ffffffff812b7820>]
xen_evtchn_do_upcall+0x37/0x4c
Jun 5 20:29:28 f13 kernel: [<ffffffff81013f3e>]
xen_do_hypervisor_callback+0x1e/0x30
Jun 5 20:29:28 f13 kernel: INITIAL USE at:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108c3d3>]
__lock_acquire+0x3c1/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>]
lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>]
_spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a815>]
evtchn_interrupt+0x2b/0x119 [xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffff810b80f4>]
handle_IRQ_event+0x53/0x119
Jun 5 20:29:28 f13 kernel: [<ffffffff810ba096>]
handle_level_irq+0x7d/0xdf
Jun 5 20:29:28 f13 kernel: [<ffffffff812b72bd>]
__xen_evtchn_do_upcall+0xe7/0x168
Jun 5 20:29:28 f13 kernel: [<ffffffff812b7820>]
xen_evtchn_do_upcall+0x37/0x4c
Jun 5 20:29:28 f13 kernel: [<ffffffff81013f3e>]
xen_do_hypervisor_callback+0x1e/0x30
Jun 5 20:29:28 f13 kernel: }
Jun 5 20:29:28 f13 kernel: ... key at: [<ffffffffa015afb8>]
__key.27039+0x0/0xfffffffffffffaaa [xen_evtchn]
Jun 5 20:29:28 f13 kernel: ... acquired at:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108bfb1>] check_irq_usage+0x5d/0xbe
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ca6a>] __lock_acquire+0xa58/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>] lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>] _spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffff8117bd76>] xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel: [<ffffffff8117be94>] remove_proc_entry+0x34/0x221
Jun 5 20:29:28 f13 kernel: [<ffffffff810bab5b>]
unregister_handler_proc+0x31/0x35
Jun 5 20:29:28 f13 kernel: [<ffffffff810b925a>] __free_irq+0x104/0x193
Jun 5 20:29:28 f13 kernel: [<ffffffff810b9321>] free_irq+0x38/0x53
Jun 5 20:29:28 f13 kernel: [<ffffffff812b7c03>]
unbind_from_irqhandler+0x15/0x20
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a09a>]
evtchn_unbind_from_user+0x23/0x36 [xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a3c7>] evtchn_ioctl+0x1e5/0x2c7
[xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffff81135e95>] vfs_ioctl+0x22/0x87
Jun 5 20:29:28 f13 kernel: [<ffffffff811363fe>] do_vfs_ioctl+0x488/0x4ce
Jun 5 20:29:28 f13 kernel: [<ffffffff8113649a>] sys_ioctl+0x56/0x79
Jun 5 20:29:28 f13 kernel: [<ffffffff81012cb2>]
system_call_fastpath+0x16/0x1b
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel: the dependencies between the lock to be acquired
and HARDIRQ-irq-unsafe lock:
Jun 5 20:29:28 f13 kernel: -> (proc_subdir_lock){+.+...} ops: 0 {
Jun 5 20:29:28 f13 kernel: HARDIRQ-ON-W at:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108c35c>]
__lock_acquire+0x34a/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>]
lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>]
_spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffff8117bd76>]
xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel: [<ffffffff8117c8ef>]
__proc_create+0x44/0x125
Jun 5 20:29:28 f13 kernel: [<ffffffff8117cc05>]
proc_symlink+0x30/0xa3
Jun 5 20:29:28 f13 kernel: [<ffffffff819b8fde>]
proc_root_init+0x62/0xb9
Jun 5 20:29:28 f13 kernel: [<ffffffff81995d49>]
start_kernel+0x400/0x433
Jun 5 20:29:28 f13 kernel: [<ffffffff819952c1>]
x86_64_start_reservations+0xac/0xb0
Jun 5 20:29:28 f13 kernel: [<ffffffff819990f3>]
xen_start_kernel+0x659/0x660
Jun 5 20:29:28 f13 kernel: SOFTIRQ-ON-W at:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108c37d>]
__lock_acquire+0x36b/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>]
lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>]
_spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffff8117bd76>]
xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel: [<ffffffff8117c8ef>]
__proc_create+0x44/0x125
Jun 5 20:29:28 f13 kernel: [<ffffffff8117cc05>]
proc_symlink+0x30/0xa3
Jun 5 20:29:28 f13 kernel: [<ffffffff819b8fde>]
proc_root_init+0x62/0xb9
Jun 5 20:29:28 f13 kernel: [<ffffffff81995d49>]
start_kernel+0x400/0x433
Jun 5 20:29:28 f13 kernel: [<ffffffff819952c1>]
x86_64_start_reservations+0xac/0xb0
Jun 5 20:29:28 f13 kernel: [<ffffffff819990f3>]
xen_start_kernel+0x659/0x660
Jun 5 20:29:28 f13 kernel: INITIAL USE at:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108c3d3>]
__lock_acquire+0x3c1/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>]
lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>]
_spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffff8117bd76>]
xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel: [<ffffffff8117c8ef>]
__proc_create+0x44/0x125
Jun 5 20:29:28 f13 kernel: [<ffffffff8117cc05>]
proc_symlink+0x30/0xa3
Jun 5 20:29:28 f13 kernel: [<ffffffff819b8fde>]
proc_root_init+0x62/0xb9
Jun 5 20:29:28 f13 kernel: [<ffffffff81995d49>]
start_kernel+0x400/0x433
Jun 5 20:29:28 f13 kernel: [<ffffffff819952c1>]
x86_64_start_reservations+0xac/0xb0
Jun 5 20:29:28 f13 kernel: [<ffffffff819990f3>]
xen_start_kernel+0x659/0x660
Jun 5 20:29:28 f13 kernel: }
Jun 5 20:29:28 f13 kernel: ... key at: [<ffffffff8172b238>]
proc_subdir_lock+0x18/0x40
Jun 5 20:29:28 f13 kernel: ... acquired at:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108bfb1>] check_irq_usage+0x5d/0xbe
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ca6a>] __lock_acquire+0xa58/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>] lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>] _spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffff8117bd76>] xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel: [<ffffffff8117be94>] remove_proc_entry+0x34/0x221
Jun 5 20:29:28 f13 kernel: [<ffffffff810bab5b>]
unregister_handler_proc+0x31/0x35
Jun 5 20:29:28 f13 kernel: [<ffffffff810b925a>] __free_irq+0x104/0x193
Jun 5 20:29:28 f13 kernel: [<ffffffff810b9321>] free_irq+0x38/0x53
Jun 5 20:29:28 f13 kernel: [<ffffffff812b7c03>]
unbind_from_irqhandler+0x15/0x20
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a09a>]
evtchn_unbind_from_user+0x23/0x36 [xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a3c7>] evtchn_ioctl+0x1e5/0x2c7
[xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffff81135e95>] vfs_ioctl+0x22/0x87
Jun 5 20:29:28 f13 kernel: [<ffffffff811363fe>] do_vfs_ioctl+0x488/0x4ce
Jun 5 20:29:28 f13 kernel: [<ffffffff8113649a>] sys_ioctl+0x56/0x79
Jun 5 20:29:28 f13 kernel: [<ffffffff81012cb2>]
system_call_fastpath+0x16/0x1b
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel:
Jun 5 20:29:28 f13 kernel: stack backtrace:
Jun 5 20:29:28 f13 kernel: Pid: 1508, comm: xenstored Not tainted 2.6.32.15 #2
Jun 5 20:29:28 f13 kernel: Call Trace:
Jun 5 20:29:28 f13 kernel: [<ffffffff8108bf40>] check_usage+0x349/0x35d
Jun 5 20:29:28 f13 kernel: [<ffffffff8100f465>] ? xen_sched_clock+0x14/0x8c
Jun 5 20:29:28 f13 kernel: [<ffffffff8100f572>] ? check_events+0x12/0x20
Jun 5 20:29:28 f13 kernel: [<ffffffff8108bfb1>] check_irq_usage+0x5d/0xbe
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ca6a>] __lock_acquire+0xa58/0xd3a
Jun 5 20:29:28 f13 kernel: [<ffffffff8100f465>] ? xen_sched_clock+0x14/0x8c
Jun 5 20:29:28 f13 kernel: [<ffffffff8108ce28>] lock_acquire+0xdc/0x102
Jun 5 20:29:28 f13 kernel: [<ffffffff8117bd76>] ? xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel: [<ffffffff8100f572>] ? check_events+0x12/0x20
Jun 5 20:29:28 f13 kernel: [<ffffffff81170076>] ? posix_acl_clone+0x10/0x31
Jun 5 20:29:28 f13 kernel: [<ffffffff81478cf1>] _spin_lock+0x36/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffff8117bd76>] ? xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel: [<ffffffff8117bd76>] xlate_proc_name+0x3d/0xbb
Jun 5 20:29:28 f13 kernel: [<ffffffff8117be94>] remove_proc_entry+0x34/0x221
Jun 5 20:29:28 f13 kernel: [<ffffffff8100ede1>] ?
xen_force_evtchn_callback+0xd/0xf
Jun 5 20:29:28 f13 kernel: [<ffffffff8100f572>] ? check_events+0x12/0x20
Jun 5 20:29:28 f13 kernel: [<ffffffff8100ede1>] ?
xen_force_evtchn_callback+0xd/0xf
Jun 5 20:29:28 f13 kernel: [<ffffffff8100f572>] ? check_events+0x12/0x20
Jun 5 20:29:28 f13 kernel: [<ffffffff8100ede1>] ?
xen_force_evtchn_callback+0xd/0xf
Jun 5 20:29:28 f13 kernel: [<ffffffff8100f572>] ? check_events+0x12/0x20
Jun 5 20:29:28 f13 kernel: [<ffffffff810bab5b>]
unregister_handler_proc+0x31/0x35
Jun 5 20:29:28 f13 kernel: [<ffffffff810b925a>] __free_irq+0x104/0x193
Jun 5 20:29:28 f13 kernel: [<ffffffff810b9321>] free_irq+0x38/0x53
Jun 5 20:29:28 f13 kernel: [<ffffffff812b7c03>]
unbind_from_irqhandler+0x15/0x20
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a09a>]
evtchn_unbind_from_user+0x23/0x36 [xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffffa015a3c7>] evtchn_ioctl+0x1e5/0x2c7
[xen_evtchn]
Jun 5 20:29:28 f13 kernel: [<ffffffffa015643e>] ? privcmd_ioctl+0x75/0x87
[xenfs]
Jun 5 20:29:28 f13 kernel: [<ffffffff81135e95>] vfs_ioctl+0x22/0x87
Jun 5 20:29:28 f13 kernel: [<ffffffff8100ede1>] ?
xen_force_evtchn_callback+0xd/0xf
Jun 5 20:29:28 f13 kernel: [<ffffffff811363fe>] do_vfs_ioctl+0x488/0x4ce
Jun 5 20:29:28 f13 kernel: [<ffffffff81012cea>] ? sysret_check+0x2e/0x69
Jun 5 20:29:28 f13 kernel: [<ffffffff8113649a>] sys_ioctl+0x56/0x79
Jun 5 20:29:28 f13 kernel: [<ffffffff81012cb2>] system_call_fastpath+0x16/0x1b
Jun 5 20:29:29 f13 avahi-daemon[1384]: Withdrawing address record for
fe80::fcff:ffff:feff:ffff on vif1.0.
Jun 5 20:29:29 f13 kernel: virbr0: port 1(vif1.0) entering disabled state
Jun 5 20:29:29 f13 kernel: virbr0: port 1(vif1.0) entering disabled state
Kernel .config here:
http://pasik.reaktio.net/xen/pv_ops-dom0-debug/config-2.6.32.15-pvops-dom0-xen-stable-x86_64
Any ideas?
-- Pasi
_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-devel
|
<Prev in Thread] |
Current Thread |
[Next in Thread>
|
- [Xen-devel] xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock,
Pasi Kärkkäinen <=
|
Previous by Date: |
Re: [Xen-users] Re: [Xen-devel] ARP problems with xen 4.0 with pvops kernel 2.6.32.15, Jeremy Fitzhardinge |
Next by Date: |
[Xen-devel] Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock, Jeremy Fitzhardinge |
Previous by Thread: |
Re: [Xen-devel] xenfs aka /proc/xen, Bastian Blank |
Next by Thread: |
[Xen-devel] Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock, Jeremy Fitzhardinge |
Indexes: |
[Date]
[Thread]
[Top]
[All Lists] |
|
|