1*e137d3e0SchristosThe following are demonstrations of the vopstat script. 2*e137d3e0Schristos 3*e137d3e0Schristos 4*e137d3e0SchristosBy default, vopstat traces activity at the vnode interface and prints 5*e137d3e0Schristossummaries every five seconds. It will either trace all filesystems or 6*e137d3e0Schristosjust the mountpoint specified. 7*e137d3e0Schristos 8*e137d3e0SchristosHere it was run on /extra1, while a tar command archived /extra1, 9*e137d3e0Schristos 10*e137d3e0Schristos # ./vopstat /extra1 11*e137d3e0Schristos VOP Physical IO Count 12*e137d3e0Schristos fop_getpage 66 13*e137d3e0Schristos 14*e137d3e0Schristos VOP Count Count 15*e137d3e0Schristos fop_readdir 1 16*e137d3e0Schristos fop_read 2 17*e137d3e0Schristos fop_cmp 2 18*e137d3e0Schristos fop_seek 3 19*e137d3e0Schristos fop_close 7 20*e137d3e0Schristos fop_open 10 21*e137d3e0Schristos fop_getattr 12 22*e137d3e0Schristos fop_access 13 23*e137d3e0Schristos fop_lookup 16 24*e137d3e0Schristos fop_rwunlock 3802 25*e137d3e0Schristos fop_rwlock 3802 26*e137d3e0Schristos fop_putpage 4701 27*e137d3e0Schristos fop_getpage 6648 28*e137d3e0Schristos fop_dispose 19109 29*e137d3e0Schristos 30*e137d3e0Schristos VOP Wall Time mSeconds 31*e137d3e0Schristos fop_readdir 0 32*e137d3e0Schristos fop_cmp 0 33*e137d3e0Schristos fop_read 0 34*e137d3e0Schristos fop_seek 0 35*e137d3e0Schristos fop_close 0 36*e137d3e0Schristos fop_open 0 37*e137d3e0Schristos fop_access 0 38*e137d3e0Schristos fop_getattr 0 39*e137d3e0Schristos fop_lookup 0 40*e137d3e0Schristos fop_rwunlock 64 41*e137d3e0Schristos fop_putpage 86 42*e137d3e0Schristos fop_rwlock 93 43*e137d3e0Schristos fop_dispose 346 44*e137d3e0Schristos fop_getpage 402 45*e137d3e0Schristos ^C 46*e137d3e0Schristos 47*e137d3e0SchristosThere were 66 calls for physical I/O operations, fop_getpage, as files 48*e137d3e0Schristoswere read from disk. The VOP Count show that there were many calls to 49*e137d3e0Schristosfop_putpage and fop_getpage, as tar works its way through files; and 50*e137d3e0Schristosmany more to fop_dispose. The total elaspsed time for these calls 51*e137d3e0Schristosare listed at the bottom, in milleseconds. 52*e137d3e0Schristos 53*e137d3e0SchristosThis rate of events will put some pressure on the DTrace buffer, 54*e137d3e0Schristosyou may see dynamic variable drops. 55*e137d3e0Schristos 56*e137d3e0Schristos 57*e137d3e0Schristos 58*e137d3e0Schristosvopstat also has a -t option to trace activity. Here it is run on /extra1 59*e137d3e0Schristoswhile an "ls" command listed files from that directory, 60*e137d3e0Schristos 61*e137d3e0Schristos# ./vopstat -t /extra1 62*e137d3e0Schristos Event Device Path RW Size Offset 63*e137d3e0Schristos-> fop_getattr - /extra1 - 0 0 64*e137d3e0Schristos<- fop_getattr - /extra1 - 0 0 65*e137d3e0Schristos-> fop_access - /extra1 - 0 0 66*e137d3e0Schristos<- fop_access - /extra1 - 0 0 67*e137d3e0Schristos-> fop_open - /extra1 - 0 0 68*e137d3e0Schristos<- fop_open - /extra1 - 0 0 69*e137d3e0Schristos-> fop_getattr - /extra1 - 0 0 70*e137d3e0Schristos<- fop_getattr - /extra1 - 0 0 71*e137d3e0Schristos-> fop_rwlock - /extra1 - 0 0 72*e137d3e0Schristos<- fop_rwlock - /extra1 - 0 0 73*e137d3e0Schristos-> fop_readdir - /extra1 - 0 0 74*e137d3e0Schristos-> fop_getpage - /extra1 - 0 0 75*e137d3e0Schristos<- fop_getpage - /extra1 - 0 0 76*e137d3e0Schristos-> fop_rwunlock - /extra1 - 0 0 77*e137d3e0Schristos<- fop_rwunlock - /extra1 - 0 0 78*e137d3e0Schristos-> fop_rwlock - /extra1 - 0 0 79*e137d3e0Schristos<- fop_rwlock - /extra1 - 0 0 80*e137d3e0Schristos-> fop_readdir - /extra1 - 0 0 81*e137d3e0Schristos<- fop_readdir - /extra1 - 0 0 82*e137d3e0Schristos-> fop_rwunlock - /extra1 - 0 0 83*e137d3e0Schristos<- fop_rwunlock - /extra1 - 0 0 84*e137d3e0Schristos-> fop_close - /extra1 - 0 512 85*e137d3e0Schristos<- fop_close - /extra1 - 0 512 86*e137d3e0Schristos^C 87*e137d3e0Schristos 88*e137d3e0SchristosEach call can be seen as it happened, including the entry and return of 89*e137d3e0Schristosthese calls. 90