Re: acquiring duplicate lock of same type: "ftlk"

2009/9/9 John Baldwin <jhb_at_freebsd.org>:
> On Tuesday 08 September 2009 3:42:13 pm pluknet wrote:
>> 2009/9/8 Attilio Rao <attilio_at_freebsd.org>:
>> > 2009/9/8 Kostik Belousov <kostikbel_at_gmail.com>:
>> >> On Mon, Sep 07, 2009 at 10:15:48PM +0400, pluknet wrote:
>> >>> lock order reversal:
>> >>>  1st 0xc75365b8 pseudofs (pseudofs) _at_ /usr/src/sys/kern/vfs_lookup.c:497
>> >>>  2nd 0xc088ea3c allproc (allproc) _at_ /usr/src/sys/kern/kern_proc.c:292
>> >>> KDB: stack backtrace:
>> >>> db_trace_self_wrapper(c07fd8ea,e82148e4,c060a145,c05fac1b,c08008bf,...)
>> >>> at db_trace_self_wrapper+0x26
>> >>> kdb_backtrace(c05fac1b,c08008bf,c58eabe8,c58e30d0,e8214940,...) at
>> >>> kdb_backtrace+0x29
>> >>> _witness_debugger(c08008bf,c088ea3c,c07f981d,c58e30d0,c07f96f0,...) at
>> >>> _witness_debugger+0x25
>> >>> witness_checkorder(c088ea3c,1,c07f96f0,124,0,...) at
> witness_checkorder+0x839
>> >>> _sx_slock(c088ea3c,0,c07f96f0,124,c73c4980,...) at _sx_slock+0x85
>> >>> pfind(514,c72ba1a0,4,c07f8d78,c5fe1b40,...) at pfind+0x2f
>> >>> pfs_visible(0,0,c07f042d,7c,c7536560,...) at pfs_visible+0x3a
>> >>> pfs_lookup(e8214a40,c082715e,c7536560,c7536560,e8214bf8,...) at
> pfs_lookup+0x3dd
>> >>> VOP_CACHEDLOOKUP_APV(c0843960,e8214a40,e8214bf8,e8214be4,c73c4e80,...)
>> >>> at VOP_CACHEDLOOKUP_APV+0xc5
>> >>> vfs_cache_lookup(e8214acc,c08087d0,c0875a00,200000,e8214bcc,...) at
>> >>> vfs_cache_lookup+0xd6
>> >>> VOP_LOOKUP_APV(c0843960,e8214acc,e8214bf8,1f1,e8214be4,...) at
>> >>> VOP_LOOKUP_APV+0xe5
>> >>> lookup(e8214bcc,c5fd1800,0,c5,c5ef77f8,...) at lookup+0x63b
>> >>> namei(e8214bcc,c5c1500d,3f3,e8214c20,c5c1500d,...) at namei+0x57f
>> >>> kern_alternate_path(c5fe1b40,c0b4921c,2879f478,0,e8214c74,...) at
> kern_alternate
>> >>> _path+0x1cd
>> >>> linux_emul_convpath(c5fe1b40,2879f478,0,e8214c74,0,...) at
>> >>> linux_emul_convpath+0x3c
>> >>> linux_open(c5fe1b40,e8214cf8,e8214d18,e8214d1c,c0b4b58c,...) at
> linux_open+0x41
>> >>> syscall(e8214d38) at syscall+0x2b4
>> >>> Xint0x80_syscall() at Xint0x80_syscall+0x20
>> >>> --- syscall (5, Linux ELF, linux_open), eip = 0x2889115e, esp =
>> >>> 0xbfbfbd1c, ebp = 0xbfbfbd6c ---
>> >>> acquiring duplicate lock of same type: "ftlk"
>> >>> [...]
>> >>
>> >> The second LOR actually exposes the right order. It would be interesting
>> >> to look up the point where the other order is established.
>> >
>> > You would manually patch the witness static table with this order and
>> > the opposite will show, when happening.
>> >
>>
>> I've patched witness order table, and still no opposite case,
>> nor any pseudofs related LORs at all.
>>         { "pseudofs", &lock_class_lockmgr },
>>         { "allproc", &lock_class_sx },
>>         { NULL, NULL },
>>
>> Seen orders with pseudofs:
>> "ufs","pseudofs"
>> "pseudofs","allproc"
>> "pseudofs","process lock"
>> "pseudofs","vnode interlock"
>> "pseudofs","struct mount mtx"
>> "pseudofs","UMA zone"
>> "pseudofs","sleep mtxpool"
>> "pseudofs","Name Cache"
>> "pseudofs","vnode_free_list"
>> "pseudofs","pfs_node"
>> "pseudofs","pfs_vncache"
>>
>> Something else?
>
> What are the seen orders with "allproc"?
>

sysctl debug.witness.fullgraph | grep allproc
"proctree","allproc"
"allproc","allprison"
"allproc","process lock"
"allproc","user map"
"allproc","fdesc"
"allproc","filedesc structure"
"sysctl lock","allproc"
"pseudofs","allproc"

Also, if it matters, I saw this LOR today:

lock order reversal:
 1st 0xc7f01164 ufs (ufs) _at_ /usr/RELENG_8/src/sys/kern/vfs_mount.c:1054
 2nd 0xc7fb5058 pseudofs (pseudofs) _at_
/usr/RELENG_8/src/sys/fs/pseudofs/pseudofs_vncache.c:193
KDB: stack backtrace:
db_trace_self_wrapper(c0c7545b,eab2c850,c08c0f75,c08b1cfb,c0c783a3,...)
at db_trace_self_wrapper+0x26
kdb_backtrace(c08b1cfb,c0c783a3,c612fbe8,c61281a0,eab2c8ac,...) at
kdb_backtrace+0x29
_witness_debugger(c0c783a3,c7fb5058,c0c679b8,c61281a0,c0c6803f,...) at
_witness_debugger+0x25
witness_checkorder(c7fb5058,9,c0c6803f,c1,c7fb5074,...) at
witness_checkorder+0x839
__lockmgr_args(c7fb5058,80400,c7fb5074,0,0,...) at __lockmgr_args+0x7a7
vop_stdlock(eab2c9b4,c087030a,c7fb50a8,80400,c7fb5000,...) at vop_stdlock+0x62
VOP_LOCK1_APV(c0d55580,eab2c9b4,c0911dcf,c0d92080,c7fb5000,...) at
VOP_LOCK1_APV+0xb5
_vn_lock(c7fb5000,80400,c0c6803f,c1,c0f3339c,...) at _vn_lock+0x5e
pfs_vncache_alloc(c6764c94,eab2cc30,c7d1cb00,186a0,eab2cc60,...) at
pfs_vncache_alloc+0x232
pfs_root(c6764c94,80000,eab2cc30,42c,0,...) at pfs_root+0x2d
vfs_donmount(c7ba76c0,0,c6b66500,c6b66500,bfbfdc89,...) at vfs_donmount+0x14c2
nmount(c7ba76c0,eab2ccf8,c,c7ba76c0,c0d5a638,...) at nmount+0x75
syscall(eab2cd38) at syscall+0x2a3
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (378, FreeBSD ELF32, nmount), eip = 0x280e876b, esp =
0xbfbfdc5c, ebp = 0xbfbfe1b8 ---


-- 
wbr,
pluknet