1 The following are examples of sh_flowinfo.d.
3 This is a simple script to trace the flow of Bourne shell functions,
4 builtins and external commands. Here it traces the example program,
5 Code/Shell/func_abc.sh.
8 C PID DELTA(us) FILE:LINE TYPE -- NAME
9 0 19634 2 func_abc.sh:23 func -> func_a
10 0 19634 24 func_abc.sh:18 builtin -> echo
11 0 19634 41 func_abc.sh:- builtin <- echo
12 0 19634 5873 func_abc.sh:19 cmd -> sleep
13 0 19634 999373 func_abc.sh:- cmd <- sleep
14 0 19634 39 func_abc.sh:20 func -> func_b
15 0 19634 22 func_abc.sh:11 builtin -> echo
16 0 19634 40 func_abc.sh:- builtin <- echo
17 0 19634 4661 func_abc.sh:12 cmd -> sleep
18 0 19634 1005349 func_abc.sh:- cmd <- sleep
19 0 19634 49 func_abc.sh:13 func -> func_c
20 0 19634 22 func_abc.sh:5 builtin -> echo
21 0 19634 38 func_abc.sh:- builtin <- echo
22 0 19634 4949 func_abc.sh:6 cmd -> sleep
23 0 19634 1004817 func_abc.sh:- cmd <- sleep
24 0 19634 36 func_abc.sh:- func <- func_c
25 0 19634 14 func_abc.sh:- func <- func_b
26 0 19634 8 func_abc.sh:- func <- func_a
28 As each function is entered, the third column is indented by 2 spaces. This
29 shows which function is calling who - the output abovebegins by showing that
30 func_a() began, and then called func_b().
32 The DELTA(us) column shows time from that line to the previous line, and
33 so can be a bit tricky to read. For example, the fifth line of data output
34 (skipping the header) reads as "the time from the command sleep beginning
35 to ending was 999373 us, or 1.0 seconds".
37 The LINE column shows the line in the file what was being executed. Refer
38 to the source program to see what this line refers to.
40 If the output looks shuffled, check the CPU "C" column - if it changes,
41 then the output is probably shuffled. See Notes/ALLsnoop_notes.txt for
42 details and suggested workarounds.
44 See Notes/ALLflow_notes.txt for important notes about reading flow outputs.
47 The following traces the firefox startup script.
50 C PID DELTA(us) FILE:LINE TYPE -- NAME
51 0 156789 1 firefox:- subsh -> pid 156790
52 0 156789 20 firefox:- subsh <- = 0
53 0 156789 31651 firefox:- subsh -> pid 156791
54 0 156789 20 firefox:- subsh <- = 0
55 0 156789 10502 firefox:109 builtin -> test
56 0 156789 59 firefox:- builtin <- test
57 0 156789 3804 firefox:- subsh -> pid 156792
58 0 156789 21 firefox:- subsh <- = 0
59 0 156789 22029 firefox:114 builtin -> [
60 0 156789 57 firefox:- builtin <- [
61 0 156789 90910 firefox:- subsh -> pid 156793
62 0 156789 22 firefox:- subsh <- = 0
63 0 156789 159492 firefox:- subsh -> pid 156794
64 0 156789 22 firefox:- subsh <- = 0
65 0 156789 127 firefox:116 builtin -> cd
66 0 156789 54 firefox:- builtin <- cd
67 0 156789 209757 firefox:- subsh -> pid 156795
68 0 156789 23 firefox:- subsh <- = 0
69 0 156795 206160 firefox:- subsh -> pid 156796
70 0 156795 9 firefox:- subsh <- = 0
71 0 156789 12115 firefox:118 builtin -> [
72 0 156789 61 firefox:- builtin <- [
73 0 156789 200529 firefox:- subsh -> pid 156797
74 0 156789 24 firefox:- subsh <- = 0
75 0 156789 136 firefox:123 builtin -> [
76 0 156789 58 firefox:- builtin <- [
77 0 156789 21 firefox:124 builtin -> cd
78 0 156789 19 firefox:- builtin <- cd
79 0 156798 175 firefox:1 builtin -> pwd
80 0 156798 65 firefox:- builtin <- pwd
81 0 156789 108835 firefox:- subsh -> pid 156798
82 0 156789 18 firefox:- subsh <- = 0
83 0 156789 119 firefox:128 builtin -> break
84 0 156789 15 firefox:- builtin <- break
85 0 156789 21 firefox:131 builtin -> cd
86 0 156789 26 firefox:- builtin <- cd
87 0 156789 61 firefox:133 builtin -> [
88 0 156789 9 firefox:- builtin <- [
89 0 156789 73508 firefox:147 builtin -> [
90 0 156789 25 firefox:- builtin <- [
91 0 156800 184 firefox:1 builtin -> echo
92 0 156800 175 firefox:- builtin <- echo
93 0 156789 15966 firefox:- subsh -> pid 156799
94 0 156789 22 firefox:- subsh <- = 0
95 0 156799 12091 firefox:- subsh -> pid 156800
96 0 156799 10 firefox:- subsh <- = 0
97 0 156802 178 firefox:1 builtin -> echo
98 0 156802 167 firefox:- builtin <- echo
99 0 156789 13822 firefox:- subsh -> pid 156801
100 0 156789 18 firefox:- subsh <- = 0
101 0 156801 81683 firefox:- subsh -> pid 156802
102 0 156801 21 firefox:- subsh <- = 0
103 0 156789 78324 firefox:158 builtin -> [
104 0 156789 37 firefox:- builtin <- [
105 0 156789 54 firefox:194 builtin -> export
106 0 156789 9 firefox:- builtin <- export
107 0 156789 26 firefox:197 func -> moz_pis_startstop_scripts
108 0 156789 61 firefox:62 builtin -> export
109 0 156789 9 firefox:- builtin <- export
110 0 156789 413 firefox:67 builtin -> [
111 0 156789 34 firefox:- builtin <- [
112 0 156789 40 firefox:69 builtin -> .
113 0 156789 20833 firefox:18 func -> moz_spc_verbose_echo
114 0 156789 26 firefox:15 builtin -> :
115 0 156789 16 firefox:- builtin <- :
116 0 156789 15 firefox:- func <- moz_spc_verbose_echo
117 0 156789 105106 firefox:- subsh -> pid 156803
118 0 156789 22 firefox:- subsh <- = 0
119 0 156789 129 firefox:19 builtin -> [
120 0 156789 17 firefox:- builtin <- [
121 0 156789 33 firefox:20 func -> moz_spc_verbose_echo
122 0 156789 14 firefox:15 builtin -> :
123 0 156789 7 firefox:- builtin <- :
124 0 156789 9 firefox:- func <- moz_spc_verbose_echo
125 0 156789 21 firefox:23 builtin -> [
126 0 156789 8 firefox:- builtin <- [
127 0 156789 16 firefox:26 builtin -> [
128 0 156789 8 firefox:- builtin <- [
129 0 156789 24 firefox:29 builtin -> [
130 0 156789 43 firefox:- builtin <- [
131 0 156789 77 firefox:36 func -> moz_spc_verbose_echo
132 0 156789 9 firefox:15 builtin -> :
133 0 156789 8 firefox:- builtin <- :
134 0 156789 8 firefox:- func <- moz_spc_verbose_echo
135 0 156789 158947 firefox:- subsh -> pid 156804
136 0 156789 22 firefox:- subsh <- = 0
137 0 156789 210112 firefox:- subsh -> pid 156805
138 0 156789 22 firefox:- subsh <- = 0
139 0 156805 205500 firefox:- subsh -> pid 156806
140 0 156805 10 firefox:- subsh <- = 0
141 0 156805 200987 firefox:- subsh -> pid 156807
142 0 156805 20 firefox:- subsh <- = 0
143 0 156789 363564 firefox:40 func -> moz_spc_verbose_echo
144 0 156789 26 firefox:15 builtin -> :
145 0 156789 17 firefox:- builtin <- :
146 0 156789 15 firefox:- func <- moz_spc_verbose_echo
147 0 156809 234 firefox:1 builtin -> [
148 0 156809 70 firefox:- builtin <- [
149 0 156789 46950 firefox:- subsh -> pid 156808
150 0 156789 22 firefox:- subsh <- = 0
151 0 156808 42371 firefox:- subsh -> pid 156809
152 0 156808 10 firefox:- subsh <- = 0
153 0 156789 27278 firefox:43 builtin -> [
154 0 156789 26 firefox:- builtin <- [
155 0 156789 62 firefox:44 func -> moz_spc_verbose_echo
156 0 156789 15 firefox:15 builtin -> :
157 0 156789 8 firefox:- builtin <- :
158 0 156789 10 firefox:- func <- moz_spc_verbose_echo
159 0 156789 30 firefox:67 func -> moz_spc_verbose_echo
160 0 156789 9 firefox:15 builtin -> :
161 0 156789 8 firefox:- builtin <- :
162 0 156789 7 firefox:- func <- moz_spc_verbose_echo
163 0 156789 8 firefox:- builtin <- .
164 0 156789 28 firefox:67 builtin -> [
165 0 156789 31 firefox:- builtin <- [
166 0 156789 8 firefox:- func <- moz_pis_startstop_scripts
167 0 156789 97 firefox:199 builtin -> [
168 0 156789 35 firefox:- builtin <- [
169 0 156789 29 firefox:205 builtin -> [
170 0 156789 9 firefox:- builtin <- [
171 0 156789 72519 firefox:209 cmd -> /usr/lib/firefox/run-mozilla.sh
172 0 156810 1 run-mozilla.sh:- subsh -> pid 156811
173 0 156810 15 run-mozilla.sh:- subsh <- = 0
174 0 156810 129474 run-mozilla.sh:- subsh -> pid 156812
175 0 156810 24 run-mozilla.sh:- subsh <- = 0
176 0 156810 743 run-mozilla.sh:258 builtin -> [
177 0 156810 28 run-mozilla.sh:- builtin <- [
178 0 156810 212 run-mozilla.sh:275 builtin -> break
179 0 156810 10 run-mozilla.sh:- builtin <- break
180 0 156810 31 run-mozilla.sh:283 builtin -> [
181 0 156810 10 run-mozilla.sh:- builtin <- [
182 0 156810 16 run-mozilla.sh:286 builtin -> shift
183 0 156810 9 run-mozilla.sh:- builtin <- shift
184 0 156810 55 run-mozilla.sh:291 builtin -> [
185 0 156810 9 run-mozilla.sh:- builtin <- [
186 0 156810 36 run-mozilla.sh:317 builtin -> [
187 0 156810 34 run-mozilla.sh:- builtin <- [
188 0 156810 37 run-mozilla.sh:327 builtin -> [
189 0 156810 9 run-mozilla.sh:- builtin <- [
190 0 156810 142 run-mozilla.sh:362 builtin -> [
191 0 156810 9 run-mozilla.sh:- builtin <- [
192 0 156810 26 run-mozilla.sh:366 builtin -> export
193 0 156810 9 run-mozilla.sh:- builtin <- export
194 0 156810 37 run-mozilla.sh:369 builtin -> [
195 0 156810 9 run-mozilla.sh:- builtin <- [
196 0 156810 18 run-mozilla.sh:371 builtin -> [
197 0 156810 19 run-mozilla.sh:- builtin <- [
198 0 156810 112 run-mozilla.sh:379 builtin -> [
199 0 156810 10 run-mozilla.sh:- builtin <- [
200 0 156810 23 run-mozilla.sh:418 builtin -> export
201 0 156810 9 run-mozilla.sh:- builtin <- export
202 0 156810 45 run-mozilla.sh:419 builtin -> export
203 0 156810 10 run-mozilla.sh:- builtin <- export
204 0 156810 27 run-mozilla.sh:421 builtin -> [
205 0 156810 9 run-mozilla.sh:- builtin <- [
206 0 156810 29 run-mozilla.sh:425 func -> moz_run_program
207 0 156810 32 run-mozilla.sh:137 builtin -> [
208 0 156810 25 run-mozilla.sh:- builtin <- [
209 0 156810 20 run-mozilla.sh:145 func -> moz_test_binary
210 0 156810 17 run-mozilla.sh:97 builtin -> [
211 0 156810 23 run-mozilla.sh:- builtin <- [
212 0 156810 15 run-mozilla.sh:99 builtin -> [
213 0 156810 26 run-mozilla.sh:- builtin <- [
214 0 156810 13 run-mozilla.sh:101 builtin -> return
215 0 156810 9 run-mozilla.sh:- builtin <- return
216 0 156810 11 run-mozilla.sh:- func <- moz_test_binary
217 0 156810 18 run-mozilla.sh:146 builtin -> [
218 0 156810 9 run-mozilla.sh:- builtin <- [
219 0 156814 185 run-mozilla.sh:1 builtin -> type
220 0 156814 118188 run-mozilla.sh:- builtin <- type
221 0 156810 167284 run-mozilla.sh:- subsh -> pid 156813
222 0 156810 23 run-mozilla.sh:- subsh <- = 0
223 0 156813 162135 run-mozilla.sh:- subsh -> pid 156814
224 0 156813 12 run-mozilla.sh:- subsh <- = 0
225 0 156813 200125 run-mozilla.sh:- subsh -> pid 156815
226 0 156813 22 run-mozilla.sh:- subsh <- = 0
227 0 156810 203465 run-mozilla.sh:152 builtin -> [
228 0 156810 51 run-mozilla.sh:- builtin <- [
229 0 156810 21 run-mozilla.sh:156 builtin -> [
230 0 156810 9 run-mozilla.sh:- builtin <- [
231 0 156810 15 run-mozilla.sh:159 builtin -> [
232 0 156810 14 run-mozilla.sh:- builtin <- [
233 0 156810 65752 run-mozilla.sh:- subsh -> pid 156816
234 0 156810 24 run-mozilla.sh:- subsh <- = 0
235 0 156816 251788 run-mozilla.sh:- subsh -> pid 156817
236 0 156816 22 run-mozilla.sh:- subsh <- = 0
237 0 156810 299677 run-mozilla.sh:167 cmd -> /usr/lib/firefox/firefox-bin
238 0 156810 5124906 run-mozilla.sh:- cmd <- /usr/lib/firefox/firefox-bin
239 0 156789 5993798 firefox:- cmd <- /usr/lib/firefox/run-mozilla.sh
241 Now latencies can investigated by line number.