Poor TTF font performance on Linux with newer VM

Hi all,

I have recently been building VMs on Linux (to fix a bug in the
FilePlugin), and with my shiny new patched 3.9-7 VM (build from the head
of svn plus my patch) the TTF font performance (Bitstream Vera Sans) has
dropped through the floor.

I'm using a BookMorph with lots of Bitstream text morphs, and switching
pages causes the CPU to peg at 100% in Squeak for several seconds.

Switching back to a 3.7-7 VM causes the font rendering to run at normal
speed again - even when I take a 3.7-7 source tree, patch it to fix the
FilePlugin bug, and recompile.

So - it looks like something between 3.7-7 and 3.9-7 causes the TTF
performance to bottom out. What could it be? Any ideas?

Tony

PS. all this is on Debian, gcc 4.0.4, and I could be wrong about
identifying font rendering as the problem area. I know Squeak suddenly
seems to take a looooong time to do anything TTF related - strike fonts
seem to run at normal speed.

--
 [][][] Tony Garnock-Jones     | Mob: +44 (0)7905 974 211
   [][] LShift Ltd             | Tel: +44 (0)20 7729 7060
 []  [] http://www.lshift.net/ | Email: [hidden email]

On Thu, May 18, 2006 at 10:40:58AM +0100, Tony Garnock-Jones wrote:
I don't know the answer to your question, but from what you're
describing I might guess the TTF font rendering uses some plugin
that is missing from your new VM. Check "Smalltalk listLoadedModules"
on your 3.7-7 VM (after doing something with your BookMorph) and
see if it shows some plugin that you have not included in your
3.9-7 build.

Dave

Thanks for that - I had suspected it might be a plugin. I've followed
your suggestion, and the plugin list is almost identical except for
OSProcess and FFI plugins.

I've just run "MessageTally spyOn: [3 timesRepeat: [self nextPage]]" on
my BookMorph. The two results are dramatically different: on the 3.7 VM,
477ms for the whole thing; on the 3.9 VM, 50354ms for the whole thing! A
factor of 100x slower.

I've attached the traces, in case they're meaningful at a glance to
anyone reading.

Regards,
  Tony

David T. Lewis wrote:
--
 [][][] Tony Garnock-Jones     | Mob: +44 (0)7905 974 211
   [][] LShift Ltd             | Tel: +44 (0)20 7729 7060
 []  [] http://www.lshift.net/ | Email: [hidden email]

 - 461 tallies, 477 msec.

**Tree**
100.0% {477ms} BookMorph>>nextPage
  100.0% {477ms} BookMorph>>goToPage:
    100.0% {477ms} BookMorph>>goToPage:transitionSpec:
      100.0% {477ms} BookMorph>>goToPageMorph:transitionSpec:
        57.7% {275ms} PasteUpMorph>>displayWorld
          |57.7% {275ms} PasteUpMorph>>privateOuterDisplayWorld
          |  57.7% {275ms} WorldState>>displayWorld:submorphs:
          |    57.7% {275ms} WorldState>>drawWorld:submorphs:invalidAreasOn:
          |      57.7% {275ms} FormCanvas(Canvas)>>fullDrawMorph:
          |        57.7% {275ms} FormCanvas(Canvas)>>fullDraw:
          |          57.7% {275ms} BookMorph(Morph)>>fullDrawOn:
          |            57.7% {275ms} BookMorph(Morph)>>drawSubmorphsOn:
          |              57.7% {275ms} FormCanvas(Canvas)>>fullDrawMorph:
          |                57.7% {275ms} FormCanvas(Canvas)>>fullDraw:
          |                  57.7% {275ms} PasteUpMorph(Morph)>>fullDrawOn:
          |                    52.3% {249ms} PasteUpMorph>>drawSubmorphsOn:
          |                      |52.3% {249ms} FormCanvas(Canvas)>>fullDrawMorph:
