[nfs] process locks in "bo_wwait" on 6.4

Fri Jun 26 16:51:17 UTC 2009

2009/6/26 pluknet <pluknet at gmail.com>:
> Hello.
>
> While building a module on nfs mounted /usr/src
> I got an unkillable process waiting forever in bo_wwait.

Small note: iface on NFS server has mtu changed from 1500 to 1450.
Can this be a source of the problem?

>
> # make
> Warning: Object directory not changed from original /usr/src/sys/modules/linux
> @ -> /usr/src/sys
> machine -> /usr/src/sys/i386/include
> cc -c -O2 -fno-strict-aliasing -pipe -Werror -D_KERNEL -DKLD_MODULE
> -nostdinc -I- -I. -I@ -I@/contrib/altq -I@/../include -I/usr/include
> -finline-limit=8000 -mno-align-long-strings
> -mpreferred-stack-boundary=2 -mno-mmx -mno-3dnow -mno-sse -mno-sse2
> -ffreestanding -Wall -Wredundant-decls -Wnested-externs
> -Wstrict-prototypes -Wmissing-prototypes -Wpointer-arith -Winline
> -Wcast-qual -fformat-extensions -std=c99
> /usr/src/sys/modules/linux/../../i386/linux/linux_genassym.c
> sh @/kern/genassym.sh linux_genassym.o > linux_assym.h
> echo "#define COMPAT_43 1" > opt_compat.h
> echo "#define INET6 1" > opt_inet6.h
> :> opt_mac.h
> :> opt_vmpage.h
> awk -f @/tools/vnode_if.awk @/kern/vnode_if.src -p
> load: 1.08  cmd: awk 37581 [bo_wwait] 0.00u 0.00s 0% 1472k
>
> All others subsystems seems to work.
>
> db> bt 37581
> Tracing pid 37581 tid 100364 td 0xc93c7b60
> sched_switch(c93c7b60,0,1) at sched_switch+0x143
> mi_switch(1,0,c93c7b60,eed95a24,c06ce6f0,...) at mi_switch+0x1ba
> sleepq_switch(ce138854) at sleepq_switch+0x87
> sleepq_wait(ce138854,0,c93c7b60,ce138830,0,...) at sleepq_wait+0x5c
> msleep(ce138854,ce1387ec,4d,c096823e,0) at msleep+0x269
> bufobj_wwait(ce138830,0,0,0,ce1387ec,...) at bufobj_wwait+0x37
> nfs_flush(ce138770,1,c93c7b60,0,c93c7b60,...) at nfs_flush+0x8c8
> nfs_close(eed95b80) at nfs_close+0xfd
> VOP_CLOSE_APV(c09ec5c0,eed95b80) at VOP_CLOSE_APV+0x38
> vn_close(ce138770,2,cd769100,c93c7b60) at vn_close+0x5a
> vn_closefile(c9094900,c93c7b60) at vn_closefile+0xea
> fdrop_locked(c9094900,c93c7b60,cf054600,eed95ca8,c06875f3,...) at
> fdrop_locked+0xd0
> fdrop(c9094900,c93c7b60,c93c7b60,eed95c64,1,...) at fdrop+0x41
> closef(c9094900,c93c7b60,0,eed95d38,c949ea78,...) at closef+0x42f
> kern_close(c93c7b60,3,eed95d30,c08e1d4b,c93c7b60,...) at kern_close+0x20d
> close(c93c7b60,eed95d04) at close+0x10
> syscall(3b,808003b,bfbf003b,0,28190a20,...) at syscall+0x2bf
> Xint0x80_syscall() at Xint0x80_syscall+0x1f
> --- syscall (6, FreeBSD ELF32, close), eip = 0x2816c1e7, esp =
> 0xbfbfeb1c, ebp = 0xbfbfeb38 ---
> db> show lockedvnods
> Locked vnodes
>
> 0xce138770: tag nfs, type VREG
>    usecount 1, writecount 0, refcount 3 mountedhere 0
>    flags ()
>    v_object 0xcd0a2528 ref 0 pages 1
>     lock type nfs: EXCL (count 1) by thread 0xc93c7b60 (pid 37581)
>        fileid 1372174 fsid 0x100ff05
> db> show lockedbufs
> buf at 0xdbf92d08
> b_flags = 0x20000024<vmio,cache,async>
> b_error = 0, b_bufsize = 2048, b_bcount = 1779, b_resid = 0
> b_bufobj = (0xce138830), b_data = 0xe2e99000, b_blkno = 0
> b_npages = 1, pages(OBJ, IDX, PA): (0xcd0a2528, 0x0, 0xa8067000)
>
> db> show proc 37581
> Process 37581 (awk) at 0xc949ea78:
>  state: NORMAL
>  uid: 0  gids: 0, 0, 2, 3, 4, 5, 20, 31
>  parent: pid 37557 at 0xc949e860
>  ABI: FreeBSD ELF32
>  arguments: awk
>  threads: 1
> 100364                   D       bo_wwait 0xce138854 awk
>
> Next.
>
> # umount /usr/src
> load: 0.36  cmd: umount 37888 [nfs] 0.00u 0.04s 0% 900k
>
> db> bt 37888
> Tracing pid 37888 tid 100130 td 0xc93c84e0
> sched_switch(c93c84e0,0,1) at sched_switch+0x143
> mi_switch(1,0,c93c84e0,eeda4aa0,c06ce6f0,...) at mi_switch+0x1ba
> sleepq_switch(ce1387c8) at sleepq_switch+0x87
> sleepq_wait(ce1387c8,0,c93c84e0,ce1387c8,4,...) at sleepq_wait+0x5c
> msleep(ce1387c8,c0a4af54,50,c09729b5,0,...) at msleep+0x269
> acquire(eeda4b20,40,60000,c93c84e0,0,...) at acquire+0x7b
> lockmgr(ce1387c8,2002,ce1387ec,c93c84e0,eeda4b44,...) at lockmgr+0x3fe
> vop_stdlock(eeda4b68) at vop_stdlock+0x1e
> VOP_LOCK_APV(c09ec5c0,eeda4b68) at VOP_LOCK_APV+0x43
> vn_lock(ce138770,2002,c93c84e0) at vn_lock+0xf4
> vflush(cf4f8cf8,1,0,c93c84e0) at vflush+0x136
> nfs_unmount(cf4f8cf8,8000000,c93c84e0) at nfs_unmount+0x3c
> dounmount(cf4f8cf8,8000000,c93c84e0) at dounmount+0x3fa
> unmount(c93c84e0,eeda4d04) at unmount+0x279
> syscall(3b,3b,3b,804a4aa,804de10,...) at syscall+0x2bf
> Xint0x80_syscall() at Xint0x80_syscall+0x1f
> --- syscall (22, FreeBSD ELF32, unmount), eip = 0x280be967, esp =
> 0xbfbfe56c, ebp = 0xbfbfe618 ---
> db> show lockedvnods
> Locked vnodes
>
> 0xca176aa0: tag ufs, type VDIR
>    usecount 1, writecount 0, refcount 1 mountedhere 0xcf4f8cf8
>    flags ()
>    v_object 0xcb111294 ref 0 pages 0
>     lock type ufs: EXCL (count 1) by thread 0xc93c84e0 (pid 37888)
>        ino 1436672, on dev aacd0s1f
>
> 0xce138770: tag nfs, type VREG
>    usecount 1, writecount 0, refcount 4 mountedhere 0
>    flags ()
>    v_object 0xcd0a2528 ref 0 pages 1
>     lock type nfs: EXCL (count 1) by thread 0xc93c7b60 (pid 37581)
> with 1 pending
>        fileid 1372174 fsid 0x100ff05
> db> show lockedbufs
> buf at 0xdbf92d08
> b_flags = 0x20000024<vmio,cache,async>
> b_error = 0, b_bufsize = 2048, b_bcount = 1779, b_resid = 0
> b_bufobj = (0xce138830), b_data = 0xe2e99000, b_blkno = 0
> b_npages = 1, pages(OBJ, IDX, PA): (0xcd0a2528, 0x0, 0xa8067000)
> db> show proc 37888
> Process 37888 (umount) at 0xc949e000:
>  state: NORMAL
>  uid: 0  gids: 0, 0, 2, 3, 4, 5, 20, 31
>  parent: pid 37812 at 0xc936ea78
>  ABI: FreeBSD ELF32
>  arguments: umount
>  threads: 1
> 100130                   D       nfs      0xce1387c8 umount
>
>
> --
> wbr,
> pluknet
>

-- 
wbr,
pluknet