Re: [Pharo-project] Save and quit vs. Save - a clue to performance???

July 17, 2009

      Nicolas,

Thanks for investigating this.  As I said before, I suspect badness might follow any attempt to fork the extra work; once the user can do something with the image, they might do something that will race with the save/restart.  A better way to go would be to get the vm to tell the image when it is loading and shutting down, and do some Dolphin-like thinking with session managers.  It won't be trivial to do, but the current situation is inefficient.

Even with things as-is, is there any danger to moving the

        Cursor normal show

to the end of the re-start sequence?  Should that help to make the duration of the save cursor more "honest?"  I tried it briefly without much apparent success, but the machine in question takes a long time to save an image anyway.

Bill

-----Original Message-----
From: pharo-project-bounces@lists.gforge.inria.fr [mailto:pharo-project-bounces@lists.gforge.inria.fr] On Behalf Of Nicolas Cellier
Sent: Friday, July 17, 2009 3:32 PM
To: Pharo-project@lists.gforge.inria.fr
Subject: Re: [Pharo-project] Save and quit vs. Save - a clue to performance???

As a follow-up

1) I asked the vm-dev list about opportunity to add a primFork() but it appears to be highly non portable (at least on windows)

2) I inquired what happens during a simple snapshot with this snippet (save, not quit)

MessageTally spyOn: [
        Object flushDependents.
        Object flushEvents.
        Smalltalk processShutDownList: false.
        Cursor write show.
        Smalltalk at: #ImageSegment
                ifPresent: [:theClass | theClass reclaimObsoleteSegmentFiles].
        Cursor normal show.
        Smalltalk setGCParameters.
        Smalltalk processStartUpList: false.]

And got these results: (highly variating...)

 - 1709 tallies, 1715 msec.

**Tree**
51.9% {890ms} SystemDictionary>>processShutDownList:
  |51.9% {890ms} SystemDictionary>>send:toClassesNamedIn:with:
  |  51.9% {890ms} FileDirectory class(Behavior)>>shutDown:
  |    33.4% {573ms} FileDirectory class>>shutDown
  |      |33.4% {573ms} SmalltalkImage>>closeSourceFiles
  |      |  33.4% {573ms} MultiByteFileStream(StandardFileStream)>>close
  |      |    33.4% {573ms} MultiByteFileStream(StandardFileStream)>>unregister
  |      |      33.4% {573ms} MultiByteFileStream
class(StandardFileStream class)>>unregister:
  |      |        33.4% {573ms} WeakRegistry>>remove:ifAbsent:
  |      |          33.4% {573ms}
WeakIdentityKeyDictionary(Dictionary)>>removeKey:ifAbsent:
  |      |            33.4% {573ms}
WeakIdentityKeyDictionary(WeakKeyDictionary)>>fixCollisionsFrom:
  |      |              33.4% {573ms}
WeakIdentityKeyDictionary(WeakKeyDictionary)>>rehash
  |    14.3% {245ms} Form class>>shutDown
  |      |12.7% {218ms} primitives
  |    4.2% {72ms} StrikeFont class>>shutDown
  |      4.2% {72ms} StrikeFont>>reset
  |        3.6% {62ms} StrikeFont>>name
40.8% {700ms} SystemDictionary>>processStartUpList:
  |40.8% {700ms} SystemDictionary>>send:toClassesNamedIn:with:
  |  40.8% {700ms} InputEventPollingFetcher class(Behavior)>>startUp:
  |    35.1% {602ms} InputEventPollingFetcher class(InputEventFetcher
class)>>startUp
  |      |35.1% {602ms} InputEventPollingFetcher(InputEventFetcher)>>startUp
  |      |  35.1% {602ms}
InputEventPollingFetcher(InputEventFetcher)>>installEventLoop
  |      |    35.1% {602ms} BlockClosure>>forkAt:
  |      |      35.1% {602ms} Process>>resume
  |    3.7% {63ms} FileDirectory class>>startUp
  |      3.6% {62ms} SmalltalkImage>>openSourceFiles
  |        3.6% {62ms} FileDirectory class>>openSources:andChanges:forImage:
  |          2.9% {50ms} FileDirectory class>>openSources:forImage:
  |            2.0% {34ms} FileDirectory class>>openSources:forImage:
