cddl/contrib/dtracetoolkit/Examples/vopstat_example.txt

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