summaryrefslogtreecommitdiffstats
path: root/cddl/contrib/dtracetoolkit/Examples/pl_flow_example.txt
blob: dcce6e04de031a77a46037d3f5a1195bc3f60998 (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
The following are examples of pl_flow.d.

This is a simple script to trace the flow of Perl subroutines (functions).
Here it traces the example program, Code/Perl/func_abc.pl.

   # pl_flow.d 
     C TIME(us)          FILE             -- SUB
     0 2979519183757     func_abc.pl      -> func_a
     0 2979520190159     func_abc.pl        -> func_b
     0 2979521200166     func_abc.pl          -> func_c
     0 2979522210184     func_abc.pl          <- func_c
     0 2979522210199     func_abc.pl        <- func_b
     0 2979522210207     func_abc.pl      <- func_a
   ^C

As each subroutine is entered, the third column is indented by 2 spaces. This
shows which subroutine is calling who - the output abovebegins by showing that
func_a() began, and then called func_b().

If the output looks shuffled, check the CPU "C" and "TIME" columns, and 
post sort based on TIME if necessary.

See Notes/ALLflow_notes.txt for important notes about reading flow outputs.



The following traces a Perl network interface statistics tool, "nicstat"
version 0.99,

# pl_flow.d
  C TIME(us)         FILE             -- SUB
  0 4181899422549    nicstat          -> BEGIN
  0 4181899423048    strict.pm          -> bits
  0 4181899423081    strict.pm          <- bits
  0 4181899423105    strict.pm          -> import
  0 4181899423126    strict.pm          <- import
  0 4181899423133    nicstat          <- BEGIN
  0 4181899423157    nicstat          -> BEGIN
  0 4181899445634    Exporter.pm        -> import
  0 4181899445730    Exporter.pm        <- import
  0 4181899445743    nicstat          <- BEGIN
  0 4181899445770    nicstat          -> BEGIN
  0 4181899446066    Kstat.pm           -> BEGIN
  0 4181899446076    strict.pm            -> import
  0 4181899446087    strict.pm            <- import
  0 4181899446094    Kstat.pm           <- BEGIN
  0 4181899446116    Kstat.pm           -> BEGIN
  0 4181899453669    DynaLoader.pm        -> BEGIN
  0 4181899453810    vars.pm                -> BEGIN
  0 4181899453821    vars.pm                <- BEGIN
  0 4181899453921    vars.pm                -> BEGIN
  0 4181899454494    warnings.pm              -> BEGIN
  0 4181899455149    warnings.pm              <- BEGIN
  0 4181899457183    register.pm              -> import
  0 4181899457202    register.pm                -> mkMask
  0 4181899457214    register.pm                <- mkMask
  0 4181899457264    register.pm                -> mkMask
  0 4181899457274    register.pm                <- mkMask
  0 4181899457283    register.pm              <- import
  0 4181899457290    vars.pm                <- BEGIN
  0 4181899457316    vars.pm                -> BEGIN
  0 4181899457324    strict.pm                -> import
  0 4181899457332    strict.pm                  -> bits
  0 4181899457345    strict.pm                  <- bits
  0 4181899457353    strict.pm                <- import
  0 4181899457359    vars.pm                <- BEGIN
  0 4181899457652    vars.pm                -> import
  0 4181899457703    vars.pm                <- import
  0 4181899457710    DynaLoader.pm        <- BEGIN
  0 4181899457758    DynaLoader.pm        -> BEGIN
  0 4181899457883    Config.pm              -> BEGIN
  0 4181899457890    strict.pm                -> import
  0 4181899457899    strict.pm                <- import
  0 4181899457906    Config.pm              <- BEGIN
  0 4181899458038    Config.pm              -> BEGIN
  0 4181899458045    strict.pm                -> unimport
  0 4181899458053    strict.pm                  -> bits
  0 4181899458063    strict.pm                  <- bits
  0 4181899458077    strict.pm                <- unimport
  0 4181899458084    Config.pm              <- BEGIN
  0 4181899458426    Config.pm              -> TIEHASH
  0 4181899458435    Config.pm              <- TIEHASH
  0 4181899458476    Config.pm              -> import
  0 4181899458493    Config.pm              <- import
  0 4181899458500    DynaLoader.pm        <- BEGIN
  0 4181899459978    AutoLoader.pm        -> BEGIN
  0 4181899459990    strict.pm              -> import
  0 4181899460033    strict.pm              <- import
  0 4181899460064    AutoLoader.pm        <- BEGIN
  0 4181899460088    AutoLoader.pm        -> BEGIN
  0 4181899460096    AutoLoader.pm        <- BEGIN
  0 4181899460187    AutoLoader.pm        -> BEGIN
  0 4181899460199    AutoLoader.pm        <- BEGIN
  0 4181899460582    AutoLoader.pm        -> BEGIN
  0 4181899460590    strict.pm              -> unimport
  0 4181899460598    strict.pm                -> bits
  0 4181899460611    strict.pm                <- bits
  0 4181899460619    strict.pm              <- unimport
  0 4181899460625    AutoLoader.pm        <- BEGIN
  0 4181899460830    AutoLoader.pm        -> BEGIN
  0 4181899460838    strict.pm              -> unimport
  0 4181899460845    strict.pm                -> bits
  0 4181899460855    strict.pm                <- bits
  0 4181899460862    strict.pm              <- unimport
  0 4181899460869    AutoLoader.pm        <- BEGIN
  0 4181899461092    AutoLoader.pm        -> BEGIN
  0 4181899461100    strict.pm              -> unimport
  0 4181899461107    strict.pm                -> bits
  0 4181899461116    strict.pm                <- bits
  0 4181899461124    strict.pm              <- unimport
  0 4181899461130    AutoLoader.pm        <- BEGIN
  0 4181899461238    Config.pm            -> FETCH
  0 4181899461250    Config.pm            <- FETCH
  0 4181899461264    Config.pm            -> FETCH
  0 4181899461272    Config.pm            <- FETCH
  0 4181899461282    Config.pm            -> FETCH
  0 4181899461290    Config.pm            <- FETCH
  0 4181899461299    Config.pm            -> FETCH
  0 4181899461307    Config.pm            <- FETCH
  0 4181899461403    Kstat.pm           <- BEGIN
  0 4181899461432    Kstat.pm           -> BEGIN
  0 4181899461440    vars.pm              -> import
  0 4181899461476    vars.pm              <- import
  0 4181899461483    Kstat.pm           <- BEGIN
  0 4181899461539    DynaLoader.pm      -> bootstrap
  0 4181899461769    DynaLoader.pm        -> dl_load_flags
  0 4181899461777    DynaLoader.pm        <- dl_load_flags
  0 4181899462208    DynaLoader.pm      <- bootstrap
  0 4181899462231    nicstat          <- BEGIN
  0 4181899468306    Std.pm           -> getopts
  0 4181899468351    Exporter.pm        -> import
  0 4181899468390    Exporter.pm        <- import
  0 4181899468405    Std.pm           <- getopts
  0 4181899468426    nicstat          -> find_nets
  0 4181899521011    nicstat          <- find_nets
  0 4181899521415    nicstat          -> fetch_net_data
  0 4181899564973    nicstat          <- fetch_net_data
  0 4181899565526    nicstat          -> print_neat
  0 4181899565672    nicstat          <- print_neat
  0 4181899565680    nicstat          -> print_neat
  0 4181899565902    nicstat          <- print_neat
  0 4181899565909    nicstat          -> print_neat
  0 4181899566033    nicstat          <- print_neat
  0 4181899566039    nicstat          -> print_neat
  0 4181899566165    nicstat          <- print_neat
  0 4181899566172    nicstat          -> print_neat
  0 4181899566331    nicstat          <- print_neat
  0 4181899566338    nicstat          -> print_neat
  0 4181899566494    nicstat          <- print_neat
  0 4181899566791    nicstat          -> print_neat
  0 4181899566953    nicstat          <- print_neat
  0 4181899566961    nicstat          -> print_neat
  0 4181899567085    nicstat          <- print_neat
  0 4181899567091    nicstat          -> print_neat
  0 4181899567247    nicstat          <- print_neat
  0 4181899567254    nicstat          -> print_neat
  0 4181899567377    nicstat          <- print_neat
  0 4181899567383    nicstat          -> print_neat
  0 4181899567538    nicstat          <- print_neat
  0 4181899567544    nicstat          -> print_neat
  0 4181899567666    nicstat          <- print_neat
  0 4181899567977    nicstat          -> print_neat
  0 4181899568232    nicstat          <- print_neat
  0 4181899568240    nicstat          -> print_neat
  0 4181899568397    nicstat          <- print_neat
  0 4181899568404    nicstat          -> print_neat
  0 4181899568528    nicstat          <- print_neat
  0 4181899568535    nicstat          -> print_neat
  0 4181899568656    nicstat          <- print_neat
  0 4181899568663    nicstat          -> print_neat
  0 4181899568819    nicstat          <- print_neat
  0 4181899568826    nicstat          -> print_neat
  0 4181899568947    nicstat          <- print_neat
  0 4181899572708    Config.pm        -> DESTROY
  0 4181899572735    Config.pm        <- DESTROY

After initialising Perl libraries and modules, the "nicstat" program ran,
the output matching what was expected from the source.

OpenPOWER on IntegriCloud