6.1% {105ms} InputEventPollingFetcher(InputEventFetcher)>>installEventLoop
  6.1% {105ms} InputEventPollingFetcher(InputEventFetcher)>>eventLoop
    6.1% {105ms} InputEventPollingFetcher>>waitForInput
      6.1% {105ms} Delay>>wait
        6.1% {105ms} Delay>>unschedule

**Leaves**
35.2% {604ms} Process>>resume
33.5% {575ms} WeakIdentityKeyDictionary(WeakKeyDictionary)>>rehash
12.7% {218ms} Form class>>shutDown
6.1% {105ms} Delay>>unschedule
3.6% {62ms} StrikeFont>>name

**Memory**
        old                     -7,519,288 bytes
        young           +5,575,572 bytes
        used            -1,943,716 bytes
        free            -203,436 bytes

**GCs**
        full                    1 totalling 578ms (34.0% uptime), avg 578.0ms
        incr            12 totalling 14ms (1.0% uptime), avg 1.0ms
        tenures         0
        root table      0 overflows

 - 1117 tallies, 1120 msec.

**Tree**
75.8% {849ms} SystemDictionary>>processShutDownList:
  |75.8% {849ms} SystemDictionary>>send:toClassesNamedIn:with:
  |  75.8% {849ms} FileDirectory class(Behavior)>>shutDown:
  |    48.9% {548ms} FileDirectory class>>shutDown
  |      |48.9% {548ms} SmalltalkImage>>closeSourceFiles
  |      |  48.9% {548ms} MultiByteFileStream(StandardFileStream)>>close
  |      |    48.9% {548ms} MultiByteFileStream(StandardFileStream)>>unregister
  |      |      48.9% {548ms} MultiByteFileStream
class(StandardFileStream class)>>unregister:
  |      |        48.7% {545ms} WeakRegistry>>remove:ifAbsent:
  |      |          48.7% {545ms}
WeakIdentityKeyDictionary(Dictionary)>>removeKey:ifAbsent:
  |      |            48.7% {545ms}
WeakIdentityKeyDictionary(WeakKeyDictionary)>>fixCollisionsFrom:
  |      |              48.7% {545ms}
WeakIdentityKeyDictionary(WeakKeyDictionary)>>rehash
  |    20.7% {232ms} Form class>>shutDown
  |      |20.7% {232ms} Form>>hibernate
  |      |  18.1% {203ms} ByteArray class(Behavior)>>new:
  |      |  2.6% {29ms} primitives
  |    6.3% {71ms} StrikeFont class>>shutDown
  |      6.3% {71ms} StrikeFont>>reset
  |        5.9% {66ms} TextStyle class>>named:
  |          5.9% {66ms} Dictionary>>at:ifAbsent:
  |            5.9% {66ms} Dictionary(Set)>>findElementOrNil:
  |              5.9% {66ms} Dictionary>>scanFor:
  |                5.9% {66ms} ByteSymbol(Symbol)>>=
13.9% {156ms} SystemDictionary>>processStartUpList:
  |13.9% {156ms} SystemDictionary>>send:toClassesNamedIn:with:
  |  13.9% {156ms} InputEventPollingFetcher class(Behavior)>>startUp:
  |    4.6% {52ms} FileDirectory class>>startUp
  |      |4.5% {50ms} SmalltalkImage>>openSourceFiles
  |      |  4.4% {49ms} FileDirectory class>>openSources:andChanges:forImage:
  |      |    3.3% {37ms} FileDirectory class>>openSources:forImage:
  |      |      2.1% {24ms} FileDirectory class>>openSources:forImage:
  |    4.0% {45ms} InputEventPollingFetcher class(InputEventFetcher
class)>>startUp
  |      |4.0% {45ms} InputEventPollingFetcher(InputEventFetcher)>>startUp
  |      |  4.0% {45ms}
InputEventPollingFetcher(InputEventFetcher)>>installEventLoop
  |      |    4.0% {45ms} BlockClosure>>forkAt:
  |      |      4.0% {45ms} Process>>resume
  |    3.3% {37ms} InputEventSensor class>>startUp
  |      3.3% {37ms} InputEventSensor class>>installKeyDecodeTable
  |        2.7% {30ms} Character>>isAlphaNumeric
  |          2.6% {29ms} Character>>isLetter
  |            2.5% {28ms} Latin1Environment class(LanguageEnvironment
class)>>isLetter:
  |              2.5% {28ms} Unicode class>>isLetter:
  |                2.5% {28ms} SparseLargeTable>>at:
  |                  2.5% {28ms} SparseLargeTable>>pvtCheckIndex:
