Skip to contentSkip to conversation

[2.6.20] BUG: workqueue leaked lock

PATCH In review Folkert van Heusden 9 participants 35 messages Mar 13, 2007 – Mar 22, 2007

Subsystems (2)
lore
Share & tools
lore
#0 lore raw

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================
[ 1792.436492] svc: unknown version (0 for prog 100003, nfsd)
[ 1846.683648] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1846.683701]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1846.683832] 2 locks held by nfsd4/3577:
[ 1846.683885]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1846.683980]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1846.683988]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1846.683994]  [<c1003d7f>] show_trace+0x12/0x14
[ 1846.683997]  [<c1003e79>] dump_stack+0x16/0x18
[ 1846.684001]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1846.684006]  [<c102c437>] worker_thread+0x146/0x165
[ 1846.684012]  [<c102f797>] kthread+0x97/0xc4
[ 1846.684023]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1846.684027]  =======================
[ 1936.638930] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1936.638992]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1936.639141] 2 locks held by nfsd4/3577:
[ 1936.639195]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1936.639292]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1936.639301]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1936.639306]  [<c1003d7f>] show_trace+0x12/0x14
[ 1936.639311]  [<c1003e79>] dump_stack+0x16/0x18
[ 1936.639314]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1936.639321]  [<c102c437>] worker_thread+0x146/0x165
[ 1936.639325]  [<c102f797>] kthread+0x97/0xc4
[ 1936.639329]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1936.639332]  =======================

this repeats several times

also:

[  137.324255] =======================================================
[  137.324359] [ INFO: possible circular locking dependency detected ]
[  137.324412] 2.6.20 #2
[  137.324457] -------------------------------------------------------
[  137.324510] tor/4857 is trying to acquire lock:
[  137.324559]  (tty_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.324765]
[  137.324766] but task is already holding lock:
[  137.324859]  (&s->s_dquot.dqptr_sem){----}, at: [<c1099403>] dquot_alloc_space+0x50/0x189
[  137.325067]
[  137.325069] which lock already depends on the new lock.
[  137.325071]
[  137.325206]
[  137.325208] the existing dependency chain (in reverse order) is:
[  137.325300]
[  137.325301] -> #4 (&s->s_dquot.dqptr_sem){----}:
[  137.325501]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.325852]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.326197]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.326538]        [<c1037624>] lock_acquire+0x62/0x81
[  137.326887]        [<c1032b5f>] down_read+0x2b/0x3d
[  137.327241]        [<c1099403>] dquot_alloc_space+0x50/0x189
[  137.327588]        [<c10a98e6>] ext3_new_blocks+0x44b/0x5a2
[  137.327935]        [<c10abe78>] ext3_alloc_blocks+0x40/0xdf
[  137.328280]        [<c10abf67>] ext3_alloc_branch+0x50/0x21b
[  137.328622]        [<c10ac445>] ext3_get_blocks_handle+0x1b8/0x367
[  137.328980]        [<c10ac76e>] ext3_getblk+0x97/0x228
[  137.329330]        [<c10ac919>] ext3_bread+0x1a/0x78
[  137.329672]        [<c10b1bc2>] ext3_mkdir+0xf4/0x270
[  137.330022]        [<c1072a6a>] vfs_mkdir+0xb3/0x161
[  137.330368]        [<c1072ba4>] sys_mkdirat+0x8c/0xc4
[  137.330714]        [<c1072bfc>] sys_mkdir+0x20/0x22
[  137.331063]        [<c1002f78>] syscall_call+0x7/0xb
[  137.331406]        [<ffffffff>] 0xffffffff
[  137.331771]
[  137.331772] -> #3 (&ei->truncate_mutex){--..}:
[  137.331979]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.332332]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.332676]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.333025]        [<c1037624>] lock_acquire+0x62/0x81
[  137.333370]        [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.333930]        [<c1205b88>] mutex_lock+0x8/0xa
[  137.334271]        [<c10ae14f>] ext3_truncate+0x170/0x468
[  137.334613]        [<c1058e72>] vmtruncate+0xa6/0x116
[  137.334949]        [<c107d587>] inode_setattr+0x145/0x16c
[  137.334613]        [<c1058e72>] vmtruncate+0xa6/0x116
[  137.334949]        [<c107d587>] inode_setattr+0x145/0x16c
[  137.335286]        [<c10af071>] ext3_setattr+0x150/0x22f
[  137.335627]        [<c107d909>] notify_change+0x35b/0x392
[  137.335968]        [<c10679d2>] do_truncate+0x52/0x75
[  137.336305]        [<c1071f5e>] may_open+0x1ec/0x231
[  137.336642]        [<c107211c>] open_namei+0xda/0x59b
[  137.336975]        [<c106863a>] do_filp_open+0x2c/0x53
[  137.337310]        [<c106896f>] do_sys_open+0x52/0xd8
[  137.337645]        [<c1068a11>] sys_open+0x1c/0x1e
[  137.337980]        [<c1002f78>] syscall_call+0x7/0xb
[  137.338315]        [<ffffffff>] 0xffffffff
[  137.338665]
[  137.338666] -> #2 (&inode->i_alloc_sem){--..}:
[  137.338864]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.339200]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.339535]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.339874]        [<c1037624>] lock_acquire+0x62/0x81
[  137.340207]        [<c1032bf5>] down_write+0x2b/0x45
[  137.340545]        [<c107d890>] notify_change+0x2e2/0x392
[  137.340886]        [<c10679d2>] do_truncate+0x52/0x75
[  137.341222]        [<c1071f5e>] may_open+0x1ec/0x231
[  137.341557]        [<c107211c>] open_namei+0xda/0x59b
[  137.341898]        [<c106863a>] do_filp_open+0x2c/0x53
[  137.342236]        [<c106896f>] do_sys_open+0x52/0xd8
[  137.342572]        [<c1068a11>] sys_open+0x1c/0x1e
[  137.343109]        [<c1002f78>] syscall_call+0x7/0xb
[  137.343444]        [<ffffffff>] 0xffffffff
[  137.343792]
[  137.343793] -> #1 (&sysfs_inode_imutex_key){--..}:
[  137.343988]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.344320]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.344655]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.344986]        [<c1037624>] lock_acquire+0x62/0x81
[  137.345321]        [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.345658]        [<c1205b88>] mutex_lock+0x8/0xa
[  137.345991]        [<c10a5447>] sysfs_hash_and_remove+0x43/0x11c
[  137.346328]        [<c10a5ef7>] sysfs_remove_file+0xd/0x12
[  137.346660]        [<c114b00c>] device_remove_file+0x32/0x44
[  137.346992]        [<c114b6d9>] device_del+0x174/0x1d2
[  137.347325]        [<c114b742>] device_unregister+0xb/0x15
[  137.347661]        [<c114b93d>] device_destroy+0x8d/0x9a
[  137.347994]        [<c1137a38>] vcs_remove_sysfs+0x1c/0x38
[  137.348328]        [<c113e0d8>] con_close+0x5e/0x6b
[  137.348661]        [<c1130103>] release_dev+0x4c4/0x6ce
[  137.348999]        [<c113077b>] tty_release+0x12/0x1c
[  137.349332]        [<c106a471>] __fput+0x145/0x16e
[  137.349671]        [<c106a32a>] fput+0x19/0x1b
[  137.350004]        [<c1068a92>] filp_close+0x3c/0x75
[  137.350338]        [<c1068b34>] sys_close+0x69/0xb4
[  137.350671]        [<c1002f78>] syscall_call+0x7/0xb
[  137.351003]        [<ffffffff>] 0xffffffff
[  137.351352]
[  137.351354] -> #0 (tty_mutex){--..}:
[  137.351544]        [<c1035398>] check_prev_add+0x34/0x206
[  137.352086]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.352421]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.352759]        [<c1037624>] lock_acquire+0x62/0x81
[  137.353090]        [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.353426]        [<c1205b88>] mutex_lock+0x8/0xa
[  137.353761]        [<c1098d79>] print_warning+0x8c/0x15d
[  137.354096]        [<c1099537>] dquot_alloc_space+0x184/0x189
[  137.354434]        [<c10a98e6>] ext3_new_blocks+0x44b/0x5a2
[  137.354773]        [<c10abe78>] ext3_alloc_blocks+0x40/0xdf
[  137.355109]        [<c10abf67>] ext3_alloc_branch+0x50/0x21b
[  137.355446]        [<c10ac445>] ext3_get_blocks_handle+0x1b8/0x367
[  137.355783]        [<c10ac66c>] ext3_get_block+0x78/0xe3
[  137.356121]        [<c108a239>] __block_prepare_write+0x168/0x3fd
[  137.356459]        [<c108ad10>] block_prepare_write+0x28/0x3b
[  137.356800]        [<c10acbcd>] ext3_prepare_write+0x3f/0x18d
[  137.357138]        [<c104dbe5>] generic_file_buffered_write+0x197/0x5e6
[  137.357474]        [<c104e2e2>] __generic_file_aio_write_nolock+0x2ae/0x5ad
[  137.357817]        [<c104e6ea>] generic_file_aio_write+0x58/0xc4
[  137.358156]        [<c10aa723>] ext3_file_write+0x2d/0xba
[  137.357817]        [<c104e6ea>] generic_file_aio_write+0x58/0xc4
[  137.358156]        [<c10aa723>] ext3_file_write+0x2d/0xba
[  137.358495]        [<c1069441>] do_sync_write+0xc7/0x116
[  137.358838]        [<c1069612>] vfs_write+0x182/0x187
[  137.359176]        [<c10696b8>] sys_write+0x3d/0x64
[  137.359513]        [<c1002f78>] syscall_call+0x7/0xb
[  137.359848]        [<ffffffff>] 0xffffffff
[  137.360200]
[  137.360202] other info that might help us debug this:
[  137.360204]
[  137.360335] 3 locks held by tor/4857:
[  137.360382]  #0:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.360625]  #1:  (&ei->truncate_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.361072]  #2:  (&s->s_dquot.dqptr_sem){----}, at: [<c1099403>] dquot_alloc_space+0x50/0x189
[  137.361313]
[  137.361314] stack backtrace:
[  137.361401]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[  137.361488]  [<c1003d7f>] show_trace+0x12/0x14
[  137.361571]  [<c1003e79>] dump_stack+0x16/0x18
[  137.361663]  [<c1034d6d>] print_circular_bug_tail+0x6f/0x71
[  137.361752]  [<c1035398>] check_prev_add+0x34/0x206
[  137.361838]  [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.362786]  [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.362877]  [<c1037624>] lock_acquire+0x62/0x81
[  137.362960]  [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.363047]  [<c1205b88>] mutex_lock+0x8/0xa
[  137.363132]  [<c1098d79>] print_warning+0x8c/0x15d
[  137.363217]  [<c1099537>] dquot_alloc_space+0x184/0x189
[  137.363302]  [<c10a98e6>] ext3_new_blocks+0x44b/0x5a2
[  137.363391]  [<c10abe78>] ext3_alloc_blocks+0x40/0xdf
[  137.363476]  [<c10abf67>] ext3_alloc_branch+0x50/0x21b
[  137.363561]  [<c10ac445>] ext3_get_blocks_handle+0x1b8/0x367
[  137.363650]  [<c10ac66c>] ext3_get_block+0x78/0xe3
[  137.363735]  [<c108a239>] __block_prepare_write+0x168/0x3fd
[  137.363822]  [<c108ad10>] block_prepare_write+0x28/0x3b
[  137.363908]  [<c10acbcd>] ext3_prepare_write+0x3f/0x18d
[  137.363996]  [<c104dbe5>] generic_file_buffered_write+0x197/0x5e6
[  137.364084]  [<c104e2e2>] __generic_file_aio_write_nolock+0x2ae/0x5ad
[  137.364171]  [<c104e6ea>] generic_file_aio_write+0x58/0xc4
[  137.364254]  [<c10aa723>] ext3_file_write+0x2d/0xba
[  137.364340]  [<c1069441>] do_sync_write+0xc7/0x116
[  137.364425]  [<c1069612>] vfs_write+0x182/0x187
[  137.364511]  [<c10696b8>] sys_write+0x3d/0x64
[  137.364595]  [<c1002f78>] syscall_call+0x7/0xb
[  137.364682]  =======================
[  137.471738] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[  137.471812]     last function: laundromat_main+0x0/0x69 [nfsd]
[  137.471923] 2 locks held by nfsd4/3577:
[  137.471971]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.472209]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.472445]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[  137.472528]  [<c1003d7f>] show_trace+0x12/0x14
[  137.472613]  [<c1003e79>] dump_stack+0x16/0x18
[  137.472695]  [<c102c2e8>] run_workqueue+0x167/0x170
[  137.472779]  [<c102c437>] worker_thread+0x146/0x165
[  137.472861]  [<c102f797>] kthread+0x97/0xc4
[  137.472943]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[  137.473026]  =======================

