Training courses

Kernel and Embedded Linux

Bootlin training courses

Embedded Linux, kernel,
Yocto Project, Buildroot, real-time,
graphics, boot time, debugging...

Bootlin logo

Elixir Cross Referencer

Open Menu /external/cddl/dtracetoolkit/dist/Examples/pl_flowinfo_example.txt 
  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
180
181
182
183
184
185
186
187
188
The following are examples of pl_flowinfo.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_flowinfo.d
   C    PID  DELTA(us)              FILE:LINE TYPE     -- SUB
   0 305127          2       func_abc.pl:15   sub      -> func_a
   0 305127    1008776       func_abc.pl:9    sub        -> func_b
   0 305127    1010019       func_abc.pl:4    sub          -> func_c
   0 305127    1009979       func_abc.pl:4    sub          <- func_c
   0 305127         26       func_abc.pl:9    sub        <- func_b
   0 305127          9       func_abc.pl:15   sub      <- 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().

The DELTA(us) column shows time from that line to the previous line, and
so can be a bit tricky to read. For example, the second line of data output
(skipping the header) reads as "the time from func_a() beginning to
func_b() beginning was 1008776 us, or 1.01 seconds".

The LINE column shows the line in the file what was being executed. Refer
to the source program to see what this line refers to.

If the output looks shuffled, check the CPU "C" column - if it changes,
then the output is probably shuffled. See Notes/ALLsnoop_notes.txt for
details and suggested workarounds.

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_flowinfo.d
C    PID  DELTA(us)              FILE:LINE TYPE     -- SUB
0 305132          2           nicstat:83   sub      -> BEGIN
0 305132        444         strict.pm:12   sub        -> bits
0 305132         34         strict.pm:12   sub        <- bits
0 305132         32         strict.pm:28   sub        -> import
0 305132         22         strict.pm:28   sub        <- import
0 305132          8           nicstat:83   sub      <- BEGIN
0 305132         26           nicstat:84   sub      -> BEGIN
0 305132       2339       Exporter.pm:30   sub        -> import
0 305132         83       Exporter.pm:30   sub        <- import
0 305132         14           nicstat:84   sub      <- BEGIN
0 305132         27           nicstat:85   sub      -> BEGIN
0 305132        205          Kstat.pm:34   sub        -> BEGIN
0 305132         11         strict.pm:28   sub          -> import
0 305132         11         strict.pm:28   sub          <- import
0 305132          8          Kstat.pm:34   sub        <- BEGIN
0 305132         23          Kstat.pm:35   sub        -> BEGIN
0 305132        187     DynaLoader.pm:18   sub          -> BEGIN
0 305132         73           vars.pm:3    sub            -> BEGIN
0 305132          9           vars.pm:3    sub            <- BEGIN
0 305132         34           vars.pm:7    sub            -> BEGIN
0 305132        470       warnings.pm:134  sub              -> BEGIN
0 305132        598       warnings.pm:134  sub              <- BEGIN
0 305132       2151       register.pm:37   sub              -> import
0 305132         23       register.pm:28   sub                -> mkMask
0 305132         13       register.pm:28   sub                <- mkMask
0 305132         53       register.pm:28   sub                -> mkMask
0 305132         11       register.pm:28   sub                <- mkMask
0 305132         11       register.pm:37   sub              <- import
0 305132          8           vars.pm:7    sub            <- BEGIN
0 305132         28           vars.pm:8    sub            -> BEGIN
0 305132          9         strict.pm:28   sub              -> import
0 305132          8         strict.pm:12   sub                -> bits
0 305132         13         strict.pm:12   sub                <- bits
0 305132          9         strict.pm:28   sub              <- import
0 305132          8           vars.pm:8    sub            <- BEGIN
0 305132        294           vars.pm:11   sub            -> import
0 305132         52           vars.pm:11   sub            <- import
0 305132          8     DynaLoader.pm:18   sub          <- BEGIN
0 305132         48     DynaLoader.pm:25   sub          -> BEGIN
0 305132         97         Config.pm:5    sub            -> BEGIN
0 305132          9         strict.pm:28   sub              -> import
0 305132          9         strict.pm:28   sub              <- import
0 305132          8         Config.pm:5    sub            <- BEGIN
0 305132        134         Config.pm:31   sub            -> BEGIN
0 305132          9         strict.pm:33   sub              -> unimport
0 305132          8         strict.pm:12   sub                -> bits
0 305132         11         strict.pm:12   sub                <- bits
0 305132         16         strict.pm:33   sub              <- unimport
0 305132          8         Config.pm:31   sub            <- BEGIN
0 305132        343         Config.pm:60   sub            -> TIEHASH
0 305132         10         Config.pm:60   sub            <- TIEHASH
0 305132         44         Config.pm:25   sub            -> import
0 305132         18         Config.pm:25   sub            <- import
0 305132          9     DynaLoader.pm:25   sub          <- BEGIN
0 305132       1301     AutoLoader.pm:3    sub          -> BEGIN
0 305132         11         strict.pm:28   sub            -> import
0 305132         10         strict.pm:28   sub            <- import
0 305132          9     AutoLoader.pm:3    sub          <- BEGIN
0 305132         22     AutoLoader.pm:4    sub          -> BEGIN
0 305132          9     AutoLoader.pm:4    sub          <- BEGIN
0 305132         89     AutoLoader.pm:14   sub          -> BEGIN
0 305132         13     AutoLoader.pm:14   sub          <- BEGIN
0 305132        375     AutoLoader.pm:95   sub          -> BEGIN
0 305132          9         strict.pm:33   sub            -> unimport
0 305132          8         strict.pm:12   sub              -> bits
0 305132         11         strict.pm:12   sub              <- bits
0 305132          9         strict.pm:33   sub            <- unimport
0 305132          8     AutoLoader.pm:95   sub          <- BEGIN
0 305132        203     AutoLoader.pm:128  sub          -> BEGIN
0 305132          9         strict.pm:33   sub            -> unimport
0 305132          8         strict.pm:12   sub              -> bits
0 305132         11         strict.pm:12   sub              <- bits
0 305132          9         strict.pm:33   sub            <- unimport
0 305132          8     AutoLoader.pm:128  sub          <- BEGIN
0 305132        220     AutoLoader.pm:173  sub          -> BEGIN
0 305132          9         strict.pm:33   sub            -> unimport
0 305132          8         strict.pm:12   sub              -> bits
0 305132         10         strict.pm:12   sub              <- bits
0 305132          9         strict.pm:33   sub            <- unimport
0 305132          8     AutoLoader.pm:173  sub          <- BEGIN
0 305132        103         Config.pm:52   sub          -> FETCH
0 305132         12         Config.pm:52   sub          <- FETCH
0 305132         16         Config.pm:52   sub          -> FETCH
0 305132          9         Config.pm:52   sub          <- FETCH
0 305132         11         Config.pm:52   sub          -> FETCH
0 305132          9         Config.pm:52   sub          <- FETCH
0 305132         11         Config.pm:52   sub          -> FETCH
0 305132          9         Config.pm:52   sub          <- FETCH
0 305132         95          Kstat.pm:35   sub        <- BEGIN
0 305132         29          Kstat.pm:36   sub        -> BEGIN
0 305132         10           vars.pm:11   sub          -> import
0 305132         33           vars.pm:11   sub          <- import
0 305132          8          Kstat.pm:36   sub        <- BEGIN
0 305132         56     DynaLoader.pm:133  sub        -> bootstrap
0 305132        314     DynaLoader.pm:48   sub          -> dl_load_flags
0 305132         11     DynaLoader.pm:48   sub          <- dl_load_flags
0 305132       1113     DynaLoader.pm:133  sub        <- bootstrap
0 305132         41           nicstat:85   sub      <- BEGIN
0 305132       6102            Std.pm:219  sub      -> getopts
0 305132         52       Exporter.pm:30   sub        -> import
0 305132         40       Exporter.pm:30   sub        <- import
0 305132         22            Std.pm:219  sub      <- getopts
0 305132         24           nicstat:264  sub      -> find_nets
0 305132      79662           nicstat:264  sub      <- find_nets
0 305132        420           nicstat:304  sub      -> fetch_net_data
0 305132      43871           nicstat:304  sub      <- fetch_net_data
0 305132        479           nicstat:372  sub      -> print_neat
0 305132        150           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        220           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        126           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        125           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        157           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        171           nicstat:372  sub      <- print_neat
0 305132        343           nicstat:372  sub      -> print_neat
0 305132        128           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        157           nicstat:372  sub      <- print_neat
0 305132          9           nicstat:372  sub      -> print_neat
0 305132        125           nicstat:372  sub      <- print_neat
0 305132          9           nicstat:372  sub      -> print_neat
0 305132        123           nicstat:372  sub      <- print_neat
0 305132          9           nicstat:372  sub      -> print_neat
0 305132        160           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        124           nicstat:372  sub      <- print_neat
0 305132        342           nicstat:372  sub      -> print_neat
0 305132        126           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        123           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        156           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        153           nicstat:372  sub      <- print_neat
0 305132         10           nicstat:372  sub      -> print_neat
0 305132        123           nicstat:372  sub      <- print_neat
0 305132          9           nicstat:372  sub      -> print_neat
0 305132        123           nicstat:372  sub      <- print_neat
0 305132       3736         Config.pm:63   sub      -> DESTROY
0 305132         32         Config.pm:63   sub      <- DESTROY

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