xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user

xen-devel.lists.xenproject.org archive mirror
 help / color / mirror / Atom feed

* xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock
@ 2010-06-06 17:33 Pasi Kärkkäinen
  2010-06-06 17:41 ` Jeremy Fitzhardinge
  0 siblings, 1 reply; 9+ messages in thread
From: Pasi Kärkkäinen @ 2010-06-06 17:33 UTC (permalink / raw)
  To: xen-devel; +Cc: Jeremy Fitzhardinge

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

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

* Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock
  2010-06-06 17:33 xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock Pasi Kärkkäinen
@ 2010-06-06 17:41 ` Jeremy Fitzhardinge
  2010-06-06 18:54   ` Pasi Kärkkäinen
  0 siblings, 1 reply; 9+ messages in thread
From: Jeremy Fitzhardinge @ 2010-06-06 17:41 UTC (permalink / raw)
  To: Pasi Kärkkäinen; +Cc: xen-devel

On 06/06/2010 10:33 AM, Pasi Kärkkäinen wrote:
> 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
>   

Does this help?

>From 3f5e554f669098c84c82ce75e7577f7e0f3fccde Mon Sep 17 00:00:00 2001
From: Jeremy Fitzhardinge <jeremy.fitzhardinge@citrix.com>
Date: Fri, 28 May 2010 15:28:27 -0700
Subject: [PATCH] xen/evtchn: don't do unbind_from_irqhandler under spinlock

unbind_from_irqhandler can end up doing /proc operations, which can't
happen under a spinlock.  So before removing the IRQ handler,
disable the irq under the port_user lock (masking the underlying event
channel and making sure the irq handler isn't running concurrently and
won't start running), then remove the handler without the lock.

Signed-off-by: Jeremy Fitzhardinge <jeremy.fitzhardinge@citrix.com>

diff --git a/drivers/xen/evtchn.c b/drivers/xen/evtchn.c
index f79ac5c..6a3a129 100644
--- a/drivers/xen/evtchn.c
+++ b/drivers/xen/evtchn.c
@@ -375,10 +375,12 @@ static long evtchn_ioctl(struct file *file,
 			break;
 		}
 
-		evtchn_unbind_from_user(u, unbind.port);
+		disable_irq(irq_from_evtchn(unbind.port));
 
 		spin_unlock_irq(&port_user_lock);
 
+		evtchn_unbind_from_user(u, unbind.port);
+
 		rc = 0;
 		break;
 	}
@@ -484,11 +486,18 @@ static int evtchn_release(struct inode *inode, struct file *filp)
 		if (get_port_user(i) != u)
 			continue;
 
-		evtchn_unbind_from_user(get_port_user(i), i);
+		disable_irq(irq_from_evtchn(i));
 	}
 
 	spin_unlock_irq(&port_user_lock);
 
+	for (i = 0; i < NR_EVENT_CHANNELS; i++) {
+		if (get_port_user(i) != u)
+			continue;
+
+		evtchn_unbind_from_user(get_port_user(i), i);
+	}
+
 	kfree(u->name);
 	kfree(u);
 

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

* Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock
  2010-06-06 17:41 ` Jeremy Fitzhardinge
@ 2010-06-06 18:54   ` Pasi Kärkkäinen
  2010-06-07 12:58     ` Pasi Kärkkäinen
  0 siblings, 1 reply; 9+ messages in thread
From: Pasi Kärkkäinen @ 2010-06-06 18:54 UTC (permalink / raw)
  To: Jeremy Fitzhardinge; +Cc: xen-devel

On Sun, Jun 06, 2010 at 10:41:04AM -0700, Jeremy Fitzhardinge wrote:
> On 06/06/2010 10:33 AM, Pasi Kärkkäinen wrote:
> > 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
> >   
> 
> Does this help?
> 

It gave failing hunks so I had to manually apply it to 2.6.32.15, 
but it seems to fix that issue. No "unsafe lock order" messages anymore.

Thanks!

-- Pasi

> From 3f5e554f669098c84c82ce75e7577f7e0f3fccde Mon Sep 17 00:00:00 2001
> From: Jeremy Fitzhardinge <jeremy.fitzhardinge@citrix.com>
> Date: Fri, 28 May 2010 15:28:27 -0700
> Subject: [PATCH] xen/evtchn: don't do unbind_from_irqhandler under spinlock
> 
> unbind_from_irqhandler can end up doing /proc operations, which can't
> happen under a spinlock.  So before removing the IRQ handler,
> disable the irq under the port_user lock (masking the underlying event
> channel and making sure the irq handler isn't running concurrently and
> won't start running), then remove the handler without the lock.
> 
> Signed-off-by: Jeremy Fitzhardinge <jeremy.fitzhardinge@citrix.com>
> 
> diff --git a/drivers/xen/evtchn.c b/drivers/xen/evtchn.c
> index f79ac5c..6a3a129 100644
> --- a/drivers/xen/evtchn.c
> +++ b/drivers/xen/evtchn.c
> @@ -375,10 +375,12 @@ static long evtchn_ioctl(struct file *file,
>  			break;
>  		}
>  
> -		evtchn_unbind_from_user(u, unbind.port);
> +		disable_irq(irq_from_evtchn(unbind.port));
>  
>  		spin_unlock_irq(&port_user_lock);
>  
> +		evtchn_unbind_from_user(u, unbind.port);
> +
>  		rc = 0;
>  		break;
>  	}
> @@ -484,11 +486,18 @@ static int evtchn_release(struct inode *inode, struct file *filp)
>  		if (get_port_user(i) != u)
>  			continue;
>  
> -		evtchn_unbind_from_user(get_port_user(i), i);
> +		disable_irq(irq_from_evtchn(i));
>  	}
>  
>  	spin_unlock_irq(&port_user_lock);
>  
> +	for (i = 0; i < NR_EVENT_CHANNELS; i++) {
> +		if (get_port_user(i) != u)
> +			continue;
> +
> +		evtchn_unbind_from_user(get_port_user(i), i);
> +	}
> +
>  	kfree(u->name);
>  	kfree(u);
>  
> 
> 

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

* Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock
  2010-06-06 18:54   ` Pasi Kärkkäinen
@ 2010-06-07 12:58     ` Pasi Kärkkäinen
  2010-06-07 16:50       ` Jeremy Fitzhardinge
  0 siblings, 1 reply; 9+ messages in thread
From: Pasi Kärkkäinen @ 2010-06-07 12:58 UTC (permalink / raw)
  To: Jeremy Fitzhardinge; +Cc: xen-devel

On Sun, Jun 06, 2010 at 09:54:01PM +0300, Pasi Kärkkäinen wrote:
> On Sun, Jun 06, 2010 at 10:41:04AM -0700, Jeremy Fitzhardinge wrote:
> > On 06/06/2010 10:33 AM, Pasi Kärkkäinen wrote:
> > > 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
> > >   
> > 
> > Does this help?
> > 
> 
> It gave failing hunks so I had to manually apply it to 2.6.32.15, 
> but it seems to fix that issue. No "unsafe lock order" messages anymore.
> 

Hmm.. it seems I still get this:


device vif1.0 entered promiscuous mode
virbr0: topology change detected, propagating
virbr0: port 1(vif1.0) entering forwarding state
  alloc irq_desc for 1242 on node 0
  alloc kstat_irqs on node 0
  alloc irq_desc for 1241 on node 0
  alloc kstat_irqs on node 0
  alloc irq_desc for 1240 on node 0
  alloc kstat_irqs on node 0
  alloc irq_desc for 1239 on node 0
  alloc kstat_irqs on node 0
------------[ cut here ]------------
WARNING: at kernel/lockdep.c:2323 trace_hardirqs_on_caller+0xb7/0x135()
Hardware name: X7SB4/E
Modules linked in: xen_gntdev ipt_MASQUERADE iptable_nat nf_nat bridge stp llc sunrpc ip6t_REJECT nf_conntrack_ipv6 ip6table_filter ip6_tables ipv6 xen_
evtchn xenfs e1000e iTCO_wdt i2c_i801 joydev iTCO_vendor_support serio_raw shpchp pcspkr floppy usb_storage video output aic79xx scsi_transport_spi rade
on ttm drm_kms_helper drm i2c_algo_bit i2c_core [last unloaded: scsi_wait_scan]
Pid: 23, comm: xenwatch Not tainted 2.6.32.15 #3
Call Trace:
 <IRQ>  [<ffffffff81059c11>] warn_slowpath_common+0x7c/0x94
 [<ffffffff81478acb>] ? _spin_unlock_irq+0x30/0x3c
 [<ffffffff81059c3d>] warn_slowpath_null+0x14/0x16
 [<ffffffff8108b156>] trace_hardirqs_on_caller+0xb7/0x135
 [<ffffffff8108b1e1>] trace_hardirqs_on+0xd/0xf
 [<ffffffff81478acb>] _spin_unlock_irq+0x30/0x3c
 [<ffffffff812c19b9>] add_to_net_schedule_list_tail+0x92/0x9b
 [<ffffffff812c19fa>] netif_be_int+0x38/0xd0
 [<ffffffff810b80f4>] handle_IRQ_event+0x53/0x119
 [<ffffffff810ba096>] handle_level_irq+0x7d/0xdf
 [<ffffffff812b72bd>] __xen_evtchn_do_upcall+0xe7/0x168
 [<ffffffff812b7820>] xen_evtchn_do_upcall+0x37/0x4c
 [<ffffffff81013f3e>] xen_do_hypervisor_callback+0x1e/0x30
 <EOI>  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
 [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
 [<ffffffff812b9fe3>] ? notify_remote_via_evtchn+0x1e/0x44
 [<ffffffff81477801>] ? __mutex_lock_common+0x36a/0x37b
 [<ffffffff812ba966>] ? xs_talkv+0x5c/0x174
 [<ffffffff812ba354>] ? xb_write+0x16e/0x18a
 [<ffffffff812ba974>] ? xs_talkv+0x6a/0x174
 [<ffffffff81242c46>] ? kasprintf+0x38/0x3a
 [<ffffffff812babc3>] ? xs_single+0x3a/0x3c
 [<ffffffff812bb271>] ? xenbus_read+0x42/0x5b
 [<ffffffff812c416c>] ? frontend_changed+0x649/0x675
 [<ffffffff812bc453>] ? xenbus_otherend_changed+0xe9/0x176
 [<ffffffff8100f55f>] ? xen_restore_fl_direct_end+0x0/0x1
 [<ffffffff8108d91e>] ? lock_release+0x198/0x1a5
 [<ffffffff812bca7e>] ? frontend_changed+0x10/0x12
 [<ffffffff812ba6eb>] ? xenwatch_thread+0x111/0x14c
 [<ffffffff81079d4a>] ? autoremove_wake_function+0x0/0x39
 [<ffffffff812ba5da>] ? xenwatch_thread+0x0/0x14c
 [<ffffffff81079a78>] ? kthread+0x7f/0x87
 [<ffffffff81013dea>] ? child_rip+0xa/0x20
 [<ffffffff81013750>] ? restore_args+0x0/0x30
 [<ffffffff81013de0>] ? child_rip+0x0/0x20
---[ end trace c5022d288d3812ac ]---
blkback: ring-ref 770, event-channel 9, protocol 2 (x86_32-abi)
  alloc irq_desc for 1238 on node 0
  alloc kstat_irqs on node 0
vif1.0: no IPv6 routers present



-- Pasi




> 
> > From 3f5e554f669098c84c82ce75e7577f7e0f3fccde Mon Sep 17 00:00:00 2001
> > From: Jeremy Fitzhardinge <jeremy.fitzhardinge@citrix.com>
> > Date: Fri, 28 May 2010 15:28:27 -0700
> > Subject: [PATCH] xen/evtchn: don't do unbind_from_irqhandler under spinlock
> > 
> > unbind_from_irqhandler can end up doing /proc operations, which can't
> > happen under a spinlock.  So before removing the IRQ handler,
> > disable the irq under the port_user lock (masking the underlying event
> > channel and making sure the irq handler isn't running concurrently and
> > won't start running), then remove the handler without the lock.
> > 
> > Signed-off-by: Jeremy Fitzhardinge <jeremy.fitzhardinge@citrix.com>
> > 
> > diff --git a/drivers/xen/evtchn.c b/drivers/xen/evtchn.c
> > index f79ac5c..6a3a129 100644
> > --- a/drivers/xen/evtchn.c
> > +++ b/drivers/xen/evtchn.c
> > @@ -375,10 +375,12 @@ static long evtchn_ioctl(struct file *file,
> >  			break;
> >  		}
> >  
> > -		evtchn_unbind_from_user(u, unbind.port);
> > +		disable_irq(irq_from_evtchn(unbind.port));
> >  
> >  		spin_unlock_irq(&port_user_lock);
> >  
> > +		evtchn_unbind_from_user(u, unbind.port);
> > +
> >  		rc = 0;
> >  		break;
> >  	}
> > @@ -484,11 +486,18 @@ static int evtchn_release(struct inode *inode, struct file *filp)
> >  		if (get_port_user(i) != u)
> >  			continue;
> >  
> > -		evtchn_unbind_from_user(get_port_user(i), i);
> > +		disable_irq(irq_from_evtchn(i));
> >  	}
> >  
> >  	spin_unlock_irq(&port_user_lock);
> >  
> > +	for (i = 0; i < NR_EVENT_CHANNELS; i++) {
> > +		if (get_port_user(i) != u)
> > +			continue;
> > +
> > +		evtchn_unbind_from_user(get_port_user(i), i);
> > +	}
> > +
> >  	kfree(u->name);
> >  	kfree(u);
> >  
> > 
> > 

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

* Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock
  2010-06-07 12:58     ` Pasi Kärkkäinen
@ 2010-06-07 16:50       ` Jeremy Fitzhardinge
  2010-07-20 11:53         ` Pasi Kärkkäinen
  0 siblings, 1 reply; 9+ messages in thread
From: Jeremy Fitzhardinge @ 2010-06-07 16:50 UTC (permalink / raw)
  To: Pasi Kärkkäinen; +Cc: xen-devel

On 06/07/2010 05:58 AM, Pasi Kärkkäinen wrote:
> On Sun, Jun 06, 2010 at 09:54:01PM +0300, Pasi Kärkkäinen wrote:
>   
>> On Sun, Jun 06, 2010 at 10:41:04AM -0700, Jeremy Fitzhardinge wrote:
>>     
>>> On 06/06/2010 10:33 AM, Pasi Kärkkäinen wrote:
>>>       
>>>> 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
>>>>   
>>>>         
>>> Does this help?
>>>
>>>       
>> It gave failing hunks so I had to manually apply it to 2.6.32.15, 
>> but it seems to fix that issue. No "unsafe lock order" messages anymore.
>>
>>     
> Hmm.. it seems I still get this:
>   

OK, thanks.  Let me look at it; that was a first cut patch I did the
other day when I noticed the problem, but I hadn't got around to testing
it myself.

    J

