cddl/contrib/dtracetoolkit/Examples/pl_flowinfo_example.txt

   1 The following are examples of pl_flowinfo.d.
   2
   3 This is a simple script to trace the flow of Perl subroutines (functions).
   4 Here it traces the example program, Code/Perl/func_abc.pl.
   5
   6    # pl_flowinfo.d
   7    C    PID  DELTA(us)              FILE:LINE TYPE     -- SUB
   8    0 305127          2       func_abc.pl:15   sub      -> func_a
   9    0 305127    1008776       func_abc.pl:9    sub        -> func_b
  10    0 305127    1010019       func_abc.pl:4    sub          -> func_c
  11    0 305127    1009979       func_abc.pl:4    sub          <- func_c
  12    0 305127         26       func_abc.pl:9    sub        <- func_b
  13    0 305127          9       func_abc.pl:15   sub      <- func_a
  14    ^C
  15
  16 As each subroutine is entered, the third column is indented by 2 spaces. This
  17 shows which subroutine is calling who - the output abovebegins by showing that
  18 func_a() began, and then called func_b().
  19
  20 The DELTA(us) column shows time from that line to the previous line, and
  21 so can be a bit tricky to read. For example, the second line of data output
  22 (skipping the header) reads as "the time from func_a() beginning to
  23 func_b() beginning was 1008776 us, or 1.01 seconds".
  24
  25 The LINE column shows the line in the file what was being executed. Refer
  26 to the source program to see what this line refers to.
  27
  28 If the output looks shuffled, check the CPU "C" column - if it changes,
  29 then the output is probably shuffled. See Notes/ALLsnoop_notes.txt for
  30 details and suggested workarounds.
  31
  32 See Notes/ALLflow_notes.txt for important notes about reading flow outputs.
  33
  34
  35
  36 The following traces a Perl network interface statistics tool, "nicstat"
  37 version 0.99,
  38
  39 # pl_flowinfo.d
  40 C    PID  DELTA(us)              FILE:LINE TYPE     -- SUB
  41 0 305132          2           nicstat:83   sub      -> BEGIN
  42 0 305132        444         strict.pm:12   sub        -> bits
  43 0 305132         34         strict.pm:12   sub        <- bits
  44 0 305132         32         strict.pm:28   sub        -> import
  45 0 305132         22         strict.pm:28   sub        <- import
  46 0 305132          8           nicstat:83   sub      <- BEGIN
  47 0 305132         26           nicstat:84   sub      -> BEGIN
  48 0 305132       2339       Exporter.pm:30   sub        -> import
  49 0 305132         83       Exporter.pm:30   sub        <- import
  50 0 305132         14           nicstat:84   sub      <- BEGIN
  51 0 305132         27           nicstat:85   sub      -> BEGIN
  52 0 305132        205          Kstat.pm:34   sub        -> BEGIN
  53 0 305132         11         strict.pm:28   sub          -> import
  54 0 305132         11         strict.pm:28   sub          <- import
  55 0 305132          8          Kstat.pm:34   sub        <- BEGIN
  56 0 305132         23          Kstat.pm:35   sub        -> BEGIN
  57 0 305132        187     DynaLoader.pm:18   sub          -> BEGIN
  58 0 305132         73           vars.pm:3    sub            -> BEGIN
  59 0 305132          9           vars.pm:3    sub            <- BEGIN
  60 0 305132         34           vars.pm:7    sub            -> BEGIN
  61 0 305132        470       warnings.pm:134  sub              -> BEGIN
  62 0 305132        598       warnings.pm:134  sub              <- BEGIN
  63 0 305132       2151       register.pm:37   sub              -> import
  64 0 305132         23       register.pm:28   sub                -> mkMask
  65 0 305132         13       register.pm:28   sub                <- mkMask
  66 0 305132         53       register.pm:28   sub                -> mkMask
  67 0 305132         11       register.pm:28   sub                <- mkMask
  68 0 305132         11       register.pm:37   sub              <- import
  69 0 305132          8           vars.pm:7    sub            <- BEGIN
  70 0 305132         28           vars.pm:8    sub            -> BEGIN
  71 0 305132          9         strict.pm:28   sub              -> import
  72 0 305132          8         strict.pm:12   sub                -> bits
  73 0 305132         13         strict.pm:12   sub                <- bits
  74 0 305132          9         strict.pm:28   sub              <- import
  75 0 305132          8           vars.pm:8    sub            <- BEGIN
  76 0 305132        294           vars.pm:11   sub            -> import
  77 0 305132         52           vars.pm:11   sub            <- import
  78 0 305132          8     DynaLoader.pm:18   sub          <- BEGIN
  79 0 305132         48     DynaLoader.pm:25   sub          -> BEGIN
  80 0 305132         97         Config.pm:5    sub            -> BEGIN
  81 0 305132          9         strict.pm:28   sub              -> import
  82 0 305132          9         strict.pm:28   sub              <- import
  83 0 305132          8         Config.pm:5    sub            <- BEGIN
  84 0 305132        134         Config.pm:31   sub            -> BEGIN
  85 0 305132          9         strict.pm:33   sub              -> unimport
  86 0 305132          8         strict.pm:12   sub                -> bits
  87 0 305132         11         strict.pm:12   sub                <- bits
  88 0 305132         16         strict.pm:33   sub              <- unimport
  89 0 305132          8         Config.pm:31   sub            <- BEGIN
  90 0 305132        343         Config.pm:60   sub            -> TIEHASH
  91 0 305132         10         Config.pm:60   sub            <- TIEHASH
  92 0 305132         44         Config.pm:25   sub            -> import
  93 0 305132         18         Config.pm:25   sub            <- import
  94 0 305132          9     DynaLoader.pm:25   sub          <- BEGIN
  95 0 305132       1301     AutoLoader.pm:3    sub          -> BEGIN
  96 0 305132         11         strict.pm:28   sub            -> import
  97 0 305132         10         strict.pm:28   sub            <- import
  98 0 305132          9     AutoLoader.pm:3    sub          <- BEGIN
  99 0 305132         22     AutoLoader.pm:4    sub          -> BEGIN
 100 0 305132          9     AutoLoader.pm:4    sub          <- BEGIN
 101 0 305132         89     AutoLoader.pm:14   sub          -> BEGIN
 102 0 305132         13     AutoLoader.pm:14   sub          <- BEGIN
 103 0 305132        375     AutoLoader.pm:95   sub          -> BEGIN
 104 0 305132          9         strict.pm:33   sub            -> unimport
 105 0 305132          8         strict.pm:12   sub              -> bits
 106 0 305132         11         strict.pm:12   sub              <- bits
 107 0 305132          9         strict.pm:33   sub            <- unimport
 108 0 305132          8     AutoLoader.pm:95   sub          <- BEGIN
 109 0 305132        203     AutoLoader.pm:128  sub          -> BEGIN
 110 0 305132          9         strict.pm:33   sub            -> unimport
 111 0 305132          8         strict.pm:12   sub              -> bits
 112 0 305132         11         strict.pm:12   sub              <- bits
 113 0 305132          9         strict.pm:33   sub            <- unimport
 114 0 305132          8     AutoLoader.pm:128  sub          <- BEGIN
 115 0 305132        220     AutoLoader.pm:173  sub          -> BEGIN
 116 0 305132          9         strict.pm:33   sub            -> unimport
 117 0 305132          8         strict.pm:12   sub              -> bits
 118 0 305132         10         strict.pm:12   sub              <- bits
 119 0 305132          9         strict.pm:33   sub            <- unimport
 120 0 305132          8     AutoLoader.pm:173  sub          <- BEGIN
 121 0 305132        103         Config.pm:52   sub          -> FETCH
 122 0 305132         12         Config.pm:52   sub          <- FETCH
 123 0 305132         16         Config.pm:52   sub          -> FETCH
 124 0 305132          9         Config.pm:52   sub          <- FETCH
 125 0 305132         11         Config.pm:52   sub          -> FETCH
 126 0 305132          9         Config.pm:52   sub          <- FETCH
 127 0 305132         11         Config.pm:52   sub          -> FETCH
 128 0 305132          9         Config.pm:52   sub          <- FETCH
 129 0 305132         95          Kstat.pm:35   sub        <- BEGIN
 130 0 305132         29          Kstat.pm:36   sub        -> BEGIN
 131 0 305132         10           vars.pm:11   sub          -> import
 132 0 305132         33           vars.pm:11   sub          <- import
 133 0 305132          8          Kstat.pm:36   sub        <- BEGIN
 134 0 305132         56     DynaLoader.pm:133  sub        -> bootstrap
 135 0 305132        314     DynaLoader.pm:48   sub          -> dl_load_flags
 136 0 305132         11     DynaLoader.pm:48   sub          <- dl_load_flags
 137 0 305132       1113     DynaLoader.pm:133  sub        <- bootstrap
 138 0 305132         41           nicstat:85   sub      <- BEGIN
 139 0 305132       6102            Std.pm:219  sub      -> getopts
 140 0 305132         52       Exporter.pm:30   sub        -> import
 141 0 305132         40       Exporter.pm:30   sub        <- import
 142 0 305132         22            Std.pm:219  sub      <- getopts
 143 0 305132         24           nicstat:264  sub      -> find_nets
 144 0 305132      79662           nicstat:264  sub      <- find_nets
 145 0 305132        420           nicstat:304  sub      -> fetch_net_data
 146 0 305132      43871           nicstat:304  sub      <- fetch_net_data
 147 0 305132        479           nicstat:372  sub      -> print_neat
 148 0 305132        150           nicstat:372  sub      <- print_neat
 149 0 305132         10           nicstat:372  sub      -> print_neat
 150 0 305132        220           nicstat:372  sub      <- print_neat
 151 0 305132         10           nicstat:372  sub      -> print_neat
 152 0 305132        126           nicstat:372  sub      <- print_neat
 153 0 305132         10           nicstat:372  sub      -> print_neat
 154 0 305132        125           nicstat:372  sub      <- print_neat
 155 0 305132         10           nicstat:372  sub      -> print_neat
 156 0 305132        157           nicstat:372  sub      <- print_neat
 157 0 305132         10           nicstat:372  sub      -> print_neat
 158 0 305132        171           nicstat:372  sub      <- print_neat
 159 0 305132        343           nicstat:372  sub      -> print_neat
 160 0 305132        128           nicstat:372  sub      <- print_neat
 161 0 305132         10           nicstat:372  sub      -> print_neat
 162 0 305132        157           nicstat:372  sub      <- print_neat
 163 0 305132          9           nicstat:372  sub      -> print_neat
 164 0 305132        125           nicstat:372  sub      <- print_neat
 165 0 305132          9           nicstat:372  sub      -> print_neat
 166 0 305132        123           nicstat:372  sub      <- print_neat
 167 0 305132          9           nicstat:372  sub      -> print_neat
 168 0 305132        160           nicstat:372  sub      <- print_neat
 169 0 305132         10           nicstat:372  sub      -> print_neat
 170 0 305132        124           nicstat:372  sub      <- print_neat
 171 0 305132        342           nicstat:372  sub      -> print_neat
 172 0 305132        126           nicstat:372  sub      <- print_neat
 173 0 305132         10           nicstat:372  sub      -> print_neat
 174 0 305132        123           nicstat:372  sub      <- print_neat
 175 0 305132         10           nicstat:372  sub      -> print_neat
 176 0 305132        156           nicstat:372  sub      <- print_neat
 177 0 305132         10           nicstat:372  sub      -> print_neat
 178 0 305132        153           nicstat:372  sub      <- print_neat
 179 0 305132         10           nicstat:372  sub      -> print_neat
 180 0 305132        123           nicstat:372  sub      <- print_neat
 181 0 305132          9           nicstat:372  sub      -> print_neat
 182 0 305132        123           nicstat:372  sub      <- print_neat
 183 0 305132       3736         Config.pm:63   sub      -> DESTROY
 184 0 305132         32         Config.pm:63   sub      <- DESTROY
 185
 186 After initialising Perl libraries and modules, the "nicstat" program ran,
 187 the output matching what was expected from the source.
 188