[52.3% {249ms} FormCanvas(Canvas)>>fullDraw:
[  52.3% {249ms} TextMorph(Morph)>>fullDrawOn:
[    52.3% {249ms} FormCanvas(Canvas)>>drawMorph:
[      52.3% {249ms} FormCanvas(Canvas)>>draw:
[        52.3% {249ms} TextMorph>>drawOn:
[          30.6% {146ms} FormCanvas>>paragraph:bounds:color:
[            |30.6% {146ms} MultiNewParagraph>>displayOn:using:at:
[            |  30.6% {146ms} MultiDisplayScanner>>displayLine:offset:leftInRun:
[            |    27.1% {129ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
[            |      19.3% {92ms} TTCFont>>glyphInfoOf:into:
[            |        |11.3% {54ms} TTCFont>>ascentOf:
[            |        |  |11.3% {54ms} TTCFont>>ascent
[            |        |  |  6.7% {32ms} TTCFont>>pixelSize
[            |        |  |    |6.7% {32ms} TextStyle class>>pointsToPixels:
[            |        |  |    |  6.7% {32ms} TextStyle class>>pixelsPerInch
[            |        |  |    |    6.7% {32ms} Dictionary>>at:ifAbsentPut:
[            |        |  |    |      5.2% {25ms} Dictionary>>at:ifAbsent:
[[3.0% {14ms} primitives
[[2.2% {10ms} Dictionary(Set)>>findElementOrNil:
[[  2.2% {10ms} Dictionary>>scanFor:
[[    2.2% {10ms} ByteSymbol(String)>>hash
[            |        |  |  4.6% {22ms} Float(Number)>>//
[            |        |  |    3.0% {14ms} primitives
[            |        |8.0% {38ms} TTCFont>>formOf:
[            |        |  8.0% {38ms} TTCFont>>computeForm:
[            |        |    6.3% {30ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
[            |        |      6.3% {30ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
[            |        |        6.3% {30ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
[            |        |          5.0% {24ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
[            |        |            3.0% {14ms} BalloonCanvas>>ensuredEngine
[[3.0% {14ms} BalloonEngine class(Behavior)>>new
[[  3.0% {14ms} BalloonEngine>>initialize
[[    3.0% {14ms} BalloonEngine>>bitBlt:
[            |      2.8% {13ms} primitives
[          21.7% {104ms} TextMorph>>paragraph
[            21.7% {104ms} MultiNewParagraph(NewParagraph)>>compose:style:from:in:
[              21.7% {104ms} MultiNewParagraph(NewParagraph)>>composeAll
[                21.7% {104ms} MultiNewParagraph(NewParagraph)>>composeLinesFrom:to:delta:into:priorLines:atY:
[                  21.7% {104ms} TextComposer>>composeLinesFrom:to:del...ner:wantsColumnBreaks:
[                    21.7% {104ms} TextComposer>>composeAllLines
[                      21.7% {104ms} TextComposer>>composeOneLine
[                        21.7% {104ms} TextComposer>>composeAllRectangles:
[                          21.7% {104ms} TextComposer>>composeEachRectangleIn:
[                            21.7% {104ms} CompositionScanner>>composeFrom:inRectan...leftSide:rightSide:
[                              19.7% {94ms} CompositionScanner(CharacterScanner)>>scanCharactersFrom:to...stopConditions:kern:
[                                19.7% {94ms} CompositionScanner(CharacterScanner)>>basicScanCharactersFr...stopConditions:kern:
[[19.7% {94ms} TTCFont>>widthOf:
[[  19.7% {94ms} TTCFont>>computeForm:
[[    17.6% {84ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
[[      |17.6% {84ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
[[      |  17.6% {84ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
[[      |    12.6% {60ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
[[      |      |9.1% {43ms} BalloonEngine>>drawGeneralBezierShape...borderColor:transform:
[[      |      |  |4.8% {23ms} BalloonEngine>>postFlushIfNeeded
[[      |      |  |  |4.8% {23ms} BalloonEngine>>copyBits
[[      |      |  |  |  4.8% {23ms} BalloonEngine>>copyLoopFaster
[[      |      |  |4.3% {21ms} BalloonEngine>>registerFill:and:
[[      |      |  |  4.3% {21ms} BalloonEngine>>registerFills:
[[      |      |  |    2.4% {11ms} BalloonEngine>>registerFill:
[[      |      |3.5% {17ms} BalloonCanvas>>ensuredEngine
[[      |    5.0% {24ms} MatrixTransform2x3 class>>withScale:
[[    2.2% {10ms} TTCFont>>pixelSize
[[      2.2% {10ms} TextStyle class>>pointsToPixels:
[[        2.2% {10ms} TextStyle class>>pixelsPerInch
[[          2.2% {10ms} Dictionary>>at:ifAbsentPut:
[[            2.2% {10ms} Dictionary>>at:ifAbsent:
[[              2.2% {10ms} Dictionary(Set)>>findElementOrNil:
[[                2.2% {10ms} Dictionary>>scanFor:
[[                  2.2% {10ms} ByteSymbol(String)>>hash
[[                    2.2% {10ms} ByteString class(Object)>>hash
          |                    2.8% {13ms} FormCanvas(Canvas)>>drawMorph:
          |                      2.8% {13ms} FormCanvas(Canvas)>>draw:
[2.8% {13ms} PasteUpMorph>>drawOn:
[  2.8% {13ms} PasteUpMorph(Morph)>>drawOn:
[    2.8% {13ms} FormCanvas(Canvas)>>fillRectangle:fillStyle:borderStyle:
[      2.8% {13ms} FormCanvas>>fillRectangle:fillStyle:
[        2.8% {13ms} FormCanvas>>balloonFillRectangle:fillStyle:
[          2.8% {13ms} BalloonCanvas>>fillRectangle:fillStyle:
[            2.8% {13ms} BalloonCanvas>>drawRectangle:color:borderWidth:borderColor:
[              2.8% {13ms} BalloonEngine>>drawRectangle:fill:bor...borderColor:transform:
[                2.8% {13ms} BalloonEngine>>postFlushIfNeeded
[                  2.8% {13ms} BalloonEngine>>copyBits
[                    2.8% {13ms} BalloonEngine>>copyLoopFaster
        38.8% {185ms} PasteUpMorph(Morph)>>updateCachedThumbnail
          |38.8% {185ms} BookPageThumbnailMorph>>computeThumbnail
          |  38.8% {185ms} PasteUpMorph(Morph)>>imageForm
          |    38.8% {185ms} PasteUpMorph(Morph)>>imageFormForRectangle:
          |      38.8% {185ms} PasteUpMorph(Morph)>>imageForm:forRectangle:
          |        38.8% {185ms} FormCanvas(Canvas)>>fullDrawMorph:
          |          38.8% {185ms} FormCanvas(Canvas)>>fullDraw:
          |            38.8% {185ms} PasteUpMorph(Morph)>>fullDrawOn:
          |              31.2% {149ms} PasteUpMorph>>drawSubmorphsOn:
          |                |31.2% {149ms} FormCanvas(Canvas)>>fullDrawMorph:
          |                |  31.2% {149ms} FormCanvas(Canvas)>>fullDraw:
          |                |    31.2% {149ms} TextMorph(Morph)>>fullDrawOn:
          |                |      31.2% {149ms} FormCanvas(Canvas)>>drawMorph:
[31.2% {149ms} FormCanvas(Canvas)>>draw:
[  31.2% {149ms} TextMorph>>drawOn:
[    31.2% {149ms} FormCanvas>>paragraph:bounds:color:
[      31.2% {149ms} MultiNewParagraph>>displayOn:using:at:
[        31.2% {149ms} MultiDisplayScanner>>displayLine:offset:leftInRun:
[          28.2% {135ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
[            19.1% {91ms} TTCFont>>glyphInfoOf:into:
[              |17.6% {84ms} TTCFont>>ascentOf:
[              |  17.6% {84ms} TTCFont>>ascent
[              |    15.0% {72ms} TTCFont>>pixelSize
[              |      |15.0% {72ms} TextStyle class>>pointsToPixels:
[              |      |  15.0% {72ms} TextStyle class>>pixelsPerInch
[              |      |    15.0% {72ms} Dictionary>>at:ifAbsentPut:
[              |      |      13.2% {63ms} Dictionary>>at:ifAbsent:
[              |      |        8.9% {42ms} primitives
[              |      |        4.3% {21ms} Dictionary(Set)>>findElementOrNil:
[              |      |          2.4% {11ms} Dictionary>>scanFor:
[              |    2.6% {12ms} Float(Number)>>//
[            4.8% {23ms} GrafPort(BitBlt)>>sourceForm:
[            2.8% {13ms} primitives
          |              7.6% {36ms} FormCanvas(Canvas)>>drawMorph:
          |                7.6% {36ms} FormCanvas(Canvas)>>draw:
          |                  7.6% {36ms} PasteUpMorph>>drawOn:
          |                    7.6% {36ms} PasteUpMorph(Morph)>>drawOn:
          |                      7.6% {36ms} FormCanvas(Canvas)>>fillRectangle:fillStyle:borderStyle:
[7.6% {36ms} FormCanvas>>fillRectangle:fillStyle:
[  7.6% {36ms} FormCanvas>>balloonFillRectangle:fillStyle:
[    7.6% {36ms} BalloonCanvas>>fillRectangle:fillStyle:
[      7.6% {36ms} BalloonCanvas>>drawRectangle:color:borderWidth:borderColor:
[        7.6% {36ms} BalloonEngine>>drawRectangle:fill:bor...borderColor:transform:
[          7.6% {36ms} BalloonEngine>>postFlushIfNeeded
[            7.6% {36ms} BalloonEngine>>copyBits
[              7.6% {36ms} BalloonEngine>>copyLoopFaster
        3.5% {17ms} PasteUpMorph>>startSteppingSubmorphsOf:
          3.5% {17ms} PasteUpMorph(Morph)>>arrangeToStartSteppingIn:

**Leaves**
16.9% {81ms} BalloonEngine>>copyLoopFaster
13.2% {63ms} Dictionary>>at:ifAbsent:
6.5% {31ms} GrafPort(BitBlt)>>sourceForm:
5.6% {27ms} Float(Number)>>//
5.6% {27ms} Array(SequenceableCollection)>>do:
5.6% {27ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
5.0% {24ms} MatrixTransform2x3 class>>withScale:
3.7% {18ms} Dictionary(Set)>>findElementOrNil:
3.5% {17ms} Float(Number)>>floor
3.5% {17ms} Rectangle>>setOrigin:corner:
3.3% {16ms} Dictionary>>at:ifAbsentPut:
3.3% {16ms} ByteString class(Object)>>hash
3.3% {16ms} GrafPort(BitBlt)>>sourceOrigin:
3.0% {14ms} Point>>extent:
2.4% {11ms} BalloonEngine>>registerFill:
2.2% {10ms} ByteSymbol(String)>>hash

**Memory**
        old +832,264 bytes
        young -549,516 bytes
        used +282,748 bytes
        free -282,748 bytes

**GCs**
        full 0 totalling 0ms (0.0% uptime)
        incr 47 totalling 37ms (8.0% uptime), avg 1.0ms
        tenures 1 (avg 47 GCs/tenure)
        root table 0 overflows

 - 50151 tallies, 50354 msec.

**Tree**
100.0% {50354ms} BookMorph>>nextPage
  100.0% {50354ms} BookMorph>>goToPage:
    100.0% {50354ms} BookMorph>>goToPage:transitionSpec:
      100.0% {50354ms} BookMorph>>goToPageMorph:transitionSpec:
        61.2% {30817ms} PasteUpMorph(Morph)>>updateCachedThumbnail
          |61.2% {30817ms} BookPageThumbnailMorph>>computeThumbnail
          |  61.2% {30817ms} PasteUpMorph(Morph)>>imageForm
          |    61.2% {30817ms} PasteUpMorph(Morph)>>imageFormForRectangle:
          |      61.2% {30817ms} PasteUpMorph(Morph)>>imageForm:forRectangle:
          |        61.2% {30817ms} FormCanvas(Canvas)>>fullDrawMorph:
          |          61.2% {30817ms} FormCanvas(Canvas)>>fullDraw:
          |            61.2% {30817ms} PasteUpMorph(Morph)>>fullDrawOn:
          |              61.2% {30817ms} PasteUpMorph>>drawSubmorphsOn:
          |                61.2% {30817ms} FormCanvas(Canvas)>>fullDrawMorph:
          |                  61.2% {30817ms} FormCanvas(Canvas)>>fullDraw:
          |                    61.2% {30817ms} TextMorph(Morph)>>fullDrawOn:
          |                      61.1% {30766ms} FormCanvas(Canvas)>>drawMorph:
[61.1% {30766ms} FormCanvas(Canvas)>>draw:
[  61.1% {30766ms} TextMorph>>drawOn:
[    61.1% {30766ms} FormCanvas>>paragraph:bounds:color:
[      61.1% {30766ms} MultiNewParagraph>>displayOn:using:at:
[        61.1% {30766ms} MultiDisplayScanner>>displayLine:offset:leftInRun:
[          29.2% {14703ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
[            |27.5% {13847ms} TTCFont>>glyphInfoOf:into:
[            |  20.0% {10071ms} TTCFont>>formOf:
[            |    |19.2% {9668ms} TTCFont>>computeForm:
[            |    |  17.8% {8963ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
[            |    |    17.8% {8963ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
[            |    |      17.8% {8963ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
[            |    |        10.5% {5287ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
[            |    |          |7.7% {3877ms} BalloonCanvas>>ensuredEngine
[            |    |          |  |7.6% {3827ms} BalloonEngine class(Behavior)>>new
[            |    |          |  |  7.6% {3827ms} BalloonEngine>>initialize
[            |    |          |  |    7.0% {3525ms} BitBlt class>>toForm:
[[6.7% {3374ms} primitives
[            |    |          |2.6% {1309ms} BalloonEngine>>drawGeneralBezierShape...borderColor:transform:
[            |    |        3.6% {1813ms} Form class>>extent:depth:
[            |    |          |3.6% {1813ms} Form>>setExtent:depth:
[            |    |          |  3.6% {1813ms} primitives
[            |    |        2.8% {1410ms} Form(DisplayMedium)>>fillColor:
[            |  6.6% {3323ms} TTCFont>>ascentOf:
[            |    6.6% {3323ms} TTCFont>>ascent
[            |      4.4% {2216ms} TTCFont>>pixelSize
[            |        |4.4% {2216ms} TextStyle class>>pointsToPixels:
[            |        |  4.4% {2216ms} TextStyle class>>pixelsPerInch
[            |        |    4.1% {2065ms} Dictionary>>at:ifAbsentPut:
[            |        |      4.1% {2065ms} Dictionary>>at:ifAbsent:
[            |        |        3.0% {1511ms} Dictionary(Set)>>findElementOrNil:
[            |        |          2.7% {1360ms} Dictionary>>scanFor:
[            |      2.2% {1108ms} Float(Number)>>//
[          28.0% {14099ms} MultiDisplayScanner(MultiCharacterScanner)>>scanCharactersFrom...opConditions:kern:
[            |28.0% {14099ms} MultiDisplayScanner(MultiCharacterScanner)>>basicScanCharacter...opConditions:kern:
[            |  28.0% {14099ms} TTCFont>>widthOf:
[            |    26.4% {13293ms} TTCFont>>computeForm:
[            |      25.8% {12991ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
[            |        25.8% {12991ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
[            |          25.8% {12991ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
[            |            19.8% {9970ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
[            |              |14.9% {7503ms} BalloonCanvas>>ensuredEngine
[            |              |  |14.2% {7150ms} BalloonEngine class(Behavior)>>new
[            |              |  |  14.2% {7150ms} BalloonEngine>>initialize
[            |              |  |    12.2% {6143ms} BitBlt class>>toForm:
[[12.2% {6143ms} primitives
[            |              |5.0% {2518ms} BalloonEngine>>drawGeneralBezierShape...borderColor:transform:
[            |              |  3.1% {1561ms} BalloonEngine>>registerFill:and:
[            |              |    3.1% {1561ms} BalloonEngine>>registerFills:
[            |              |      2.5% {1259ms} BalloonEngine>>registerFill:
[            |            2.8% {1410ms} Form(DisplayMedium)>>fillColor:
[          3.1% {1561ms} MultiDisplayScanner>>endOfRun
[            3.0% {1511ms} MultiDisplayScanner>>setStopConditions
[              3.0% {1511ms} MultiDisplayScanner>>setFont
[                3.0% {1511ms} MultiDisplayScanner(MultiCharacterScanner)>>setFont
[                  3.0% {1511ms} TTCFont>>widthOf:
[                    2.5% {1259ms} TTCFont>>computeForm:
[                      2.5% {1259ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
[                        2.5% {1259ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
[                          2.5% {1259ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
        38.2% {19235ms} PasteUpMorph>>displayWorld
          38.2% {19235ms} PasteUpMorph>>privateOuterDisplayWorld
            38.2% {19235ms} WorldState>>displayWorld:submorphs:
              38.2% {19235ms} WorldState>>drawWorld:submorphs:invalidAreasOn:
                38.2% {19235ms} FormCanvas(Canvas)>>fullDrawMorph:
                  38.2% {19235ms} FormCanvas(Canvas)>>fullDraw:
                    38.2% {19235ms} BookMorph(Morph)>>fullDrawOn:
                      38.2% {19235ms} BookMorph(Morph)>>drawSubmorphsOn:
                        38.2% {19235ms} FormCanvas(Canvas)>>fullDrawMorph:
                          38.2% {19235ms} FormCanvas(Canvas)>>fullDraw:
                            38.2% {19235ms} PasteUpMorph(Morph)>>fullDrawOn:
                              37.4% {18832ms} PasteUpMorph>>drawSubmorphsOn:
                                37.4% {18832ms} FormCanvas(Canvas)>>fullDrawMorph:
[37.4% {18832ms} FormCanvas(Canvas)>>fullDraw:
[  37.4% {18832ms} TextMorph(Morph)>>fullDrawOn:
[    37.3% {18782ms} FormCanvas(Canvas)>>drawMorph:
[      37.3% {18782ms} FormCanvas(Canvas)>>draw:
[        37.3% {18782ms} TextMorph>>drawOn:
[          30.7% {15459ms} FormCanvas>>paragraph:bounds:color:
[            |30.7% {15459ms} MultiNewParagraph>>displayOn:using:at:
[            |  30.7% {15459ms} MultiDisplayScanner>>displayLine:offset:leftInRun:
[            |    16.1% {8107ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
[            |      |11.9% {5992ms} TTCFont>>glyphInfoOf:into:
[            |      |  6.9% {3474ms} TTCFont>>ascentOf:
[            |      |    |6.9% {3474ms} TTCFont>>ascent
[            |      |    |  4.7% {2367ms} TTCFont>>pixelSize
[            |      |    |    4.4% {2216ms} TextStyle class>>pointsToPixels:
[            |      |    |      4.4% {2216ms} TextStyle class>>pixelsPerInch
[            |      |    |        4.2% {2115ms} Dictionary>>at:ifAbsentPut:
[            |      |    |          3.6% {1813ms} Dictionary>>at:ifAbsent:
[            |      |  5.0% {2518ms} TTCFont>>formOf:
[            |      |    4.7% {2367ms} TTCFont>>computeForm:
[            |      |      3.8% {1913ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
[            |      |        3.8% {1913ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
[            |      |          3.8% {1913ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
[            |      |            2.1% {1057ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
[            |    11.3% {5690ms} MultiDisplayScanner(MultiCharacterScanner)>>scanCharactersFrom...opConditions:kern:
[            |      11.3% {5690ms} MultiDisplayScanner(MultiCharacterScanner)>>basicScanCharacter...opConditions:kern:
[            |        11.2% {5640ms} TTCFont>>widthOf:
[            |          11.2% {5640ms} TTCFont>>computeForm:
[            |            9.8% {4935ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
[            |              9.8% {4935ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
[            |                9.8% {4935ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
[            |                  5.8% {2921ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
[            |                    3.4% {1712ms} BalloonCanvas>>ensuredEngine
[            |                    2.4% {1208ms} BalloonEngine>>drawGeneralBezierShape...borderColor:transform:
[          6.6% {3323ms} TextMorph>>paragraph
[            6.6% {3323ms} MultiNewParagraph(NewParagraph)>>compose:style:from:in:
[              6.6% {3323ms} MultiNewParagraph(NewParagraph)>>composeAll
[                6.6% {3323ms} MultiNewParagraph(NewParagraph)>>composeLinesFrom:to:delta:into:priorLines:atY:
[                  6.6% {3323ms} TextComposer>>composeLinesFrom:to:del...ner:wantsColumnBreaks:
[                    6.6% {3323ms} TextComposer>>composeAllLines
[                      6.6% {3323ms} TextComposer>>composeOneLine
[                        6.6% {3323ms} TextComposer>>composeAllRectangles:
[                          6.6% {3323ms} TextComposer>>composeEachRectangleIn:
[                            6.4% {3223ms} CompositionScanner>>composeFrom:inRectan...leftSide:rightSide:
[                              6.1% {3072ms} CompositionScanner(CharacterScanner)>>scanCharactersFrom:to...stopConditions:kern:
[                                6.1% {3072ms} CompositionScanner(CharacterScanner)>>basicScanCharactersFr...stopConditions:kern:
[[6.1% {3072ms} TTCFont>>widthOf:
[[  5.8% {2921ms} TTCFont>>computeForm:
[[    4.6% {2316ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
[[      4.6% {2316ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
[[        4.6% {2316ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
[[          2.9% {1460ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:

**Leaves**
20.3% {10222ms} BitBlt class>>toForm:
6.1% {3072ms} Form>>setExtent:depth:
5.3% {2669ms} Rectangle>>setOrigin:corner:
3.6% {1813ms} Dictionary>>at:ifAbsent:
3.3% {1662ms} Point>>+
3.0% {1511ms} Dictionary>>scanFor:
3.0% {1511ms} Float(Number)>>//
2.8% {1410ms} Point>>*
2.5% {1259ms} Association>>key:value:
2.5% {1259ms} Form(DisplayMedium)>>fillColor:
2.2% {1108ms} Color>>pixelWordFor:filledWith:
2.2% {1108ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
2.1% {1057ms} BalloonEngine>>copyLoopFaster

**Memory**
        old +1,565,496 bytes
        young -1,278,376 bytes
        used +287,120 bytes
        free +1,279,316 bytes

**GCs**
        full 1 totalling 200ms (0.0% uptime), avg 200.0ms
        incr 518 totalling 1,117ms (2.0% uptime), avg 2.0ms
        tenures 2 (avg 259 GCs/tenure)
        root table 0 overflows

Hi!

Tony Garnock-Jones <[hidden email]> wrote:
> Thanks for that - I had suspected it might be a plugin. I've followed
> your suggestion, and the plugin list is almost identical except for
> OSProcess and FFI plugins.
>
> I've just run "MessageTally spyOn: [3 timesRepeat: [self nextPage]]" on
> my BookMorph. The two results are dramatically different: on the 3.7 VM,
> 477ms for the whole thing; on the 3.9 VM, 50354ms for the whole thing! A
> factor of 100x slower.

Just wanted to mention that this might indeed be the issue I have been
experiencing with the new VM in my IRCe image - I thought it had to do
with Socket communication, but hey, it might as well be this in fact.

regards, Göran

Are you saying that your 3.9 VM does *not* have the FFI plugin? If
that is the case, try adding it to the build in case FFI is being
used for the TTF fonts in some way.

But your message tally seems to be pointing to BitBlt, which would
suggest the BitBltPlugin, but I don't think anything would be working
at all if BitBltPlugin was not working. That's all I can think of,
maybe someone else can spot what's wrong?

Dave

On Thu, May 18, 2006 at 11:53:55AM +0100, Tony Garnock-Jones wrote:
>

David T. Lewis wrote:
> Are you saying that your 3.9 VM does *not* have the FFI plugin? If
> that is the case, try adding it to the build in case FFI is being
> used for the TTF fonts in some way.

No, the 3.9 VM *does* have an internal SqueakFFIPrims, whereas the 3.7
VM does *not* have an internal SqueakFFIPrims.

Conversely, the 3.7 VM has an internal UnixOSProcessPlugin, where the
3.9 VM does not (it is external and present in the lib directory, though
not loaded).

Summary of changes (excluding version differences):

Present only in 3.7-7: AioPlugin, UnixOSProcessPlugin
Present only in 3.9-4, 3.9-7, SVN trunk: CroquetPlugin, FloatMathPlugin
The lists are otherwise the same.

Tony
--
 [][][] Tony Garnock-Jones     | Mob: +44 (0)7905 974 211
   [][] LShift Ltd             | Tel: +44 (0)20 7729 7060
 []  [] http://www.lshift.net/ | Email: [hidden email]

I've just checked against 3.9-4 (built from source tarball from
squeakvm.org), and it's still hideously slow. So it's down to something
that changed between 3.7-7 and 3.9-4. Or perhaps CroquetPlugin or
FloatMathPlugin. Or AioPlugin or UnixOSProcess :-)

Tony.

[hidden email] wrote:

I've just tried a similar setup in a 3.9b-7032 image with 3.7-7 and
3.9-svn, and I get

3.7-7 - 107 tallies, 120 msec.
3.9-svn just after Smalltalk garbageCollect - 990 tallies, 1005 msec.
3.9-svn otherwise - 1323 tallies, 1343 msec.

So either the glyph caching isn't aggressive enough for this use case (I
made sure to use a real-world text example, rather than homogenous
repeats of the same string), or it's some other problem.

Traces attached.

Regards,
  Tony

Tony Garnock-Jones wrote:
 - 107 tallies, 120 msec.

**Tree**
99.1% {119ms} BookMorph>>nextPage
  99.1% {119ms} BookMorph>>goToPage:
    99.1% {119ms} BookMorph>>goToPage:transitionSpec:
      99.1% {119ms} BookMorph>>goToPageMorph:transitionSpec:
        57.0% {68ms} PasteUpMorph(Morph)>>fullReleaseCachedState
          |57.0% {68ms} TextMorph>>releaseCachedState
          |  57.0% {68ms} TextMorph>>paragraph
          |    57.0% {68ms} MultiNewParagraph(NewParagraph)>>compose:style:from:in:
          |      57.0% {68ms} MultiNewParagraph(NewParagraph)>>composeAll
          |        57.0% {68ms} MultiNewParagraph(NewParagraph)>>composeLinesFrom:to:delta:into:priorLines:atY:
          |          57.0% {68ms} TextComposer>>composeLinesFrom:to:del...ner:wantsColumnBreaks:
          |            57.0% {68ms} TextComposer>>composeAllLines
          |              50.5% {61ms} TextComposer>>composeOneLine
          |                |43.9% {53ms} TextComposer>>composeAllRectangles:
          |                |  |43.9% {53ms} TextComposer>>composeEachRectangleIn:
          |                |  |  29.0% {35ms} CompositionScanner>>composeFrom:inRectan...leftSide:rightSide:
          |                |  |    |22.4% {27ms} CompositionScanner>>setStopConditions
          |                |  |    |  |22.4% {27ms} CompositionScanner>>setFont
          |                |  |    |  |  22.4% {27ms} CompositionScanner(CharacterScanner)>>setFont
          |                |  |    |  |    22.4% {27ms} TextFontReference>>emphasizeScanner:
          |                |  |    |  |      22.4% {27ms} CompositionScanner>>setActualFont:
          |                |  |    |  |        21.5% {26ms} TTCFont>>descent
          |                |  |    |  |          21.5% {26ms} TTCFont>>pixelSize
          |                |  |    |  |            21.5% {26ms} TextStyle class>>pointsToPixels:
          |                |  |    |  |              21.5% {26ms} TextStyle class>>pixelsPerInch
          |                |  |    |  |                21.5% {26ms} Dictionary>>at:ifAbsentPut:
          |                |  |    |  |                  21.5% {26ms} Dictionary>>at:ifAbsent:
          |                |  |    |  |                    21.5% {26ms} Dictionary(Set)>>findElementOrNil:
          |                |  |    |  |                      21.5% {26ms} Dictionary>>scanFor:
          |                |  |    |  |                        21.5% {26ms} ByteSymbol(String)>>hash
          |                |  |    |  |                          20.6% {25ms} primitives
          |                |  |    |6.5% {8ms} CompositionScanner(CharacterScanner)>>handleIndentation
          |                |  |    |  6.5% {8ms} SmallInteger(Integer)>>timesRepeat:
          |                |  |  15.0% {18ms} SmallInteger(Magnitude)>>max:
          |                |6.5% {8ms} Rectangle>>rectanglesAt:height:
          |                |  6.5% {8ms} Point>>corner:
          |                |    6.5% {8ms} Rectangle class>>origin:corner:
          |                |      6.5% {8ms} Rectangle>>setOrigin:corner:
          |              6.5% {8ms} Rectangle>>bottom
        42.1% {51ms} PasteUpMorph>>displayWorld
          42.1% {51ms} PasteUpMorph>>privateOuterDisplayWorld
            42.1% {51ms} WorldState>>displayWorld:submorphs:
              42.1% {51ms} WorldState>>drawWorld:submorphs:invalidAreasOn:
                42.1% {51ms} FormCanvas(Canvas)>>fullDrawMorph:
                  42.1% {51ms} FormCanvas(Canvas)>>fullDraw:
                    42.1% {51ms} BookMorph(Morph)>>fullDrawOn:
                      42.1% {51ms} BookMorph(Morph)>>drawSubmorphsOn:
                        42.1% {51ms} FormCanvas(Canvas)>>fullDrawMorph:
                          42.1% {51ms} FormCanvas(Canvas)>>fullDraw:
                            42.1% {51ms} PasteUpMorph(Morph)>>fullDrawOn:
                              42.1% {51ms} PasteUpMorph>>drawSubmorphsOn:
                                42.1% {51ms} FormCanvas(Canvas)>>fullDrawMorph:
                                  42.1% {51ms} FormCanvas(Canvas)>>fullDraw:
                                    42.1% {51ms} TextMorph(Morph)>>fullDrawOn:
                                      42.1% {51ms} FormCanvas(Canvas)>>drawMorph:
                                        42.1% {51ms} FormCanvas(Canvas)>>draw:
                                          42.1% {51ms} TextMorph>>drawOn:
                                            42.1% {51ms} FormCanvas>>paragraph:bounds:color:
                                              42.1% {51ms} MultiNewParagraph>>displayOn:using:at:
                                                42.1% {51ms} MultiDisplayScanner>>displayLine:offset:leftInRun:
                                                  29.0% {35ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
                                                    |15.0% {18ms} primitives
                                                    |14.0% {17ms} GrafPort>>copyBits
                                                  13.1% {16ms} MultiDisplayScanner>>setStopConditions
                                                    13.1% {16ms} MultiDisplayScanner>>setFont
                                                      13.1% {16ms} TTCFont>>installOn:foregroundColor:backgroundColor:
                                                        13.1% {16ms} GrafPort>>installTTCFont:foregroundColor:backgroundColor:
                                                          13.1% {16ms} GrafPort(BitBlt)>>installTTCFont:foregroundColor:backgroundColor:
                                                            13.1% {16ms} TTCFont>>height
                                                              13.1% {16ms} TTCFont>>pixelSize
                                                                13.1% {16ms} TextStyle class>>pointsToPixels:
                                                                  13.1% {16ms} TextStyle class>>pixelsPerInch
                                                                    13.1% {16ms} Dictionary>>at:ifAbsentPut:

**Leaves**
20.6% {25ms} ByteSymbol(String)>>hash
15.9% {19ms} SmallInteger(Magnitude)>>max:
15.0% {18ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
14.0% {17ms} GrafPort>>copyBits
13.1% {16ms} Dictionary>>at:ifAbsentPut:
6.5% {8ms} Rectangle>>bottom
6.5% {8ms} SmallInteger(Integer)>>timesRepeat:
6.5% {8ms} Rectangle>>setOrigin:corner:

**Memory**
        old +80,608 bytes
        young -226,056 bytes
        used -145,448 bytes
        free +145,448 bytes

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

 - 1323 tallies, 1343 msec.

**Tree**
100.0% {1343ms} BookMorph>>nextPage
  100.0% {1343ms} BookMorph>>goToPage:
    100.0% {1343ms} BookMorph>>goToPage:transitionSpec:
      100.0% {1343ms} BookMorph>>goToPageMorph:transitionSpec:
        81.1% {1089ms} PasteUpMorph(Morph)>>fullReleaseCachedState
          |81.1% {1089ms} TextMorph>>releaseCachedState
          |  81.1% {1089ms} TextMorph>>paragraph
          |    81.1% {1089ms} MultiNewParagraph(NewParagraph)>>compose:style:from:in:
          |      81.1% {1089ms} MultiNewParagraph(NewParagraph)>>composeAll
          |        81.1% {1089ms} MultiNewParagraph(NewParagraph)>>composeLinesFrom:to:delta:into:priorLines:atY:
          |          81.1% {1089ms} TextComposer>>composeLinesFrom:to:del...ner:wantsColumnBreaks:
          |            81.0% {1088ms} TextComposer>>composeAllLines
          |              81.0% {1088ms} TextComposer>>composeOneLine
          |                80.2% {1077ms} TextComposer>>composeAllRectangles:
          |                  80.0% {1074ms} TextComposer>>composeEachRectangleIn:
          |                    79.4% {1066ms} CompositionScanner>>composeFrom:inRectan...leftSide:rightSide:
          |                      73.7% {990ms} CompositionScanner(CharacterScanner)>>scanCharactersFrom:to...stopConditions:kern:
          |                        |73.5% {987ms} CompositionScanner(CharacterScanner)>>basicScanCharactersFr...stopConditions:kern:
          |                        |  72.1% {968ms} TTCFont>>widthOf:
          |                        |    67.2% {902ms} TTCFont>>computeForm:
          |                        |      |63.0% {846ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
          |                        |      |  |63.0% {846ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
          |                        |      |  |  62.7% {842ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
          |                        |      |  |    44.8% {602ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
          |                        |      |  |      |27.2% {365ms} BalloonEngine>>drawGeneralBezierShape...borderColor:transform:
          |                        |      |  |      |  |18.9% {254ms} BalloonEngine>>postFlushIfNeeded
          |                        |      |  |      |  |  |17.0% {228ms} BalloonEngine>>copyBits
          |                        |      |  |      |  |  |  16.5% {222ms} BalloonEngine>>copyLoopFaster
          |                        |      |  |      |  |  |    16.4% {220ms} primitives
          |                        |      |  |      |  |6.1% {82ms} BalloonEngine>>registerFill:and:
          |                        |      |  |      |  |  5.4% {73ms} BalloonEngine>>registerFills:
          |                        |      |  |      |  |    2.8% {38ms} BalloonEngine>>registerFill:
          |                        |      |  |      |  |      2.4% {32ms} Color>>scaledPixelValue32
          |                        |      |  |      |  |        2.2% {30ms} Color>>pixelWordForDepth:
          |                        |      |  |      |17.4% {234ms} BalloonCanvas>>ensuredEngine
          |                        |      |  |      |  9.5% {128ms} BalloonEngine class(Behavior)>>new
          |                        |      |  |      |    |9.5% {128ms} BalloonEngine>>initialize
          |                        |      |  |      |    |  5.2% {70ms} BalloonEngine>>bitBlt:
          |                        |      |  |      |  5.0% {67ms} BalloonEngine>>bitBlt:
          |                        |      |  |    5.7% {77ms} Form(DisplayMedium)>>fillColor:
          |                        |      |  |      |4.3% {58ms} Form(DisplayMedium)>>fill:fillColor:
          |                        |      |  |      |  3.9% {52ms} Form>>fill:rule:fillColor:
          |                        |      |  |      |    2.0% {27ms} BitBlt class>>toForm:
          |                        |      |  |    4.1% {55ms} BalloonCanvas class(FormCanvas class)>>on:
          |                        |      |  |      3.3% {44ms} BalloonCanvas(FormCanvas)>>setForm:
          |                        |      |  |        2.1% {28ms} GrafPort class(BitBlt class)>>toForm:
          |                        |      |2.1% {28ms} TTCFont>>pixelSize
          |                        |      |  2.0% {27ms} TextStyle class>>pointsToPixels:
          |                        |      |    2.0% {27ms} TextStyle class>>pixelsPerInch
          |                        |    2.1% {28ms} Character>>charCode
          |                      3.6% {48ms} CompositionScanner>>setStopConditions
          |                        3.6% {48ms} CompositionScanner>>setFont
          |                          3.4% {46ms} CompositionScanner(CharacterScanner)>>setFont
        18.3% {246ms} PasteUpMorph>>displayWorld
          18.3% {246ms} PasteUpMorph>>privateOuterDisplayWorld
            18.3% {246ms} WorldState>>displayWorld:submorphs:
              18.2% {244ms} WorldState>>drawWorld:submorphs:invalidAreasOn:
                18.2% {244ms} FormCanvas(Canvas)>>fullDrawMorph:
                  18.2% {244ms} FormCanvas(Canvas)>>fullDraw:
                    18.2% {244ms} BookMorph(Morph)>>fullDrawOn:
                      18.2% {244ms} BookMorph(Morph)>>drawSubmorphsOn:
                        18.2% {244ms} FormCanvas(Canvas)>>fullDrawMorph:
                          18.2% {244ms} FormCanvas(Canvas)>>fullDraw:
                            18.2% {244ms} PasteUpMorph(Morph)>>fullDrawOn:
                              17.5% {235ms} PasteUpMorph>>drawSubmorphsOn:
                                17.0% {228ms} FormCanvas(Canvas)>>fullDrawMorph:
                                  17.0% {228ms} FormCanvas(Canvas)>>fullDraw:
                                    17.0% {228ms} TextMorph(Morph)>>fullDrawOn:
                                      17.0% {228ms} FormCanvas(Canvas)>>drawMorph:
                                        17.0% {228ms} FormCanvas(Canvas)>>draw:
                                          17.0% {228ms} TextMorph>>drawOn:
                                            17.0% {228ms} FormCanvas>>paragraph:bounds:color:
                                              17.0% {228ms} MultiNewParagraph>>displayOn:using:at:
                                                17.0% {228ms} MultiDisplayScanner>>displayLine:offset:leftInRun:
                                                  9.0% {121ms} MultiDisplayScanner(MultiCharacterScanner)>>scanCharactersFrom...opConditions:kern:
                                                    |9.0% {121ms} MultiDisplayScanner(MultiCharacterScanner)>>basicScanCharacter...opConditions:kern:
                                                    |  9.0% {121ms} TTCFont>>widthOf:
                                                    |    8.7% {117ms} TTCFont>>computeForm:
                                                    |      7.8% {105ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
                                                    |        7.8% {105ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
                                                    |          7.8% {105ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
                                                    |            5.6% {75ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
                                                    |              2.9% {39ms} BalloonEngine>>drawGeneralBezierShape...borderColor:transform:
                                                    |              2.6% {35ms} BalloonCanvas>>ensuredEngine
                                                  6.8% {91ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
                                                    4.9% {66ms} TTCFont>>glyphInfoOf:into:
                                                      4.5% {60ms} TTCFont>>formOf:
                                                        3.3% {44ms} TTCFont>>computeForm:
                                                          3.1% {42ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
                                                            3.1% {42ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
                                                              3.1% {42ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
                                                                2.3% {31ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:

**Leaves**
19.5% {262ms} BalloonEngine>>copyLoopFaster
3.6% {48ms} Character>>charCode
2.9% {39ms} Rectangle>>setOrigin:corner:
2.1% {28ms} Rectangle>>top
2.0% {27ms} LargePositiveInteger class(Behavior)>>new:

**Memory**
        old +150,016 bytes
        young +80,404 bytes
        used +230,420 bytes
        free -230,420 bytes

**GCs**
        full 0 totalling 0ms (0.0% uptime)
        incr 174 totalling 62ms (5.0% uptime), avg 0.0ms
        tenures 2 (avg 87 GCs/tenure)
        root table 0 overflows

 - 990 tallies, 1005 msec.

**Tree**
100.0% {1005ms} BookMorph>>nextPage
  100.0% {1005ms} BookMorph>>goToPage:
    100.0% {1005ms} BookMorph>>goToPage:transitionSpec:
      99.9% {1004ms} BookMorph>>goToPageMorph:transitionSpec:
        74.7% {751ms} PasteUpMorph(Morph)>>fullReleaseCachedState
          |74.7% {751ms} TextMorph>>releaseCachedState
          |  74.7% {751ms} TextMorph>>paragraph
          |    74.7% {751ms} MultiNewParagraph(NewParagraph)>>compose:style:from:in:
          |      74.7% {751ms} MultiNewParagraph(NewParagraph)>>composeAll
          |        74.7% {751ms} MultiNewParagraph(NewParagraph)>>composeLinesFrom:to:delta:into:priorLines:atY:
          |          74.7% {751ms} TextComposer>>composeLinesFrom:to:del...ner:wantsColumnBreaks:
          |            73.9% {743ms} TextComposer>>composeAllLines
          |              73.9% {743ms} TextComposer>>composeOneLine
          |                73.5% {739ms} TextComposer>>composeAllRectangles:
          |                  73.3% {737ms} TextComposer>>composeEachRectangleIn:
          |                    73.0% {734ms} CompositionScanner>>composeFrom:inRectan...leftSide:rightSide:
          |                      67.3% {676ms} CompositionScanner(CharacterScanner)>>scanCharactersFrom:to...stopConditions:kern:
          |                        |67.1% {674ms} CompositionScanner(CharacterScanner)>>basicScanCharactersFr...stopConditions:kern:
          |                        |  65.9% {662ms} TTCFont>>widthOf:
          |                        |    61.2% {615ms} TTCFont>>computeForm:
          |                        |      57.1% {574ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
          |                        |        |57.0% {573ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
          |                        |        |  56.7% {570ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
          |                        |        |    40.2% {404ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
          |                        |        |      |24.4% {245ms} BalloonEngine>>drawGeneralBezierShape...borderColor:transform:
          |                        |        |      |  |17.4% {175ms} BalloonEngine>>postFlushIfNeeded
          |                        |        |      |  |  |16.0% {161ms} BalloonEngine>>copyBits
          |                        |        |      |  |  |  15.3% {154ms} BalloonEngine>>copyLoopFaster
          |                        |        |      |  |  |    14.0% {141ms} primitives
          |                        |        |      |  |5.1% {51ms} BalloonEngine>>registerFill:and:
          |                        |        |      |  |  4.5% {45ms} BalloonEngine>>registerFills:
          |                        |        |      |  |    2.4% {24ms} BalloonEngine>>registerFill:
          |                        |        |      |  |      2.2% {22ms} Color>>scaledPixelValue32
          |                        |        |      |15.7% {158ms} BalloonCanvas>>ensuredEngine
          |                        |        |      |  8.7% {87ms} BalloonEngine class(Behavior)>>new
          |                        |        |      |    |8.5% {85ms} BalloonEngine>>initialize
          |                        |        |      |    |  5.5% {55ms} BalloonEngine>>bitBlt:
          |                        |        |      |  4.6% {46ms} BalloonEngine>>bitBlt:
          |                        |        |    5.6% {56ms} Form(DisplayMedium)>>fillColor:
          |                        |        |      |4.8% {48ms} Form(DisplayMedium)>>fill:fillColor:
          |                        |        |      |  4.4% {44ms} Form>>fill:rule:fillColor:
          |                        |        |      |    2.4% {24ms} BitBlt>>copy:from:in:fillColor:rule:
          |                        |        |    4.5% {45ms} BalloonCanvas class(FormCanvas class)>>on:
          |                        |        |      4.0% {40ms} BalloonCanvas(FormCanvas)>>setForm:
          |                        |      2.8% {28ms} TTCFont>>pixelSize
          |                        |        2.2% {22ms} TextStyle class>>pointsToPixels:
          |                      4.2% {42ms} CompositionScanner>>setStopConditions
          |                        4.2% {42ms} CompositionScanner>>setFont
          |                          4.0% {40ms} CompositionScanner(CharacterScanner)>>setFont
          |                            2.6% {26ms} TTCFont>>widthOf:
          |                              2.4% {24ms} TTCFont>>computeForm:
          |                                2.3% {23ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
          |                                  2.3% {23ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
          |                                    2.3% {23ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
        24.2% {243ms} PasteUpMorph>>displayWorld
          24.2% {243ms} PasteUpMorph>>privateOuterDisplayWorld
            24.2% {243ms} WorldState>>displayWorld:submorphs:
              24.0% {241ms} WorldState>>drawWorld:submorphs:invalidAreasOn:
                24.0% {241ms} FormCanvas(Canvas)>>fullDrawMorph:
                  24.0% {241ms} FormCanvas(Canvas)>>fullDraw:
                    24.0% {241ms} BookMorph(Morph)>>fullDrawOn:
                      23.9% {240ms} BookMorph(Morph)>>drawSubmorphsOn:
                        23.9% {240ms} FormCanvas(Canvas)>>fullDrawMorph:
                          23.9% {240ms} FormCanvas(Canvas)>>fullDraw:
                            23.9% {240ms} PasteUpMorph(Morph)>>fullDrawOn:
                              22.4% {225ms} PasteUpMorph>>drawSubmorphsOn:
                                22.4% {225ms} FormCanvas(Canvas)>>fullDrawMorph:
                                  22.4% {225ms} FormCanvas(Canvas)>>fullDraw:
                                    22.4% {225ms} TextMorph(Morph)>>fullDrawOn:
                                      22.4% {225ms} FormCanvas(Canvas)>>drawMorph:
                                        22.4% {225ms} FormCanvas(Canvas)>>draw:
                                          22.4% {225ms} TextMorph>>drawOn:
                                            22.4% {225ms} FormCanvas>>paragraph:bounds:color:
                                              22.4% {225ms} MultiNewParagraph>>displayOn:using:at:
                                                22.1% {222ms} MultiDisplayScanner>>displayLine:offset:leftInRun:
                                                  13.5% {136ms} MultiDisplayScanner(MultiCharacterScanner)>>scanCharactersFrom...opConditions:kern:
                                                    |13.5% {136ms} MultiDisplayScanner(MultiCharacterScanner)>>basicScanCharacter...opConditions:kern:
                                                    |  13.4% {135ms} TTCFont>>widthOf:
                                                    |    13.0% {131ms} TTCFont>>computeForm:
                                                    |      12.3% {124ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
                                                    |        12.2% {123ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
                                                    |          12.2% {123ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
                                                    |            9.5% {95ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:
                                                    |              4.7% {47ms} BalloonEngine>>drawGeneralBezierShape...borderColor:transform:
                                                    |                |2.9% {29ms} BalloonEngine>>postFlushIfNeeded
                                                    |                |  2.2% {22ms} BalloonEngine>>copyBits
                                                    |                |    2.2% {22ms} BalloonEngine>>copyLoopFaster
                                                    |              4.6% {46ms} BalloonCanvas>>ensuredEngine
                                                    |                2.4% {24ms} BalloonEngine class(Behavior)>>new
                                                    |                  2.3% {23ms} BalloonEngine>>initialize
                                                  8.2% {82ms} TTCFont>>displayString:on:from:to:at:kern:baselineY:
                                                    5.2% {52ms} TTCFont>>glyphInfoOf:into:
                                                      4.9% {49ms} TTCFont>>formOf:
                                                        3.7% {37ms} TTCFont>>computeForm:
                                                          3.5% {35ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth:
                                                            3.5% {35ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor:
                                                              3.5% {35ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis:
                                                                2.3% {23ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor:

**Leaves**
18.1% {182ms} BalloonEngine>>copyLoopFaster
2.9% {29ms} Character>>charCode
2.6% {26ms} Rectangle>>setOrigin:corner:
2.4% {24ms} BalloonEdgeData class(Behavior)>>new
2.4% {24ms} LargePositiveInteger class(Behavior)>>new:

**Memory**
        old +109,396 bytes
        young -11,092 bytes
        used +98,304 bytes
        free -98,304 bytes

**GCs**
        full 0 totalling 0ms (0.0% uptime)
        incr 129 totalling 36ms (4.0% uptime), avg 0.0ms
        tenures 1 (avg 129 GCs/tenure)
        root table 0 overflows