Folkert van Heusden

Signature · 5 lines
MultiTail is a versatile tool for watching logfiles and output of
commands. Filtering, coloring, merging, diff-view, etc.
http://www.vanheusden.com/multitail/
----------------------------------------------------------------------
Phone: +31-6-41278122, PGP-key: 1F28D8AE, www.vanheusden.com
#1 lore raw
Quoted 20 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================
[ 1792.436492] svc: unknown version (0 for prog 100003, nfsd)
[ 1846.683648] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1846.683701]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1846.683832] 2 locks held by nfsd4/3577:
[ 1846.683885]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
Quoted 8 lines
[ 1846.683980]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1846.683988]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1846.683994]  [<c1003d7f>] show_trace+0x12/0x14
[ 1846.683997]  [<c1003e79>] dump_stack+0x16/0x18
[ 1846.684001]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1846.684006]  [<c102c437>] worker_thread+0x146/0x165
[ 1846.684012]  [<c102f797>] kthread+0x97/0xc4
[ 1846.684023]  [<c1003bdb>] kernel_thread_helper+0x7/0x10

Oleg, that's a fairly incomprehensible message we have in there. Can you please explain what it means?

#2 lore raw
Quoted 3 lines
Quoted 3 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577

...

Quoted 3 lines
Quoted 1 line
[ 1846.684023]  [<c1003bdb>] kernel_thread_helper+0x7/0x10

Oleg, that's a fairly incomprehensible message we have in there. Can you please explain what it means?

Haha ok :-)

Good, since I run 2.6.20 with these debugging switches switched on, I get occasionally errors like these. I get ALWAYS the following error when the system first boots when the TOR executable is started:

[  137.324255] =======================================================
[  137.324359] [ INFO: possible circular locking dependency detected ]
[  137.324412] 2.6.20 #2
[  137.324457] -------------------------------------------------------
[  137.324510] tor/4857 is trying to acquire lock:
[  137.324559]  (tty_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.324765]
[  137.324766] but task is already holding lock:
[  137.324859]  (&s->s_dquot.dqptr_sem){----}, at: [<c1099403>] dquot_alloc_space+0x50/0x189
[  137.325067]
[  137.325069] which lock already depends on the new lock.
[  137.325071]
[  137.325206]
[  137.325208] the existing dependency chain (in reverse order) is:
[  137.325300]
[  137.325301] -> #4 (&s->s_dquot.dqptr_sem){----}:
[  137.325501]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.325852]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.326197]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.326538]        [<c1037624>] lock_acquire+0x62/0x81
[  137.326887]        [<c1032b5f>] down_read+0x2b/0x3d
[  137.327241]        [<c1099403>] dquot_alloc_space+0x50/0x189
[  137.327588]        [<c10a98e6>] ext3_new_blocks+0x44b/0x5a2
[  137.327935]        [<c10abe78>] ext3_alloc_blocks+0x40/0xdf
[  137.328280]        [<c10abf67>] ext3_alloc_branch+0x50/0x21b
[  137.328622]        [<c10ac445>] ext3_get_blocks_handle+0x1b8/0x367
[  137.328980]        [<c10ac76e>] ext3_getblk+0x97/0x228
[  137.329330]        [<c10ac919>] ext3_bread+0x1a/0x78
[  137.329672]        [<c10b1bc2>] ext3_mkdir+0xf4/0x270
[  137.330022]        [<c1072a6a>] vfs_mkdir+0xb3/0x161
[  137.330368]        [<c1072ba4>] sys_mkdirat+0x8c/0xc4
[  137.330714]        [<c1072bfc>] sys_mkdir+0x20/0x22
[  137.331063]        [<c1002f78>] syscall_call+0x7/0xb
[  137.331406]        [<ffffffff>] 0xffffffff
[  137.331771]
[  137.331772] -> #3 (&ei->truncate_mutex){--..}:
[  137.331979]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.332332]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.332676]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.333025]        [<c1037624>] lock_acquire+0x62/0x81
[  137.333370]        [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.333930]        [<c1205b88>] mutex_lock+0x8/0xa
[  137.334271]        [<c10ae14f>] ext3_truncate+0x170/0x468
[  137.334613]        [<c1058e72>] vmtruncate+0xa6/0x116
[  137.334949]        [<c107d587>] inode_setattr+0x145/0x16c
[  137.335286]        [<c10af071>] ext3_setattr+0x150/0x22f
[  137.335627]        [<c107d909>] notify_change+0x35b/0x392
[  137.335968]        [<c10679d2>] do_truncate+0x52/0x75
[  137.336305]        [<c1071f5e>] may_open+0x1ec/0x231
[  137.336642]        [<c107211c>] open_namei+0xda/0x59b
[  137.336975]        [<c106863a>] do_filp_open+0x2c/0x53
[  137.337310]        [<c106896f>] do_sys_open+0x52/0xd8
[  137.337645]        [<c1068a11>] sys_open+0x1c/0x1e
[  137.337980]        [<c1002f78>] syscall_call+0x7/0xb
[  137.338315]        [<ffffffff>] 0xffffffff
[  137.338665]
[  137.338666] -> #2 (&inode->i_alloc_sem){--..}:
[  137.338864]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.339200]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.339535]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.339200]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.339535]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.339874]        [<c1037624>] lock_acquire+0x62/0x81
[  137.340207]        [<c1032bf5>] down_write+0x2b/0x45
[  137.340545]        [<c107d890>] notify_change+0x2e2/0x392
[  137.340886]        [<c10679d2>] do_truncate+0x52/0x75
[  137.341222]        [<c1071f5e>] may_open+0x1ec/0x231
[  137.341557]        [<c107211c>] open_namei+0xda/0x59b
[  137.341898]          [<c1068a11>] sys_open+0x1c/0x1e
[  137.343109]        [<c1002f78>] syscall_call+0x7/0xb
[  137.343444]        [<ffffffff>] 0xffffffff
[  137.343792]
[  137.343793] -> #1 (&sysfs_inode_imutex_key){--..}:
[  137.343988]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.344320]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.344655]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.344986]        [<c1037624>] lock_acquire+0x62/0x81
[  137.345321]        [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.345658]        [<c1205b88>] mutex_lock+0x8/0xa
[  137.345991]        [<c10a5447>] sysfs_hash_and_remove+0x43/0x11c
[  137.346328]        [<c10a5ef7>] sysfs_remove_file+0xd/0x12
[  137.346660]        [<c114b00c>] device_remove_file+0x32/0x44
[  137.346992]        [<c114b6d9>] device_del+0x174/0x1d2
[  137.347325]        [<c114b742>] device_unregister+0xb/0x15
[  137.347661]        [<c114b93d>] device_destroy+0x8d/0x9a
[  137.347994]        [<c1137a38>] vcs_remove_sysfs+0x1c/0x38
[  137.348328]        [<c113e0d8>] con_close+0x5e/0x6b
[  137.348661]        [<c1130103>] release_dev+0x4c4/0x6ce
[  137.348999]        [<c113077b>] tty_release+0x12/0x1c
[  137.349332]         [<c10aa723>] ext3_file_write+0x2d/0xba
[  137.358495]        [<c1069441>] do_sync_write+0xc7/0x116
[  137.358838]        [<c1069612>] vfs_write+0x182/0x187
[  137.359176]        [<c10696b8>] sys_write+0x3d/0x64
[  137.359513]        [<c1002f78>] syscall_call+0x7/0xb
[  137.359848]        [<ffffffff>] 0xffffffff
[  137.360200]
[  137.360202] other info that might help us debug this:
[  137.360204]
[  137.360335] 3 locks held by tor/4857:
[  137.360382]  #0:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.360625]  #1:  (&ei->truncate_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.361072]  #2:  (&s->s_dquot.dqptr_sem){----}, at: [<c1099403>] dquot_alloc_space+0x50/0x189
[  137.361313]
[  137.361314] stack backtrace:
[  137.361401]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[  137.361488]  [<c1003d7f>] show_trace+0x12/0x14
[  137.361571]  [<c1003e79>] dump_stack+0x16/0x18
[  137.361663]  [<c1034d6d>] print_circular_bug_tail+0x6f/0x71
[  137.361752]  [<c1035398>] check_prev_add+0x34/0x206
[  137.361838]  [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.362786]  [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.362877]  [<c1037624>] lock_acquire+0x62/0x81
[  137.362960]  [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.363047]  [<c1205b88>] mutex_lock+0x8/0xa
[  137.363132]  [<c1098d79>] print_warning+0x8c/0x15d
[  137.363217]  [<c1099537>] dquot_alloc_space+0x184/0x189
[  137.363302]  [<c10a98e6>] ext3_new_blocks+0x44b/0x5a2
[  137.363391]  [<c10abe78>] ext3_alloc_blocks+0x40/0xdf
[  137.363476]  [<c10abf67>] ext3_alloc_branch+0x50/0x21b
[  137.363561]  [<c10ac445>] ext3_get_blocks_handle+0x1b8/0x367
[  137.363650]  [<c10ac66c>] ext3_get_block+0x78/0xe3
[  137.363735]  [<c108a239>] __block_prepare_write+0x168/0x3fd
[  137.363822]  [<c108ad10>] block_prepare_write+0x28/0x3b
[  137.363908]  [<c10acbcd>] ext3_prepare_write+0x3f/0x18d
[  137.363996]  [<c104dbe5>] generic_file_buffered_write+0x197/0x5e6
[  137.364084]  [<c104e2e2>] __generic_file_aio_write_nolock+0x2ae/0x5ad
[  137.364171]  [<c104e6ea>] generic_file_aio_write+0x58/0xc4
[  137.364254]  [<c10aa723>] ext3_file_write+0x2d/0xba
[  137.364340]  [<c1069441>] do_sync_write+0xc7/0x116
[  137.364425]  [<c1069612>] vfs_write+0x182/0x187
[  137.364511]  [<c10696b8>] sys_write+0x3d/0x64
[  137.364595]  [<c1002f78>] syscall_call+0x7/0xb
[  137.364682]  =======================

