I looked into this one a bit more, and here's where we're sleeping:

db> t
getblk(bf29660, 3c1f60, 2000, 0, 0, badcafe) at getblk+0xb0
bread(3ff03030, 3c1f60, 2000, ffffffffffffffff, 40055528, 19) at bread+0x30
ffs_update(40055600, 160, 111bd14, 2823000, 11e6800, 1) at ffs_update+0x1f8
VOP_UPDATE(4075d2a0, 0, 0, 0, 11e6958, 11e6850) at VOP_UPDATE+0x34
ufs_inactive(0, e8, 1137528, 2823000, 10291a8, 154) at ufs_inactive+0xdc
VOP_INACTIVE(4075d2a0, 3febdc20, 0, 140f0b8, 140f000, 3febdc20) at VOP_INACTIVE+0x2c
vput(4075d2a0, 1, 28c2380, 3febdc20, badcafe, badcafe) at vput+0x170
vn_close(0, 1, 28c2380, 3febdc20, badcafe, badcafe) at vn_close+0x44
vn_closefile(3feeec80, 3febdc20, 109306c, badcafe, badcafe, badcafe) at vn_closefile+0x10
closef(3feeec80, 3febdc20, 3feeeb90, 7, 3fec08c0, 3feeec80) at closef+0x210
fdrelease(3febdc20, 8, 8, 11e6938, 11e6958, 11e6850) at fdrelease+0xb4
sys_close(3febdc20, 40055dd0, 40055dc0, 1052400, 10291a8, 89d) at sys_close+0x1c
syscall(6, 40055ed0, 152710, 0, 1416800, 154) at syscall+0x8a8
syscall_setup(8, a9b, 89d, 277600, 0, badcafe) at syscall_setup+0x140


we go to update the atime on one inode but the buffer is busy
(presumably because it's being written).  I'd guess that inodes in
different parts of the tree occasionally happen to be in the same buffer,
so we end up having to wait for i/o for no good reason.

one way to avoid this would be to update the atime in the inode buffer
in VOP_FSYNC() (ie. in the syncer's context) rather than in the context
of close().

-Chuck


On Fri, Jun 08, 2001 at 10:45:54AM -0400, Bill Sommerfeld wrote:
> 2) atime updates throttle hot-cache read performance:
> 
> (this is after boosting kern.maxvnodes to 80000, followed by several
> "tar cvf /dev/null /usr/src" runs to get all of /usr/src into UBC
> cache)
> 
> # mount -u -o noatime /usr
> # tar cf /dev/null /usr/src
> tar: Removing leading / from absolute path names in the archive.
> # time tar cf /dev/null /usr/src 
> tar: Removing leading / from absolute path names in the archive.
> tar cf /dev/null /usr/src  0.67s user 9.79s system 99% cpu 10.525 total
> # mount -u -o atime /usr 
> # time tar cf /dev/null /usr/src
> tar: Removing leading / from absolute path names in the archive.
> tar cf /dev/null /usr/src  0.73s user 11.60s system 17% cpu 1:09.91 total
> # mount -u -o noatime /usr        
> # time tar cf /dev/null /usr/src
> tar: Removing leading / from absolute path names in the archive.
> tar cf /dev/null /usr/src  0.73s user 10.31s system 51% cpu 21.363 total
> # time tar cf /dev/null /usr/src
> tar: Removing leading / from absolute path names in the archive.
> tar cf /dev/null /usr/src  0.78s user 9.65s system 99% cpu 10.528 total
> 
> 					- Bill