>
> device vif1.0 entered promiscuous mode
> virbr0: topology change detected, propagating
> virbr0: port 1(vif1.0) entering forwarding state
>   alloc irq_desc for 1242 on node 0
>   alloc kstat_irqs on node 0
>   alloc irq_desc for 1241 on node 0
>   alloc kstat_irqs on node 0
>   alloc irq_desc for 1240 on node 0
>   alloc kstat_irqs on node 0
>   alloc irq_desc for 1239 on node 0
>   alloc kstat_irqs on node 0
> ------------[ cut here ]------------
> WARNING: at kernel/lockdep.c:2323 trace_hardirqs_on_caller+0xb7/0x135()
> Hardware name: X7SB4/E
> Modules linked in: xen_gntdev ipt_MASQUERADE iptable_nat nf_nat bridge stp llc sunrpc ip6t_REJECT nf_conntrack_ipv6 ip6table_filter ip6_tables ipv6 xen_
> evtchn xenfs e1000e iTCO_wdt i2c_i801 joydev iTCO_vendor_support serio_raw shpchp pcspkr floppy usb_storage video output aic79xx scsi_transport_spi rade
> on ttm drm_kms_helper drm i2c_algo_bit i2c_core [last unloaded: scsi_wait_scan]
> Pid: 23, comm: xenwatch Not tainted 2.6.32.15 #3
> Call Trace:
>  <IRQ>  [<ffffffff81059c11>] warn_slowpath_common+0x7c/0x94
>  [<ffffffff81478acb>] ? _spin_unlock_irq+0x30/0x3c
>  [<ffffffff81059c3d>] warn_slowpath_null+0x14/0x16
>  [<ffffffff8108b156>] trace_hardirqs_on_caller+0xb7/0x135
>  [<ffffffff8108b1e1>] trace_hardirqs_on+0xd/0xf
>  [<ffffffff81478acb>] _spin_unlock_irq+0x30/0x3c
>  [<ffffffff812c19b9>] add_to_net_schedule_list_tail+0x92/0x9b
>  [<ffffffff812c19fa>] netif_be_int+0x38/0xd0
>  [<ffffffff810b80f4>] handle_IRQ_event+0x53/0x119
>  [<ffffffff810ba096>] handle_level_irq+0x7d/0xdf
>  [<ffffffff812b72bd>] __xen_evtchn_do_upcall+0xe7/0x168
>  [<ffffffff812b7820>] xen_evtchn_do_upcall+0x37/0x4c
>  [<ffffffff81013f3e>] xen_do_hypervisor_callback+0x1e/0x30
>  <EOI>  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
>  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
>  [<ffffffff812b9fe3>] ? notify_remote_via_evtchn+0x1e/0x44
>  [<ffffffff81477801>] ? __mutex_lock_common+0x36a/0x37b
>  [<ffffffff812ba966>] ? xs_talkv+0x5c/0x174
>  [<ffffffff812ba354>] ? xb_write+0x16e/0x18a
>  [<ffffffff812ba974>] ? xs_talkv+0x6a/0x174
>  [<ffffffff81242c46>] ? kasprintf+0x38/0x3a
>  [<ffffffff812babc3>] ? xs_single+0x3a/0x3c
>  [<ffffffff812bb271>] ? xenbus_read+0x42/0x5b
>  [<ffffffff812c416c>] ? frontend_changed+0x649/0x675
>  [<ffffffff812bc453>] ? xenbus_otherend_changed+0xe9/0x176
>  [<ffffffff8100f55f>] ? xen_restore_fl_direct_end+0x0/0x1
>  [<ffffffff8108d91e>] ? lock_release+0x198/0x1a5
>  [<ffffffff812bca7e>] ? frontend_changed+0x10/0x12
>  [<ffffffff812ba6eb>] ? xenwatch_thread+0x111/0x14c
>  [<ffffffff81079d4a>] ? autoremove_wake_function+0x0/0x39
>  [<ffffffff812ba5da>] ? xenwatch_thread+0x0/0x14c
>  [<ffffffff81079a78>] ? kthread+0x7f/0x87
>  [<ffffffff81013dea>] ? child_rip+0xa/0x20
>  [<ffffffff81013750>] ? restore_args+0x0/0x30
>  [<ffffffff81013de0>] ? child_rip+0x0/0x20
> ---[ end trace c5022d288d3812ac ]---
> blkback: ring-ref 770, event-channel 9, protocol 2 (x86_32-abi)
>   alloc irq_desc for 1238 on node 0
>   alloc kstat_irqs on node 0
> vif1.0: no IPv6 routers present
>
>
>
> -- Pasi
>
>
>
>
>   
>>     
>>> From 3f5e554f669098c84c82ce75e7577f7e0f3fccde Mon Sep 17 00:00:00 2001
>>> From: Jeremy Fitzhardinge <jeremy.fitzhardinge@citrix.com>
>>> Date: Fri, 28 May 2010 15:28:27 -0700
>>> Subject: [PATCH] xen/evtchn: don't do unbind_from_irqhandler under spinlock
>>>
>>> unbind_from_irqhandler can end up doing /proc operations, which can't
>>> happen under a spinlock.  So before removing the IRQ handler,
>>> disable the irq under the port_user lock (masking the underlying event
>>> channel and making sure the irq handler isn't running concurrently and
>>> won't start running), then remove the handler without the lock.
>>>
>>> Signed-off-by: Jeremy Fitzhardinge <jeremy.fitzhardinge@citrix.com>
>>>
>>> diff --git a/drivers/xen/evtchn.c b/drivers/xen/evtchn.c
>>> index f79ac5c..6a3a129 100644
>>> --- a/drivers/xen/evtchn.c
>>> +++ b/drivers/xen/evtchn.c
>>> @@ -375,10 +375,12 @@ static long evtchn_ioctl(struct file *file,
>>>  			break;
>>>  		}
>>>  
>>> -		evtchn_unbind_from_user(u, unbind.port);
>>> +		disable_irq(irq_from_evtchn(unbind.port));
>>>  
>>>  		spin_unlock_irq(&port_user_lock);
>>>  
>>> +		evtchn_unbind_from_user(u, unbind.port);
>>> +
>>>  		rc = 0;
>>>  		break;
>>>  	}
>>> @@ -484,11 +486,18 @@ static int evtchn_release(struct inode *inode, struct file *filp)
>>>  		if (get_port_user(i) != u)
>>>  			continue;
>>>  
>>> -		evtchn_unbind_from_user(get_port_user(i), i);
>>> +		disable_irq(irq_from_evtchn(i));
>>>  	}
>>>  
>>>  	spin_unlock_irq(&port_user_lock);
>>>  
>>> +	for (i = 0; i < NR_EVENT_CHANNELS; i++) {
>>> +		if (get_port_user(i) != u)
>>> +			continue;
>>> +
>>> +		evtchn_unbind_from_user(get_port_user(i), i);
>>> +	}
>>> +
>>>  	kfree(u->name);
>>>  	kfree(u);
>>>  
>>>
>>>
>>>       
>   

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

* Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock
  2010-06-07 16:50       ` Jeremy Fitzhardinge
@ 2010-07-20 11:53         ` Pasi Kärkkäinen
  2010-07-20 16:17           ` Jeremy Fitzhardinge
  0 siblings, 1 reply; 9+ messages in thread
From: Pasi Kärkkäinen @ 2010-07-20 11:53 UTC (permalink / raw)
  To: Jeremy Fitzhardinge; +Cc: xen-devel

On Mon, Jun 07, 2010 at 09:50:13AM -0700, Jeremy Fitzhardinge wrote:
> On 06/07/2010 05:58 AM, Pasi Kärkkäinen wrote:
> > On Sun, Jun 06, 2010 at 09:54:01PM +0300, Pasi Kärkkäinen wrote:
> >   
> >> On Sun, Jun 06, 2010 at 10:41:04AM -0700, Jeremy Fitzhardinge wrote:
> >>     
> >>> On 06/06/2010 10:33 AM, Pasi Kärkkäinen wrote:
> >>>       
> >>>> 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
> >>>>   
> >>>>         
> >>> Does this help?
> >>>
> >>>       
> >> It gave failing hunks so I had to manually apply it to 2.6.32.15, 
> >> but it seems to fix that issue. No "unsafe lock order" messages anymore.
> >>
> >>     
> > Hmm.. it seems I still get this:
> >   
> 
> OK, thanks.  Let me look at it; that was a first cut patch I did the
> other day when I noticed the problem, but I hadn't got around to testing
> it myself.
> 

I just tried the latest xen/stable-2.6.32.16 (as of today), 
without any additional patches, and I get this:


device vif1.0 entered promiscuous mode
virbr0: topology change detected, propagating
virbr0: port 1(vif1.0) entering forwarding state
  alloc irq_desc for 1242 on node 0
  alloc kstat_irqs on node 0
  alloc irq_desc for 1241 on node 0
  alloc kstat_irqs on node 0
  alloc irq_desc for 1240 on node 0
  alloc kstat_irqs on node 0
blkback: ring-ref 8, event-channel 8, protocol 1 (x86_64-abi)
  alloc irq_desc for 1239 on node 0
  alloc kstat_irqs on node 0
vif1.0: no IPv6 routers present
  alloc irq_desc for 1238 on node 0
  alloc kstat_irqs on node 0
------------[ cut here ]------------
WARNING: at kernel/lockdep.c:2323 trace_hardirqs_on_caller+0xb7/0x135()
Hardware name: X7SB4/E
Modules linked in: ipt_MASQUERADE iptable_nat nf_nat bridge stp llc sunrpc ip6t_REJECT nf_conntrack_ipv6 ip6table_filter ip6_tables ipv6 xen_gntdev xen_evtchn xenfs e1000e shpchp i2c_i801 pcspkr iTCO_wdt iTCO_vendor_support serio_raw joydev floppy usb_storage video output aic79xx scsi_transport_spi radeon ttm drm_kms_helper drm i2c_algo_bit i2c_core [last unloaded: scsi_wait_scan]
Pid: 23, comm: xenwatch Not tainted 2.6.32.16 #6
Call Trace:
 <IRQ>  [<ffffffff81059c41>] warn_slowpath_common+0x7c/0x94
 [<ffffffff8147896b>] ? _spin_unlock_irq+0x30/0x3c
 [<ffffffff81059c6d>] warn_slowpath_null+0x14/0x16
 [<ffffffff8108b186>] trace_hardirqs_on_caller+0xb7/0x135
 [<ffffffff8108b211>] trace_hardirqs_on+0xd/0xf
 [<ffffffff8147896b>] _spin_unlock_irq+0x30/0x3c
 [<ffffffff812c15d7>] add_to_net_schedule_list_tail+0x92/0x9b
 [<ffffffff812c1618>] netif_be_int+0x38/0xcd
 [<ffffffff810b8144>] handle_IRQ_event+0x53/0x119
 [<ffffffff810ba0e6>] handle_level_irq+0x7d/0xdf
 [<ffffffff812b6f45>] __xen_evtchn_do_upcall+0xe1/0x16e
 [<ffffffff812b74b8>] xen_evtchn_do_upcall+0x37/0x4c
 [<ffffffff81013f3e>] xen_do_hypervisor_callback+0x1e/0x30
 <EOI>  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
 [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
 [<ffffffff812b9f9b>] ? notify_remote_via_evtchn+0x1e/0x44
 [<ffffffff814776a1>] ? __mutex_lock_common+0x36a/0x37b
 [<ffffffff812ba8b8>] ? xs_talkv+0x5c/0x174
 [<ffffffff812ba30c>] ? xb_write+0x16e/0x18a
 [<ffffffff812ba8c6>] ? xs_talkv+0x6a/0x174
 [<ffffffff81242b86>] ? kasprintf+0x38/0x3a
 [<ffffffff812bab15>] ? xs_single+0x3a/0x3c
 [<ffffffff812bb0f0>] ? xenbus_read+0x42/0x5b
 [<ffffffff812c3de4>] ? frontend_changed+0x655/0x681
 [<ffffffff812bc0e7>] ? xenbus_otherend_changed+0xe9/0x176
 [<ffffffff8100f34f>] ? xen_restore_fl_direct_end+0x0/0x1
 [<ffffffff8108d94e>] ? lock_release+0x198/0x1a5
 [<ffffffff812bc712>] ? frontend_changed+0x10/0x12
 [<ffffffff812ba63d>] ? xenwatch_thread+0x111/0x14c
 [<ffffffff81079d7a>] ? autoremove_wake_function+0x0/0x39
 [<ffffffff812ba52c>] ? xenwatch_thread+0x0/0x14c
 [<ffffffff81079aa8>] ? kthread+0x7f/0x87
 [<ffffffff81013dea>] ? child_rip+0xa/0x20
 [<ffffffff81013750>] ? restore_args+0x0/0x30
 [<ffffffff81013de0>] ? child_rip+0x0/0x20
---[ end trace b036c0423b0ee26a ]---
  alloc irq_desc for 1237 on node 0
  alloc kstat_irqs on node 0
device vif2.0 entered promiscuous mode


-- Pasi

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

* Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock
  2010-07-20 11:53         ` Pasi Kärkkäinen