Now apart from this reproducable problem, I suddenly also get these errors in dmesg:

[  137.471738] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[  137.471812]     last function: laundromat_main+0x0/0x69 [nfsd]
[  137.471923] 2 locks held by nfsd4/3577:
[  137.471971]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.472209]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.472445]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[  137.472528]  [<c1003d7f>] show_trace+0x12/0x14
[  137.472613]  [<c1003e79>] dump_stack+0x16/0x18
[  137.472695]  [<c102c2e8>] run_workqueue+0x167/0x170
[  137.472779]  [<c102c437>] worker_thread+0x146/0x165
[  137.472861]  [<c102f797>] kthread+0x97/0xc4
[  137.472943]  [<c1003bdb>] kernel_thread_helper+0x7/0x10

These happen on 2 times per minute and then once in 2 minutes.

The last one (while writing this message) is:

[182932.590394] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[182932.590450]     last function: laundromat_main+0x0/0x69 [nfsd]
[182932.590557] 2 locks held by nfsd4/3577:
[182932.590600]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[182932.590830]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[182932.591061]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[182932.591145]  [<c1003d7f>] show_trace+0x12/0x14
[182932.591234]  [<c1003e79>] dump_stack+0x16/0x18
[182932.591316]  [<c102c2e8>] run_workqueue+0x167/0x170
[182932.591399]  [<c102c437>] worker_thread+0x146/0x165
[182932.591482]  [<c102f797>] kthread+0x97/0xc4
[182932.591564]  [<c1003bdb>] kernel_thread_helper+0x7/0x10

Config can be found here:
http://keetweej.vanheusden.com/~folkert/config-2.6.20.txt

System is a P4 @ 3.2GHz with 2GB of ram. IDE harddisks, 5 mounts mounted on a server connected via a 1Gb lan. The other end (the server) runs 2.6.19.1.

On the problem-system this is the output of nfsstat:

Server rpc stats:

calls      badcalls   badauth    badclnt    xdrcall
1833       611        611        0          0

Server nfs v2:
null getattr setattr root lookup readlink
611 100% 0 0% 0 0% 0 0% 0 0% 0 0%
read wrcache write create remove rename
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
link symlink mkdir rmdir readdir fsstat
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%

Server nfs v3:
null getattr setattr lookup access readlink
611 100% 0 0% 0 0% 0 0% 0 0% 0 0%
read write create mkdir symlink mknod
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
remove rmdir rename link readdir readdirplus
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
fsstat fsinfo pathconf commit
0 0% 0 0% 0 0% 0 0%

Server nfs v4:
null compound
611 100% 0 0%

Server nfs v4 operations:
op0-unused op1-unused op2-future access close commit
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
create delegpurge delegreturn getattr getfh link
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
lock lockt locku lookup lookup_root nverify
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
open openattr open_conf open_dgrd putfh putpubfh
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
putrootfh read readdir readlink remove rename
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
renew restorefh savefh secinfo setattr setcltid
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
setcltidconf verify write rellockowner
0 0% 0 0% 0 0% 0 0%

Client rpc stats:

calls      retrans    authrefrsh
1404874    5502       0

Client nfs v2:
null getattr setattr root lookup readlink
0 0% 157240 11% 11360 0% 0 0% 707396 50% 20434 1%
read wrcache write create remove rename
18 0% 0 0% 471048 33% 2900 0% 323 0% 2888 0%
link symlink mkdir rmdir readdir fsstat
0 0% 2 0% 60 0% 32 0% 27463 1% 3709 0%

Client nfs v4:
null read write commit open open_conf
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
open_noat open_dgrd close setattr fsinfo renew
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
setclntid confirm lock lockt locku access
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
getattr lookup lookup_root remove rename link
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
symlink create pathconf statfs readlink readdir
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
server_caps delegreturn
0 0% 0 0%

Folkert van Heusden

Signature · 3 lines
www.biglumber.com <- site where one can exchange PGP key signatures 
----------------------------------------------------------------------
Phone: +31-6-41278122, PGP-key: 1F28D8AE, www.vanheusden.com
#3 lore raw
Quoted 10 lines · Folkert van Heusden
Quoted 3 lines
Quoted 3 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577

...

Quoted 3 lines
Quoted 1 line
[ 1846.684023]  [<c1003bdb>] kernel_thread_helper+0x7/0x10

Oleg, that's a fairly incomprehensible message we have in there. Can you please explain what it means?

Haha ok :-)

Quoted 8 lines

Good, since I run 2.6.20 with these debugging switches switched on, I get occasionally errors like these. I get ALWAYS the following error when the system first boots when the TOR executable is started:

[  137.324255] =======================================================
[  137.324359] [ INFO: possible circular locking dependency detected ]
[  137.324412] 2.6.20 #2
[  137.324457] -------------------------------------------------------

Hi,

IMHO you should now switch off lockdep ("Lock debuging: ..." options), until you update or get some patch for this circular problem. Your logs should be sufficient to nfsd people and lockdep turns off checking after this anyway. I don't know if this is a known and real locking problem, but it could be interesting now, if workqueue error would reapear. It seems nfsd code is breaking somewhere with locks held - maybe because of problems with lockdep's error handling.

Regards,
Jarek P.

#4 lore raw

dquot.c: possible circular locking Re: [2.6.20] BUG: workqueue leaked lock

In reply to Folkert van Heusden
Quoted 1 line · Folkert van Heusden
Quoted 1 line
Quoted 1 line · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

Quoted 6 lines

Haha ok :-)

Good, since I run 2.6.20 with these debugging switches switched on, I get occasionally errors like these. I get ALWAYS the following error when the system first boots when the TOR executable is started:

Quoted 11 lines
[  137.324255] =======================================================
[  137.324359] [ INFO: possible circular locking dependency detected ]
[  137.324412] 2.6.20 #2
[  137.324457] -------------------------------------------------------
[  137.324510] tor/4857 is trying to acquire lock:
[  137.324559]  (tty_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.324765]
[  137.324766] but task is already holding lock:
[  137.324859]  (&s->s_dquot.dqptr_sem){----}, at: [<c1099403>] dquot_alloc_space+0x50/0x189
[  137.325067]
[  137.325069] which lock already depends on the new lock.

IMHO lockdep found that two locks are taken in different order:

-> #1: 1) tty_mutex in con_console() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_console in dquot_alloc_space() with print_warning()

Probably print_warning() and flush_warnings() should be reworked to do printing without dqptr_sem or locking order should be changed. I hope somebody from this CC can work it out better.

Regards,
Jarek P.

