Re: 2.6.17-rc5-mm3: bad unlock ordering (reiser4?)

["Barry K. Nathan" <barryn@pobox.com>]

On 6/4/06, Ingo Molnar <mingo@elte.hu> wrote:
> reporting the first one only is necessary, because the validator cannot
> trust a system's dependency info that it sees as incorrect. Deadlock
> possibilities are quite rare in a kernel that is "in balance". Right now
> we are not "in balance" yet, because the validator has only been added a
> couple of days ago. The flurry of initial fixes will die down quickly.

So, does that mean the plan is to annotate/tweak things in order to
shut up *each and every* false positive in the kernel?

Anyway, I tried your patch and I got this:

[  401.004071] (            smbd-920  |#0): new 324990707 us user-latency.
[  401.004264] stopped custom tracer.
[  401.004412]
[  401.004425] ======================================
[  401.004687] [ BUG: bad unlock ordering detected! ]
[  401.004849] --------------------------------------
[  401.005010] smbd/920 is trying to release lock (&txnh->hlock) at:
[  401.005302]  [<e09a8332>] get_current_atom_locked_nocheck+0x3d/0x46 [reiser4]
[  401.005702] but the next lock to release is:
[  401.005856]  (&atom->alock){--..}, at: [<e09a78da>]
txnh_get_atom+0x23/0x85 [reiser4]
[  401.006391]
[  401.006405] other info that might help us debug this:
[  401.006660] 2 locks held by smbd/920:
[  401.006804]  #0:  (&inode->i_mutex){--..}, at: [<c0299d58>]
mutex_lock+0xd/0xf
[  401.007373]  #1:  (&txnh->hlock){--..}, at: [<e09a78cc>]
txnh_get_atom+0x15/0x85 [reiser4]
[  401.008021]
[  401.008034] stack backtrace:
[  401.010115]  [<c01032ab>] show_trace_log_lvl+0x64/0x125
[  401.010538]  [<c01038bd>] show_trace+0x1b/0x20
[  401.010955]  [<c0103914>] dump_stack+0x1f/0x24
[  401.011367]  [<c012f4b9>] lockdep_release+0x192/0x35e
[  401.013039]  [<c029b6dc>] _spin_unlock+0x19/0x27
[  401.014899]  [<e09a8332>] get_current_atom_locked_nocheck+0x3d/0x46 [reiser4]
[  401.015674]  [<e09b3c83>] oid_count_allocated+0xd/0x2c [reiser4]
[  401.016649]  [<e09bb853>] write_sd_by_inode_common+0x1fd/0x502 [reiser4]
[  401.017788]  [<e09bbb85>] create_object_common+0x2d/0x37 [reiser4]
[  401.018926]  [<e09b8f47>] create_vfs_object+0x376/0x551 [reiser4]
[  401.020011]  [<e09b91ab>] create_common+0x44/0x4b [reiser4]
[  401.021047]  [<c0167a6e>] vfs_create+0x67/0xad
[  401.024271]  [<c016a832>] open_namei+0x19b/0x6cd
[  401.027492]  [<c0158d64>] do_filp_open+0x2b/0x42
[  401.030193]  [<c0158ddc>] do_sys_open+0x61/0xef
[  401.032721]  [<c0158e9d>] sys_open+0x18/0x1a
[  401.035432]  [<c029b8cc>] syscall_call+0x7/0xb

dmesg and /proc/latency_trace are here:
http://members.cox.net/barrykn/linux/trace/dmesg.reiser4-3
http://members.cox.net/barrykn/linux/trace/latency_trace_reiser4-3.bz2
-- 
-Barry K. Nathan <barryn@pobox.com>