1 The following are examples of pl_flowinfo.d.
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.
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
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().
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".
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.
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.
32 See Notes/ALLflow_notes.txt for important notes about reading flow outputs.
36 The following traces a Perl network interface statistics tool, "nicstat"
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
186 After initialising Perl libraries and modules, the "nicstat" program ran,
187 the output matching what was expected from the source.