svn commit: r190380 - in head/sys: cddl/dev/dtnfsclient nfsclient sys

[Robert Watson]

On Tue, 24 Mar 2009, Robert Watson wrote:

>  Add DTrace probes to the NFS access and attribute caches.  Access cache
>  events are:
>
>    nfsclient:accesscache:flush:done
>    nfsclient:accesscache:get:hit
>    nfsclient:accesscache:get:miss
>    nfsclient:accesscache:load:done
>
>  They pass the vnode, uid, and requested or loaded access mode (if any);
>  the load event may also report a load error if the RPC fails.
>
>  The attribute cache events are:
>
>    nfsclient:attrcache:flush:done
>    nfsclient:attrcache:get:hit
>    nfsclient:attrcache:get:miss
>    nfsclient:attrcache:load:done
>
>  They pass the vnode, optionally the vattr if one is present (hit or load),
>  and in the case of a load event, also a possible RPC error.

This will probably want to be changed in a few ways before we consider it 
done, but I've found it quite useful already in understanding our NFS client 
and how the various caches interact.  Typical trace output might look like 
this, combining the previously committed NFSv3 RPC tracing with cache tracing:

bin  syscall       module      probe         vnode *
---- ------------- ----------- ------------- ----------
ls   lstat         attrcache   get:hit       3282019108
ls   stat          attrcache   get:hit       3282019108
ls   open          accesscache get:hit       3282019108
ls   open          attrcache   flush:done    3282019108
ls   open          attrcache   get:miss      3282019108
ls   open          nfs3        getattr:start 3282019108
ls   open          nfs3        getattr:done  3282019108
ls   fstat         attrcache   get:hit       3282019108
ls   fstatfs       nfs3        fsstat:start  3282019108
ls   fstatfs       nfs3        fsstat:done   3282019108
ls   fstat         attrcache   get:hit       3282019108
ls   fchdir        accesscache get:hit       3282019108
ls   getdirentries attrcache   get:hit       3282019108
ls   lstat         accesscache get:hit       3282019108
ls   lstat         attrcache   get:hit       3281944576
ls   lstat         attrcache   get:hit       3281944576
ls   getdirentries attrcache   get:hit       3282019108
ls   pathconf      accesscache get:hit       3282019108
ls   pathconf      attrcache   get:hit       3281944576

If you're using this on a multi-CPU box, make sure your probes trace 
timestamps and that you sort by them, if you require ordering, since NFS tends 
to bounce around a bit, especially for loopback NFS testing. :-)

Robert N M Watson
Computer Laboratory
University of Cambridge