Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1762709AbXHJIAT (ORCPT ); Fri, 10 Aug 2007 04:00:19 -0400 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1752351AbXHJH77 (ORCPT ); Fri, 10 Aug 2007 03:59:59 -0400 Received: from xdsl-664.zgora.dialog.net.pl ([81.168.226.152]:1456 "EHLO tuxland.pl" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751564AbXHJH75 (ORCPT ); Fri, 10 Aug 2007 03:59:57 -0400 From: Mariusz Kozlowski To: Andrew Morton , netdev@vger.kernel.org, Jeff Garzik Subject: Re: 2.6.23-rc2-mm2: possible irq lock inversion dependency detected Date: Fri, 10 Aug 2007 09:59:52 +0200 User-Agent: KMail/1.9.5 Cc: linux-kernel@vger.kernel.org References: <20070809224254.11f42716.akpm@linux-foundation.org> In-Reply-To: <20070809224254.11f42716.akpm@linux-foundation.org> MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Content-Disposition: inline Message-Id: <200708100959.53348.m.kozlowski@tuxland.pl> Sender: linux-kernel-owner@vger.kernel.org X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 41672 Lines: 780 Hello, Have fun :) ========================================================= [ INFO: possible irq lock inversion dependency detected ] 2.6.23-rc2-mm2 #1 --------------------------------------------------------- depscan.sh/5928 just changed the state of lock: (_xmit_ETHER){-+..}, at: [] dev_watchdog+0x17/0xcc but this lock took another, soft-irq-unsafe lock in the past: (&tp->lock){--..} and interrupts could create inverse lock ordering between them. other info that might help us debug this: no locks held by depscan.sh/5928. the first lock's dependencies: -> (_xmit_ETHER){-+..} ops: 27 { initial-use at: [] __lock_acquire+0x217/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_bh+0x3a/0x47 [] dev_set_rx_mode+0x14/0x3b [] dev_change_flags+0x68/0x190 [] devinet_ioctl+0x4af/0x652 [] inet_ioctl+0x56/0x71 [] sock_ioctl+0xa5/0x1d4 [] do_ioctl+0x22/0x71 [] vfs_ioctl+0x55/0x29e [] sys_ioctl+0x33/0x69 [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff in-softirq-W at: [] __lock_acquire+0x6f2/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock+0x35/0x42 [] dev_watchdog+0x17/0xcc [] run_timer_softirq+0x14b/0x1a9 [] __do_softirq+0x5b/0xb2 [] do_softirq+0x4d/0x4f [] irq_exit+0x48/0x4a [] do_IRQ+0x98/0xd0 [] common_interrupt+0x2e/0x34 [] 0xffffffff hardirq-on-W at: [] __lock_acquire+0x73e/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_bh+0x3a/0x47 [] dev_set_rx_mode+0x14/0x3b [] dev_change_flags+0x68/0x190 [] devinet_ioctl+0x4af/0x652 [] inet_ioctl+0x56/0x71 [] sock_ioctl+0xa5/0x1d4 [] do_ioctl+0x22/0x71 [] vfs_ioctl+0x55/0x29e [] sys_ioctl+0x33/0x69 [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff } ... key at: [] netdev_xmit_lock_key+0x8/0x1c0 -> (&tp->lock){--..} ops: 44 { initial-use at: [] __lock_acquire+0x217/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock+0x35/0x42 [] rtl8139_interrupt+0x27/0x469 [8139too] [] request_irq+0xba/0x108 [] rtl8139_open+0x2f/0x1e2 [8139too] [] dev_open+0x37/0x76 [] dev_change_flags+0x8e/0x190 [] devinet_ioctl+0x4af/0x652 [] inet_ioctl+0x56/0x71 [] sock_ioctl+0xa5/0x1d4 [] do_ioctl+0x22/0x71 [] vfs_ioctl+0x55/0x29e [] sys_ioctl+0x33/0x69 [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff softirq-on-W at: [] __lock_acquire+0x767/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock+0x35/0x42 [] rtl8139_interrupt+0x27/0x469 [8139too] [] free_irq+0x11b/0x146 [] rtl8139_close+0x8a/0x14a [8139too] [] dev_close+0x57/0x74 [] dev_change_flags+0x8e/0x190 [] devinet_ioctl+0x4af/0x652 [] inet_ioctl+0x56/0x71 [] sock_ioctl+0xa5/0x1d4 [] do_ioctl+0x22/0x71 [] vfs_ioctl+0x55/0x29e [] sys_ioctl+0x33/0x69 [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff hardirq-on-W at: [] __lock_acquire+0x73e/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock+0x35/0x42 [] rtl8139_interrupt+0x27/0x469 [8139too] [] free_irq+0x11b/0x146 [] rtl8139_close+0x8a/0x14a [8139too] [] dev_close+0x57/0x74 [] dev_change_flags+0x8e/0x190 [] devinet_ioctl+0x4af/0x652 [] inet_ioctl+0x56/0x71 [] sock_ioctl+0xa5/0x1d4 [] do_ioctl+0x22/0x71 [] vfs_ioctl+0x55/0x29e [] sys_ioctl+0x33/0x69 [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff } ... key at: [] __key.19796+0x0/0xffffd3c9 [8139too] ... acquired at: [] __lock_acquire+0x109b/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] rtl8139_set_rx_mode+0x1e/0x166 [8139too] [] __dev_set_rx_mode+0x24/0x85 [] dev_set_rx_mode+0x26/0x3b [] dev_open+0x5a/0x76 [] dev_change_flags+0x8e/0x190 [] devinet_ioctl+0x4af/0x652 [] inet_ioctl+0x56/0x71 [] sock_ioctl+0xa5/0x1d4 [] do_ioctl+0x22/0x71 [] vfs_ioctl+0x55/0x29e [] sys_ioctl+0x33/0x69 [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff -> (&priv->lock){++..} ops: 113 { initial-use at: [] __lock_acquire+0x217/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irq+0x3b/0x48 [] orinoco_init+0x8f5/0xbbd [orinoco] [] register_netdevice+0x13a/0x3f8 [] register_netdev+0x32/0x3f [] orinoco_cs_probe+0x368/0x3df [orinoco_cs] [] pcmcia_device_probe+0xc9/0x14c [pcmcia] [] driver_probe_device+0xa6/0x198 [] __driver_attach+0xa2/0xa4 [] bus_for_each_dev+0x43/0x61 [] driver_attach+0x19/0x1b [] bus_add_driver+0x7e/0x1a5 [] driver_register+0x45/0x75 [] pcmcia_register_driver+0xdb/0x12f [pcmcia] [] 0xde84b024 [] sys_init_module+0xc4/0x1622 [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff in-hardirq-W at: [] __lock_acquire+0x949/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] orinoco_interrupt+0x3f/0x1219 [orinoco] [] handle_IRQ_event+0x28/0x59 [] handle_level_irq+0xad/0x10b [] do_IRQ+0x93/0xd0 [] common_interrupt+0x2e/0x34 [] do_softirq+0x4d/0x4f [] irq_exit+0x48/0x4a [] do_IRQ+0x98/0xd0 [] common_interrupt+0x2e/0x34 [] orinoco_get_wireless_stats+0xeb/0x140 [orinoco] [] get_wireless_stats+0x1a/0x21 [] wireless_seq_show+0x20/0x143 [] seq_read+0x1af/0x2b8 [] proc_reg_read+0x57/0x78 [] vfs_read+0xaa/0x147 [] sys_read+0x3d/0x7b [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff in-softirq-W at: [] __lock_acquire+0x6f2/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] orinoco_interrupt+0x3f/0x1219 [orinoco] [] handle_IRQ_event+0x28/0x59 [] handle_level_irq+0xad/0x10b [] do_IRQ+0x93/0xd0 [] common_interrupt+0x2e/0x34 [] do_softirq+0x4d/0x4f [] irq_exit+0x48/0x4a [] do_IRQ+0x98/0xd0 [] common_interrupt+0x2e/0x34 [] orinoco_get_wireless_stats+0xeb/0x140 [orinoco] [] get_wireless_stats+0x1a/0x21 [] wireless_seq_show+0x20/0x143 [] seq_read+0x1af/0x2b8 [] proc_reg_read+0x57/0x78 [] vfs_read+0xaa/0x147 [] sys_read+0x3d/0x7b [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff } ... key at: [] __key.20430+0x0/0xffffc9cd [orinoco] -> (lweventlist_lock){+...} ops: 8 { initial-use at: [] __lock_acquire+0x217/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] linkwatch_add_event+0x10/0x31 [] linkwatch_fire_event+0x35/0x37 [] netif_carrier_off+0x19/0x20 [] alloc_orinocodev+0x181/0x19c [orinoco] [] orinoco_cs_probe+0x1d/0x3df [orinoco_cs] [] pcmcia_device_probe+0xc9/0x14c [pcmcia] [] driver_probe_device+0xa6/0x198 [] __driver_attach+0xa2/0xa4 [] bus_for_each_dev+0x43/0x61 [] driver_attach+0x19/0x1b [] bus_add_driver+0x7e/0x1a5 [] driver_register+0x45/0x75 [] pcmcia_register_driver+0xdb/0x12f [pcmcia] [] 0xde84b024 [] sys_init_module+0xc4/0x1622 [] sysenter_past_esp+0x5f/0x99 [] 0xffffffff in-hardirq-W at: [] __lock_acquire+0x949/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] linkwatch_add_event+0x10/0x31 [] linkwatch_fire_event+0x35/0x37 [] netif_carrier_on+0x29/0x2b [] orinoco_interrupt+0x1067/0x1219 [orinoco] [] handle_IRQ_event+0x28/0x59 [] handle_level_irq+0xad/0x10b [] do_IRQ+0x93/0xd0 [] common_interrupt+0x2e/0x34 [] cpuidle_idle_call+0x74/0x99 [] cpu_idle+0x87/0x89 [] rest_init+0x60/0x62 [] start_kernel+0x23a/0x2c5 [<00000000>] 0x0 [] 0xffffffff } ... key at: [] lweventlist_lock+0x10/0x20 ... acquired at: [] __lock_acquire+0x109b/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] linkwatch_add_event+0x10/0x31 [] linkwatch_fire_event+0x35/0x37 [] netif_carrier_on+0x29/0x2b [] orinoco_interrupt+0x1067/0x1219 [orinoco] [] handle_IRQ_event+0x28/0x59 [] handle_level_irq+0xad/0x10b [] do_IRQ+0x93/0xd0 [] common_interrupt+0x2e/0x34 [] cpuidle_idle_call+0x74/0x99 [] cpu_idle+0x87/0x89 [] rest_init+0x60/0x62 [] start_kernel+0x23a/0x2c5 [<00000000>] 0x0 [] 0xffffffff -> (&cwq->lock){++..} ops: 4593 { initial-use at: [] __lock_acquire+0x217/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] __queue_work+0xf/0x2d [] queue_work+0x57/0x90 [] call_usermodehelper_exec+0xce/0xe1 [] kobject_uevent_env+0x34d/0x449 [] kobject_uevent+0xa/0xf [] kset_register+0x32/0x38 [] subsystem_register+0x8/0xa [] bus_register+0x65/0x1f3 [] platform_bus_init+0x23/0x38 [] driver_init+0x1c/0x31 [] kernel_init+0x5d/0x26b [] kernel_thread_helper+0x7/0x1c [] 0xffffffff in-hardirq-W at: [] __lock_acquire+0x949/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] __queue_work+0xf/0x2d [] queue_work+0x57/0x90 [] acpi_os_execute+0xae/0xcb [] acpi_ec_gpe_handler+0x4d/0x5e [] acpi_ev_gpe_dispatch+0x4b/0x115 [] acpi_ev_gpe_detect+0x9a/0xe1 [] acpi_ev_sci_xrupt_handler+0x15/0x1d [] acpi_irq+0xe/0x18 [] handle_IRQ_event+0x28/0x59 [] handle_level_irq+0xad/0x10b [] do_IRQ+0x93/0xd0 [] common_interrupt+0x2e/0x34 [] cpu_idle+0x87/0x89 [] rest_init+0x60/0x62 [] start_kernel+0x23a/0x2c5 [<00000000>] 0x0 [] 0xffffffff in-softirq-W at: [] __lock_acquire+0x6f2/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] __queue_work+0xf/0x2d [] delayed_work_timer_fn+0x24/0x28 [] run_timer_softirq+0x14b/0x1a9 [] __do_softirq+0x5b/0xb2 [] do_softirq+0x4d/0x4f [] irq_exit+0x48/0x4a [] do_IRQ+0x98/0xd0 [] common_interrupt+0x2e/0x34 [] run_workqueue+0xe8/0x1f3 [] worker_thread+0x9a/0xf2 [] kthread+0x36/0x58 [] kernel_thread_helper+0x7/0x1c [] 0xffffffff } ... key at: [] __key.11148+0x0/0x8 -> (&q->lock){++..} ops: 74830 { initial-use at: [] __lock_acquire+0x217/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irq+0x3b/0x48 [] wait_for_completion+0x24/0xb5 [] kthread_create+0x69/0xa8 [] cpu_callback+0x48/0xa3 [] spawn_ksoftirqd+0x1c/0x4e [] kernel_init+0x3c/0x26b [] kernel_thread_helper+0x7/0x1c [] 0xffffffff in-hardirq-W at: [] __lock_acquire+0x949/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] __wake_up+0x15/0x42 [] acpi_ec_gpe_handler+0x26/0x5e [] acpi_ev_gpe_dispatch+0x4b/0x115 [] acpi_ev_gpe_detect+0x9a/0xe1 [] acpi_ev_sci_xrupt_handler+0x15/0x1d [] acpi_irq+0xe/0x18 [] handle_IRQ_event+0x28/0x59 [] handle_level_irq+0xad/0x10b [] do_IRQ+0x93/0xd0 [] common_interrupt+0x2e/0x34 [] cpu_idle+0x87/0x89 [] rest_init+0x60/0x62 [] start_kernel+0x23a/0x2c5 [<00000000>] 0x0 [] 0xffffffff in-softirq-W at: [] __lock_acquire+0x6f2/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] complete+0x15/0x4b [] wakeme_after_rcu+0xb/0xd [] __rcu_process_callbacks+0x69/0x1cf [] rcu_process_callbacks+0x12/0x23 [] tasklet_action+0x3b/0x7b [] __do_softirq+0x5b/0xb2 [] do_softirq+0x4d/0x4f [] irq_exit+0x48/0x4a [] do_IRQ+0x98/0xd0 [] common_interrupt+0x2e/0x34 [] cpu_idle+0x87/0x89 [] rest_init+0x60/0x62 [] start_kernel+0x23a/0x2c5 [<00000000>] 0x0 [] 0xffffffff } ... key at: [] __key.11466+0x0/0x8 -> (&rq->rq_lock_key){++..} ops: 216798 { initial-use at: [] __lock_acquire+0x217/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] init_idle+0x40/0x6d [] sched_init+0x169/0x17c [] start_kernel+0xd5/0x2c5 [<00000000>] 0x0 [] 0xffffffff in-hardirq-W at: [] __lock_acquire+0x949/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock+0x35/0x42 [] scheduler_tick+0x20/0x192 [] update_process_times+0x43/0x62 [] tick_periodic+0x24/0x75 [] tick_handle_periodic+0x18/0x7a [] timer_interrupt+0xe/0x15 [] handle_IRQ_event+0x28/0x59 [] handle_level_irq+0xad/0x10b [] do_IRQ+0x93/0xd0 [] common_interrupt+0x2e/0x34 [] setup_irq+0xf2/0x20d [] time_init_hook+0x19/0x1b [] hpet_time_init+0xd/0x15 [] start_kernel+0x1d5/0x2c5 [<00000000>] 0x0 [] 0xffffffff in-softirq-W at: [] __lock_acquire+0x6f2/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock+0x35/0x42 [] task_rq_lock+0x28/0x40 [] try_to_wake_up+0x18/0x92 [] default_wake_function+0xb/0xd [] __wake_up_common+0x39/0x59 [] complete+0x3a/0x4b [] wakeme_after_rcu+0xb/0xd [] __rcu_process_callbacks+0x69/0x1cf [] rcu_process_callbacks+0x12/0x23 [] tasklet_action+0x3b/0x7b [] __do_softirq+0x5b/0xb2 [] do_softirq+0x4d/0x4f [] irq_exit+0x48/0x4a [] do_IRQ+0x98/0xd0 [] common_interrupt+0x2e/0x34 [] cpu_idle+0x87/0x89 [] rest_init+0x60/0x62 [] start_kernel+0x23a/0x2c5 [<00000000>] 0x0 [] 0xffffffff } ... key at: [] per_cpu__runqueues+0x468/0x470 ... acquired at: [] __lock_acquire+0x109b/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock+0x35/0x42 [] task_rq_lock+0x28/0x40 [] try_to_wake_up+0x18/0x92 [] default_wake_function+0xb/0xd [] __wake_up_common+0x39/0x59 [] complete+0x3a/0x4b [] kthread+0x1f/0x58 [] kernel_thread_helper+0x7/0x1c [] 0xffffffff ... acquired at: [] __lock_acquire+0x109b/0x11ac [] lock_acquire+0x99/0xb2 [] _spin_lock_irqsave+0x3e/0x4e [] __wake_up+0x15/0x42 [] insert_work+0x60/0x75 [] __queue_work+0x1f/0x2d [] queue_work+0x57/0x90 [] call_usermodehelper_exec+0xce/0xe1 [] kobject_uevent_env+0x34d/0x449 [] kobject_uevent+0xa/0xf [] kset_register+0x32/0x38 [] subsystem_register+0x8/0xa [] bus_register+0x65/0x1f3 [] platform_bus_init+0x23/0x38 [] driver_init+0x1c/0x31 [] kernel_init+0x5d/0x26b [] kernel_thread_helper+0x7/0x1c [] 0xffffffff ... acquired at: [] __lock_acquire+0x109b/0x11ac [] lock_acquire+0x99/0xb2 [