Quoted 123 lines
[  137.325071]
[  137.325206]
[  137.325208] the existing dependency chain (in reverse order) is:
[  137.325300]
[  137.325301] -> #4 (&s->s_dquot.dqptr_sem){----}:
[  137.325501]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.325852]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.326197]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.326538]        [<c1037624>] lock_acquire+0x62/0x81
[  137.326887]        [<c1032b5f>] down_read+0x2b/0x3d
[  137.327241]        [<c1099403>] dquot_alloc_space+0x50/0x189
[  137.327588]        [<c10a98e6>] ext3_new_blocks+0x44b/0x5a2
[  137.327935]        [<c10abe78>] ext3_alloc_blocks+0x40/0xdf
[  137.328280]        [<c10abf67>] ext3_alloc_branch+0x50/0x21b
[  137.328622]        [<c10ac445>] ext3_get_blocks_handle+0x1b8/0x367
[  137.328980]        [<c10ac76e>] ext3_getblk+0x97/0x228
[  137.329330]        [<c10ac919>] ext3_bread+0x1a/0x78
[  137.329672]        [<c10b1bc2>] ext3_mkdir+0xf4/0x270
[  137.330022]        [<c1072a6a>] vfs_mkdir+0xb3/0x161
[  137.330368]        [<c1072ba4>] sys_mkdirat+0x8c/0xc4
[  137.330714]        [<c1072bfc>] sys_mkdir+0x20/0x22
[  137.331063]        [<c1002f78>] syscall_call+0x7/0xb
[  137.331406]        [<ffffffff>] 0xffffffff
[  137.331771]
[  137.331772] -> #3 (&ei->truncate_mutex){--..}:
[  137.331979]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.332332]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.332676]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.333025]        [<c1037624>] lock_acquire+0x62/0x81
[  137.333370]        [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.333930]        [<c1205b88>] mutex_lock+0x8/0xa
[  137.334271]        [<c10ae14f>] ext3_truncate+0x170/0x468
[  137.334613]        [<c1058e72>] vmtruncate+0xa6/0x116
[  137.334949]        [<c107d587>] inode_setattr+0x145/0x16c
[  137.335286]        [<c10af071>] ext3_setattr+0x150/0x22f
[  137.335627]        [<c107d909>] notify_change+0x35b/0x392
[  137.335968]        [<c10679d2>] do_truncate+0x52/0x75
[  137.336305]        [<c1071f5e>] may_open+0x1ec/0x231
[  137.336642]        [<c107211c>] open_namei+0xda/0x59b
[  137.336975]        [<c106863a>] do_filp_open+0x2c/0x53
[  137.337310]        [<c106896f>] do_sys_open+0x52/0xd8
[  137.337645]        [<c1068a11>] sys_open+0x1c/0x1e
[  137.337980]        [<c1002f78>] syscall_call+0x7/0xb
[  137.338315]        [<ffffffff>] 0xffffffff
[  137.338665]
[  137.338666] -> #2 (&inode->i_alloc_sem){--..}:
[  137.338864]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.339200]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.339535]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.339200]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.339535]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.339874]        [<c1037624>] lock_acquire+0x62/0x81
[  137.340207]        [<c1032bf5>] down_write+0x2b/0x45
[  137.340545]        [<c107d890>] notify_change+0x2e2/0x392
[  137.340886]        [<c10679d2>] do_truncate+0x52/0x75
[  137.341222]        [<c1071f5e>] may_open+0x1ec/0x231
[  137.341557]        [<c107211c>] open_namei+0xda/0x59b
[  137.341898]          [<c1068a11>] sys_open+0x1c/0x1e
[  137.343109]        [<c1002f78>] syscall_call+0x7/0xb
[  137.343444]        [<ffffffff>] 0xffffffff
[  137.343792]
[  137.343793] -> #1 (&sysfs_inode_imutex_key){--..}:
[  137.343988]        [<c10354b8>] check_prev_add+0x154/0x206
[  137.344320]        [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.344655]        [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.344986]        [<c1037624>] lock_acquire+0x62/0x81
[  137.345321]        [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.345658]        [<c1205b88>] mutex_lock+0x8/0xa
[  137.345991]        [<c10a5447>] sysfs_hash_and_remove+0x43/0x11c
[  137.346328]        [<c10a5ef7>] sysfs_remove_file+0xd/0x12
[  137.346660]        [<c114b00c>] device_remove_file+0x32/0x44
[  137.346992]        [<c114b6d9>] device_del+0x174/0x1d2
[  137.347325]        [<c114b742>] device_unregister+0xb/0x15
[  137.347661]        [<c114b93d>] device_destroy+0x8d/0x9a
[  137.347994]        [<c1137a38>] vcs_remove_sysfs+0x1c/0x38
[  137.348328]        [<c113e0d8>] con_close+0x5e/0x6b
[  137.348661]        [<c1130103>] release_dev+0x4c4/0x6ce
[  137.348999]        [<c113077b>] tty_release+0x12/0x1c
[  137.349332]         [<c10aa723>] ext3_file_write+0x2d/0xba
[  137.358495]        [<c1069441>] do_sync_write+0xc7/0x116
[  137.358838]        [<c1069612>] vfs_write+0x182/0x187
[  137.359176]        [<c10696b8>] sys_write+0x3d/0x64
[  137.359513]        [<c1002f78>] syscall_call+0x7/0xb
[  137.359848]        [<ffffffff>] 0xffffffff
[  137.360200]
[  137.360202] other info that might help us debug this:
[  137.360204]
[  137.360335] 3 locks held by tor/4857:
[  137.360382]  #0:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.360625]  #1:  (&ei->truncate_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[  137.361072]  #2:  (&s->s_dquot.dqptr_sem){----}, at: [<c1099403>] dquot_alloc_space+0x50/0x189
[  137.361313]
[  137.361314] stack backtrace:
[  137.361401]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[  137.361488]  [<c1003d7f>] show_trace+0x12/0x14
[  137.361571]  [<c1003e79>] dump_stack+0x16/0x18
[  137.361663]  [<c1034d6d>] print_circular_bug_tail+0x6f/0x71
[  137.361752]  [<c1035398>] check_prev_add+0x34/0x206
[  137.361838]  [<c10355d4>] check_prevs_add+0x6a/0xd5
[  137.362786]  [<c1036dd2>] __lock_acquire+0x61c/0xa05
[  137.362877]  [<c1037624>] lock_acquire+0x62/0x81
[  137.362960]  [<c1205c09>] __mutex_lock_slowpath+0x75/0x28c
[  137.363047]  [<c1205b88>] mutex_lock+0x8/0xa
[  137.363132]  [<c1098d79>] print_warning+0x8c/0x15d
[  137.363217]  [<c1099537>] dquot_alloc_space+0x184/0x189
[  137.363302]  [<c10a98e6>] ext3_new_blocks+0x44b/0x5a2
[  137.363391]  [<c10abe78>] ext3_alloc_blocks+0x40/0xdf
[  137.363476]  [<c10abf67>] ext3_alloc_branch+0x50/0x21b
[  137.363561]  [<c10ac445>] ext3_get_blocks_handle+0x1b8/0x367
[  137.363650]  [<c10ac66c>] ext3_get_block+0x78/0xe3
[  137.363735]  [<c108a239>] __block_prepare_write+0x168/0x3fd
[  137.363822]  [<c108ad10>] block_prepare_write+0x28/0x3b
[  137.363908]  [<c10acbcd>] ext3_prepare_write+0x3f/0x18d
[  137.363996]  [<c104dbe5>] generic_file_buffered_write+0x197/0x5e6
[  137.364084]  [<c104e2e2>] __generic_file_aio_write_nolock+0x2ae/0x5ad
[  137.364171]  [<c104e6ea>] generic_file_aio_write+0x58/0xc4
[  137.364254]  [<c10aa723>] ext3_file_write+0x2d/0xba
[  137.364340]  [<c1069441>] do_sync_write+0xc7/0x116
[  137.364425]  [<c1069612>] vfs_write+0x182/0x187
[  137.364511]  [<c10696b8>] sys_write+0x3d/0x64
[  137.364595]  [<c1002f78>] syscall_call+0x7/0xb
[  137.364682]  =======================
#5 lore raw

Re: dquot.c: possible circular locking Re: [2.6.20] BUG: workqueue leaked lock

On Tue, Mar 20, 2007 at 12:17:01PM +0100, Jarek Poplawski wrote:
...

Quoted 4 lines

IMHO lockdep found that two locks are taken in different order:

-> #1: 1) tty_mutex in con_console() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_console in dquot_alloc_space() with print_warning()

Should be:
-> #0: 1) dqptr_sem 2) tty_mutex in dquot_alloc_space() with print_warning()

Jarek P.

#6 lore raw

Re: dquot.c: possible circular locking Re: [2.6.20] BUG: workqueue leaked lock

Quoted 6 lines · Jarek Poplawski

On Tue, Mar 20, 2007 at 12:17:01PM +0100, Jarek Poplawski wrote:
...

Quoted 4 lines

IMHO lockdep found that two locks are taken in different order:

-> #1: 1) tty_mutex in con_console() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_console in dquot_alloc_space() with print_warning()

Once more - should be:
-> #1: 1) tty_mutex in con_close() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_mutex in dquot_alloc_space() with print_warning()

Very sorry!!!
Jarek P.

#7 lore raw

Re: dquot.c: possible circular locking Re: [2.6.20] BUG: workqueue leaked lock

Quoted 11 lines · Jarek Poplawski
Quoted 6 lines · Jarek Poplawski

On Tue, Mar 20, 2007 at 12:17:01PM +0100, Jarek Poplawski wrote:
...

Quoted 4 lines

IMHO lockdep found that two locks are taken in different order:

-> #1: 1) tty_mutex in con_console() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_console in dquot_alloc_space() with print_warning()

Once more - should be:
-> #1: 1) tty_mutex in con_close() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_mutex in dquot_alloc_space() with print_warning()

