[squeak-dev] Profiling
Eliot Miranda
eliot.miranda at gmail.com
Thu Jan 10 19:08:26 UTC 2013
On Wed, Jan 9, 2013 at 8:33 PM, Colin Putney <colin at wiresong.com> wrote:
> Hi all,
>
> I'm trying to optimize some slow code, but having trouble getting a time
> profile that shows where the time is being spent. Here's the results from
> MessageTally class>>spyOn:
>
> - 31249 tallies, 31251 msec.
>
> **Tree**
> --------------------------------
> Process: other processes
> --------------------------------
> 3.9% {1233ms} EventSensor>>eventTickler
> 3.9% {1231ms} Delay>>wait
> --------------------------------
> Process: (40s) 77070: nil
> --------------------------------
> 95.5% {29853ms} ALReadWriteTransaction(ALTransaction)>>commit:
> 95.5% {29848ms} ALReadWriteTransaction>>commit
> 94.7% {29593ms} Dictionary>>keysAndValuesDo:
> 94.7% {29593ms} Dictionary>>associationsDo:
> **Leaves**
> 94.7% {29593ms} Dictionary>>associationsDo:
> 3.9% {1231ms} Delay>>wait
>
> **Memory**
> old +891,120 bytes
> young -273,076 bytes
> used +618,044 bytes
> free -618,044 bytes
>
> **GCs**
> full 0 totalling 0 ms (0% uptime)
> incr 56 totalling 28 ms (0.1% uptime), avg 0.5 ms
> tenures 12 (avg 4 GCs/tenure)
> root table 0 overflows
>
>
>
> Obviously, Dictionary>>associationsDo: isn't really a leaf method. I
> suspect that Cog is generating native code for the contents of the loop and
> it's not getting interrupted by the tally process. (I've tried running on
> an interpreter VM, but it fails with FFI errors, so no help there.)
>
Yes, Cog will generate native code for associationsDo: and the block its
running. No, Cog won't prevent that block being interrupted by the tally
process.
e.g.
| count p |
count := 0.
p := [[count < 10] whileTrue: [(Delay forMilliseconds: 50) wait. count :=
count + 1]] newProcess.
p priority: Processor activePriority + 1.
p resume.
[count < 10] whileTrue: [Smalltalk globals "*" associationsDo: [:nada|]].
count
Substitute a number of blocks, e.g.
| count p |
count := 0.
p := [[count < 10] whileTrue: [(Delay forMilliseconds: 50) wait. count :=
count + 1]] newProcess.
p priority: Processor activePriority + 1.
p resume.
[count < 10] whileTrue: [Smalltalk globals associationsDo: [:nada| | i | i
:= 0. [count < 10] whileTrue: [i even ifTrue: [i := i + 1] ifFalse: [i := i
- 1]]]].
count
However, if all the associationsDo: block does is invoke a primitive then
the Squeak profiler will not produce useful info. The default profiler
doesn't profile primitives correctly. As others in this thread have
pointed out there;s a better profiler written by Andreas Raab, which does
profile primitives properly.
(* in 4.4 use e.g. (Smalltalk globals instVarNamed: 'contents'))
> Anybody have any ideas for how to get a better profile?
>
> Colin
>
BTW, what is the body of that block, if you can make it public?
--
best,
Eliot
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.squeakfoundation.org/pipermail/squeak-dev/attachments/20130110/032f6042/attachment.htm
More information about the Squeak-dev
mailing list
|