Re: LOR on nfs: vfs_vnops.c:301 kern_descrip.c:1580

On Monday, August 16, 2010 2:54:56 pm Kostik Belousov wrote:
> On Mon, Aug 16, 2010 at 09:07:24PM +0400, pluknet wrote:
> > On 16 August 2010 21:05, pluknet <pluknet_at_gmail.com> wrote:
> > > Hi.
> > >
> > > Seeing on mostly idle, recently updated current, while closing a file.
> > > Presumably never reported on ML.
> > >
> > > lock order reversal:
> > >  1st 0xffffff00198199f8 nfs (nfs) _at_ /usr/src/sys/kern/vfs_vnops.c:301
> > >  2nd 0xffffff000234a048 filedesc structure (filedesc structure) _at_
> > > /usr/src/sys/kern/kern_descrip.c:1580
> > > KDB: stack backtrace:
> > > db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
> > > _witness_debugger() at _witness_debugger+0x2e
> > > witness_checkorder() at witness_checkorder+0x807
> > > _sx_xlock() at _sx_xlock+0x55
> > > fdinit() at fdinit+0x5b
> > > fdcopy() at fdcopy+0x2a
> > > fork1() at fork1+0x836
> > > kproc_create() at kproc_create+0x63
> > > nfs_nfsiodnew() at nfs_nfsiodnew+0xd7
> > > nfs_asyncio() at nfs_asyncio+0xa6
> > > nfs_strategy() at nfs_strategy+0x83
> > > bufstrategy() at bufstrategy+0x43
> > > nfs_writebp() at nfs_writebp+0xcf
> > > nfs_flush() at nfs_flush+0x1dc
> > > nfs_close() at nfs_close+0x213
> > > vn_close() at vn_close+0x10e
> > > vn_closefile() at vn_closefile+0x5a
> > > _fdrop() at _fdrop+0x23
> > > closef() at closef+0x5b
> > > kern_close() at kern_close+0x110
> > > syscallenter() at syscallenter+0x1aa
> > > syscall() at syscall+0x4c
> > > Xfast_syscall() at Xfast_syscall+0xe2
> > > --- syscall (6, FreeBSD ELF64, close), rip = 0x80089830c, rsp =
> > > 0x7fffffffea88, rbp = 0 ---
> > >
> > >
> > 
> > Mostly the same (different 2nd lock path).
> > 
> > lock order reversal:
> >  1st 0xffffff00198199f8 nfs (nfs) _at_ /usr/src/sys/kern/vfs_vnops.c:301
> >  2nd 0xffffffff80ca47e0 proctree (proctree) _at_ 
/usr/src/sys/kern/kern_fork.c:335
> > KDB: stack backtrace:
> > db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
> > _witness_debugger() at _witness_debugger+0x2e
> > witness_checkorder() at witness_checkorder+0x807
> > _sx_slock() at _sx_slock+0x55
> > fork1() at fork1+0x190
> > kproc_create() at kproc_create+0x63
> > nfs_nfsiodnew() at nfs_nfsiodnew+0xd7
> > nfs_asyncio() at nfs_asyncio+0xa6
> > nfs_strategy() at nfs_strategy+0x83
> > bufstrategy() at bufstrategy+0x43
> > nfs_writebp() at nfs_writebp+0xcf
> > nfs_flush() at nfs_flush+0x1dc
> > nfs_close() at nfs_close+0x213
> > vn_close() at vn_close+0x10e
> > vn_closefile() at vn_closefile+0x5a
> > _fdrop() at _fdrop+0x23
> > closef() at closef+0x5b
> > kern_close() at kern_close+0x110
> > syscallenter() at syscallenter+0x1aa
> > syscall() at syscall+0x4c
> > Xfast_syscall() at Xfast_syscall+0xe2
> > --- syscall (6, FreeBSD ELF64, close), rip = 0x80089830c, rsp =
> > 0x7fffffffea88, rbp = 0 ---
> > 
> Both LORs are valid. The fork performed deep inside the VFS call stack
> is obviously problematic. As a workaround, you may fix the number of
> nfsiods.
> 
> Proper fix might consist of creating a shepherd thread which only task
> is to act on the requests on creating new nfsiods.
> 
> Would you try to implement this ? I will provide the assistance, if needed.

Or queue a task to create new nfsiod threads instead of invoking 
kproc_create() directly.  That can be cheaper than creating a dedicated 
shepherd thread.

-- 
John Baldwin