Profiling?

Herbert König herbertkoenig at gmx.net
Thu Apr 6 17:53:35 UTC 2006


Hello Hilaire,

HF> I have tried the MessageTally, however I don't really understand the
HF> output and the data does not seem practical to use, I can't really see
HF> where are the bottleneck from this data.

I ran into similar problems once. As far as I understand the callstack
is sampled at certain intervals to build the analysis.

So generally if you have something that is controlled by some UI you
will find World>>doOneCycleFor: on the top and it gets hard to
understand. Otherwise it seems quite straightforward to me.
On top you find what you spied on and then you find every method with
the time spent in it.

Time for top level seems (I believe) to include the time for all sends
which happen in this message down to the leaves.

There is an issue with primitives which are not interrupted by
MessageTally, so they will not show up.

The [[ break the indentation, I wished this would happen less. Maybe
it's easy to change, even for me :-))

So one thing is not to use WorldMenu, debug, start/browse MessageTally
but to use MessageTally>>spyOn: aBlock.

This is obtained with spyOn:
 - 2461 tallies, 2462 msec.

**Tree**
97.4% {2398ms} AssemblerAuswertungApp>>oldCollectEvaluateDisplay
  |85.1% {2095ms} ProduktionsDatenKommentiert>>collectCommentedPrüfRepRecords
  |  |85.1% {2095ms} ProduktionsDatenbankAnbindung>>collectComment...m:andZeitraum:
  |  |  67.6% {1664ms} ProduktionsDatenbankAnbindung>>collectComment...m:andZeitraum:
  |  |    |67.2% {1654ms} ProduktionsDatenbankAnbindung>>copyRecordsFro...o:usingSource:
  <<-- now the culprit in the MySQL driver
  |  |    |  62.3% {1534ms} JdmResultSet>>currentRowAsDictionary   <<-
  <<-- solution was to use something else
  |  |    |    |57.5% {1416ms} JdmResultSet>>valueNamed:
  |  |    |    |  |55.8% {1374ms} JdmResultSet>>valueAt:

If I do the same profiling via the UI I get like you an endless list.
One half happens inside HandMorph's events and the other half
somewhere in the drawing routines.

If you have thousands of Morphs you might have problems due to the
fact hat HandMorph spends a lot of time trying to find out to whom to
dispatch mouse events.

This one seems the first one which is written by you.
>> DrGDrawable(PasteUpMorph)>>processEvent:using:
>>       |  |  |      |        |        31.6% {1168ms}


HF> Are there alternative tools for profiling?
If you have a suspicion already:

Time millisecondsToRun: [10000 timesRepeat: [yourSuspiciousMethod]]

Doug Way said in Dec2004:
This and other performance tuning tips are on this swiki page:

http://minnow.cc.gatech.edu/squeak/1799

In 2005 Alexandre Bergel wanted to do some work on profiling, maybe he
did something. (Brainstorming on profiling)

Anyway if you find something let me know for I'm interested too though
I have no pressing needs right now.

I don't know much about the inner working of squeak so maybe others
give more qualified help :-))

Cheers

Herbert                            mailto:herbertkoenig at gmx.net




More information about the Squeak-dev mailing list