8.5% {95ms} InputEventPollingFetcher(InputEventFetcher)>>installEventLoop
  8.5% {95ms} InputEventPollingFetcher(InputEventFetcher)>>eventLoop
    8.5% {95ms} InputEventPollingFetcher>>waitForInput
      8.5% {95ms} Delay>>wait
        8.5% {95ms} Delay>>unschedule

**Leaves**
48.8% {547ms} WeakIdentityKeyDictionary(WeakKeyDictionary)>>rehash
18.1% {203ms} ByteArray class(Behavior)>>new:
8.5% {95ms} Delay>>unschedule
6.2% {69ms} ByteSymbol(Symbol)>>=
4.2% {47ms} Process>>resume
2.6% {29ms} Form>>hibernate
2.5% {28ms} SparseLargeTable>>pvtCheckIndex:

**Memory**
        old                     +5,931,864 bytes
        young           -13,040 bytes
        used            +5,918,824 bytes
        free            +57,240 bytes

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

 - 1451 tallies, 1456 msec.

**Tree**
62.9% {916ms} SystemDictionary>>processShutDownList:
  |62.9% {916ms} SystemDictionary>>send:toClassesNamedIn:with:
  |  31.5% {459ms} StrikeFont class(Behavior)>>shutDown:
  |    |13.9% {202ms} Form class>>shutDown
  |    |  |13.2% {192ms} primitives
  |    |9.2% {134ms} StrikeFont class>>shutDown
  |    |  |9.2% {134ms} StrikeFont>>reset
  |    |  |  4.7% {68ms} TextStyle class>>named:
  |    |  |    |4.7% {68ms} TextStyle(Object)>>isKindOf:
  |    |  |  4.3% {63ms} Array(Collection)>>detect:ifNone:
  |    |8.5% {124ms} InputEventPollingFetcher class(InputEventFetcher
class)>>shutDown
  |    |  8.5% {124ms} InputEventPollingFetcher(InputEventFetcher)>>shutDown
  |    |    8.5% {124ms} InputEventPollingFetcher>>terminateEventLoop
  |    |      8.5% {124ms}
InputEventPollingFetcher(InputEventFetcher)>>terminateEventLoop
  |    |        8.5% {124ms} Process>>terminate
  |    |          8.5% {124ms} Process>>popTo:
  |    |            8.5% {124ms} Process>>return:value:
  |    |              8.5% {124ms} Process>>complete:
  |    |                8.5% {124ms}
MethodContext(ContextPart)>>runUntilErrorOrReturnFrom:
  |    |                  8.5% {124ms} ContextPart class>>contextOn:do:
  |  31.4% {457ms} BlockClosure>>on:do:
35.7% {520ms} SystemDictionary>>processStartUpList:
  35.7% {520ms} SystemDictionary>>send:toClassesNamedIn:with:
    35.7% {520ms} InputEventPollingFetcher class(Behavior)>>startUp:
      29.9% {435ms} InputEventPollingFetcher class(InputEventFetcher class)>>startUp
        |29.9% {435ms} InputEventPollingFetcher(InputEventFetcher)>>startUp
        |  29.9% {435ms}
InputEventPollingFetcher(InputEventFetcher)>>installEventLoop
        |    29.9% {435ms} BlockClosure>>forkAt:
        |      29.9% {435ms} Process>>resume
      3.6% {52ms} FileDirectory class>>startUp
        3.5% {51ms} SmalltalkImage>>openSourceFiles
          3.4% {50ms} FileDirectory class>>openSources:andChanges:forImage:
            2.5% {36ms} FileDirectory class>>openSources:forImage:

**Leaves**
31.4% {457ms} BlockClosure>>on:do:
30.0% {437ms} Process>>resume
13.2% {192ms} Form class>>shutDown
8.5% {124ms} ContextPart class>>contextOn:do:
4.7% {68ms} TextStyle(Object)>>isKindOf:
4.3% {63ms} Array(Collection)>>detect:ifNone:

**Memory**
        old                     -146,072 bytes
        young           -406,232 bytes
        used            -552,304 bytes
        free            +406,132 bytes

**GCs**
        full                    1 totalling 392ms (27.0% uptime), avg 392.0ms
        incr            12 totalling 13ms (1.0% uptime), avg 1.0ms
        tenures         0
        root table      0 overflows

 - 1877 tallies, 1882 msec.

**Tree**
49.4% {930ms} SystemDictionary>>processStartUpList:
  |49.4% {930ms} SystemDictionary>>send:toClassesNamedIn:with:
  |  49.4% {930ms} InputEventPollingFetcher class(Behavior)>>startUp:
  |    44.9% {845ms} InputEventPollingFetcher class(InputEventFetcher
class)>>startUp
  |      |44.9% {845ms} InputEventPollingFetcher(InputEventFetcher)>>startUp
  |      |  44.9% {845ms}
InputEventPollingFetcher(InputEventFetcher)>>installEventLoop
  |      |    44.9% {845ms} BlockClosure>>forkAt:
  |      |      44.9% {845ms} Process>>resume
  |    2.7% {51ms} FileDirectory class>>startUp
  |      2.7% {51ms} SmalltalkImage>>openSourceFiles
  |        2.6% {49ms} FileDirectory class>>openSources:andChanges:forImage:
45.9% {864ms} SystemDictionary>>processShutDownList:
  |45.9% {864ms} SystemDictionary>>send:toClassesNamedIn:with:
  |  45.9% {864ms} ExternalSettings class(Behavior)>>shutDown:
  |    24.5% {461ms} ExternalSettings class>>shutDown
  |      |24.5% {461ms} ServerDirectory class>>releaseExternalSettings
  |      |  24.5% {461ms} Preferences class>>doesNotUnderstand:
  |      |    24.5% {461ms} Preferences class>>valueOfFlag:
  |      |      24.5% {461ms} Preferences class>>valueOfPreference:ifAbsent:
  |      |        24.5% {461ms} Preferences class>>preferenceAt:ifAbsent:
  |      |          24.5% {461ms} IdentityDictionary(Dictionary)>>at:ifAbsent:
  |      |            24.5% {461ms} IdentityDictionary(Set)>>findElementOrNil:
  |      |              24.5% {461ms} IdentityDictionary>>scanFor:
  |    17.8% {335ms} StrikeFont class>>shutDown
  |      |10.7% {201ms} StrikeFontSet class(Behavior)>>allSubInstancesDo:
  |      |  |10.7% {201ms} StrikeFontSet class(Behavior)>>allInstancesDo:
  |      |7.1% {134ms} StrikeFont>>reset
  |      |  3.7% {70ms} StrikeFont>>familyName
  |      |    |3.7% {70ms} ByteString(String)>>withoutTrailingDigits
  |      |    |  3.7% {70ms} Character>>isDigit
  |      |    |    3.7% {70ms} Latin1Environment
class(LanguageEnvironment class)>>isDigit:
  |      |  3.2% {60ms} ByteString(SequenceableCollection)>>,
  |      |    3.2% {60ms}
ByteString(SequenceableCollection)>>copyReplaceFrom:to:with:
  |      |      3.2% {60ms} ByteString(Object)>>species
  |    3.6% {68ms} Form class>>shutDown
  |      3.6% {68ms} Form class(Behavior)>>allInstancesDo:
3.7% {70ms} InputEventPollingFetcher(InputEventFetcher)>>installEventLoop
  3.7% {70ms} InputEventPollingFetcher(InputEventFetcher)>>eventLoop
    3.7% {70ms} InputEventPollingFetcher>>waitForInput
      3.7% {70ms} Delay>>wait
        3.7% {70ms} Delay>>unschedule

**Leaves**
44.9% {845ms} Process>>resume
24.5% {461ms} IdentityDictionary>>scanFor:
14.3% {269ms} StrikeFontSet class(Behavior)>>allInstancesDo:
3.7% {70ms} Latin1Environment class(LanguageEnvironment class)>>isDigit:
3.7% {70ms} Delay>>unschedule
3.2% {60ms} ByteString(Object)>>species

**Memory**
        old                     -13,012,128 bytes
        young           +5,635,236 bytes
        used            -7,376,892 bytes
        free            -822,368 bytes