@ 2010-07-20 16:17           ` Jeremy Fitzhardinge
  2010-07-20 17:17             ` Pasi Kärkkäinen
  0 siblings, 1 reply; 9+ messages in thread
From: Jeremy Fitzhardinge @ 2010-07-20 16:17 UTC (permalink / raw)
  To: Pasi Kärkkäinen; +Cc: xen-devel

On 07/20/2010 04:53 AM, Pasi Kärkkäinen wrote:
> On Mon, Jun 07, 2010 at 09:50:13AM -0700, Jeremy Fitzhardinge wrote:
>   
>> On 06/07/2010 05:58 AM, Pasi Kärkkäinen wrote:
>>     
>>> On Sun, Jun 06, 2010 at 09:54:01PM +0300, Pasi Kärkkäinen wrote:
>>>   
>>>       
>>>> On Sun, Jun 06, 2010 at 10:41:04AM -0700, Jeremy Fitzhardinge wrote:
>>>>     
>>>>         
>>>>> On 06/06/2010 10:33 AM, Pasi Kärkkäinen wrote:
>>>>>       
>>>>>           
>>>>>> 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
>>>>>>   
>>>>>>         
>>>>>>             
>>>>> Does this help?
>>>>>
>>>>>       
>>>>>           
>>>> It gave failing hunks so I had to manually apply it to 2.6.32.15, 
>>>> but it seems to fix that issue. No "unsafe lock order" messages anymore.
>>>>
>>>>     
>>>>         
>>> Hmm.. it seems I still get this:
>>>   
>>>       
>> OK, thanks.  Let me look at it; that was a first cut patch I did the
>> other day when I noticed the problem, but I hadn't got around to testing
>> it myself.
>>
>>     
> I just tried the latest xen/stable-2.6.32.16 (as of today), 
> without any additional patches, and I get this:
>   

Is that new?

    J

>
> device vif1.0 entered promiscuous mode
> virbr0: topology change detected, propagating
> virbr0: port 1(vif1.0) entering forwarding state
>   alloc irq_desc for 1242 on node 0
>   alloc kstat_irqs on node 0
>   alloc irq_desc for 1241 on node 0
>   alloc kstat_irqs on node 0
>   alloc irq_desc for 1240 on node 0
>   alloc kstat_irqs on node 0
> blkback: ring-ref 8, event-channel 8, protocol 1 (x86_64-abi)
>   alloc irq_desc for 1239 on node 0
>   alloc kstat_irqs on node 0
> vif1.0: no IPv6 routers present
>   alloc irq_desc for 1238 on node 0
>   alloc kstat_irqs on node 0
> ------------[ cut here ]------------
> WARNING: at kernel/lockdep.c:2323 trace_hardirqs_on_caller+0xb7/0x135()
> Hardware name: X7SB4/E
> Modules linked in: ipt_MASQUERADE iptable_nat nf_nat bridge stp llc sunrpc ip6t_REJECT nf_conntrack_ipv6 ip6table_filter ip6_tables ipv6 xen_gntdev xen_evtchn xenfs e1000e shpchp i2c_i801 pcspkr iTCO_wdt iTCO_vendor_support serio_raw joydev floppy usb_storage video output aic79xx scsi_transport_spi radeon ttm drm_kms_helper drm i2c_algo_bit i2c_core [last unloaded: scsi_wait_scan]
> Pid: 23, comm: xenwatch Not tainted 2.6.32.16 #6
> Call Trace:
>  <IRQ>  [<ffffffff81059c41>] warn_slowpath_common+0x7c/0x94
>  [<ffffffff8147896b>] ? _spin_unlock_irq+0x30/0x3c
>  [<ffffffff81059c6d>] warn_slowpath_null+0x14/0x16
>  [<ffffffff8108b186>] trace_hardirqs_on_caller+0xb7/0x135
>  [<ffffffff8108b211>] trace_hardirqs_on+0xd/0xf
>  [<ffffffff8147896b>] _spin_unlock_irq+0x30/0x3c
>  [<ffffffff812c15d7>] add_to_net_schedule_list_tail+0x92/0x9b
>  [<ffffffff812c1618>] netif_be_int+0x38/0xcd
>  [<ffffffff810b8144>] handle_IRQ_event+0x53/0x119
>  [<ffffffff810ba0e6>] handle_level_irq+0x7d/0xdf
>  [<ffffffff812b6f45>] __xen_evtchn_do_upcall+0xe1/0x16e
>  [<ffffffff812b74b8>] xen_evtchn_do_upcall+0x37/0x4c
>  [<ffffffff81013f3e>] xen_do_hypervisor_callback+0x1e/0x30
>  <EOI>  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
>  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
>  [<ffffffff812b9f9b>] ? notify_remote_via_evtchn+0x1e/0x44
>  [<ffffffff814776a1>] ? __mutex_lock_common+0x36a/0x37b
>  [<ffffffff812ba8b8>] ? xs_talkv+0x5c/0x174
>  [<ffffffff812ba30c>] ? xb_write+0x16e/0x18a
>  [<ffffffff812ba8c6>] ? xs_talkv+0x6a/0x174
>  [<ffffffff81242b86>] ? kasprintf+0x38/0x3a
>  [<ffffffff812bab15>] ? xs_single+0x3a/0x3c
>  [<ffffffff812bb0f0>] ? xenbus_read+0x42/0x5b
>  [<ffffffff812c3de4>] ? frontend_changed+0x655/0x681
>  [<ffffffff812bc0e7>] ? xenbus_otherend_changed+0xe9/0x176
>  [<ffffffff8100f34f>] ? xen_restore_fl_direct_end+0x0/0x1
>  [<ffffffff8108d94e>] ? lock_release+0x198/0x1a5
>  [<ffffffff812bc712>] ? frontend_changed+0x10/0x12
>  [<ffffffff812ba63d>] ? xenwatch_thread+0x111/0x14c
>  [<ffffffff81079d7a>] ? autoremove_wake_function+0x0/0x39
>  [<ffffffff812ba52c>] ? xenwatch_thread+0x0/0x14c
>  [<ffffffff81079aa8>] ? kthread+0x7f/0x87
>  [<ffffffff81013dea>] ? child_rip+0xa/0x20
>  [<ffffffff81013750>] ? restore_args+0x0/0x30
>  [<ffffffff81013de0>] ? child_rip+0x0/0x20
> ---[ end trace b036c0423b0ee26a ]---
>   alloc irq_desc for 1237 on node 0
>   alloc kstat_irqs on node 0
> device vif2.0 entered promiscuous mode
>
>
> -- Pasi
>
>   

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

* Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock
  2010-07-20 16:17           ` Jeremy Fitzhardinge
@ 2010-07-20 17:17             ` Pasi Kärkkäinen
  2010-08-26 18:05               ` Bruce Edge
  0 siblings, 1 reply; 9+ messages in thread
From: Pasi Kärkkäinen @ 2010-07-20 17:17 UTC (permalink / raw)
  To: Jeremy Fitzhardinge; +Cc: xen-devel

On Tue, Jul 20, 2010 at 09:17:26AM -0700, Jeremy Fitzhardinge wrote:
> On 07/20/2010 04:53 AM, Pasi Kärkkäinen wrote:
> > On Mon, Jun 07, 2010 at 09:50:13AM -0700, Jeremy Fitzhardinge wrote:
> >   
> >> On 06/07/2010 05:58 AM, Pasi Kärkkäinen wrote:
> >>     
> >>> On Sun, Jun 06, 2010 at 09:54:01PM +0300, Pasi Kärkkäinen wrote:
> >>>   
> >>>       
> >>>> On Sun, Jun 06, 2010 at 10:41:04AM -0700, Jeremy Fitzhardinge wrote:
> >>>>     
> >>>>         
> >>>>> On 06/06/2010 10:33 AM, Pasi Kärkkäinen wrote:
> >>>>>       
> >>>>>           
> >>>>>> 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
> >>>>>>   
> >>>>>>         
> >>>>>>             
> >>>>> Does this help?
> >>>>>
> >>>>>       
> >>>>>           
> >>>> It gave failing hunks so I had to manually apply it to 2.6.32.15, 
> >>>> but it seems to fix that issue. No "unsafe lock order" messages anymore.
> >>>>
> >>>>     
> >>>>         
> >>> Hmm.. it seems I still get this:
> >>>   
> >>>       
> >> OK, thanks.  Let me look at it; that was a first cut patch I did the
> >> other day when I noticed the problem, but I hadn't got around to testing
> >> it myself.
> >>
> >>     
> > I just tried the latest xen/stable-2.6.32.16 (as of today), 
> > without any additional patches, and I get this:
> >   
> 
> Is that new?
> 

I think it's the same as earlier..

-- Pasi

> 
> >
> > device vif1.0 entered promiscuous mode
> > virbr0: topology change detected, propagating
> > virbr0: port 1(vif1.0) entering forwarding state
> >   alloc irq_desc for 1242 on node 0
> >   alloc kstat_irqs on node 0
> >   alloc irq_desc for 1241 on node 0
> >   alloc kstat_irqs on node 0
> >   alloc irq_desc for 1240 on node 0
> >   alloc kstat_irqs on node 0
> > blkback: ring-ref 8, event-channel 8, protocol 1 (x86_64-abi)
> >   alloc irq_desc for 1239 on node 0
> >   alloc kstat_irqs on node 0
> > vif1.0: no IPv6 routers present
> >   alloc irq_desc for 1238 on node 0
> >   alloc kstat_irqs on node 0
> > ------------[ cut here ]------------
> > WARNING: at kernel/lockdep.c:2323 trace_hardirqs_on_caller+0xb7/0x135()
> > Hardware name: X7SB4/E
> > Modules linked in: ipt_MASQUERADE iptable_nat nf_nat bridge stp llc sunrpc ip6t_REJECT nf_conntrack_ipv6 ip6table_filter ip6_tables ipv6 xen_gntdev xen_evtchn xenfs e1000e shpchp i2c_i801 pcspkr iTCO_wdt iTCO_vendor_support serio_raw joydev floppy usb_storage video output aic79xx scsi_transport_spi radeon ttm drm_kms_helper drm i2c_algo_bit i2c_core [last unloaded: scsi_wait_scan]
> > Pid: 23, comm: xenwatch Not tainted 2.6.32.16 #6
> > Call Trace:
> >  <IRQ>  [<ffffffff81059c41>] warn_slowpath_common+0x7c/0x94
> >  [<ffffffff8147896b>] ? _spin_unlock_irq+0x30/0x3c
> >  [<ffffffff81059c6d>] warn_slowpath_null+0x14/0x16
> >  [<ffffffff8108b186>] trace_hardirqs_on_caller+0xb7/0x135
> >  [<ffffffff8108b211>] trace_hardirqs_on+0xd/0xf
> >  [<ffffffff8147896b>] _spin_unlock_irq+0x30/0x3c
> >  [<ffffffff812c15d7>] add_to_net_schedule_list_tail+0x92/0x9b
> >  [<ffffffff812c1618>] netif_be_int+0x38/0xcd
> >  [<ffffffff810b8144>] handle_IRQ_event+0x53/0x119
> >  [<ffffffff810ba0e6>] handle_level_irq+0x7d/0xdf
> >  [<ffffffff812b6f45>] __xen_evtchn_do_upcall+0xe1/0x16e
> >  [<ffffffff812b74b8>] xen_evtchn_do_upcall+0x37/0x4c
> >  [<ffffffff81013f3e>] xen_do_hypervisor_callback+0x1e/0x30
> >  <EOI>  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
> >  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
> >  [<ffffffff812b9f9b>] ? notify_remote_via_evtchn+0x1e/0x44
> >  [<ffffffff814776a1>] ? __mutex_lock_common+0x36a/0x37b
> >  [<ffffffff812ba8b8>] ? xs_talkv+0x5c/0x174
> >  [<ffffffff812ba30c>] ? xb_write+0x16e/0x18a
> >  [<ffffffff812ba8c6>] ? xs_talkv+0x6a/0x174
> >  [<ffffffff81242b86>] ? kasprintf+0x38/0x3a
> >  [<ffffffff812bab15>] ? xs_single+0x3a/0x3c
> >  [<ffffffff812bb0f0>] ? xenbus_read+0x42/0x5b
> >  [<ffffffff812c3de4>] ? frontend_changed+0x655/0x681
> >  [<ffffffff812bc0e7>] ? xenbus_otherend_changed+0xe9/0x176
> >  [<ffffffff8100f34f>] ? xen_restore_fl_direct_end+0x0/0x1
> >  [<ffffffff8108d94e>] ? lock_release+0x198/0x1a5
> >  [<ffffffff812bc712>] ? frontend_changed+0x10/0x12
> >  [<ffffffff812ba63d>] ? xenwatch_thread+0x111/0x14c
> >  [<ffffffff81079d7a>] ? autoremove_wake_function+0x0/0x39
> >  [<ffffffff812ba52c>] ? xenwatch_thread+0x0/0x14c
> >  [<ffffffff81079aa8>] ? kthread+0x7f/0x87
> >  [<ffffffff81013dea>] ? child_rip+0xa/0x20
> >  [<ffffffff81013750>] ? restore_args+0x0/0x30
> >  [<ffffffff81013de0>] ? child_rip+0x0/0x20
> > ---[ end trace b036c0423b0ee26a ]---
> >   alloc irq_desc for 1237 on node 0
> >   alloc kstat_irqs on node 0
> > device vif2.0 entered promiscuous mode
> >
> >
> > -- Pasi
> >
> >   
> 

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

* Re: Re: xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock
  2010-07-20 17:17             ` Pasi Kärkkäinen
