-
Notifications
You must be signed in to change notification settings - Fork 133
/
Copy pathtcl_flowtime_example.txt
197 lines (188 loc) · 9.96 KB
/
tcl_flowtime_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
189
190
191
192
193
194
195
196
Following are examples of running tcl_flowtime.d.
Here the tcl_flowtime.d script is running on the program
Code/Tcl/func_abc.tcl.
# tcl_flowtime.d
C PID TIME(us) DELTA(us) -- CALL
0 17901 4436098007906 2 > if
0 17901 4436098007976 70 > info
0 17901 4436098007998 21 < info
0 17901 4436098008050 52 > proc
0 17901 4436098008063 12 < proc
0 17901 4436098008069 6 < if
0 17901 4436098008085 15 > tclInit
0 17901 4436098008286 201 -> tclInit
0 17901 4436098008295 8 > global
0 17901 4436098008305 10 < global
0 17901 4436098008311 6 > global
0 17901 4436098008318 6 < global
0 17901 4436098008323 5 > rename
0 17901 4436098008342 18 < rename
0 17901 4436098008353 10 > info
0 17901 4436098008362 9 < info
0 17901 4436098008369 6 > info
0 17901 4436098008395 25 < info
0 17901 4436098008403 8 > unset
0 17901 4436098008410 6 < unset
0 17901 4436098008416 5 > concat
0 17901 4436098008425 8 < concat
0 17901 4436098008440 15 > file
0 17901 4436098008459 18 < file
0 17901 4436098008465 6 > file
0 17901 4436098008543 78 < file
0 17901 4436098008550 7 > file
0 17901 4436098008560 9 < file
0 17901 4436098008567 7 > file
0 17901 4436098008671 104 < file
0 17901 4436098008678 7 > file
0 17901 4436098008688 9 < file
0 17901 4436098008695 6 > file
0 17901 4436098008780 84 < file
0 17901 4436098008787 6 > file
0 17901 4436098008796 9 < file
0 17901 4436098008803 6 > file
0 17901 4436098008854 51 < file
0 17901 4436098008862 7 > uplevel
0 17901 4436098008872 10 > source
0 17901 4436098009290 417 > if
0 17901 4436098009304 14 > info
0 17901 4436098009311 7 < info
0 17901 4436098009319 7 < if
0 17901 4436098009331 11 > package
0 17901 4436098009340 9 < package
0 17901 4436098009353 12 > if
0 17901 4436098009363 10 > info
0 17901 4436098009369 6 < info
0 17901 4436098009390 20 > info
0 17901 4436098009413 22 < info
0 17901 4436098009421 7 < if
0 17901 4436098009439 18 > namespace
0 17901 4436098009530 90 > variable
0 17901 4436098009537 7 < variable
0 17901 4436098009544 6 > info
0 17901 4436098009554 10 < info
0 17901 4436098009561 6 > info
0 17901 4436098009567 6 < info
0 17901 4436098009573 5 > info
0 17901 4436098009579 6 < info
0 17901 4436098009586 6 > file
0 17901 4436098009605 19 < file
0 17901 4436098009611 6 > list
0 17901 4436098009627 15 < list
0 17901 4436098009633 6 > foreach
0 17901 4436098009658 24 > lsearch
0 17901 4436098009665 7 < lsearch
0 17901 4436098009673 7 > lappend
0 17901 4436098009680 7 < lappend
0 17901 4436098009689 9 > lsearch
0 17901 4436098009694 5 < lsearch
0 17901 4436098009700 6 > lappend
0 17901 4436098009707 6 < lappend
0 17901 4436098009712 5 < foreach
0 17901 4436098009719 6 > info
0 17901 4436098009726 7 < info
0 17901 4436098009732 5 > file
0 17901 4436098009749 17 < file
0 17901 4436098009756 6 > file
0 17901 4436098009772 16 < file
0 17901 4436098009778 6 > file
0 17901 4436098009787 9 < file
0 17901 4436098009795 7 > lsearch
0 17901 4436098009800 5 < lsearch
0 17901 4436098009806 6 > lappend
0 17901 4436098009812 5 < lappend
0 17901 4436098009818 5 > info
0 17901 4436098009823 5 < info
0 17901 4436098009830 6 > foreach
0 17901 4436098009840 9 > lsearch
0 17901 4436098009845 5 < lsearch
0 17901 4436098009851 6 > lappend
0 17901 4436098009857 5 < lappend
0 17901 4436098009862 5 < foreach
0 17901 4436098009868 5 < namespace
0 17901 4436098009896 27 > if
0 17901 4436098009915 18 > interp
0 17901 4436098009922 7 < interp
0 17901 4436098009930 8 < if
0 17901 4436098009943 12 > package
0 17901 4436098009949 5 < package
0 17901 4436098009960 10 > if
0 17901 4436098009970 10 > interp
0 17901 4436098009976 5 < interp
0 17901 4436098010018 41 < if
0 17901 4436098010036 18 > if
0 17901 4436098010049 12 > namespace
0 17901 4436098010057 7 < namespace
0 17901 4436098010063 6 < if
0 17901 4436098010074 11 > set
0 17901 4436098010081 6 < set
0 17901 4436098010089 8 > set
0 17901 4436098010095 5 < set
0 17901 4436098010104 9 > if
0 17901 4436098010116 12 > namespace
0 17901 4436098010122 6 < namespace
0 17901 4436098010133 10 > proc
0 17901 4436098010142 8 < proc
0 17901 4436098010148 5 < if
0 17901 4436098010228 79 > proc
0 17901 4436098010237 8 < proc
0 17901 4436098010255 18 > proc
0 17901 4436098010264 9 < proc
0 17901 4436098010293 29 > proc
0 17901 4436098010301 7 < proc
0 17901 4436098010320 18 > proc
0 17901 4436098010329 9 < proc
0 17901 4436098010342 13 > proc
0 17901 4436098010350 7 < proc
0 17901 4436098010394 44 > if
0 17901 4436098010418 23 > proc
0 17901 4436098010437 18 < proc
0 17901 4436098010443 6 < if
0 17901 4436098010563 120 > proc
0 17901 4436098010575 12 < proc
0 17901 4436098010582 7 < source
0 17901 4436098010588 5 < uplevel
0 17901 4436098010596 8 <- tclInit
0 17901 4436098010610 13 < tclInit
0 17901 4436098010800 190 > proc
0 17901 4436098010809 8 < proc
0 17901 4436098010818 9 > proc
0 17901 4436098010825 6 < proc
0 17901 4436098010833 8 > proc
0 17901 4436098010840 6 < proc
0 17901 4436098010847 7 > func_a
0 17901 4436098010863 15 -> func_a
0 17901 4436098010870 6 > puts
0 17901 4436098011006 136 < puts
0 17901 4436098011014 7 > after
0 17901 4436099020588 1009573 < after
0 17901 4436099020611 23 > func_b
0 17901 4436099020646 34 -> func_b
0 17901 4436099020655 8 > puts
0 17901 4436099020697 41 < puts
0 17901 4436099020703 6 > after
0 17901 4436100030614 1009910 < after
0 17901 4436100030638 24 > func_c
0 17901 4436100030671 32 -> func_c
0 17901 4436100030680 9 > puts
0 17901 4436100030723 42 < puts
0 17901 4436100030729 6 > after
0 17901 4436101040600 1009870 < after
0 17901 4436101040623 22 <- func_c
0 17901 4436101040633 10 < func_c
0 17901 4436101040639 6 <- func_b
0 17901 4436101040645 5 < func_b
0 17901 4436101040651 5 <- func_a
0 17901 4436101040656 5 < func_a
0 17901 4436101040682 25 > exit
You can see the output is in six columns.
The first column is CPU-id, the second is PID, third is the time since boot in
microseconds, fourth is the elapsed time since the previous action. The fifth
and sixth columns represent the action. The Tcl command or procedure name is
prefixed by an indicator reprenting what is happening. These may be ->
(procedure entry), <- (procedure return), > (command entry), or < (command
return).
As each action is taken, the fifth and sixth columns are indented by 2 spaces.
This shows which procedure or command is calling which.
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.