Hello,

This *is* amazing stuff....Yamamoto-san wrote a beautiful book as well (it's shown on the Squeakland site in "Media"...). We are making slow in-roads with the Japanese publisher to see about getting that translated into English...

Sumi-san's page (http://sumim.no-ip.com:8080) is as impressive as Yamamoto-san's. The problem is his wiki is too active so that it is hard to translate at any point. Probably online translation proxy may be helpful.

-- Yoshiki

On Thursday 10 June 2004 11:43 am, John Voiklis wrote:

Hello All,

As some of you know, I am doing both Squeak- and Non-Squeak-related research at Teachers College. One such non-Squeak project relates to Richard Mayer's work on multimedia, interactivity, and learning. Without going too much into the details, Mayers experiments included simulations and/or animations of drum brakes, air pumps, et al. For our experiments at TC, I have built a "how drum brakes work" etoy (first URL below), a highly idealized simulation based closely on the simulation used by Mayer. The problem is that it moves slower than mollasses. I don't understand why, given that there are fewer concurrently running scripts than the version of the etoy (second link below) that I used for last semester's experiment. Can anyone help?

Hi John,

You can profile things yourself. From the World menu (which you can get by hitting the ESC key), choose "debug...", then "start/browse MessageTally". Say OK to the dialog.

Now run your simulation for a while and then move the mouse to the top of the screen.

You'll see a time profile. The top part is a representation of the call tree with percentages of time spent in each method, and the bottom is the source text of the method.

So here's a profile from 11 seconds of running your simulation:

- 598 tallies, 11039 msec.

**Tree** 99.8% {11017ms} PasteUpMorph>>doOneCycle 99.8% {11017ms} WorldState>>doOneCycleFor: 99.7% {11006ms} WorldState>>doOneCycleNowFor: 54.7% {6038ms} WorldState>>displayWorldSafely: |54.7% {6038ms} PasteUpMorph>>displayWorld | 54.7% {6038ms} PasteUpMorph>>privateOuterDisplayWorld | 54.7% {6038ms} WorldState>>displayWorld:submorphs: | 47.5% {5244ms} WorldState>>drawWorld:submorphs:invalidAreasOn: | |47.5% {5244ms} FormCanvas(Canvas)>>fullDrawMorph: | | 47.5% {5244ms} FormCanvas(Canvas)>>fullDraw: | | 47.5% {5244ms} ViewerFlapTab(Morph)>>fullDrawOn: | | 25.8% {2848ms} TransformationMorph(TransformMorph)>>drawSubmorphsOn: | | |24.9% {2749ms} FormCanvas>>transformBy:clippingTo:during:smoothing: | | | 24.4% {2694ms} WarpBlt>>warpBits | | 18.7% {2064ms} ViewerFlapTab(Morph)>>drawSubmorphsOn: | | 18.7% {2064ms} FormCanvas(Canvas)>>fullDrawMorph: | | 18.7% {2064ms} FormCanvas(Canvas)>>fullDraw: | | 18.7% {2064ms} ThumbnailMorph(Morph)>>fullDrawOn: | | 18.2% {2009ms} FormCanvas(Canvas)>>drawMorph: | | 18.2% {2009ms} FormCanvas(Canvas)>>draw: [18.2% {2009ms} ThumbnailMorph>>drawOn: [ 16.2% {1788ms} Time class>>millisecondClockValue | 7.2% {795ms} WorldState>>forceDamageToScreen: | 7.2% {795ms} DisplayScreen>>forceDamageToScreen: | 7.2% {795ms} DisplayScreen>>forceToScreen: 44.6% {4923ms} PasteUpMorph>>runStepMethods 44.6% {4923ms} WorldState>>runStepMethodsIn: 44.6% {4923ms} WorldState>>runLocalStepMethodsIn: 44.5% {4912ms} StepMessage(MorphicAlarm)>>value: 44.5% {4912ms} SketchMorph(Morph)>>stepAt: 43.6% {4813ms} Player178202(Player)>>stepAt: 43.6% {4813ms} Player178202(Player)>>runAllTickingScripts: 43.6% {4813ms} ScriptInstantiation>>runIfTicking: 43.6% {4813ms} Player178202>>spin 43.6% {4813ms} Player178202(Player)>>overlaps: 43.5% {4802ms} TransformationMorph(Morph)>>imageForm 43.5% {4802ms} TransformationMorph(Morph)>>imageFormForRectangle: 43.5% {4802ms} TransformationMorph(Morph)>>imageForm:forRectangle: 43.5% {4802ms} FormCanvas(Canvas)>>fullDrawMorph: [43.5% {4802ms} FormCanvas(Canvas)>>fullDraw: [ 43.5% {4802ms} TransformationMorph(Morph)>>fullDrawOn: [ 43.3% {4780ms} TransformationMorph(TransformMorph)>>drawSubmorphsOn: [ 42.5% {4692ms} FormCanvas>>transformBy:clippingTo:during:smoothing: [ 42.1% {4647ms} WarpBlt>>warpBits

**Leaves** 66.6% {7352ms} WarpBlt>>warpBits 16.6% {1832ms} Time class>>millisecondClockValue 7.2% {795ms} DisplayScreen>>forceToScreen: 4.0% {442ms} GrafPort>>copyBits

**Memory** old +1,758,712 bytes young -1,218,592 bytes used +540,120 bytes free -540,120 bytes

**GCs** full 0 totalling 0ms (0.0% uptime) incr 584 totalling 337ms (3.0% uptime), avg 1.0ms tenures 1 (avg 584 GCs/tenure) root table 0 overflows

So what does this mean?

First, the lines that start with a '[' square bracket are just ones that should be indented even further. I have indented them here.

Where you see the percentage of a child item about the same as its parent, it means that the parent isn't spending any time of its own.

So we can go down the tree and see that:

* 7.2% of the time is being spent updating the screen (forceDamageToScreen:) this is because your wheel keeps spinning

* 47.5% of the sime is being spent drawing flap tabs if you hide the flaps your simulation should speed up greatly

so right there is 55% of the CPU time that's being spent.

Avoid the spinning wheel animation and hide the flap tabs and things will speed up a lot.

What more can you do?

Looking further,

* the Player178202 (named Drum; I found this by highlighting the Player178202>>spin line and bringing up the context menu and selecting "inspect instances") is spending 43.6% of the CPU time spinning.

Almost all of that time is being spent in the overlaps: test, and all of that time is being spent in updating the imageForm of the morphs themselves to make stencils to test the overlap. There's no caching being done of those forms.

I notice that Drum is being turned (which accounts for the TransformationMorph you see in the list). It is more costly to get the imageForm from a TransformationMorph (i.e. a rotated Morph) that it is from a SketchMorph that isn't rotated.

What you might want to do is make a non-rotated copy of the Drum and put it behind the rotating Drum and check *that* for overlaps.

So making these changes: - remove flap tabs - make an unrotated copy of Drum (called Drum1) and put it behind Drum. - change Drum's spin script to refer to Drum1 instead of Drum in the overlaps tests

should greatly speed things up.

And in fact, it reduces the time spent in Drum>>spin to 14% (from 43.6%).

Now the thing that's taking up the time is the redraws of TransformationMorphs (76.8%). What's transformed here? Well, the Drum itself, and the CarWheel.

I tried pausing the CarWheel's spinWheel script and found that the percentage of time spent drawing TransformationMorphs went down to 46.6%.

Perhaps you could animate the CarWheel and the Drum using separate images rather than rotating them?

Beyond that, there is definitely room for improvement (in the Smalltalk infrastructure) in the overlaps: test, which could perhaps cache image forms.