From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753348AbZEXTAI (ORCPT ); Sun, 24 May 2009 15:00:08 -0400 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1751363AbZEXS7z (ORCPT ); Sun, 24 May 2009 14:59:55 -0400 Received: from casper.infradead.org ([85.118.1.10]:59779 "EHLO casper.infradead.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750916AbZEXS7y (ORCPT ); Sun, 24 May 2009 14:59:54 -0400 Subject: Re: INFO: possible circular locking dependency at cleanup_workqueue_thread From: Peter Zijlstra To: Ming Lei Cc: Johannes Berg , Ingo Molnar , Zdenek Kabelac , "Rafael J. Wysocki" , Linux Kernel Mailing List , Gautham R Shenoy , Oleg Nesterov In-Reply-To: References: Content-Type: text/plain Date: Sun, 24 May 2009 20:58:46 +0200 Message-Id: <1243191526.6954.26.camel@laptop> Mime-Version: 1.0 X-Mailer: Evolution 2.26.1 Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Below are the original lockdep output and the one generated by applying Lei Ming's BFS shortest cycle patch. It appears to find a slightly shorter variant, removing setup_lock from the cycle -- but it might be a difference in setup or userland. Looking again at Oleg's example, I think this again falls short of finding the L1-L2 inversion, simply because we establish (and therefore find) the longer cycle first. Simply because we warn at the first cycle detected, it means we'll never continue to build dependencies to build shorter ones,.. I think? /me goes trying to construct a scenario to disprove the above. On Tue, 2009-05-12 at 09:59 +0200, Zdenek Kabelac wrote: > ======================================================= > [ INFO: possible circular locking dependency detected ] > 2.6.30-rc5-00097-gd665355 #59 > ------------------------------------------------------- > pm-suspend/12129 is trying to acquire lock: > (events){+.+.+.}, at: [] cleanup_workqueue_thread+0x26/0xd0 > > but task is already holding lock: > (cpu_add_remove_lock){+.+.+.}, at: [] > cpu_maps_update_begin+0x17/0x20 > > which lock already depends on the new lock. > > > the existing dependency chain (in reverse order) is: > > -> #5 (cpu_add_remove_lock){+.+.+.}: > [] __lock_acquire+0xc64/0x10a0 > [] lock_acquire+0x98/0x140 > [] __mutex_lock_common+0x4c/0x3b0 > [] mutex_lock_nested+0x46/0x60 > [] cpu_maps_update_begin+0x17/0x20 > [] __create_workqueue_key+0xc3/0x250 > [] stop_machine_create+0x40/0xb0 > [] sys_delete_module+0x84/0x270 > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > > -> #4 (setup_lock){+.+.+.}: > [] __lock_acquire+0xc64/0x10a0 > [] lock_acquire+0x98/0x140 > [] __mutex_lock_common+0x4c/0x3b0 > [] mutex_lock_nested+0x46/0x60 > [] stop_machine_create+0x17/0xb0 > [] disable_nonboot_cpus+0x26/0x130 > [] suspend_devices_and_enter+0xbd/0x1b0 > [] enter_state+0x107/0x170 > [] state_store+0x99/0x100 > [] kobj_attr_store+0x17/0x20 > [] sysfs_write_file+0xd9/0x160 > [] vfs_write+0xb8/0x180 > [] sys_write+0x51/0x90 > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > > -> #3 (dpm_list_mtx){+.+.+.}: > [] __lock_acquire+0xc64/0x10a0 > [] lock_acquire+0x98/0x140 > [] __mutex_lock_common+0x4c/0x3b0 > [] mutex_lock_nested+0x46/0x60 > [] device_pm_add+0x1f/0xe0 > [] device_add+0x45f/0x570 > [] wiphy_register+0x158/0x280 [cfg80211] > [] ieee80211_register_hw+0xbc/0x410 [mac80211] > [] iwl3945_pci_probe+0xa1c/0x1080 [iwl3945] > [] local_pci_probe+0x17/0x20 > [] pci_device_probe+0x88/0xb0 > [] driver_probe_device+0x89/0x180 > [] __driver_attach+0x9b/0xa0 > [] bus_for_each_dev+0x6c/0xa0 > [] driver_attach+0x1e/0x20 > [] bus_add_driver+0xd5/0x290 > [] driver_register+0x78/0x140 > [] __pci_register_driver+0x66/0xe0 > [] 0xffffffffa00bd05c > [] do_one_initcall+0x3f/0x1c0 > [] sys_init_module+0xb1/0x200 > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > > -> #2 (cfg80211_mutex){+.+.+.}: > [] __lock_acquire+0xc64/0x10a0 > [] lock_acquire+0x98/0x140 > [] __mutex_lock_common+0x4c/0x3b0 > [] mutex_lock_nested+0x46/0x60 > [] reg_todo+0x19a/0x590 [cfg80211] > [] worker_thread+0x1e8/0x3a0 > [] kthread+0x5a/0xa0 > [] child_rip+0xa/0x20 > [] 0xffffffffffffffff > > -> #1 (reg_work){+.+.+.}: > [] __lock_acquire+0xc64/0x10a0 > [] lock_acquire+0x98/0x140 > [] worker_thread+0x1e2/0x3a0 > [] kthread+0x5a/0xa0 > [] child_rip+0xa/0x20 > [] 0xffffffffffffffff > > -> #0 (events){+.+.+.}: > [] __lock_acquire+0xd36/0x10a0 > [] lock_acquire+0x98/0x140 > [] cleanup_workqueue_thread+0x4d/0xd0 > [] workqueue_cpu_callback+0xc9/0x10f > [] notifier_call_chain+0x68/0xa0 > [] raw_notifier_call_chain+0x16/0x20 > [] _cpu_down+0x1cc/0x2d0 > [] disable_nonboot_cpus+0xb0/0x130 > [] suspend_devices_and_enter+0xbd/0x1b0 > [] enter_state+0x107/0x170 > [] state_store+0x99/0x100 > [] kobj_attr_store+0x17/0x20 > [] sysfs_write_file+0xd9/0x160 > [] vfs_write+0xb8/0x180 > [] sys_write+0x51/0x90 > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > > other info that might help us debug this: > > 4 locks held by pm-suspend/12129: > #0: (&buffer->mutex){+.+.+.}, at: [] > sysfs_write_file+0x44/0x160 > #1: (pm_mutex){+.+.+.}, at: [] enter_state+0x54/0x170 > #2: (dpm_list_mtx){+.+.+.}, at: [] device_pm_lock+0x17/0x20 > #3: (cpu_add_remove_lock){+.+.+.}, at: [] > cpu_maps_update_begin+0x17/0x20 > > stack backtrace: > Pid: 12129, comm: pm-suspend Not tainted 2.6.30-rc5-00097-gd665355 #59 > Call Trace: > [] print_circular_bug_tail+0x9d/0xe0 > [] __lock_acquire+0xd36/0x10a0 > [] ? mark_lock+0x3e0/0x400 > [] lock_acquire+0x98/0x140 > [] ? cleanup_workqueue_thread+0x26/0xd0 > [] cleanup_workqueue_thread+0x4d/0xd0 > [] ? cleanup_workqueue_thread+0x26/0xd0 > [] ? trace_hardirqs_on+0xd/0x10 > [] workqueue_cpu_callback+0xc9/0x10f > [] ? cpu_callback+0x12/0x280 > [] notifier_call_chain+0x68/0xa0 > [] raw_notifier_call_chain+0x16/0x20 > [] _cpu_down+0x1cc/0x2d0 > [] disable_nonboot_cpus+0xb0/0x130 > [] suspend_devices_and_enter+0xbd/0x1b0 > [] enter_state+0x107/0x170 > [] state_store+0x99/0x100 > [] kobj_attr_store+0x17/0x20 > [] sysfs_write_file+0xd9/0x160 > [] vfs_write+0xb8/0x180 > [] ? audit_syscall_entry+0x21c/0x240 > [] sys_write+0x51/0x90 > [] system_call_fastpath+0x16/0x1b ======================================================= [ INFO: possible circular locking dependency detected ] 2.6.30-rc6-tip #9 ------------------------------------------------------- bash/6174 is trying to acquire lock: (events){+.+.+.}, at: [] cleanup_workqueue_thread+0x28/0x10a but task is already holding lock: (cpu_add_remove_lock){+.+.+.}, at: [] disable_nonboot_cpus+0x38/0x128 which lock already depends on the new lock. the existing dependency chain (in reverse order) is: -> #4 (cpu_add_remove_lock){+.+.+.}: [] __lock_acquire+0xa80/0xc08 [] lock_acquire+0x108/0x134 [] __mutex_lock_common+0x5e/0x494 [] mutex_lock_nested+0x19/0x1b [] disable_nonboot_cpus+0x38/0x128 [] suspend_devices_and_enter+0xf5/0x1f4 [] enter_state+0x168/0x1ce [] state_store+0xbc/0xdd [] kobj_attr_store+0x17/0x19 [] sysfs_write_file+0xe9/0x11e [] vfs_write+0xb0/0x10a [] sys_write+0x4c/0x75 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff -> #3 (dpm_list_mtx){+.+.+.}: [] __lock_acquire+0xa80/0xc08 [] lock_acquire+0x108/0x134 [] __mutex_lock_common+0x5e/0x494 [] mutex_lock_nested+0x19/0x1b [] device_pm_add+0x23/0xcd [] device_add+0x38b/0x549 [] wiphy_register+0x139/0x1ee [] ieee80211_register_hw+0xee/0x3bf [] iwl_setup_mac+0x8b/0xd1 [] iwl_pci_probe+0x7f5/0x921 [] local_pci_probe+0x17/0x1b [] do_work_for_cpu+0x18/0x2a [] kthread+0x5b/0x88 [] child_rip+0xa/0x20 [] 0xffffffffffffffff -> #2 (cfg80211_mutex){+.+.+.}: [] __lock_acquire+0xa80/0xc08 [] lock_acquire+0x108/0x134 [] __mutex_lock_common+0x5e/0x494 [] mutex_lock_nested+0x19/0x1b [] reg_todo+0x53/0x490 [] worker_thread+0x250/0x3dc [] kthread+0x5b/0x88 [] child_rip+0xa/0x20 [] 0xffffffffffffffff -> #1 (reg_work){+.+.+.}: [] __lock_acquire+0xa80/0xc08 [] lock_acquire+0x108/0x134 [] worker_thread+0x1d7/0x3dc [] kthread+0x5b/0x88 [] child_rip+0xa/0x20 [] 0xffffffffffffffff -> #0 (events){+.+.+.}: [] __lock_acquire+0x974/0xc08 [] lock_acquire+0x108/0x134 [] cleanup_workqueue_thread+0x4f/0x10a [] workqueue_cpu_callback+0xc9/0x10d [] notifier_call_chain+0x33/0x5b [] raw_notifier_call_chain+0x14/0x16 [] _cpu_down+0x283/0x2a0 [] disable_nonboot_cpus+0x7d/0x128 [] suspend_devices_and_enter+0xf5/0x1f4 [] enter_state+0x168/0x1ce [] state_store+0xbc/0xdd [] kobj_attr_store+0x17/0x19 [] sysfs_write_file+0xe9/0x11e [] vfs_write+0xb0/0x10a [] sys_write+0x4c/0x75 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff other info that might help us debug this: 4 locks held by bash/6174: #0: (&buffer->mutex){+.+.+.}, at: [] sysfs_write_file+0x3d/0x11e #1: (pm_mutex){+.+.+.}, at: [] enter_state+0x1c5/0x1ce #2: (dpm_list_mtx){+.+.+.}, at: [] device_pm_lock+0x17/0x19 #3: (cpu_add_remove_lock){+.+.+.}, at: [] disable_nonboot_cpus+0x38/0x128 stack backtrace: Pid: 6174, comm: bash Not tainted 2.6.30-rc6-tip #9 Call Trace: [] print_circular_bug+0x1cc/0x201 [] __lock_acquire+0x974/0xc08 [] lock_acquire+0x108/0x134 [] ? cleanup_workqueue_thread+0x28/0x10a [] cleanup_workqueue_thread+0x4f/0x10a [] ? cleanup_workqueue_thread+0x28/0x10a [] workqueue_cpu_callback+0xc9/0x10d [] notifier_call_chain+0x33/0x5b [] raw_notifier_call_chain+0x14/0x16 [] _cpu_down+0x283/0x2a0 [] disable_nonboot_cpus+0x7d/0x128 [] suspend_devices_and_enter+0xf5/0x1f4 [] enter_state+0x168/0x1ce [] state_store+0xbc/0xdd [] kobj_attr_store+0x17/0x19 [] sysfs_write_file+0xe9/0x11e [] vfs_write+0xb0/0x10a [] sys_write+0x4c/0x75 [] system_call_fastpath+0x16/0x1b