Yes, I was looking at it. Hmm, we can possibly get rid of tty_mutex being
acquired under dqptr_sem in quota code. But looking at the path from con_close() there's another inversion with i_mutex which is also acquired along the path for sysfs. And we can hardly get rid of it in the quota code.
Now none of these is a real deadlock as quota should never call
print_warning() for sysfs (it doesn't use quota) but still it's nasty. I suppose tty_mutex is above i_mutex because of those sysfs calls and it seems sysfs must be called under tty_mutex because of races with init_dev(). So it's not easy to get rid of that dependency either.

Honza

Signature · 2 lines
Jan Kara <[email protected]>
SuSE CR Labs
#8 lore raw

Re: dquot.c: possible circular locking Re: [2.6.20] BUG: workqueue leaked lock

Quoted 11 lines

Yes, I was looking at it. Hmm, we can possibly get rid of tty_mutex being
acquired under dqptr_sem in quota code. But looking at the path from con_close() there's another inversion with i_mutex which is also acquired along the path for sysfs. And we can hardly get rid of it in the quota code.
Now none of these is a real deadlock as quota should never call
print_warning() for sysfs (it doesn't use quota) but still it's nasty. I suppose tty_mutex is above i_mutex because of those sysfs calls and it seems sysfs must be called under tty_mutex because of races with init_dev(). So it's not easy to get rid of that dependency either.

maybe a far more serious option: Why on EARTH is the quota code going to TTY's directly? That's just WRONG. Maybe it wasn't 10 years ago, but nowadays most people use graphical user interfaces and the like...

can we please just get rid of this instead?

#9 lore raw

Re: dquot.c: possible circular locking Re: [2.6.20] BUG: workqueue leaked lock

Quoted 12 lines · Arjan van de Ven
Quoted 11 lines

Yes, I was looking at it. Hmm, we can possibly get rid of tty_mutex being
acquired under dqptr_sem in quota code. But looking at the path from con_close() there's another inversion with i_mutex which is also acquired along the path for sysfs. And we can hardly get rid of it in the quota code.
Now none of these is a real deadlock as quota should never call
print_warning() for sysfs (it doesn't use quota) but still it's nasty. I suppose tty_mutex is above i_mutex because of those sysfs calls and it seems sysfs must be called under tty_mutex because of races with init_dev(). So it's not easy to get rid of that dependency either.

Quoted 3 lines

maybe a far more serious option: Why on EARTH is the quota code going to TTY's directly? That's just WRONG. Maybe it wasn't 10 years ago, but nowadays most people use graphical user interfaces and the like...

We've been discussing this sometimes back in August ;)
(http://lkml.org/lkml/2006/8/8/237) and we've decided to leave the code in. The only reason why I think it should stay in is the existence of quota softlimits. There it's nice to warn the user and there's no other way to propagate this information into userspace (as the write succeeds).
One solution would be to leave the warning to some userspace process
(like warnquota) run from cron but still I'm not sure we should change the behavior.

Honza

Signature · 2 lines
Jan Kara <[email protected]>
SuSE CR Labs
#10 lore raw

Re: dquot.c: possible circular locking Re: [2.6.20] BUG: workqueue leaked lock

Quoted 16 lines · Jan Kara
Quoted 12 lines · Arjan van de Ven
Quoted 11 lines

Yes, I was looking at it. Hmm, we can possibly get rid of tty_mutex being
acquired under dqptr_sem in quota code. But looking at the path from con_close() there's another inversion with i_mutex which is also acquired along the path for sysfs. And we can hardly get rid of it in the quota code.
Now none of these is a real deadlock as quota should never call
print_warning() for sysfs (it doesn't use quota) but still it's nasty. I suppose tty_mutex is above i_mutex because of those sysfs calls and it seems sysfs must be called under tty_mutex because of races with init_dev(). So it's not easy to get rid of that dependency either.

Quoted 3 lines

maybe a far more serious option: Why on EARTH is the quota code going to TTY's directly? That's just WRONG. Maybe it wasn't 10 years ago, but nowadays most people use graphical user interfaces and the like...

Quoted 8 lines

We've been discussing this sometimes back in August ;)
(http://lkml.org/lkml/2006/8/8/237) and we've decided to leave the code in. The only reason why I think it should stay in is the existence of quota softlimits. There it's nice to warn the user and there's no other way to propagate this information into userspace (as the write succeeds).
One solution would be to leave the warning to some userspace process
(like warnquota) run from cron but still I'm not sure we should change the behavior.

or send a uevent or something

Signature · 2 lines
if you want to mail me at work (you don't), use arjan (at) linux.intel.com
Test the interaction between Linux and your BIOS via http://www.linuxfirmwarekit.org
#11 lore raw

Re: dquot.c: possible circular locking Re: [2.6.20] BUG: workqueue leaked lock

In reply to Jan Kara
Quoted 12 lines · Jan Kara
Quoted 11 lines · Jarek Poplawski
Quoted 6 lines · Jarek Poplawski

On Tue, Mar 20, 2007 at 12:17:01PM +0100, Jarek Poplawski wrote:
...

Quoted 4 lines

IMHO lockdep found that two locks are taken in different order:

-> #1: 1) tty_mutex in con_console() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_console in dquot_alloc_space() with print_warning()

Once more - should be:
-> #1: 1) tty_mutex in con_close() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_mutex in dquot_alloc_space() with print_warning()

Quoted 9 lines

Yes, I was looking at it. Hmm, we can possibly get rid of tty_mutex being
acquired under dqptr_sem in quota code. But looking at the path from con_close() there's another inversion with i_mutex which is also acquired along the path for sysfs. And we can hardly get rid of it in the quota code.
Now none of these is a real deadlock as quota should never call
print_warning() for sysfs (it doesn't use quota) but still it's nasty. I suppose tty_mutex is above i_mutex because of those sysfs calls and it seems sysfs must be called under tty_mutex because of races with init_dev(). So it's not easy to get rid of that dependency either.

I wonder if this cannot be done with a workqueue (message to a buffer, maybe after try_lock on tty_mutex) and BTW isn't there any "modern" way to queue console messages like these?

Jarek P.

#12 lore raw

Re: dquot.c: possible circular locking Re: [2.6.20] BUG: workqueue leaked lock

Quoted 23 lines · Jarek Poplawski
Quoted 12 lines · Jan Kara
Quoted 11 lines · Jarek Poplawski
Quoted 6 lines · Jarek Poplawski

On Tue, Mar 20, 2007 at 12:17:01PM +0100, Jarek Poplawski wrote:
...

Quoted 4 lines

IMHO lockdep found that two locks are taken in different order:

-> #1: 1) tty_mutex in con_console() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_console in dquot_alloc_space() with print_warning()

Once more - should be:
-> #1: 1) tty_mutex in con_close() 2) dqptr_sem (somewhere later) -> #0: 1) dqptr_sem 2) tty_mutex in dquot_alloc_space() with print_warning()

Quoted 9 lines

Yes, I was looking at it. Hmm, we can possibly get rid of tty_mutex being
acquired under dqptr_sem in quota code. But looking at the path from con_close() there's another inversion with i_mutex which is also acquired along the path for sysfs. And we can hardly get rid of it in the quota code.
Now none of these is a real deadlock as quota should never call
print_warning() for sysfs (it doesn't use quota) but still it's nasty. I suppose tty_mutex is above i_mutex because of those sysfs calls and it seems sysfs must be called under tty_mutex because of races with init_dev(). So it's not easy to get rid of that dependency either.

Quoted 3 lines

I wonder if this cannot be done with a workqueue (message to a buffer, maybe after try_lock on tty_mutex) and BTW isn't there any "modern" way to queue console messages like these?

I don't know about any such way...

Honza

Signature · 2 lines
Jan Kara <[email protected]>
SuSE CR Labs
#13 lore raw
In reply to Andrew Morton
Quoted 29 lines · Andrew Morton
Quoted 20 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================
[ 1792.436492] svc: unknown version (0 for prog 100003, nfsd)
[ 1846.683648] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1846.683701]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1846.683832] 2 locks held by nfsd4/3577:
[ 1846.683885]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
Quoted 8 lines
[ 1846.683980]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1846.683988]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1846.683994]  [<c1003d7f>] show_trace+0x12/0x14
[ 1846.683997]  [<c1003e79>] dump_stack+0x16/0x18
[ 1846.684001]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1846.684006]  [<c102c437>] worker_thread+0x146/0x165
[ 1846.684012]  [<c102f797>] kthread+0x97/0xc4
[ 1846.684023]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
Quoted 2 lines

Oleg, that's a fairly incomprehensible message we have in there. Can you please explain what it means?

I think I'm responsible for this message (commit d5abe669172f20a4129a711de0f250a4e07db298); what is says is that the function executed by the workqueue (here laundromat_main) leaked an atomic context or is still holding locks (2 locks in this case).

#14 lore raw
Quoted 30 lines · On Fri, 16 Mar 2007 09:41:20 +0100 Peter Zijlstra <[email protected]>…
Quoted 29 lines · Andrew Morton
Quoted 28 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================
[ 1792.436492] svc: unknown version (0 for prog 100003, nfsd)
[ 1846.683648] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1846.683701]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1846.683832] 2 locks held by nfsd4/3577:
[ 1846.683885]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1846.683980]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1846.683988]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1846.683994]  [<c1003d7f>] show_trace+0x12/0x14
[ 1846.683997]  [<c1003e79>] dump_stack+0x16/0x18
[ 1846.684001]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1846.684006]  [<c102c437>] worker_thread+0x146/0x165
[ 1846.684012]  [<c102f797>] kthread+0x97/0xc4
[ 1846.684023]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
Quoted 8 lines
Quoted 2 lines

Oleg, that's a fairly incomprehensible message we have in there. Can you please explain what it means?

I think I'm responsible for this message (commit d5abe669172f20a4129a711de0f250a4e07db298); what is says is that the function executed by the workqueue (here laundromat_main) leaked an atomic context or is still holding locks (2 locks in this case).

OK. That's not necessarily a bug: one could envisage a (weird) piece of code which takes a lock then releases it on a later workqueue invokation. But I'm not sure that nfs4_laundromat() is actually supposed to be doing anything like that.

Then again, maybe it is: it seems to be waddling through a directory under the control of a little state machine, with timeouts.

Neil: help?

#15 lore raw
Quoted 10 lines · On Friday March 16, [email protected] wrote:

OK. That's not necessarily a bug: one could envisage a (weird) piece of code which takes a lock then releases it on a later workqueue invokation. But I'm not sure that nfs4_laundromat() is actually supposed to be doing anything like that.

Then again, maybe it is: it seems to be waddling through a directory under the control of a little state machine, with timeouts.

Neil: help?

I'm quite certain that laundromat_main does *not* leave client_mutex locked as the last thing it does is call nfs4_unlock_state which is

	mutex_unlock(&client_mutex);

To me, that raises some doubt about whether the lock leak check is working properly...
It is somewhat harder to track locking of i_mutex, but it seems to me that every time it is taken, it is released again shortly afterwards.

So I think this must be a problem with leak detection, not with NFSd.

NeilBrown

Quoted 40 lines · On Fri, 16 Mar 2007 09:41:20 +0100 Peter Zijlstra <[email protected]>…
Quoted 39 lines · Andrew Morton
Quoted 29 lines
Quoted 20 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================
[ 1792.436492] svc: unknown version (0 for prog 100003, nfsd)
[ 1846.683648] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1846.683701]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1846.683832] 2 locks held by nfsd4/3577:
[ 1846.683885]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
Quoted 8 lines
[ 1846.683980]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1846.683988]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1846.683994]  [<c1003d7f>] show_trace+0x12/0x14
[ 1846.683997]  [<c1003e79>] dump_stack+0x16/0x18
[ 1846.684001]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1846.684006]  [<c102c437>] worker_thread+0x146/0x165
[ 1846.684012]  [<c102f797>] kthread+0x97/0xc4
[ 1846.684023]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
Quoted 2 lines

Oleg, that's a fairly incomprehensible message we have in there. Can you please explain what it means?

I think I'm responsible for this message (commit d5abe669172f20a4129a711de0f250a4e07db298); what is says is that the function executed by the workqueue (here laundromat_main) leaked an atomic context or is still holding locks (2 locks in this case).

#16 lore raw
Quoted 42 lines · Neil Brown
Quoted 9 lines · On Friday March 16, [email protected] wrote:

OK. That's not necessarily a bug: one could envisage a (weird) piece of code which takes a lock then releases it on a later workqueue invokation. But I'm not sure that nfs4_laundromat() is actually supposed to be doing anything like that.

Then again, maybe it is: it seems to be waddling through a directory under the control of a little state machine, with timeouts.

Neil: help?

I'm quite certain that laundromat_main does *not* leave client_mutex locked as the last thing it does is call nfs4_unlock_state which is

	mutex_unlock(&client_mutex);

To me, that raises some doubt about whether the lock leak check is working properly...
It is somewhat harder to track locking of i_mutex, but it seems to me that every time it is taken, it is released again shortly afterwards.

So I think this must be a problem with leak detection, not with NFSd.

NeilBrown

Quoted 18 lines · On Fri, 16 Mar 2007 09:41:20 +0100 Peter Zijlstra <[email protected]>…
Quoted 17 lines · Andrew Morton
Quoted 15 lines
Quoted 15 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================

...

Quoted 4 lines
Quoted 4 lines
Quoted 4 lines

I think I'm responsible for this message (commit d5abe669172f20a4129a711de0f250a4e07db298); what is says is that the function executed by the workqueue (here laundromat_main) leaked an atomic context or is still holding locks (2 locks in this case).

This check is valid with keventd, but it looks like nfsd runs kthread by itself. I'm not sure it's illegal to hold locks then, so, if I'm not wrong with this, here is my patch proposal (for testing) to take this into consideration.

---

