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. |