**GCs**
        full                    1 totalling 800ms (43.0% uptime), avg 800.0ms
        incr            12 totalling 11ms (1.0% uptime), avg 1.0ms
        tenures         1 (avg 12 GCs/tenure)
        root table      0 overflows

2009/7/16 Nicolas Cellier <nicolas.cellier.aka.nice@gmail.com>:
...
Current policy is to cleanup before saving, and reconnect after saving
as if a fresh startup occured As you seem to suggest, a possible
alternative without using fork would be to:
1) distinguish whether this is a newly restarted image (primSnapshot
returning true or false...)
2) perform all the clean-ups at startup if newly restarted image
3) rely on the process exit() to perform required resource clean-up in
case we quit (or let a self aboutToQuit do some)
Step 2) would deserve great care, any unprotected access to an
uninitialized pointer of the old image would crash or trash memory...
Nicolas
2009/7/16 Schwab,Wilhelm K <bschwab@anest.ufl.edu>:
...
Nicolas,
One thing I forgot to mention: thread safety???  IIRC, Dolphin triggers startup events, and all external resources clear pointers then (though they will release on shutdown, not image saving) to force a lazy connection.
I see why, absent help from the vm, the image does not know when it starts and stops.  What I do not get is why the vm does not tell it.  If it did, I _think_ we could clean all of this up.  Sometimes the truth hurts though, so please find any faults in my logic (or lack thereof).
Bill
-----Original Message-----
From: pharo-project-bounces@lists.gforge.inria.fr
[mailto:pharo-project-bounces@lists.gforge.inria.fr] On Behalf Of
Nicolas Cellier
Sent: Thursday, July 16, 2009 3:11 PM
To: Pharo-project@lists.gforge.inria.fr
Subject: Re: [Pharo-project] Save and quit vs. Save - a clue to performance???
Yes, it would require a small vm change to fork.
To be more accurate here's a simplified draft of my proposition:
The fork has one bit different, so let it be a prilmitive returning true or false:
primFork
   "return true if we are in the forked image, false in the original"
<primitive: XXX>
snapshot
   self primFork ifTrue: [
       self aboutToSnapshot.
       self primSaveAndQuit.
       self returnFromSnapshot].
Nicolas
2009/7/16 Schwab,Wilhelm K <bschwab@anest.ufl.edu>:
...
Nicolas,
I'm all for doing this better, and have watched for a while as (it appears to me at least) Squeak got ever closer to having formal startup and shutdown code.  However, the idea that Squeak "just runs" persists, perhaps for the good.  It strikes me that we can do better, but it would require image and vm changes.
Bill
-----Original Message-----
From: pharo-project-bounces@lists.gforge.inria.fr
[mailto:pharo-project-bounces@lists.gforge.inria.fr] On Behalf Of
Nicolas Cellier
Sent: Thursday, July 16, 2009 2:10 PM
To: Pharo-project@lists.gforge.inria.fr
Subject: Re: [Pharo-project] Save and quit vs. Save - a clue to performance???
Does that really has to be so ?
An alternative would be to clone the process (fork) and do a snapshotAndQuit in the clone.
Nicolas
2009/7/16 Lukas Renggli <renggli@gmail.com>:
...
...
These things happen when they should, and do not happen when they should not, as apparently is the case for Squeak/Pharo.
It is correct that these scripts are run after a snapshot, because
when the image is saved it has to be shutdown so that it can come
up correctly again. I guess Dolphin works exactly the same. The
problem in Pharo/Squeak is that some of shutdown and startup
scripts might not really be necessary to run in the case of a save
without quit, so feel free to submit optimizations in this area.
Lukas
--
Lukas Renggli
http://www.lukas-renggli.ch
_______________________________________________
Pharo-project mailing list
Pharo-project@lists.gforge.inria.fr
http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
_______________________________________________
Pharo-project mailing list
Pharo-project@lists.gforge.inria.fr
http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
_______________________________________________
Pharo-project mailing list
Pharo-project@lists.gforge.inria.fr
http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
_______________________________________________
Pharo-project mailing list
Pharo-project@lists.gforge.inria.fr
http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
_______________________________________________
Pharo-project mailing list
Pharo-project@lists.gforge.inria.fr
http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project
_______________________________________________
Pharo-project mailing list
Pharo-project@lists.gforge.inria.fr
http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project