cddl/contrib/dtracetoolkit/Examples/pl_flow_example.txt

   1 The following are examples of pl_flow.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_flow.d
   7      C TIME(us)          FILE             -- SUB
   8      0 2979519183757     func_abc.pl      -> func_a
   9      0 2979520190159     func_abc.pl        -> func_b
  10      0 2979521200166     func_abc.pl          -> func_c
  11      0 2979522210184     func_abc.pl          <- func_c
  12      0 2979522210199     func_abc.pl        <- func_b
  13      0 2979522210207     func_abc.pl      <- 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 If the output looks shuffled, check the CPU "C" and "TIME" columns, and
  21 post sort based on TIME if necessary.
  22
  23 See Notes/ALLflow_notes.txt for important notes about reading flow outputs.
  24
  25
  26
  27 The following traces a Perl network interface statistics tool, "nicstat"
  28 version 0.99,
  29
  30 # pl_flow.d
  31   C TIME(us)         FILE             -- SUB
  32   0 4181899422549    nicstat          -> BEGIN
  33   0 4181899423048    strict.pm          -> bits
  34   0 4181899423081    strict.pm          <- bits
  35   0 4181899423105    strict.pm          -> import
  36   0 4181899423126    strict.pm          <- import
  37   0 4181899423133    nicstat          <- BEGIN
  38   0 4181899423157    nicstat          -> BEGIN
  39   0 4181899445634    Exporter.pm        -> import
  40   0 4181899445730    Exporter.pm        <- import
  41   0 4181899445743    nicstat          <- BEGIN
  42   0 4181899445770    nicstat          -> BEGIN
  43   0 4181899446066    Kstat.pm           -> BEGIN
  44   0 4181899446076    strict.pm            -> import
  45   0 4181899446087    strict.pm            <- import
  46   0 4181899446094    Kstat.pm           <- BEGIN
  47   0 4181899446116    Kstat.pm           -> BEGIN
  48   0 4181899453669    DynaLoader.pm        -> BEGIN
  49   0 4181899453810    vars.pm                -> BEGIN
  50   0 4181899453821    vars.pm                <- BEGIN
  51   0 4181899453921    vars.pm                -> BEGIN
  52   0 4181899454494    warnings.pm              -> BEGIN
  53   0 4181899455149    warnings.pm              <- BEGIN
  54   0 4181899457183    register.pm              -> import
  55   0 4181899457202    register.pm                -> mkMask
  56   0 4181899457214    register.pm                <- mkMask
  57   0 4181899457264    register.pm                -> mkMask
  58   0 4181899457274    register.pm                <- mkMask
  59   0 4181899457283    register.pm              <- import
  60   0 4181899457290    vars.pm                <- BEGIN
  61   0 4181899457316    vars.pm                -> BEGIN
  62   0 4181899457324    strict.pm                -> import
  63   0 4181899457332    strict.pm                  -> bits
  64   0 4181899457345    strict.pm                  <- bits
  65   0 4181899457353    strict.pm                <- import
  66   0 4181899457359    vars.pm                <- BEGIN
  67   0 4181899457652    vars.pm                -> import
  68   0 4181899457703    vars.pm                <- import
  69   0 4181899457710    DynaLoader.pm        <- BEGIN
  70   0 4181899457758    DynaLoader.pm        -> BEGIN
  71   0 4181899457883    Config.pm              -> BEGIN
  72   0 4181899457890    strict.pm                -> import
  73   0 4181899457899    strict.pm                <- import
  74   0 4181899457906    Config.pm              <- BEGIN
  75   0 4181899458038    Config.pm              -> BEGIN
  76   0 4181899458045    strict.pm                -> unimport
  77   0 4181899458053    strict.pm                  -> bits
  78   0 4181899458063    strict.pm                  <- bits
  79   0 4181899458077    strict.pm                <- unimport
  80   0 4181899458084    Config.pm              <- BEGIN
  81   0 4181899458426    Config.pm              -> TIEHASH
  82   0 4181899458435    Config.pm              <- TIEHASH
  83   0 4181899458476    Config.pm              -> import
  84   0 4181899458493    Config.pm              <- import
  85   0 4181899458500    DynaLoader.pm        <- BEGIN
  86   0 4181899459978    AutoLoader.pm        -> BEGIN
  87   0 4181899459990    strict.pm              -> import
  88   0 4181899460033    strict.pm              <- import
  89   0 4181899460064    AutoLoader.pm        <- BEGIN
  90   0 4181899460088    AutoLoader.pm        -> BEGIN
  91   0 4181899460096    AutoLoader.pm        <- BEGIN
  92   0 4181899460187    AutoLoader.pm        -> BEGIN
  93   0 4181899460199    AutoLoader.pm        <- BEGIN
  94   0 4181899460582    AutoLoader.pm        -> BEGIN
  95   0 4181899460590    strict.pm              -> unimport
  96   0 4181899460598    strict.pm                -> bits
  97   0 4181899460611    strict.pm                <- bits
  98   0 4181899460619    strict.pm              <- unimport
  99   0 4181899460625    AutoLoader.pm        <- BEGIN
 100   0 4181899460830    AutoLoader.pm        -> BEGIN
 101   0 4181899460838    strict.pm              -> unimport
 102   0 4181899460845    strict.pm                -> bits
 103   0 4181899460855    strict.pm                <- bits
 104   0 4181899460862    strict.pm              <- unimport
 105   0 4181899460869    AutoLoader.pm        <- BEGIN
 106   0 4181899461092    AutoLoader.pm        -> BEGIN
 107   0 4181899461100    strict.pm              -> unimport
 108   0 4181899461107    strict.pm                -> bits
 109   0 4181899461116    strict.pm                <- bits
 110   0 4181899461124    strict.pm              <- unimport
 111   0 4181899461130    AutoLoader.pm        <- BEGIN
 112   0 4181899461238    Config.pm            -> FETCH
 113   0 4181899461250    Config.pm            <- FETCH
 114   0 4181899461264    Config.pm            -> FETCH
 115   0 4181899461272    Config.pm            <- FETCH
 116   0 4181899461282    Config.pm            -> FETCH
 117   0 4181899461290    Config.pm            <- FETCH
 118   0 4181899461299    Config.pm            -> FETCH
 119   0 4181899461307    Config.pm            <- FETCH
 120   0 4181899461403    Kstat.pm           <- BEGIN
 121   0 4181899461432    Kstat.pm           -> BEGIN
 122   0 4181899461440    vars.pm              -> import
 123   0 4181899461476    vars.pm              <- import
 124   0 4181899461483    Kstat.pm           <- BEGIN
 125   0 4181899461539    DynaLoader.pm      -> bootstrap
 126   0 4181899461769    DynaLoader.pm        -> dl_load_flags
 127   0 4181899461777    DynaLoader.pm        <- dl_load_flags
 128   0 4181899462208    DynaLoader.pm      <- bootstrap
 129   0 4181899462231    nicstat          <- BEGIN
 130   0 4181899468306    Std.pm           -> getopts
 131   0 4181899468351    Exporter.pm        -> import
 132   0 4181899468390    Exporter.pm        <- import
 133   0 4181899468405    Std.pm           <- getopts
 134   0 4181899468426    nicstat          -> find_nets
 135   0 4181899521011    nicstat          <- find_nets
 136   0 4181899521415    nicstat          -> fetch_net_data
 137   0 4181899564973    nicstat          <- fetch_net_data
 138   0 4181899565526    nicstat          -> print_neat
 139   0 4181899565672    nicstat          <- print_neat
 140   0 4181899565680    nicstat          -> print_neat
 141   0 4181899565902    nicstat          <- print_neat
 142   0 4181899565909    nicstat          -> print_neat
 143   0 4181899566033    nicstat          <- print_neat
 144   0 4181899566039    nicstat          -> print_neat
 145   0 4181899566165    nicstat          <- print_neat
 146   0 4181899566172    nicstat          -> print_neat
 147   0 4181899566331    nicstat          <- print_neat
 148   0 4181899566338    nicstat          -> print_neat
 149   0 4181899566494    nicstat          <- print_neat
 150   0 4181899566791    nicstat          -> print_neat
 151   0 4181899566953    nicstat          <- print_neat
 152   0 4181899566961    nicstat          -> print_neat
 153   0 4181899567085    nicstat          <- print_neat
 154   0 4181899567091    nicstat          -> print_neat
 155   0 4181899567247    nicstat          <- print_neat
 156   0 4181899567254    nicstat          -> print_neat
 157   0 4181899567377    nicstat          <- print_neat
 158   0 4181899567383    nicstat          -> print_neat
 159   0 4181899567538    nicstat          <- print_neat
 160   0 4181899567544    nicstat          -> print_neat
 161   0 4181899567666    nicstat          <- print_neat
 162   0 4181899567977    nicstat          -> print_neat
 163   0 4181899568232    nicstat          <- print_neat
 164   0 4181899568240    nicstat          -> print_neat
 165   0 4181899568397    nicstat          <- print_neat
 166   0 4181899568404    nicstat          -> print_neat
 167   0 4181899568528    nicstat          <- print_neat
 168   0 4181899568535    nicstat          -> print_neat
 169   0 4181899568656    nicstat          <- print_neat
 170   0 4181899568663    nicstat          -> print_neat
 171   0 4181899568819    nicstat          <- print_neat
 172   0 4181899568826    nicstat          -> print_neat
 173   0 4181899568947    nicstat          <- print_neat
 174   0 4181899572708    Config.pm        -> DESTROY
 175   0 4181899572735    Config.pm        <- DESTROY
 176
 177 After initialising Perl libraries and modules, the "nicstat" program ran,
 178 the output matching what was expected from the source.
 179