vopstat_example.txt   [plain text]

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.