Re: LOR between nfs and proctree

On Fri, Dec 19, 2008 at 02:41:04AM +0300, pluknet wrote:
> 2008/12/19 Kostik Belousov <kostikbel_at_gmail.com>:
> > On Thu, Dec 18, 2008 at 01:43:38AM +0300, pluknet wrote:
> >> I didn't find this LOR in archives and don't know if this is known
> >> one, so I'm posting it here.
> >>
> >> lock order reversal:
> >>  1st 0xc5ea37ac nfs (nfs) _at_ /usr/src/sys/kern/vfs_vnops.c:531
> >>  2nd 0xc0889090 proctree (proctree) _at_ /usr/src/sys/kern/kern_fork.c:311
> >> KDB: stack backtrace:
> >> db_trace_self_wrapper(c07fb0cf,e7d1f8cc,c05d79e5,4,c07f662d,...) at
> >> db_trace_self_wrapper+0x26
> >> kdb_backtrace(4,c07f662d,c54fcad8,c54f6068,e7d1f928,...) at kdb_backtrace+0x29
> >> _witness_debugger(c07fdd7f,c0889090,c07f702d,c54f6068,c07f3e44,...) at
> >> _witness_debugger+0x25
> >> witness_checkorder(c0889090,1,c07f3e44,137,0,...) at witness_checkorder+0x839
> >> _sx_slock(c0889090,0,c07f3e44,137,0,...) at _sx_slock+0x85
> >> fork1(c0887530,60034,0,e7d1f9c0,c07f662d,...) at fork1+0x2cd
> >> kproc_create(c06dc780,c09f8920,0,40000,0,...) at kproc_create+0x47
> >> nfs_nfsiodnew(c09f8f70,0,c080e39a,553,0,...) at nfs_nfsiodnew+0xc5
> >> nfs_asyncio(c5c024e8,d952b670,c5af0000,c5abdd80,0,...) at nfs_asyncio+0x3a5
> >> nfs_bioread(c5ea3754,e7d1fc58,20000,c5af0000,e7d1fba0,...) at nfs_bioread+0x788
> >> nfs_read(e7d1fbc8,c5abdd80,c5e63968,c5abdd80,e7d1fbe8,...) at nfs_read+0x44
> >> VOP_READ_APV(c085d360,e7d1fbc8,c0805cb8,213,c5abde24,...) at VOP_READ_APV+0xa5
> >> vn_read(c5e63968,e7d1fc58,c5af0000,0,c5abdd80,...) at vn_read+0x1ee
> >> dofileread(e7d1fc58,ffffffff,ffffffff,0,c5e63968,...) at dofileread+0x96
> >> kern_readv(c5abdd80,4,e7d1fc58,e7d1fc78,1,...) at kern_readv+0x58
> >> read(c5abdd80,e7d1fcf8,c,c07fe5a8,c083f5c8,...) at read+0x4f
> >> syscall(e7d1fd38) at syscall+0x2a3
> >> Xint0x80_syscall() at Xint0x80_syscall+0x20
> >> --- syscall (3, FreeBSD ELF32, read), eip = 0x281c7f93, esp =
> >> 0xbfbfeaec, ebp = 0xbfbfec28 ---
> >
> > It is more or less known, nfs may create new nfsiod while holding vnode
> > lock. Severity of the issue lowered with removal of the single-threading
> > from the fork(), but it is still real. Workaround is to create required
> > amount of nfsiod in advance.
> >
> 
> Thank you for reply.
> 
> Are those two related?
> 
> lock order reversal:
>  1st 0xd9529b40 bufwait (bufwait) _at_ /usr/src/sys/kern/vfs_bio.c:1783
>  2nd 0xc70868b4 so_snd_sx (so_snd_sx) _at_ /usr/src/sys/kern/uipc_sockbuf.c:148
> KDB: stack backtrace:
> db_trace_self_wrapper(c07fb0cf,e800364c,c05d79e5,4,c07f662d,...) at
> db_trace_self_wrapper+0x26
> kdb_backtrace(4,c07f662d,c54f9810,c54fc868,e80036a8,...) at kdb_backtrace+0x29
> _witness_debugger(c07fdd7f,c70868b4,c0801ece,c54fc868,c0801b8d,...) at
> _witness_debugger+0x25
> witness_checkorder(c70868b4,9,c0801b8d,94,0,...) at witness_checkorder+0x839
> _sx_xlock(c70868b4,40,c0801b8d,94,e8003740,...) at _sx_xlock+0x85
> sblock(c7086880,1,c07f0efa,3,c5b176c0,...) at sblock+0x85
> sosend_generic(c70867a8,0,0,c5eb4400,0,...) at sosend_generic+0xc2
> sosend(c70867a8,0,0,c5eb4400,0,...) at sosend+0x3f
> clnt_vc_call(c5957b60,e80038a4,10,c68d3900,e80038e0,...) at clnt_vc_call+0x43c
> clnt_reconnect_call(c5956760,e80038a4,10,c68d3900,e80038e0,...) at
> clnt_reconnect_call+0x5a0
> nfs_request(c5c5b10c,c68d3900,10,c5b176c0,c6825d00,...) at nfs_request+0x1dd
> nfs_readdirrpc(c5c5b10c,e80039b4,c6825d00,c5e7ec1c,4,...) at
> nfs_readdirrpc+0x25c
> nfs_doio(c5c5b10c,d9529ae0,c6825d00,c5b176c0,0,...) at nfs_doio+0x2f1
> nfs_bioread(c5c5b10c,e8003c00,0,c6825d00,e8003b5c,...) at nfs_bioread+0xbdb
> nfs_readdir(e8003c20,0,c5c5b10c,0,e8003c58,...) at nfs_readdir+0x153
> VOP_READDIR_APV(c085d360,e8003c20,c0805b55,ff3,0,...) at VOP_READDIR_APV+0xa5
> kern_getdirentries(c5b176c0,3,2811f000,1000,e8003c74,...) at
> kern_getdirentries+0x1f5
> getdirentries(c5b176c0,e8003cf8,10,c07fea30,c08407e0,...) at getdirentries+0x31
> syscall(e8003d38) at syscall+0x2a3
> Xint0x80_syscall() at Xint0x80_syscall+0x20
> --- syscall (196, FreeBSD ELF32, getdirentries), eip = 0x807d18f, esp
> = 0xbfbfdf0c, ebp = 0xbfbfdf38 ---
> 
> lock order reversal:
>  1st 0xd96ca6c0 bufwait (bufwait) _at_ /usr/src/sys/kern/vfs_bio.c:1783
>  2nd 0xc0889090 proctree (proctree) _at_ /usr/src/sys/kern/kern_fork.c:311
> KDB: stack backtrace:
> db_trace_self_wrapper(c07fb0cf,e81168cc,c05d79e5,4,c07f662d,...) at
> db_trace_self_wrapper+0x26
> kdb_backtrace(4,c07f662d,c54f9810,c54f6068,e8116928,...) at kdb_backtrace+0x29
> _witness_debugger(c07fdd7f,c0889090,c07f702d,c54f6068,c07f3e44,...) at
> _witness_debugger+0x25
> witness_checkorder(c0889090,1,c07f3e44,137,0,...) at witness_checkorder+0x839
> _sx_slock(c0889090,0,c07f3e44,137,0,...) at _sx_slock+0x85
> fork1(c0887530,60034,0,e81169c0,c07f662d,...) at fork1+0x2cd
> kproc_create(c06dc780,c09f8920,0,40000,0,...) at kproc_create+0x47
> nfs_nfsiodnew(c09f8f70,0,c080e39a,553,0,...) at nfs_nfsiodnew+0xc5
> nfs_asyncio(c5c5c4e8,d96ca660,c6825d00,c65db6c0,0,...) at nfs_asyncio+0x3a5
> nfs_bioread(c6cd4324,e8116c58,20000,c6825d00,e8116ba0,...) at nfs_bioread+0x788
> nfs_read(e8116bc8,c65db6c0,c5ca31f8,c65db6c0,e8116be8,...) at nfs_read+0x44
> VOP_READ_APV(c085d360,e8116bc8,c0805cb8,213,c65db764,...) at VOP_READ_APV+0xa5
> vn_read(c5ca31f8,e8116c58,c6825d00,0,c65db6c0,...) at vn_read+0x1ee
> dofileread(e8116c58,ffffffff,ffffffff,0,c5ca31f8,...) at dofileread+0x96
> kern_readv(c65db6c0,3,e8116c58,e8116c78,1,...) at kern_readv+0x58
> read(c65db6c0,e8116cf8,c,c07fe68b,c083f5c8,...) at read+0x4f
> syscall(e8116d38) at syscall+0x2a3
> Xint0x80_syscall() at Xint0x80_syscall+0x20
> --- syscall (3, FreeBSD ELF32, read), eip = 0x808a0bf, esp =
> 0xbfbfd9cc, ebp = 0xbfbfd9f8 ---
> 
> Yes, this LOR has the same backtrace with different lock only.
The second LOR has the same reason, but it is a different LOR, obviously.