The following are demonstrations of the vopstat script.
By default, vopstat traces activity at the vnode interface and prints
summaries every five seconds. It will either trace all filesystems or
just the mountpoint specified.
Here it was run on /extra1, while a tar command archived /extra1,
# ./vopstat /extra1
VOP Physical IO Count
fop_getpage 66
VOP Count Count
fop_readdir 1
fop_read 2
fop_cmp 2
fop_seek 3
fop_close 7
fop_open 10
fop_getattr 12
fop_access 13
fop_lookup 16
fop_rwunlock 3802
fop_rwlock 3802
fop_putpage 4701
fop_getpage 6648
fop_dispose 19109
VOP Wall Time mSeconds
fop_readdir 0
fop_cmp 0
fop_read 0
fop_seek 0
fop_close 0
fop_open 0
fop_access 0
fop_getattr 0
fop_lookup 0
fop_rwunlock 64
fop_putpage 86
fop_rwlock 93
fop_dispose 346
fop_getpage 402
^C
There were 66 calls for physical I/O operations, fop_getpage, as files
were read from disk. The VOP Count show that there were many calls to
fop_putpage and fop_getpage, as tar works its way through files; and
many more to fop_dispose. The total elaspsed time for these calls
are listed at the bottom, in milleseconds.
This rate of events will put some pressure on the DTrace buffer,
you may see dynamic variable drops.
vopstat also has a -t option to trace activity. Here it is run on /extra1
while an "ls" command listed files from that directory,
# ./vopstat -t /extra1
Event Device Path RW Size Offset
-> fop_getattr - /extra1 - 0 0
<- fop_getattr - /extra1 - 0 0
-> fop_access - /extra1 - 0 0
<- fop_access - /extra1 - 0 0
-> fop_open - /extra1 - 0 0
<- fop_open - /extra1 - 0 0
-> fop_getattr - /extra1 - 0 0
<- fop_getattr - /extra1 - 0 0
-> fop_rwlock - /extra1 - 0 0
<- fop_rwlock - /extra1 - 0 0
-> fop_readdir - /extra1 - 0 0
-> fop_getpage - /extra1 - 0 0
<- fop_getpage - /extra1 - 0 0
-> fop_rwunlock - /extra1 - 0 0
<- fop_rwunlock - /extra1 - 0 0
-> fop_rwlock - /extra1 - 0 0
<- fop_rwlock - /extra1 - 0 0
-> fop_readdir - /extra1 - 0 0
<- fop_readdir - /extra1 - 0 0
-> fop_rwunlock - /extra1 - 0 0
<- fop_rwunlock - /extra1 - 0 0
-> fop_close - /extra1 - 0 512
<- fop_close - /extra1 - 0 512
^C
Each call can be seen as it happened, including the entry and return of
these calls.