|
0
|
1 |
"
|
|
21
|
2 |
COPYRIGHT (c) 1995 by Claus Gittinger
|
|
|
3 |
All Rights Reserved
|
|
0
|
4 |
|
|
|
5 |
This software is furnished under a license and may be used
|
|
|
6 |
only in accordance with the terms of that license and with the
|
|
|
7 |
inclusion of the above copyright notice. This software may not
|
|
|
8 |
be provided or otherwise made available to, or used by, any
|
|
|
9 |
other person. No title to or ownership of the software is
|
|
|
10 |
hereby transferred.
|
|
|
11 |
"
|
|
|
12 |
|
|
119
|
13 |
!Object subclass:#MessageTally
|
|
21
|
14 |
instanceVariableNames:'process tree ntally theBlock spyInterval'
|
|
|
15 |
classVariableNames:''
|
|
|
16 |
poolDictionaries:''
|
|
24
|
17 |
category:'System-Debugging-Support'
|
|
0
|
18 |
!
|
|
|
19 |
|
|
9
|
20 |
!MessageTally class methodsFor:'documentation'!
|
|
|
21 |
|
|
88
|
22 |
copyright
|
|
|
23 |
"
|
|
|
24 |
COPYRIGHT (c) 1995 by Claus Gittinger
|
|
|
25 |
All Rights Reserved
|
|
|
26 |
|
|
|
27 |
This software is furnished under a license and may be used
|
|
|
28 |
only in accordance with the terms of that license and with the
|
|
|
29 |
inclusion of the above copyright notice. This software may not
|
|
|
30 |
be provided or otherwise made available to, or used by, any
|
|
|
31 |
other person. No title to or ownership of the software is
|
|
|
32 |
hereby transferred.
|
|
|
33 |
"
|
|
9
|
34 |
!
|
|
|
35 |
|
|
|
36 |
documentation
|
|
|
37 |
"
|
|
|
38 |
MessageTally allows profiling excution of a block;
|
|
|
39 |
statistic of method evaluation is output on Transcript.
|
|
|
40 |
To get statistic, use 'MessageTally spyOn:aBlock'.
|
|
|
41 |
|
|
|
42 |
example:
|
|
21
|
43 |
MessageTally spyOn:[
|
|
|
44 |
(ByteArray uninitalizedNew:1000) sort
|
|
|
45 |
]
|
|
|
46 |
|
|
|
47 |
By default, probing is done every 10ms (i.e. the execution of the block is
|
|
|
48 |
interrupted every 10ms, and the context chain analyzed).
|
|
|
49 |
For better resolution, use smaller clock ticks (if your OperatingSystem
|
|
|
50 |
supports it). Try spyDetailedOn:aBlock, which tries to measure things
|
|
|
51 |
every 1ms. (Notice, that some OS's only provide a resolution of less than
|
|
|
52 |
that time interval)
|
|
|
53 |
"
|
|
|
54 |
!
|
|
|
55 |
|
|
|
56 |
examples
|
|
9
|
57 |
"
|
|
21
|
58 |
MessageTally spyOn:[ #(6 5 4 3 2 1) sort ]
|
|
|
59 |
MessageTally spyOn:[100 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
60 |
MessageTally spyOn:[1000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
61 |
MessageTally spyOn:[10000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
62 |
MessageTally spyOn:[100000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
63 |
MessageTally spyOn:[500000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
64 |
MessageTally spyDetailedOn:[500000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
65 |
Time millisecondsToRun:[500000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
66 |
|
|
|
67 |
MessageTally spyOn:[SystemBrowser open ]
|
|
|
68 |
MessageTally spyDetailedOn:[SystemBrowser open ]
|
|
|
69 |
"
|
|
9
|
70 |
! !
|
|
0
|
71 |
|
|
|
72 |
!MessageTally class methodsFor:'instance creation'!
|
|
|
73 |
|
|
88
|
74 |
spyDetailedOn:aBlock
|
|
|
75 |
"evaluate aBlock and output time statistic on the Transcript.
|
|
|
76 |
Tick is 1ms."
|
|
|
77 |
|
|
|
78 |
^ self spyOn:aBlock interval:1
|
|
|
79 |
!
|
|
|
80 |
|
|
|
81 |
spyOn:aBlock
|
|
|
82 |
"evaluate aBlock and output time statistic on the Transcript.
|
|
|
83 |
Tick is 10ms."
|
|
|
84 |
|
|
|
85 |
^ self spyOn:aBlock interval:10
|
|
|
86 |
!
|
|
|
87 |
|
|
21
|
88 |
spyOn:aBlock interval:ms
|
|
0
|
89 |
"evaluate aBlock and output time statistic on Transcript"
|
|
|
90 |
|
|
21
|
91 |
|runTime aTally nTally|
|
|
0
|
92 |
|
|
|
93 |
aTally := self new.
|
|
21
|
94 |
runTime := aTally spyOn:aBlock interval:ms.
|
|
|
95 |
|
|
|
96 |
aTally tree isNil ifTrue:[
|
|
24
|
97 |
Transcript cr.
|
|
|
98 |
Transcript showCr:'TALLY: No probes - execution time too short;'.
|
|
|
99 |
Transcript showCr:'TALLY: retry using: spyOn:[n timesRepeat:[...]]'.
|
|
21
|
100 |
] ifFalse:[
|
|
24
|
101 |
"/ aTally tree inspect.
|
|
|
102 |
nTally := aTally nTally.
|
|
|
103 |
Transcript cr.
|
|
|
104 |
Transcript showCr:('total execution time: '
|
|
|
105 |
, runTime printString , ' ms '
|
|
|
106 |
, '(' , nTally printString , ' probes ;'
|
|
|
107 |
, ' error >= '
|
|
|
108 |
, (1000 // nTally / 10.0) printString
|
|
|
109 |
, '%)').
|
|
|
110 |
Transcript cr.
|
|
|
111 |
aTally tree printOn:Transcript.
|
|
|
112 |
Transcript cr.
|
|
|
113 |
Transcript cr.
|
|
0
|
114 |
|
|
24
|
115 |
Transcript showCr:'leafs of calling tree:'.
|
|
|
116 |
Transcript cr.
|
|
|
117 |
aTally tree printLeafsOn:Transcript.
|
|
|
118 |
Transcript cr.
|
|
21
|
119 |
|
|
24
|
120 |
"
|
|
|
121 |
aTally statistics.
|
|
|
122 |
"
|
|
21
|
123 |
].
|
|
|
124 |
|
|
|
125 |
"
|
|
|
126 |
MessageTally spyOn:[ #(6 5 4 3 2 1) sort ]
|
|
|
127 |
MessageTally spyOn:[100 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
128 |
MessageTally spyOn:[1000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
129 |
MessageTally spyOn:[10000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
130 |
MessageTally spyOn:[100000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
131 |
MessageTally spyOn:[500000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
132 |
MessageTally spyOn:[SystemBrowser open ]
|
|
|
133 |
MessageTally spyDetailedOn:[SystemBrowser open ]
|
|
|
134 |
Time millisecondsToRun:[500000 timesRepeat:[#(6 5 4 3 2 1) sort] ]
|
|
|
135 |
"
|
|
88
|
136 |
! !
|
|
|
137 |
|
|
|
138 |
!MessageTally methodsFor:'accessing'!
|
|
|
139 |
|
|
|
140 |
nTally
|
|
|
141 |
^ ntally
|
|
0
|
142 |
!
|
|
|
143 |
|
|
88
|
144 |
tree
|
|
|
145 |
^ tree
|
|
0
|
146 |
! !
|
|
|
147 |
|
|
|
148 |
!MessageTally methodsFor:'private'!
|
|
|
149 |
|
|
21
|
150 |
execute
|
|
|
151 |
theBlock value
|
|
|
152 |
! !
|
|
0
|
153 |
|
|
21
|
154 |
!MessageTally methodsFor:'probes'!
|
|
|
155 |
|
|
|
156 |
count:aContext
|
|
|
157 |
|con chain info atEnd sender home|
|
|
0
|
158 |
|
|
21
|
159 |
con := aContext.
|
|
|
160 |
con isNil ifTrue:[^ self].
|
|
0
|
161 |
|
|
21
|
162 |
ntally := ntally + 1.
|
|
|
163 |
"walk up above the interrupt context"
|
|
|
164 |
|
|
|
165 |
[con receiver == Processor] whileTrue:[
|
|
|
166 |
con := con sender
|
|
0
|
167 |
].
|
|
|
168 |
|
|
21
|
169 |
"got it - collect info from contexts"
|
|
|
170 |
|
|
|
171 |
"walk up"
|
|
|
172 |
|
|
|
173 |
con isNil ifTrue:[^ self].
|
|
|
174 |
|
|
|
175 |
atEnd := false.
|
|
0
|
176 |
|
|
21
|
177 |
[atEnd] whileFalse:[
|
|
|
178 |
con isNil ifTrue:[
|
|
|
179 |
atEnd := true
|
|
|
180 |
] ifFalse:[
|
|
|
181 |
sender := con sender.
|
|
|
182 |
sender isNil ifTrue:[
|
|
|
183 |
atEnd := true
|
|
|
184 |
] ifFalse:[
|
|
|
185 |
((sender receiver == self) and:[sender selector == #execute]) ifTrue:[
|
|
|
186 |
atEnd := true
|
|
36
|
187 |
"/ ] ifFalse:[
|
|
|
188 |
"/ (sender isMemberOf:BlockContext) ifTrue:[
|
|
|
189 |
"/ sender sender selector == #execute ifTrue:[
|
|
|
190 |
"/ atEnd := true
|
|
|
191 |
"/ ]
|
|
|
192 |
"/ ]
|
|
21
|
193 |
]
|
|
|
194 |
]
|
|
|
195 |
].
|
|
|
196 |
atEnd ifFalse:[
|
|
|
197 |
info := CallChain new.
|
|
|
198 |
(con isMemberOf:BlockContext) ifTrue:[
|
|
|
199 |
home := con methodHome.
|
|
|
200 |
home isNil ifTrue:[
|
|
|
201 |
info receiver:UndefinedObject
|
|
|
202 |
selector:'optimized'
|
|
|
203 |
class:UndefinedObject.
|
|
|
204 |
] ifFalse:[
|
|
|
205 |
info receiver:home receiver class
|
|
|
206 |
selector:home selector
|
|
|
207 |
class:con methodClass.
|
|
|
208 |
].
|
|
36
|
209 |
info isBlock:true.
|
|
21
|
210 |
] ifFalse:[
|
|
|
211 |
info receiver:con receiver class
|
|
|
212 |
selector:con selector
|
|
|
213 |
class:con methodClass.
|
|
|
214 |
].
|
|
|
215 |
info rest:chain.
|
|
|
216 |
chain := info.
|
|
|
217 |
con := sender
|
|
|
218 |
]
|
|
|
219 |
].
|
|
|
220 |
"add chain to the tree"
|
|
|
221 |
|
|
|
222 |
chain isNil ifTrue:[^ self].
|
|
|
223 |
|
|
|
224 |
tree isNil ifTrue:[
|
|
|
225 |
tree := ProfileTree new.
|
|
36
|
226 |
tree receiver:MessageTally
|
|
|
227 |
selector:#execute
|
|
|
228 |
class:MessageTally .
|
|
0
|
229 |
].
|
|
|
230 |
|
|
21
|
231 |
tree addChain:chain
|
|
|
232 |
! !
|
|
0
|
233 |
|
|
88
|
234 |
!MessageTally methodsFor:'setup'!
|
|
|
235 |
|
|
|
236 |
spyOn:aBlock interval:ms
|
|
|
237 |
"spy on execution time"
|
|
|
238 |
|
|
|
239 |
|startTime endTime running delay|
|
|
|
240 |
|
|
|
241 |
theBlock := aBlock.
|
|
|
242 |
|
|
|
243 |
Processor activeProcess withPriority:23 do:[
|
|
|
244 |
process := [
|
|
|
245 |
[
|
|
|
246 |
self execute
|
|
|
247 |
] valueNowOrOnUnwindDo:[
|
|
|
248 |
running := false.
|
|
|
249 |
theBlock := nil.
|
|
|
250 |
]
|
|
|
251 |
] newProcess.
|
|
|
252 |
|
|
|
253 |
Processor activeProcess withPriority:24 do:[
|
|
|
254 |
startTime := OperatingSystem getMillisecondTime.
|
|
|
255 |
delay := (Delay forMilliseconds:ms).
|
|
|
256 |
|
|
|
257 |
ntally := 0.
|
|
|
258 |
running := true.
|
|
|
259 |
process resume.
|
|
|
260 |
|
|
|
261 |
[running] whileTrue:[
|
|
|
262 |
delay wait.
|
|
|
263 |
self count:process suspendedContext
|
|
|
264 |
].
|
|
|
265 |
|
|
|
266 |
endTime := OperatingSystem getMillisecondTime.
|
|
|
267 |
].
|
|
|
268 |
].
|
|
|
269 |
|
|
|
270 |
tree notNil ifTrue:[tree computePercentage:ntally].
|
|
|
271 |
^ endTime - startTime
|
|
|
272 |
! !
|
|
|
273 |
|
|
98
|
274 |
!MessageTally class methodsFor:'documentation'!
|
|
|
275 |
|
|
|
276 |
version
|
|
119
|
277 |
^ '$Header: /cvs/stx/stx/libbasic3/MessageTally.st,v 1.16 1995-12-09 14:43:06 cg Exp $'
|
|
98
|
278 |
! !
|