<div dir="ltr"><br><div class="gmail_extra"><br><br><div class="gmail_quote">On Wed, Jan 9, 2013 at 8:33 PM, Colin Putney <span dir="ltr"><<a href="mailto:colin@wiresong.com" target="_blank">colin@wiresong.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div dir="ltr">
Hi all,<div><br></div><div>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:</div>
<div><br></div><blockquote style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:40px;border-top-style:none;border-right-style:none;border-bottom-style:none;border-left-style:none;border-width:initial;border-color:initial;padding-top:0px;padding-right:0px;padding-bottom:0px;padding-left:0px">
<div><div><font face="courier new, monospace"> - 31249 tallies, 31251 msec.</font></div></div><div><div><font face="courier new, monospace"><br>
</font></div></div><div><div><font face="courier new, monospace">**Tree**</font></div></div><div><div><font face="courier new, monospace">--------------------------------</font></div></div><div>
<div><font face="courier new, monospace">Process: other processes</font></div></div><div><div><font face="courier new, monospace">--------------------------------</font></div></div><div><div>
<font face="courier new, monospace">3.9% {1233ms} EventSensor>>eventTickler</font></div></div><div><div><font face="courier new, monospace"> 3.9% {1231ms} Delay>>wait</font></div></div><div>
<div><font face="courier new, monospace">--------------------------------</font></div></div><div><div><font face="courier new, monospace">Process: (40s) 77070: nil</font></div></div><div><div>
<font face="courier new, monospace">--------------------------------</font></div></div><div><div><font face="courier new, monospace">95.5% {29853ms} ALReadWriteTransaction(ALTransaction)>>commit:</font></div>
</div><div><div><font face="courier new, monospace"> 95.5% {29848ms} ALReadWriteTransaction>>commit</font></div></div><div><div><font face="courier new, monospace"> 94.7% {29593ms} Dictionary>>keysAndValuesDo:</font></div>
</div><div><div><font face="courier new, monospace"> 94.7% {29593ms} Dictionary>>associationsDo:</font></div></div><div><div><font face="courier new, monospace">**Leaves**</font></div></div>
<div><div><font face="courier new, monospace">94.7% {29593ms} Dictionary>>associationsDo:</font></div></div><div><div><font face="courier new, monospace">3.9% {1231ms} Delay>>wait</font></div>
</div><div><div><font face="courier new, monospace"><br></font></div></div><div><div><font face="courier new, monospace">**Memory**</font></div></div><div><div><font face="courier new, monospace"><span style="white-space:pre-wrap"> </span>old<span style="white-space:pre-wrap"> </span>+891,120 bytes</font></div>
</div><div><div><font face="courier new, monospace"><span style="white-space:pre-wrap"> </span>young<span style="white-space:pre-wrap"> </span>-273,076 bytes</font></div></div><div><div><font face="courier new, monospace"><span style="white-space:pre-wrap"> </span>used<span style="white-space:pre-wrap"> </span>+618,044 bytes</font></div>
</div><div><div><font face="courier new, monospace"><span style="white-space:pre-wrap"> </span>free<span style="white-space:pre-wrap"> </span>-618,044 bytes</font></div></div><div><div><font face="courier new, monospace"><br>
</font></div></div><div><div><font face="courier new, monospace">**GCs**</font></div></div><div><div><font face="courier new, monospace"><span style="white-space:pre-wrap"> </span>full<span style="white-space:pre-wrap"> </span>0 totalling 0 ms (0% uptime)</font></div>
</div><div><div><font face="courier new, monospace"><span style="white-space:pre-wrap"> </span>incr<span style="white-space:pre-wrap"> </span>56 totalling 28 ms (0.1% uptime), avg 0.5 ms</font></div>
</div><div><div><font face="courier new, monospace"><span style="white-space:pre-wrap"> </span>tenures<span style="white-space:pre-wrap"> </span>12 (avg 4 GCs/tenure)</font></div></div><div><div>
<font face="courier new, monospace"><span style="white-space:pre-wrap"> </span>root table<span style="white-space:pre-wrap"> </span>0 overflows</font></div></div></blockquote><div><div> </div><div><br></div>
<div><br></div><div>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.)</div>
</div></div></blockquote><div><br></div><div>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.</div><div><br></div>
<div>e.g.</div><div><br></div><div>| count p |</div><div>count := 0.</div><div>p := [[count < 10] whileTrue: [(Delay forMilliseconds: 50) wait. count := count + 1]] newProcess.</div><div>p priority: Processor activePriority + 1.</div>
<div>p resume.</div><div>[count < 10] whileTrue: [Smalltalk globals "*" associationsDo: [:nada|]].</div><div>count</div><div><br></div><div>Substitute a number of blocks, e.g.</div><div><br></div><div>| count p |</div>
<div>count := 0.</div><div>p := [[count < 10] whileTrue: [(Delay forMilliseconds: 50) wait. count := count + 1]] newProcess.</div><div>p priority: Processor activePriority + 1.</div><div>p resume.</div><div>[count < 10] whileTrue: [Smalltalk globals associationsDo: [:nada| | i | i := 0. [count < 10] whileTrue: [i even ifTrue: [i := i + 1] ifFalse: [i := i - 1]]]].</div>
<div>count</div><div><br></div><div>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.</div>
<div><br></div><div>(* in 4.4 use e.g. (Smalltalk globals instVarNamed: 'contents'))</div><div><br></div><blockquote class="gmail_quote" style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div dir="ltr"><div>
<div><br></div><div>Anybody have any ideas for how to get a better profile?</div><span class=""><font color="#888888"><div><br></div><div>Colin</div></font></span></div></div></blockquote><div><br></div><div>BTW, what is the body of that block, if you can make it public? </div>
</div>-- <br>best,<div>Eliot</div>
</div></div>