@ 2010-08-26 18:05               ` Bruce Edge
  0 siblings, 0 replies; 9+ messages in thread
From: Bruce Edge @ 2010-08-26 18:05 UTC (permalink / raw)
  To: Pasi Kärkkäinen; +Cc: Jeremy Fitzhardinge, xen-devel


[-- Attachment #1.1: Type: text/plain, Size: 18785 bytes --]

On Tue, Jul 20, 2010 at 10:17 AM, Pasi Kärkkäinen <pasik@iki.fi> wrote:

> On Tue, Jul 20, 2010 at 09:17:26AM -0700, Jeremy Fitzhardinge wrote:
> > On 07/20/2010 04:53 AM, Pasi Kärkkäinen wrote:
> > > On Mon, Jun 07, 2010 at 09:50:13AM -0700, Jeremy Fitzhardinge wrote:
> > >
> > >> On 06/07/2010 05:58 AM, Pasi Kärkkäinen wrote:
> > >>
> > >>> On Sun, Jun 06, 2010 at 09:54:01PM +0300, Pasi Kärkkäinen wrote:
> > >>>
> > >>>
> > >>>> On Sun, Jun 06, 2010 at 10:41:04AM -0700, Jeremy Fitzhardinge wrote:
> > >>>>
> > >>>>
> > >>>>> On 06/06/2010 10:33 AM, Pasi Kärkkäinen wrote:
> > >>>>>
> > >>>>>
> > >>>>>> 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
> > >>>>>>
> > >>>>>>
> > >>>>>>
> > >>>>> Does this help?
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>> It gave failing hunks so I had to manually apply it to 2.6.32.15,
> > >>>> but it seems to fix that issue. No "unsafe lock order" messages
> anymore.
> > >>>>
> > >>>>
> > >>>>
> > >>> Hmm.. it seems I still get this:
> > >>>
> > >>>
> > >> OK, thanks.  Let me look at it; that was a first cut patch I did the
> > >> other day when I noticed the problem, but I hadn't got around to
> testing
> > >> it myself.
> > >>
> > >>
> > > I just tried the latest xen/stable-2.6.32.16 (as of today),
> > > without any additional patches, and I get this:
> > >
> >
> > Is that new?
> >
>
> I think it's the same as earlier..
>
> -- Pasi
>
> >
> > >
> > > device vif1.0 entered promiscuous mode
> > > virbr0: topology change detected, propagating
> > > virbr0: port 1(vif1.0) entering forwarding state
> > >   alloc irq_desc for 1242 on node 0
> > >   alloc kstat_irqs on node 0
> > >   alloc irq_desc for 1241 on node 0
> > >   alloc kstat_irqs on node 0
> > >   alloc irq_desc for 1240 on node 0
> > >   alloc kstat_irqs on node 0
> > > blkback: ring-ref 8, event-channel 8, protocol 1 (x86_64-abi)
> > >   alloc irq_desc for 1239 on node 0
> > >   alloc kstat_irqs on node 0
> > > vif1.0: no IPv6 routers present
> > >   alloc irq_desc for 1238 on node 0
> > >   alloc kstat_irqs on node 0
> > > ------------[ cut here ]------------
> > > WARNING: at kernel/lockdep.c:2323 trace_hardirqs_on_caller+0xb7/0x135()
> > > Hardware name: X7SB4/E
> > > Modules linked in: ipt_MASQUERADE iptable_nat nf_nat bridge stp llc
> sunrpc ip6t_REJECT nf_conntrack_ipv6 ip6table_filter ip6_tables ipv6
> xen_gntdev xen_evtchn xenfs e1000e shpchp i2c_i801 pcspkr iTCO_wdt
> iTCO_vendor_support serio_raw joydev floppy usb_storage video output aic79xx
> scsi_transport_spi radeon ttm drm_kms_helper drm i2c_algo_bit i2c_core [last
> unloaded: scsi_wait_scan]
> > > Pid: 23, comm: xenwatch Not tainted 2.6.32.16 #6
> > > Call Trace:
> > >  <IRQ>  [<ffffffff81059c41>] warn_slowpath_common+0x7c/0x94
> > >  [<ffffffff8147896b>] ? _spin_unlock_irq+0x30/0x3c
> > >  [<ffffffff81059c6d>] warn_slowpath_null+0x14/0x16
> > >  [<ffffffff8108b186>] trace_hardirqs_on_caller+0xb7/0x135
> > >  [<ffffffff8108b211>] trace_hardirqs_on+0xd/0xf
> > >  [<ffffffff8147896b>] _spin_unlock_irq+0x30/0x3c
> > >  [<ffffffff812c15d7>] add_to_net_schedule_list_tail+0x92/0x9b
> > >  [<ffffffff812c1618>] netif_be_int+0x38/0xcd
> > >  [<ffffffff810b8144>] handle_IRQ_event+0x53/0x119
> > >  [<ffffffff810ba0e6>] handle_level_irq+0x7d/0xdf
> > >  [<ffffffff812b6f45>] __xen_evtchn_do_upcall+0xe1/0x16e
> > >  [<ffffffff812b74b8>] xen_evtchn_do_upcall+0x37/0x4c
> > >  [<ffffffff81013f3e>] xen_do_hypervisor_callback+0x1e/0x30
> > >  <EOI>  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
> > >  [<ffffffff8100940a>] ? hypercall_page+0x40a/0x100b
> > >  [<ffffffff812b9f9b>] ? notify_remote_via_evtchn+0x1e/0x44
> > >  [<ffffffff814776a1>] ? __mutex_lock_common+0x36a/0x37b
> > >  [<ffffffff812ba8b8>] ? xs_talkv+0x5c/0x174
> > >  [<ffffffff812ba30c>] ? xb_write+0x16e/0x18a
> > >  [<ffffffff812ba8c6>] ? xs_talkv+0x6a/0x174
> > >  [<ffffffff81242b86>] ? kasprintf+0x38/0x3a
> > >  [<ffffffff812bab15>] ? xs_single+0x3a/0x3c
> > >  [<ffffffff812bb0f0>] ? xenbus_read+0x42/0x5b
> > >  [<ffffffff812c3de4>] ? frontend_changed+0x655/0x681
> > >  [<ffffffff812bc0e7>] ? xenbus_otherend_changed+0xe9/0x176
> > >  [<ffffffff8100f34f>] ? xen_restore_fl_direct_end+0x0/0x1
> > >  [<ffffffff8108d94e>] ? lock_release+0x198/0x1a5
> > >  [<ffffffff812bc712>] ? frontend_changed+0x10/0x12
> > >  [<ffffffff812ba63d>] ? xenwatch_thread+0x111/0x14c
> > >  [<ffffffff81079d7a>] ? autoremove_wake_function+0x0/0x39
> > >  [<ffffffff812ba52c>] ? xenwatch_thread+0x0/0x14c
> > >  [<ffffffff81079aa8>] ? kthread+0x7f/0x87
> > >  [<ffffffff81013dea>] ? child_rip+0xa/0x20
> > >  [<ffffffff81013750>] ? restore_args+0x0/0x30
> > >  [<ffffffff81013de0>] ? child_rip+0x0/0x20
> > > ---[ end trace b036c0423b0ee26a ]---
> > >   alloc irq_desc for 1237 on node 0
> > >   alloc kstat_irqs on node 0
> > > device vif2.0 entered promiscuous mode
> > >
> > >
> > > -- Pasi
> > >
> > >
> >
>
>
I'm also seeing this with the newly released xen 4.0.1 and a  Not tainted
2.6.32.18 pvops sync'd yesterday:

2010-08-26T10:57:12.085252-07:00 kaan-18 [ 4698.128356] blkback: ring-ref 8,
event-channel 93, protocol 1 (x86_64-abi)
2010-08-26T10:57:12.126039-07:00 kaan-18 [ 4698.168555] ------------[ cut
here ]------------
2010-08-26T10:57:12.126141-07:00 kaan-18 [ 4698.168569] WARNING: at
kernel/lockdep.c:2323 trace_hardirqs_on_caller+0x12f/0x190()
2010-08-26T10:57:12.126220-07:00 kaan-18 [ 4698.168574] Hardware name:
ProLiant DL380 G6
2010-08-26T10:57:12.126297-07:00 kaan-18 [ 4698.168578] Modules linked in:
xt_physdev xenfs xen_gntdev xen_evtchn ipv6 xen_pciback
t2010-08-26T10:57:12.126297-07:00 kaan-18 [ 4698.168578] Modules linked in:
xt_physdev xenfs xen_gntdev xen_evtchn ipv6 xen_pciback t
un fbcon tileblit font bitblit softcursor bridge stp llc radeon ttm
drm_kms_helper lp drm i2c_algo_bit ipmi_si joydev i2c_core ipmi_msghandler
hpilo hpwdt parport serio_raw usbhid hid cciss usb_storage
2010-08-26T10:57:12.126405-07:00 kaan-18 [ 4698.168644] Pid: 11, comm:
xenwatch Not tainted 2.6.32.18 #1
2010-08-26T10:57:12.126482-07:00 kaan-18 [ 4698.168648] Call Trace:
2010-08-26T10:57:12.126559-07:00 kaan-18 [ 4698.168651]  <IRQ>
 [<ffffffff810a9f7f>] ? trace_hardirqs_on_caller+0x12f/0x190
2010-08-26T10:57:12.126655-07:00 kaan-18 [ 4698.168663]
 [<ffffffff8106bd60>] warn_slowpath_common+0x80/0xd0
2010-08-26T10:57:12.126731-07:00 kaan-18 [ 4698.168671]
 [<ffffffff815f3d70>] ? _spin_unlock_irq+0x30/0x40
2010-08-26T10:57:12.126806-07:00 kaan-18 [ 4698.168676]
 [<ffffffff8106bdc4>] warn_slowpath_null+0x14/0x20
2010-08-26T10:57:12.126881-07:00 kaan-18 [ 4698.168682]
 [<ffffffff810a9f7f>] trace_hardirqs_on_caller+0x12f/0x190
2010-08-26T10:57:12.126957-07:00 kaan-18 [ 4698.168688]
 [<ffffffff810a9fed>] trace_hardirqs_on+0xd/0x10
2010-08-26T10:57:12.127034-07:00 kaan-18 [ 4698.168693]
 [<ffffffff815f3d70>] _spin_unlock_irq+0x30/0x40
2010-08-26T10:57:12.127110-07:00 kaan-18 [ 4698.168700]
 [<ffffffff813c4e75>] add_to_net_schedule_list_tail+0x85/0xd0
2010-08-26T10:57:12.127186-07:00 kaan-18 [ 4698.168724]
 [<ffffffff813c60c6>] netif_be_int+0x36/0x160
2010-08-26T10:57:12.127263-07:00 kaan-18 [ 4698.168730]
 [<ffffffff810e0ea0>] handle_IRQ_event+0x70/0x180
2010-08-26T10:57:12.127338-07:00 kaan-18 [ 4698.168736]
 [<ffffffff810e3c69>] handle_level_irq+0x99/0x140
2010-08-26T10:57:12.127433-07:00 kaan-18 [ 4698.168742]
 [<ffffffff813b8acf>] __xen_evtchn_do_upcall+0x1bf/0x1f0
2010-08-26T10:57:12.127509-07:00 kaan-18 [ 4698.168747]
 [<ffffffff813b908d>] xen_evtchn_do_upcall+0x3d/0x60
2010-08-26T10:57:12.127577-07:00 kaan-18 [ 4698.168754]
 [<ffffffff8101647e>] xen_do_hypervisor_callback+0x1e/0x30
2010-08-26T10:57:12.127584-07:00 kaan-18 [ 4698.168758]  <EOI>
 [<ffffffff8100940a>] ? hypercall_page+0x40a/0x1010
2010-08-26T10:57:12.127589-07:00 kaan-18 [ 4698.168769]
 [<ffffffff8100940a>] ? hypercall_page+0x40a/0x1010
2010-08-26T10:57:12.127595-07:00 kaan-18 [ 4698.168775]
 [<ffffffff813bcd04>] ? xb_write+0x1e4/0x290
2010-08-26T10:57:12.127650-07:00 kaan-18 [ 4698.168780]
 [<ffffffff813bd77a>] ? xs_talkv+0x6a/0x1f0
2010-08-26T10:57:12.127657-07:00 kaan-18 [ 4698.168785]
 [<ffffffff813bd788>] ? xs_talkv+0x78/0x1f0
2010-08-26T10:57:12.127662-07:00 kaan-18 [ 4698.168790]
 [<ffffffff813bda7d>] ? xs_single+0x4d/0x60
2010-08-26T10:57:12.127667-07:00 kaan-18 [ 4698.168795]
 [<ffffffff813be3b2>] ? xenbus_read+0x52/0x80
2010-08-26T10:57:12.127673-07:00 kaan-18 [ 4698.168800]
 [<ffffffff813c86ac>] ? frontend_changed+0x48c/0x770
2010-08-26T10:57:12.127678-07:00 kaan-18 [ 4698.168806]
 [<ffffffff813bf61d>] ? xenbus_otherend_changed+0xdd/0x1b0
2010-08-26T10:57:12.127684-07:00 kaan-18 [ 4698.168813]
 [<ffffffff81010e3f>] ? xen_restore_fl_direct_end+0x0/0x1
2010-08-26T10:57:12.127689-07:00 kaan-18 [ 4698.168818]
 [<ffffffff810ac610>] ? lock_release+0xb0/0x230
2010-08-26T10:57:12.127770-07:00 kaan-18 [ 4698.168823]
 [<ffffffff813bf990>] ? frontend_changed+0x10/0x20
2010-08-26T10:57:12.127777-07:00 kaan-18 [ 4698.168829]
 [<ffffffff813bd3a5>] ? xenwatch_thread+0x55/0x160
2010-08-26T10:57:12.127782-07:00 kaan-18 [ 4698.168836]
 [<ffffffff810932b0>] ? autoremove_wake_function+0x0/0x40
2010-08-26T10:57:12.127788-07:00 kaan-18 [ 4698.168841]
 [<ffffffff813bd350>] ? xenwatch_thread+0x0/0x160
2010-08-26T10:57:12.127793-07:00 kaan-18 [ 4698.168847]
 [<ffffffff81092f36>] ? kthread+0x96/0xb0
2010-08-26T10:57:12.127799-07:00 kaan-18 [ 4698.168852]
 [<ffffffff8101632a>] ? child_rip+0xa/0x20
2010-08-26T10:57:12.127804-07:00 kaan-18 [ 4698.168856]
 [<ffffffff81015c90>] ? restore_args+0x0/0x30
2010-08-26T10:57:12.137042-07:00 kaan-18 [ 4698.168861]
 [<ffffffff81016320>] ? child_rip+0x0/0x20
2010-08-26T10:57:12.137052-07:00 kaan-18 [ 4698.168865] ---[ end trace
d11f63be69302ffc ]---
2010-08-26T10:57:18.775160-07:00 kaan-18 [ 4704.813405] vif3.0: no IPv6
routers present
 'cpu/8/availability': 'online', 'cpu/9/availability': 'online',
'image/suspend-cancel': '1', 'cpu/5/availability': 'online',
'cpu/0/availability': 'online', 'image/features/pae-pgdir-above-4gb': '1',
'cpu/6/availability': 'online', 'console/type': 'xenconsoled',
'cpu/12/availability': 'online', 'name': 'dpm', 'cpu/2/availability':
'online', 'domid': '3', 'image/xen-version': 'xen-3.0', 'store/port': '1',
'cpu/10/availability': 'online'}
[2010-08-26 10:57:09 1840] DEBUG (DevController:95) DevController: writing
{'protocol': 'x86_64-abi', 'state': '1', 'backend-id': '0', 'backend':
'/local/domain/0/backend/console/3/0'} to /local/domain/3/device/console/0.
[2010-08-26 10:57:09 1840] DEBUG (DevController:97) DevController: writing
{'domain': 'dpm', 'frontend': '/local/domain/3/device/console/0', 'uuid':
'460962e0-bc9b-f7de-b5f4-70715fb5d614', 'frontend-id': '3', 'state': '1',
'location': '2', 'online': '1', 'protocol': 'vt100'} to
/local/domain/0/backend/console/3/0.
[2010-08-26 10:57:09 1840] DEBUG (pciif:460)
XendDomainInfo.handleAerStateWatch
[2010-08-26 10:57:09 1840] DEBUG (XendDomainInfo:1891)
XendDomainInfo.handleShutdownWatch
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
tap2.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
vif.
[2010-08-26 10:57:09 1840] DEBUG (DevController:144) Waiting for 0.
[2010-08-26 10:57:09 1840] DEBUG (DevController:628) hotplugStatusCallback
/local/domain/0/backend/vif/3/0/hotplug-status.
[2010-08-26 10:57:09 1840] DEBUG (DevController:642) hotplugStatusCallback
1.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
vkbd.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
ioports.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
tap.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
vif2.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
console.
[2010-08-26 10:57:09 1840] DEBUG (DevController:144) Waiting for 0.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
vscsi.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
vbd.
[2010-08-26 10:57:09 1840] DEBUG (DevController:144) Waiting for 51712.
[2010-08-26 10:57:09 1840] DEBUG (DevController:628) hotplugStatusCallback
/local/domain/0/backend/vbd/3/51712/hotplug-status.
[2010-08-26 10:57:09 1840] DEBUG (DevController:642) hotplugStatusCallback
1.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
irq.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
vfb.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
pci.
[2010-08-26 10:57:09 1840] DEBUG (DevController:144) Waiting for 0.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
vusb.
[2010-08-26 10:57:09 1840] DEBUG (DevController:139) Waiting for devices
vtpm.
[2010-08-26 10:57:09 1840] INFO (XendDomain:1206) Domain dpm (3) unpaused.

==> kern.log <==
2010-08-26T10:57:12.085252-07:00 kaan-18 [ 4698.128356] blkback: ring-ref 8,
event-channel 93, protocol 1 (x86_64-abi)
2010-08-26T10:57:12.126039-07:00 kaan-18 [ 4698.168555] ------------[ cut
here ]------------
2010-08-26T10:57:12.126141-07:00 kaan-18 [ 4698.168569] WARNING: at
kernel/lockdep.c:2323 trace_hardirqs_on_caller+0x12f/0x190()
2010-08-26T10:57:12.126220-07:00 kaan-18 [ 4698.168574] Hardware name:
ProLiant DL380 G6
2010-08-26T10:57:12.126297-07:00 kaan-18 [ 4698.168578] Modules linked in:
xt_physdev xenfs xen_gntdev xen_evtchn ipv6 xen_pciback tun fbcon tileblit
font bitblit softcursor bridge stp llc radeon ttm drm_kms_helper lp drm
i2c_algo_bit ipmi_si joydev i2c_core ipmi_msghandler hpilo hpwdt parport
serio_raw usbhid hid cciss usb_storage
2010-08-26T10:57:12.126405-07:00 kaan-18 [ 4698.168644] Pid: 11, comm:
xenwatch Not tainted 2.6.32.18 #1
2010-08-26T10:57:12.126482-07:00 kaan-18 [ 4698.168648] Call Trace:
2010-08-26T10:57:12.126559-07:00 kaan-18 [ 4698.168651]  <IRQ>
 [<ffffffff810a9f7f>] ? trace_hardirqs_on_caller+0x12f/0x190
2010-08-26T10:57:12.126655-07:00 kaan-18 [ 4698.168663]
 [<ffffffff8106bd60>] warn_slowpath_common+0x80/0xd0
2010-08-26T10:57:12.126731-07:00 kaan-18 [ 4698.168671]
 [<ffffffff815f3d70>] ? _spin_unlock_irq+0x30/0x40
2010-08-26T10:57:12.126806-07:00 kaan-18 [ 4698.168676]
 [<ffffffff8106bdc4>] warn_slowpath_null+0x14/0x20
2010-08-26T10:57:12.126881-07:00 kaan-18 [ 4698.168682]
 [<ffffffff810a9f7f>] trace_hardirqs_on_caller+0x12f/0x190
2010-08-26T10:57:12.126957-07:00 kaan-18 [ 4698.168688]
 [<ffffffff810a9fed>] trace_hardirqs_on+0xd/0x10
2010-08-26T10:57:12.127034-07:00 kaan-18 [ 4698.168693]
 [<ffffffff815f3d70>] _spin_unlock_irq+0x30/0x40
2010-08-26T10:57:12.127110-07:00 kaan-18 [ 4698.168700]
 [<ffffffff813c4e75>] add_to_net_schedule_list_tail+0x85/0xd0
2010-08-26T10:57:12.127186-07:00 kaan-18 [ 4698.168724]
 [<ffffffff813c60c6>] netif_be_int+0x36/0x160
2010-08-26T10:57:12.127263-07:00 kaan-18 [ 4698.168730]
 [<ffffffff810e0ea0>] handle_IRQ_event+0x70/0x180
2010-08-26T10:57:12.127338-07:00 kaan-18 [ 4698.168736]
 [<ffffffff810e3c69>] handle_level_irq+0x99/0x140
2010-08-26T10:57:12.127433-07:00 kaan-18 [ 4698.168742]
 [<ffffffff813b8acf>] __xen_evtchn_do_upcall+0x1bf/0x1f0
2010-08-26T10:57:12.127509-07:00 kaan-18 [ 4698.168747]
 [<ffffffff813b908d>] xen_evtchn_do_upcall+0x3d/0x60
2010-08-26T10:57:12.127577-07:00 kaan-18 [ 4698.168754]
 [<ffffffff8101647e>] xen_do_hypervisor_callback+0x1e/0x30
2010-08-26T10:57:12.127584-07:00 kaan-18 [ 4698.168758]  <EOI>
 [<ffffffff8100940a>] ? hypercall_page+0x40a/0x1010
2010-08-26T10:57:12.127589-07:00 kaan-18 [ 4698.168769]
 [<ffffffff8100940a>] ? hypercall_page+0x40a/0x1010
2010-08-26T10:57:12.127595-07:00 kaan-18 [ 4698.168775]
 [<ffffffff813bcd04>] ? xb_write+0x1e4/0x290
2010-08-26T10:57:12.127650-07:00 kaan-18 [ 4698.168780]
 [<ffffffff813bd77a>] ? xs_talkv+0x6a/0x1f0
2010-08-26T10:57:12.127657-07:00 kaan-18 [ 4698.168785]
 [<ffffffff813bd788>] ? xs_talkv+0x78/0x1f0
2010-08-26T10:57:12.127662-07:00 kaan-18 [ 4698.168790]
 [<ffffffff813bda7d>] ? xs_single+0x4d/0x60
2010-08-26T10:57:12.127667-07:00 kaan-18 [ 4698.168795]
 [<ffffffff813be3b2>] ? xenbus_read+0x52/0x80
2010-08-26T10:57:12.127673-07:00 kaan-18 [ 4698.168800]
 [<ffffffff813c86ac>] ? frontend_changed+0x48c/0x770
2010-08-26T10:57:12.127678-07:00 kaan-18 [ 4698.168806]
 [<ffffffff813bf61d>] ? xenbus_otherend_changed+0xdd/0x1b0
2010-08-26T10:57:12.127684-07:00 kaan-18 [ 4698.168813]
 [<ffffffff81010e3f>] ? xen_restore_fl_direct_end+0x0/0x1
2010-08-26T10:57:12.127689-07:00 kaan-18 [ 4698.168818]
 [<ffffffff810ac610>] ? lock_release+0xb0/0x230
2010-08-26T10:57:12.127770-07:00 kaan-18 [ 4698.168823]
 [<ffffffff813bf990>] ? frontend_changed+0x10/0x20
2010-08-26T10:57:12.127777-07:00 kaan-18 [ 4698.168829]
 [<ffffffff813bd3a5>] ? xenwatch_thread+0x55/0x160
2010-08-26T10:57:12.127782-07:00 kaan-18 [ 4698.168836]
 [<ffffffff810932b0>] ? autoremove_wake_function+0x0/0x40
2010-08-26T10:57:12.127788-07:00 kaan-18 [ 4698.168841]
 [<ffffffff813bd350>] ? xenwatch_thread+0x0/0x160
2010-08-26T10:57:12.127793-07:00 kaan-18 [ 4698.168847]
 [<ffffffff81092f36>] ? kthread+0x96/0xb0
2010-08-26T10:57:12.127799-07:00 kaan-18 [ 4698.168852]
 [<ffffffff8101632a>] ? child_rip+0xa/0x20
2010-08-26T10:57:12.127804-07:00 kaan-18 [ 4698.168856]
 [<ffffffff81015c90>] ? restore_args+0x0/0x30
2010-08-26T10:57:12.137042-07:00 kaan-18 [ 4698.168861]
 [<ffffffff81016320>] ? child_rip+0x0/0x20
2010-08-26T10:57:12.137052-07:00 kaan-18 [ 4698.168865] ---[ end trace
d11f63be69302ffc ]---
2010-08-26T10:57:18.775160-07:00 kaan-18 [ 4704.813405] vif3.0: no IPv6
routers present

Possibly related, or not, domU is running of memory:

boot looks normal until here:
[    0.659086] udev: starting version 151
[    0.783917] Initialising Xen virtual ethernet driver.
[    0.805892] blkfront: xvda: barriers enabled
[    0.807202]  xvda: xvda1 xvda2 < xvda5 >
[    1.048985] EXT4-fs (xvda1): mounted filesystem with ordered data mode
[    9.025260] Out of memory: kill process 633 (init) score 898 or a child
[    9.025413] Killed process 633 (init)
[    9.344581] Out of memory: kill process 534 (rsyslogd) score 428 or a
child
[    9.344740] Killed process 629 (rsyslogd)
[    9.657456] Out of memory: kill process 424 (mountall) score 405 or a
child
[    9.657613] Killed process 424 (mountall)

-Bruce

[-- Attachment #1.2: Type: text/html, Size: 22810 bytes --]

[-- Attachment #2: Type: text/plain, Size: 138 bytes --]

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

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

end of thread, other threads:[~2010-08-26 18:05 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2010-06-06 17:33 xenstored unsafe lock order detected, xlate_proc_name, evtchn_ioctl, port_user_lock Pasi Kärkkäinen
2010-06-06 17:41 ` Jeremy Fitzhardinge
2010-06-06 18:54   ` Pasi Kärkkäinen
2010-06-07 12:58     ` Pasi Kärkkäinen
2010-06-07 16:50       ` Jeremy Fitzhardinge
2010-07-20 11:53         ` Pasi Kärkkäinen
2010-07-20 16:17           ` Jeremy Fitzhardinge
2010-07-20 17:17             ` Pasi Kärkkäinen
2010-08-26 18:05               ` Bruce Edge

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 NNTP newsgroup(s).