kernel/workqueue.c +6 -3
diff -Nurp 2.6.21-rc4-git4-/kernel/workqueue.c 2.6.21-rc4-git4/kernel/workqueue.c
@@ -316,6 +316,7 @@ static void run_workqueue(struct cpu_wor
 		struct work_struct *work = list_entry(cwq->worklist.next,
 						struct work_struct, entry);
 		work_func_t f = work->func;
+		int ld;
 
 		list_del_init(cwq->worklist.next);
 		spin_unlock_irqrestore(&cwq->lock, flags);
@@ -323,13 +324,15 @@ static void run_workqueue(struct cpu_wor
 		BUG_ON(get_wq_data(work) != cwq);
 		if (!test_bit(WORK_STRUCT_NOAUTOREL, work_data_bits(work)))
 			work_release(work);
+		ld = lockdep_depth(current);
+
 		f(work);
 
-		if (unlikely(in_atomic() || lockdep_depth(current) > 0)) {
+		if (unlikely(in_atomic() || (ld -= lockdep_depth(current)))) {
 			printk(KERN_ERR "BUG: workqueue leaked lock or atomic: "
-					"%s/0x%08x/%d\n",
+					"%s/0x%08x/%d/%d\n",
 					current->comm, preempt_count(),
-				       	current->pid);
+				       	current->pid, ld);
 			printk(KERN_ERR "    last function: ");
 			print_symbol("%s\n", (unsigned long)f);
 			debug_show_held_locks(current);
#17 lore raw
Quoted 19 lines · Jarek Poplawski
Quoted 4 lines
Quoted 4 lines · On Fri, 16 Mar 2007 09:41:20 +0100 Peter Zijlstra <[email protected]>…
Quoted 2 lines · Andrew Morton
Quoted 15 lines
Quoted 7 lines
Quoted 7 lines
Quoted 7 lines
Quoted 7 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
Quoted 8 lines
Quoted 8 lines
Quoted 8 lines
Quoted 8 lines
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================
Quoted 8 lines

...

Quoted 4 lines
Quoted 4 lines
Quoted 4 lines

I think I'm responsible for this message (commit d5abe669172f20a4129a711de0f250a4e07db298); what is says is that the function executed by the workqueue (here laundromat_main) leaked an atomic context or is still holding locks (2 locks in this case).

This check is valid with keventd, but it looks like nfsd runs kthread by itself. I'm not sure it's illegal to hold locks then,

nfsd creates laundry_wq by itself, yes, but cwq->thread runs with lockdep_depth() == 0. Unless we have a bug with lockdep_depth(), lockdep_depth() != 0 means that work->func() returns with a lock held (or it can flush its own workqueue under lock, but in that case we should have a different trace).

Personally I agree with Andrew:

Quoted 5 lines
Quoted 3 lines

OK. That's not necessarily a bug: one could envisage a (weird) piece of code which takes a lock then releases it on a later workqueue invokation.

kernel/workqueue.c static void run_workqueue(struct cpu_wor · line 331

Quoted 9 lines
kernel/workqueue.c +3 -1
@@ -323,13 +324,15 @@ static void run_workqueue(struct cpu_wor
 		BUG_ON(get_wq_data(work) != cwq);
 		if (!test_bit(WORK_STRUCT_NOAUTOREL, work_data_bits(work)))
 			work_release(work);
+		ld = lockdep_depth(current);
+
 		f(work);
 
-		if (unlikely(in_atomic() || lockdep_depth(current) > 0)) {
+		if (unlikely(in_atomic() || (ld -= lockdep_depth(current)))) {

and with this change we will also have a BUG report on "then releases it on a later workqueue invokation".

Btw. __nfs4_state_shutdown() does cancel_delayed_work(&laundromat_work). This is unneeded and imho confusing. laundry_wq was already destroyed, it would be BUG to have a pending delayed work.

Oleg.

#18 lore raw
Quoted 1 line · Oleg Nesterov

On 03/20, Jarek Poplawski wrote:

...

Quoted 16 lines
Quoted 16 lines
Quoted 16 lines
Quoted 16 lines
Quoted 16 lines · Andrew Morton
Quoted 15 lines
Quoted 15 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================

...

Quoted 8 lines
Quoted 2 lines

This check is valid with keventd, but it looks like nfsd runs kthread by itself. I'm not sure it's illegal to hold locks then,

nfsd creates laundry_wq by itself, yes, but cwq->thread runs with lockdep_depth() == 0. Unless we have a bug with lockdep_depth(), lockdep_depth() != 0 means that work->func() returns with a lock held (or it can flush its own workqueue under lock, but in that case we should have a different trace).

IMHO you can only say this thread is supposed to run with lockdep_depth() == 0. lockdep_depth is counted within a process, which starts before f(), so the only way to say f() leaked locks is to check these locks before and after f().

Quoted 5 lines

Personally I agree with Andrew:

Quoted 3 lines
Quoted 3 lines

OK. That's not necessarily a bug: one could envisage a (weird) piece of code which takes a lock then releases it on a later workqueue invokation.

But this code is named here as laundromat_main and it doesn't seem to work like this.

Quoted 9 lines
Quoted 9 lines
kernel/workqueue.c +2 -0
@@ -323,13 +324,15 @@ static void run_workqueue(struct cpu_wor
 		BUG_ON(get_wq_data(work) != cwq);
 		if (!test_bit(WORK_STRUCT_NOAUTOREL, work_data_bits(work)))
 			work_release(work);
+		ld = lockdep_depth(current);
+
 		f(work);
 
Quoted 5 lines

kernel/workqueue.c static void run_workqueue(struct cpu_wor · line 331

Quoted 2 lines
kernel/workqueue.c +1 -1
-		if (unlikely(in_atomic() || lockdep_depth(current) > 0)) {
+		if (unlikely(in_atomic() || (ld -= lockdep_depth(current)))) {

and with this change we will also have a BUG report on "then releases it on a later workqueue invokation".

Then we could say at least this code is weird (buggy - in my opinion). This patch doesn't change the way the "standard" code is treated, so I cannot see any possibility to get it worse then now.

Regards,
Jarek P.

#19 lore raw
Quoted 30 lines · Jarek Poplawski
Quoted 1 line · Oleg Nesterov

On 03/20, Jarek Poplawski wrote:

...

Quoted 16 lines
Quoted 16 lines
Quoted 16 lines
Quoted 16 lines
Quoted 16 lines · Andrew Morton
Quoted 15 lines
Quoted 15 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================

...

Quoted 8 lines
Quoted 2 lines

This check is valid with keventd, but it looks like nfsd runs kthread by itself. I'm not sure it's illegal to hold locks then,

nfsd creates laundry_wq by itself, yes, but cwq->thread runs with lockdep_depth() == 0. Unless we have a bug with lockdep_depth(), lockdep_depth() != 0 means that work->func() returns with a lock held (or it can flush its own workqueue under lock, but in that case we should have a different trace).

Quoted 4 lines

IMHO you can only say this thread is supposed to run with lockdep_depth() == 0. lockdep_depth is counted within a process, which starts before f(), so the only way to say f() leaked locks is to check these locks before and after f().

Sorry, I can't understand you. lockdep_depth is counted within a process, which starts before f(), yes. This process is cwq->thread, it was forked during create_workqueue(). It does not take any locks directly, only by calling work->func(). laundry_wq doesn't differ from keventd_wq or any other wq in this sense. nfsd does not "runs kthread by itself", it inserts the work and wakes up cwq->thread.

Quoted 7 lines
Quoted 4 lines

Personally I agree with Andrew:

Quoted 3 lines
Quoted 3 lines

OK. That's not necessarily a bug: one could envisage a (weird) piece of code which takes a lock then releases it on a later workqueue invokation.

But this code is named here as laundromat_main and it doesn't seem to work like this.

This means we have a problem with leak detection.

Quoted 10 lines
Quoted 9 lines

kernel/workqueue.c static void run_workqueue(struct cpu_wor · line 331

Quoted 6 lines
kernel/workqueue.c +3 -1
+		ld = lockdep_depth(current);
+
 		f(work);
 
-		if (unlikely(in_atomic() || lockdep_depth(current) > 0)) {
+		if (unlikely(in_atomic() || (ld -= lockdep_depth(current)))) {

and with this change we will also have a BUG report on "then releases it on a later workqueue invokation".

Quoted 3 lines

Then we could say at least this code is weird (buggy - in my opinion). This patch doesn't change the way the "standard" code is treated, so I cannot see any possibility to get it worse then now.

I didn't mean this patch makes things worse (except it conflicts with other patches in -mm tree). In fact, it may improve the diagnostics. My point is that this patch afaics has nothing to do with the discussed problem.

Oleg.

#20 lore raw
Quoted 36 lines · Oleg Nesterov
Quoted 30 lines · Jarek Poplawski
Quoted 1 line · Oleg Nesterov

On 03/20, Jarek Poplawski wrote:

...

Quoted 16 lines
Quoted 16 lines
Quoted 16 lines
Quoted 16 lines
Quoted 16 lines · Andrew Morton
Quoted 15 lines
Quoted 15 lines · On Tue, 13 Mar 2007 17:50:14 +0100 Folkert van Heusden…

...

[ 1756.728209] BUG: workqueue leaked lock or atomic: nfsd4/0x00000000/3577
[ 1756.728271]     last function: laundromat_main+0x0/0x69 [nfsd]
[ 1756.728392] 2 locks held by nfsd4/3577:
[ 1756.728435]  #0:  (client_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728679]  #1:  (&inode->i_mutex){--..}, at: [<c1205b88>] mutex_lock+0x8/0xa
[ 1756.728923]  [<c1003d57>] show_trace_log_lvl+0x1a/0x30
[ 1756.729015]  [<c1003d7f>] show_trace+0x12/0x14
[ 1756.729103]  [<c1003e79>] dump_stack+0x16/0x18
[ 1756.729187]  [<c102c2e8>] run_workqueue+0x167/0x170
[ 1756.729276]  [<c102c437>] worker_thread+0x146/0x165
[ 1756.729368]  [<c102f797>] kthread+0x97/0xc4
[ 1756.729456]  [<c1003bdb>] kernel_thread_helper+0x7/0x10
[ 1756.729547]  =======================

...

Quoted 8 lines
Quoted 2 lines

This check is valid with keventd, but it looks like nfsd runs kthread by itself. I'm not sure it's illegal to hold locks then,

nfsd creates laundry_wq by itself, yes, but cwq->thread runs with lockdep_depth() == 0. Unless we have a bug with lockdep_depth(), lockdep_depth() != 0 means that work->func() returns with a lock held (or it can flush its own workqueue under lock, but in that case we should have a different trace).

Quoted 4 lines

IMHO you can only say this thread is supposed to run with lockdep_depth() == 0. lockdep_depth is counted within a process, which starts before f(), so the only way to say f() leaked locks is to check these locks before and after f().

Quoted 6 lines

Sorry, I can't understand you. lockdep_depth is counted within a process, which starts before f(), yes. This process is cwq->thread, it was forked during create_workqueue(). It does not take any locks directly, only by calling work->func(). laundry_wq doesn't differ from keventd_wq or any other wq in this sense. nfsd does not "runs kthread by itself", it inserts the work and wakes up cwq->thread.

I think we know how it all should start and go. If only analyzing the code could be enough, this current check of lockdep_depth() is unnecessary too, because laundromat_code code looks as good as run_workqueue code. I send it for testing and I mean it - something strange is going here, so some checks should be added
- I didn't say mine is the right and will certainly help. So, if you have another idea for looking after it, let us know.

Quoted 10 lines
Quoted 8 lines
Quoted 5 lines

Personally I agree with Andrew:

Quoted 3 lines
Quoted 3 lines

OK. That's not necessarily a bug: one could envisage a (weird) piece of code which takes a lock then releases it on a later workqueue invokation.

But this code is named here as laundromat_main and it doesn't seem to work like this.

This means we have a problem with leak detection.

I totally agree!

Quoted 11 lines
Quoted 11 lines
Quoted 10 lines

kernel/workqueue.c static void run_workqueue(struct cpu_wor · line 331

Quoted 7 lines
kernel/workqueue.c +3 -1
+		ld = lockdep_depth(current);
+
 		f(work);
 
-		if (unlikely(in_atomic() || lockdep_depth(current) > 0)) {
+		if (unlikely(in_atomic() || (ld -= lockdep_depth(current)))) {

and with this change we will also have a BUG report on "then releases it on a later workqueue invokation".

Quoted 7 lines
Quoted 3 lines

Then we could say at least this code is weird (buggy - in my opinion). This patch doesn't change the way the "standard" code is treated, so I cannot see any possibility to get it worse then now.

I didn't mean this patch makes things worse (except it conflicts with other patches in -mm tree). In fact, it may improve the diagnostics. My point is that this patch afaics has nothing to do with the discussed problem.

I thought you are trying to diagnose a bug and maybe Folkert could test, if this patch makes any difference. Sorry, if I missed the real problem.

Cheers,
Jarek P.

#21 lore raw
Quoted 2 lines

I thought you are trying to diagnose a bug and maybe Folkert could test, if this patch makes any difference. Sorry, if I missed the real problem.

Yes please let me know when I can test a patch.

Folkert van Heusden

Signature · 3 lines
www.biglumber.com <- site where one can exchange PGP key signatures 
----------------------------------------------------------------------
Phone: +31-6-41278122, PGP-key: 1F28D8AE, www.vanheusden.com
#22 lore raw
In reply to Jarek Poplawski
Quoted 8 lines · Jarek Poplawski
Quoted 7 lines

Sorry, I can't understand you. lockdep_depth is counted within a process, which starts before f(), yes. This process is cwq->thread, it was forked during create_workqueue(). It does not take any locks directly, only by calling work->func(). laundry_wq doesn't differ from keventd_wq or any other wq in this sense. nfsd does not "runs kthread by itself", it inserts the work and wakes up cwq->thread.

Quoted 6 lines

I think we know how it all should start and go. If only analyzing the code could be enough, this current check of lockdep_depth() is unnecessary too, because laundromat_code code looks as good as run_workqueue code. I send it for testing and I mean it - something strange is going here, so some checks should be added
- I didn't say mine is the right and will certainly help.

Ah, sorry, I misunderstood you. I had (my fault) a false impression that you propose this patch as a "fix", while we seem to agree that the real source of this problem remains unknown.

Quoted 2 lines

So, if
you have another idea for looking after it, let us know.

No, I don't.

Oleg.

#23 lore raw
Quoted 7 lines · Oleg Nesterov
Quoted 3 lines · Jarek Poplawski

So, if
you have another idea for looking after it, let us know.

No, I don't.

Perhaps we can add lockdep_depth() checks to laundromat_main/nfs4_laundromat to rule out workqueue.c. According to the trace, we return with client_mutex held, this seems impossible. So we can also print the value of mutex_is_locked() if lockdep_depth() != 0.

Oleg.

#24 lore raw

PATCH 1/1 lockdep: lockdep_depth vs. debug_locks Re: [2.6.20] BUG: workqueue leaked lock

Here is some joke:

[PATCH] lockdep: lockdep_depth vs. debug_locks

lockdep really shouldn't be used when debug_locks == 0!

---

include/linux/lockdep.h +1 -1
diff -Nurp 2.6.21-rc4-git4-/include/linux/lockdep.h 2.6.21-rc4-git4/include/linux/lockdep.h
@@ -245,7 +245,7 @@ extern void lock_release(struct lockdep_
 
 # define INIT_LOCKDEP				.lockdep_recursion = 0,
 
-#define lockdep_depth(tsk)	((tsk)->lockdep_depth)
+#define lockdep_depth(tsk)	(debug_locks ? (tsk)->lockdep_depth : 0)
 
 #else /* !LOCKDEP */
 
#25 lore raw

Re: [PATCH] lockdep: lockdep_depth vs. debug_locks Re: [2.6.20] BUG: workqueue leaked lock

Quoted 7 lines · On Thu, 22 Mar 2007 07:11:19 +0100 Jarek Poplawski <[email protected]> wrote:

Here is some joke:

[PATCH] lockdep: lockdep_depth vs. debug_locks

lockdep really shouldn't be used when debug_locks == 0!

This isn't a very good changelog.

Quoted 11 lines

---

diff -Nurp 2.6.21-rc4-git4-/include/linux/lockdep.h 2.6.21-rc4-git4/include/linux/lockdep.h

include/linux/lockdep.h extern void lock_release(struct lockdep_ · line 251

Quoted 8 lines
include/linux/lockdep.h +1 -1
@@ -245,7 +245,7 @@ extern void lock_release(struct lockdep_
 
 # define INIT_LOCKDEP				.lockdep_recursion = 0,
 
-#define lockdep_depth(tsk)	((tsk)->lockdep_depth)
+#define lockdep_depth(tsk)	(debug_locks ? (tsk)->lockdep_depth : 0)
 
 #else /* !LOCKDEP */
 

What problem does this solve, and how does it solve it?

I assume that some codepath is incrementing ->lockdep_depth even when debug_locks==0. Isn't that wrong of it?

#26 lore raw

Re: [PATCH] lockdep: lockdep_depth vs. debug_locks Re: [2.6.20] BUG: workqueue leaked lock

Quoted 29 lines · Andrew Morton
Quoted 7 lines · On Thu, 22 Mar 2007 07:11:19 +0100 Jarek Poplawski <[email protected]> wrote:

Here is some joke:

[PATCH] lockdep: lockdep_depth vs. debug_locks

lockdep really shouldn't be used when debug_locks == 0!

This isn't a very good changelog.

Quoted 17 lines

---

diff -Nurp 2.6.21-rc4-git4-/include/linux/lockdep.h 2.6.21-rc4-git4/include/linux/lockdep.h

include/linux/lockdep.h +1 -1
@@ -245,7 +245,7 @@ extern void lock_release(struct lockdep_
 
 # define INIT_LOCKDEP				.lockdep_recursion = 0,
 
-#define lockdep_depth(tsk)	((tsk)->lockdep_depth)
+#define lockdep_depth(tsk)	(debug_locks ? (tsk)->lockdep_depth : 0)
 
Quoted 8 lines

include/linux/lockdep.h extern void lock_release(struct lockdep_ · line 251

Quoted 2 lines
include/linux/lockdep.h +0 -0
 #else /* !LOCKDEP */
 

What problem does this solve, and how does it solve it?

I assume that some codepath is incrementing ->lockdep_depth even when debug_locks==0. Isn't that wrong of it?

This should definitely solve this problem - as it was said a few times before lockdep stops registering locks after a bug, so even the lock which caused the warning isn't reported. Here lockdep found a bug in a workqueue function, so after this no lock or unlock isn't counted nor reported.

I think Ingo can tell more.

Regards,
Jarek P.

#27 lore raw

Re: [PATCH] lockdep: lockdep_depth vs. debug_locks Re: [2.6.20] BUG: workqueue leaked lock

On Thu, Mar 22, 2007 at 08:06:44AM +0100, Jarek Poplawski wrote:
...

Quoted 4 lines

This should definitely solve this problem - as it was said a few times before lockdep stops registering locks after a bug, so even the lock which caused the warning isn't reported. Here lockdep found a bug in a workqueue function,

More precisely:

lockdep found a bug during a run of workqueue function - this could be also caused by a bug from other code running simultaneusly.

Jarek P.

#28 lore raw

Re: [PATCH] lockdep: lockdep_depth vs. debug_locks Re: [2.6.20] BUG: workqueue leaked lock

In reply to Andrew Morton

On Wed, Mar 21, 2007 at 10:28:02PM -0800, Andrew Morton wrote:
...

Quoted 3 lines

I assume that some codepath is incrementing ->lockdep_depth even when debug_locks==0. Isn't that wrong of it?

lockdep simply stops to update lockdep_depth just after (during) a bug or a WARN.

Jarek P.

#29 lore raw

Re: [PATCH] lockdep: lockdep_depth vs. debug_locks Re: [2.6.20] BUG: workqueue leaked lock

In reply to Andrew Morton
Quoted 11 lines · Andrew Morton
Quoted 7 lines · On Thu, 22 Mar 2007 07:11:19 +0100 Jarek Poplawski <[email protected]> wrote:

Here is some joke:

[PATCH] lockdep: lockdep_depth vs. debug_locks

lockdep really shouldn't be used when debug_locks == 0!

This isn't a very good changelog.

Actually it's not a changelog (it's a joke).

Jarek P.

#30 lore raw

PATCH 1/1 lockdep: debug_show_all_locks & debug_show_held_locks vs. debug_locks

In reply to Jarek Poplawski

And here is some addition.

[PATCH] lockdep: debug_show_all_locks & debug_show_held_locks vs. debug_locks

lockdep's data shouldn't be used when debug_locks == 0 because it's not updated after this, so it's more misleading than helpful.

PS: probably lockdep's current-> fields should be reset after it turns debug_locks off: so, after printing a bug report, but before return from exported functions, but there are really a lot of these possibilities (e.g. after DEBUG_LOCKS_WARN_ON), so, something could be missed. (Of course direct use of this fields isn't recommended either.)

---

kernel/lockdep.c +8 -0
diff -Nurp 2.6.21-rc4-git4-/kernel/lockdep.c 2.6.21-rc4-git4/kernel/lockdep.c
@@ -2742,6 +2742,10 @@ void debug_show_all_locks(void)
 	int count = 10;
 	int unlock = 1;
 
+	if (unlikely(!debug_locks)) {
+		printk("INFO: lockdep is turned off.\n");
+		return;
+	}
 	printk("\nShowing all locks held in the system:\n");
 
 	/*
@@ -2785,6 +2789,10 @@ EXPORT_SYMBOL_GPL(debug_show_all_locks);
 
 void debug_show_held_locks(struct task_struct *task)
 {
+	if (unlikely(!debug_locks)) {
+		printk("INFO: lockdep is turned off.\n");
+		return;
+	}
 	lockdep_print_held_locks(task);
 }
 
Acked-by on v1 1/1
#31 lore raw

Re: [PATCH] lockdep: debug_show_all_locks & debug_show_held_locks vs. debug_locks

Quoted 15 lines · Jarek Poplawski

And here is some addition.

[PATCH] lockdep: debug_show_all_locks & debug_show_held_locks vs. debug_locks

lockdep's data shouldn't be used when debug_locks == 0 because it's not updated after this, so it's more misleading than helpful.

PS: probably lockdep's current-> fields should be reset after it turns debug_locks off: so, after printing a bug report, but before return from exported functions, but there are really a lot of these possibilities (e.g. after DEBUG_LOCKS_WARN_ON), so, something could be missed. (Of course direct use of this fields isn't recommended either.)

Quoted 3 lines
Quoted 27 lines

---

diff -Nurp 2.6.21-rc4-git4-/kernel/lockdep.c 2.6.21-rc4-git4/kernel/lockdep.c

kernel/lockdep.c +8 -0
@@ -2742,6 +2742,10 @@ void debug_show_all_locks(void)
 	int count = 10;
 	int unlock = 1;
 
+	if (unlikely(!debug_locks)) {
+		printk("INFO: lockdep is turned off.\n");
+		return;
+	}
 	printk("\nShowing all locks held in the system:\n");
 
 	/*
@@ -2785,6 +2789,10 @@ EXPORT_SYMBOL_GPL(debug_show_all_locks);
 
 void debug_show_held_locks(struct task_struct *task)
 {
+	if (unlikely(!debug_locks)) {
+		printk("INFO: lockdep is turned off.\n");
+		return;
+	}
 	lockdep_print_held_locks(task);
 }
 
Acked-by
#32 lore raw

Re: [PATCH] lockdep: debug_show_all_locks & debug_show_held_locks vs. debug_locks

Quoted 16 lines · Peter Zijlstra
Quoted 15 lines · Jarek Poplawski

And here is some addition.

[PATCH] lockdep: debug_show_all_locks & debug_show_held_locks vs. debug_locks

lockdep's data shouldn't be used when debug_locks == 0 because it's not updated after this, so it's more misleading than helpful.

PS: probably lockdep's current-> fields should be reset after it turns debug_locks off: so, after printing a bug report, but before return from exported functions, but there are really a lot of these possibilities (e.g. after DEBUG_LOCKS_WARN_ON), so, something could be missed. (Of course direct use of this fields isn't recommended either.)

Quoted 5 lines
Quoted 3 lines

Ingo

Acked-by on v1 1/1
#33 lore raw

Re: [PATCH] lockdep: lockdep_depth vs. debug_locks Re: [2.6.20] BUG: workqueue leaked lock

In reply to Jarek Poplawski
Quoted 5 lines · Jarek Poplawski

Here is some joke:

[PATCH] lockdep: lockdep_depth vs. debug_locks

lockdep really shouldn't be used when debug_locks == 0!

This happens then lockdep reports a fatal error, at which point it will stop tracking locks and leave whatever state was there.

Quoted 3 lines

This looks sane, thanks for figuring this out.

Quoted 14 lines

---

diff -Nurp 2.6.21-rc4-git4-/include/linux/lockdep.h 2.6.21-rc4-git4/include/linux/lockdep.h

include/linux/lockdep.h +1 -1
@@ -245,7 +245,7 @@ extern void lock_release(struct lockdep_
 
 # define INIT_LOCKDEP				.lockdep_recursion = 0,
 
-#define lockdep_depth(tsk)	((tsk)->lockdep_depth)
+#define lockdep_depth(tsk)	(debug_locks ? (tsk)->lockdep_depth : 0)
 
 #else /* !LOCKDEP */
 
Acked-by
#34 lore raw

Re: [PATCH] lockdep: lockdep_depth vs. debug_locks Re: [2.6.20] BUG: workqueue leaked lock

Quoted 10 lines · Peter Zijlstra
Quoted 5 lines · Jarek Poplawski

Here is some joke:

[PATCH] lockdep: lockdep_depth vs. debug_locks

lockdep really shouldn't be used when debug_locks == 0!

This happens then lockdep reports a fatal error, at which point it will stop tracking locks and leave whatever state was there.

Quoted 7 lines
Quoted 3 lines

This looks sane, thanks for figuring this out.

Ingo