> Yoshiki Ohshima wrote: > > Again, start up time is not a problem. Etoys start up looks a bit > > slow on XO, but that is because the DBus communication that has to be > > done. > > I frequently hear DBus being accused of latency. As badly > implemented as it might be, I can't believe a daemon relaying > a bunch of bytes over a UNIX domain socket can introduce more > than 1ms of lag per message, even on a very slow processor. > > Has anybody ever analyzed the actual DBus traffic? With timings? > How many messages are we talking about?
It seems that you are right! I took profile data in Etoys and the DBus part accounts for about 60-70ms on start up. Other 3 seconds are spent on Squeak part and I think I could speed them up a bit. The following two message tallys are taken from two different part of code upon start up. They should cover most of it. Sorry for the false alerm. -- Yoshiki ------------------------------------------------------ - 1761 tallies, 2164 msec. **Tree** 95.3% {2062ms} SystemDictionary>>send:toClassesNamedIn:with: |43.2% {935ms} Delay class(Behavior)>>startUp: | |17.0% {368ms} SecurityManager class>>startUp | | |17.0% {368ms} SecurityManager>>startUp | | | 17.0% {368ms} SecurityManager>>loadSecurityKeys | | | 16.8% {364ms} Object class>>readFrom: | | | 10.6% {229ms} Array(Object)>>isKindOf: | | | 6.2% {134ms} Compiler class>>evaluate: | | | 6.2% {134ms} Compiler class>>evaluate:for:logged: | | | 6.2% {134ms} Compiler class>>evaluate:for:notifying:logged: | | | 6.2% {134ms} Compiler>>evaluate:in:to:notifying:ifFail:logged: | | | 6.0% {130ms} Compiler>>translate:noPattern:ifFail: | | | 6.0% {130ms} Parser>>parse:class:noPattern:context:notifying:ifFail: | | | 4.7% {102ms} Parser>>init:notifying:failBlock: | | | 4.7% {102ms} Parser(Scanner)>>scan: | | | 4.7% {102ms} Parser(Scanner)>>scanToken | | | 4.7% {102ms} Parser(Scanner)>>xLitQuote | | | 4.7% {102ms} Parser(Scanner)>>scanToken [4.7% {102ms} Parser(Scanner)>>xLitQuote [ 2.4% {52ms} Parser(Scanner)>>scanToken [ |2.4% {52ms} Parser(Scanner)>>xLitQuote [ 2.3% {50ms} Parser(Scanner)>>scanLitVec [ 2.3% {50ms} Parser(Scanner)>>scanToken [ 2.3% {50ms} Parser(Scanner)>>xLitQuote | |14.2% {307ms} FileDirectory class>>startUp | | |9.7% {210ms} FileDirectory class>>setDefaultDirectory: | | | |9.4% {203ms} FilePath class>>pathName: | | | | 9.4% {203ms} FilePath class>>pathName:isEncoded: | | | | 9.4% {203ms} FilePath>>pathName:isEncoded: | | | | 9.4% {203ms} LanguageEnvironment class>>defaultFileNameConverter | | | | 9.4% {203ms} SystemDictionary>>platformName | | | | 9.4% {203ms} SystemDictionary>>getSystemAttribute: | | | | 9.4% {203ms} SystemDictionary(Object)>>deprecated:block: | | | | 9.4% {203ms} Preferences class>>showDeprecationWarnings | | | | 9.4% {203ms} Preferences class>>valueOfFlag:ifAbsent: | | |3.1% {67ms} SmalltalkImage>>openSourceFiles | | | 3.0% {65ms} FileDirectory class>>openSources:andChanges:forImage: | | | 2.6% {56ms} FileDirectory class>>openSources:forImage: | |7.3% {158ms} ExternalSettings class>>startUp | | |7.3% {158ms} ExternalSettings class>>preferenceDirectory | | | 6.2% {134ms} SmalltalkImage>>vmPath | | | 6.2% {134ms} FilePath class>>pathName:isEncoded: | | | 6.2% {134ms} FilePath>>pathName:isEncoded: | | | 6.2% {134ms} ByteString(String)>>convertFromWithConverter: | |3.8% {82ms} Delay class>>startUp |34.4% {744ms} WeakArray class>>startUp: | |34.4% {744ms} WeakArray class>>restartFinalizationProcess | | 34.2% {740ms} Semaphore class>>forMutualExclusion |13.0% {281ms} AutoStart class>>startUp: | |7.4% {160ms} AutoStart class>>checkForPluginUpdate | | |7.4% {160ms} PasteUpMorph>>install | | | 6.2% {134ms} PasteUpMorph>>installFlaps | | | 4.8% {104ms} Project>>assureFlapIntegrity | | | 4.8% {104ms} IdentityDictionary(Dictionary)>>removeKey:ifAbsent: | |5.6% {121ms} AutoStart class>>checkForUpdates | | 5.6% {121ms} PasteUpMorph>>install | | 3.5% {76ms} PasteUpMorph>>displayWorldSafely | | |3.5% {76ms} WorldState>>displayWorldSafely: | | | 3.5% {76ms} PasteUpMorph>>displayWorld | | | 3.5% {76ms} PasteUpMorph>>privateOuterDisplayWorld | | | 3.5% {76ms} WorldState>>displayWorld:submorphs: | | | 3.5% {76ms} WorldState>>drawWorld:submorphs:invalidAreasOn: | | | 3.5% {76ms} FormCanvas(Canvas)>>fullDrawMorph: | | | 3.5% {76ms} FormCanvas(Canvas)>>fullDraw: | | | 3.5% {76ms} SugarNavTab(Morph)>>fullDrawOn: | | | 3.5% {76ms} SugarNavTab(Morph)>>drawSubmorphsOn: | | | 3.5% {76ms} FormCanvas(Canvas)>>fullDrawMorph: | | | 3.5% {76ms} FormCanvas(Canvas)>>fullDraw: | | | 2.3% {50ms} SugarNavigatorBar(AlignmentMorphBob1)>>fullDrawOn: [2.3% {50ms} SugarNavigatorBar(Morph)>>fullDrawOn: | | 2.2% {48ms} PasteUpMorph>>installFlaps |4.7% {102ms} NaturalLanguageTranslator class>>startUp: | 4.7% {102ms} NaturalLanguageTranslator class>>privateStartUp | 2.8% {61ms} GetTextTranslator class>>privateStartUp | 2.7% {58ms} GetTextTranslator class>>availableLanguageLocaleIDs 4.7% {102ms} RenamedEvent class(AbstractEvent class)>>eventSelectorBlock 4.7% {102ms} ByteString(SequenceableCollection)>>, 4.7% {102ms} ByteString(SequenceableCollection)>>copyReplaceFrom:to:with: 4.7% {102ms} ByteString class(String class)>>new: **Leaves** 34.2% {740ms} Semaphore class>>forMutualExclusion 10.6% {229ms} Array(Object)>>isKindOf: 9.4% {203ms} Preferences class>>valueOfFlag:ifAbsent: 6.5% {141ms} ByteString(String)>>convertFromWithConverter: 5.2% {113ms} ByteString class(String class)>>new: 4.8% {104ms} IdentityDictionary(Dictionary)>>removeKey:ifAbsent: 3.8% {82ms} Delay class>>startUp **Memory** old +2,110,620 bytes young +23,448 bytes used +2,134,068 bytes free -16,362,732 bytes **GCs** full 1 totalling 602ms (28.0% uptime), avg 602.0ms incr 13 totalling 76ms (4.0% uptime), avg 6.0ms tenures 1 (avg 13 GCs/tenure) root table 0 overflows ------------------------------------------------------ - 180 tallies, 196 msec. **Tree** 65.0% {127ms} SugarLauncher>>joinSharedActivity |50.6% {99ms} Utilities class>>informUser:during: | |38.9% {76ms} MVCMenuMorph>>displayAt:during: | | |37.2% {73ms} PasteUpMorph>>displayWorld | | | 37.2% {73ms} PasteUpMorph>>privateOuterDisplayWorld | | | 37.2% {73ms} WorldState>>displayWorld:submorphs: | | | 35.6% {70ms} WorldState>>drawWorld:submorphs:invalidAreasOn: | | | 32.2% {63ms} FormCanvas(Canvas)>>fullDrawMorph: | | | 32.2% {63ms} FormCanvas(Canvas)>>fullDraw: | | | 32.2% {63ms} SystemWindow(Morph)>>fullDrawOn: | | | 28.9% {57ms} SystemWindow(Morph)>>drawSubmorphsOn: | | | |28.9% {57ms} FormCanvas(Canvas)>>fullDrawMorph: | | | | 28.9% {57ms} FormCanvas(Canvas)>>fullDraw: | | | | 26.1% {51ms} PluggableTextMorph(Morph)>>fullDrawOn: | | | | |25.0% {49ms} PluggableTextMorph(Morph)>>drawSubmorphsOn: | | | | | 25.0% {49ms} FormCanvas(Canvas)>>fullDrawMorph: | | | | | 25.0% {49ms} FormCanvas(Canvas)>>fullDraw: [25.0% {49ms} TransformMorph(Morph)>>fullDrawOn: [ 8.9% {17ms} ScrollBar(Morph)>>drawSubmorphsOn: [ |8.9% {17ms} FormCanvas(Canvas)>>fullDrawMorph: [ | 8.9% {17ms} FormCanvas(Canvas)>>fullDraw: [ | 8.9% {17ms} RectangleMorph(Morph)>>fullDrawOn: [ | 4.4% {9ms} FormCanvas(Canvas)>>drawMorph: [ | |4.4% {9ms} FormCanvas(Canvas)>>draw: [ | | 2.8% {5ms} RectangleMorph(Morph)>>drawOn: [ | | 2.8% {5ms} FormCanvas(Canvas)>>fillRectangle:fillStyle:borderStyle: [ | | 2.8% {5ms} RaisedBorder(SimpleBorder)>>frameRectangle:on: [ | | 2.8% {5ms} FormCanvas>>frameAndFillRectangle:fi...Color:bottomRightColor: [ | 4.4% {9ms} FormCanvas(Canvas)>>roundCornersOf:during: [ | 4.4% {9ms} FormCanvas>>roundCornersOf:in:during: [ | 4.4% {9ms} SketchMorph(Morph)>>wantsRoundedCorners [ | 4.4% {9ms} SketchMorph(Morph)>>cornerStyle [ | 4.4% {9ms} SketchMorph(Morph)>>valueOfProperty:ifAbsent: [ 7.2% {14ms} FormCanvas(Canvas)>>roundCornersOf:during: [ |7.2% {14ms} FormCanvas>>roundCornersOf:in:during: [ | 5.0% {10ms} CornerRounder class>>roundCornersOf:on:i...orderWidth:corners: [ | 2.8% {5ms} CornerRounder>>tweakCornersOf:on:in:borderWidth:corners: [ 3.3% {6ms} FormCanvas(Canvas)>>drawMorph: [ |3.3% {6ms} FormCanvas(Canvas)>>draw: [ 3.3% {6ms} IconicButton(Morph)>>drawMouseDownHighlightOn: [ 3.3% {6ms} IconicButton(Morph)>>highlightedForMouseDown | | | | 2.8% {5ms} SugarNavigatorBar(AlignmentMorphBob1)>>fullDrawOn: | | | | 2.8% {5ms} SugarNavigatorBar(Morph)>>fullDrawOn: | | | | 2.8% {5ms} SugarNavigatorBar(Morph)>>drawSubmorphsOn: | | | | 2.8% {5ms} FormCanvas(Canvas)>>fullDrawMorph: [2.8% {5ms} FormCanvas(Canvas)>>fullDraw: [ 2.8% {5ms} Morph>>fullDrawOn: [ 2.8% {5ms} Morph>>drawSubmorphsOn: [ 2.8% {5ms} FormCanvas(Canvas)>>fullDrawMorph: [ 2.8% {5ms} FormCanvas(Canvas)>>fullDraw: [ 2.8% {5ms} VariableSpacer(Morph)>>fullDrawOn: | | | 3.3% {6ms} FormCanvas(Canvas)>>drawMorph: | | | 3.3% {6ms} FormCanvas(Canvas)>>draw: | | | 3.3% {6ms} SystemWindow(Morph)>>drawOn: | | | 3.3% {6ms} SystemWindow(Morph)>>fillStyle | | | 3.3% {6ms} SystemWindow(Morph)>>valueOfProperty:ifAbsent: | |11.7% {23ms} MVCMenuMorph class>>from:title: | | 11.7% {23ms} MVCMenuMorph(MenuMorph)>>addTitle: | | 11.7% {23ms} MVCMenuMorph(MenuMorph)>>addTitle:updatingSelector:updateTarget: | | 11.7% {23ms} StringMorph>>font: | | 11.7% {23ms} StringMorph>>font:emphasis: | | 11.7% {23ms} StringMorph>>fitContents | | 11.7% {23ms} StringMorph>>measureContents | | 11.7% {23ms} TTCFont(AbstractFont)>>widthOfString: | | 11.7% {23ms} TTCFont(AbstractFont)>>widthOfString:from:to: | | 11.7% {23ms} TTCFont>>widthOf: | | 11.7% {23ms} TTCFont>>computeForm: | | 11.7% {23ms} TTGlyph>>asFormWithScale:ascender:...er:fgColor:bgColor:depth: | | 11.7% {23ms} TTGlyph>>asFormWithScale:ascender:...Color:depth:replaceColor: | | 9.4% {18ms} TTGlyph>>asFormWithScale:ascender:...:lingGlyphWidth:emphasis: | | 6.1% {12ms} BalloonCanvas>>drawGeneralBezierShape...rderWidth:borderColor: [3.9% {8ms} BalloonCanvas>>ensuredEngine |14.4% {28ms} SugarPresence>>getActivityById: | 14.4% {28ms} SugarPresence(DBusProxy)>>dbusPerform:interface:withArguments: | 14.4% {28ms} DBus>>sendDBusMessage: | 14.4% {28ms} DBus>>sendDBusMessage:timeout: | 14.4% {28ms} DBus>>sendDBusMessage:timeout:onSuccess:onError: | 14.4% {28ms} DBus>>sendMessage:timeout: | 14.4% {28ms} DBus(DBusConnection)>>sendMessage:timeout: | 14.4% {28ms} DBusMessageMethodCall(DBusMessage)>>serial: 16.7% {33ms} DBus class(DBusConnection class)>>sessionBus |16.7% {33ms} DBus class(DBusConnection class)>>getBus:from: | 16.7% {33ms} DBus>>startUp | 16.7% {33ms} DBus>>restartMainloop | 16.7% {33ms} BlockContext>>forkAt:named: | 16.7% {33ms} Process>>resume 13.3% {26ms} SugarPresenceBuddy>>nick |13.3% {26ms} SugarPresenceBuddy>>getProperties | 13.3% {26ms} SugarPresenceBuddy(DBusProxy)>>dbusPerform:interface: | 13.3% {26ms} SugarPresenceBuddy(DBusProxy)>>dbusPerform:interface:withArguments: | 13.3% {26ms} DBus>>sendDBusMessage: | 13.3% {26ms} DBus>>sendDBusMessage:timeout: | 13.3% {26ms} DBus>>sendDBusMessage:timeout:onSuccess:onError: | 13.3% {26ms} DBus>>sendMessage:timeout: | 13.3% {26ms} DBus(DBusConnection)>>sendMessage:timeout: | 13.3% {26ms} DBusMessageMethodCall(DBusMessage)>>serial: 3.9% {8ms} SugarPresence>>getOwner 3.9% {8ms} SugarPresence(DBusProxy)>>dbusPerform:interface: 3.9% {8ms} SugarPresence(DBusProxy)>>dbusPerform:interface:withArguments: 3.9% {8ms} DBus>>sendDBusMessage: 3.9% {8ms} DBus>>sendDBusMessage:timeout: 3.9% {8ms} DBus>>sendDBusMessage:timeout:onSuccess:onError: 3.9% {8ms} DBus>>sendMessage:timeout: 3.9% {8ms} DBus(DBusConnection)>>sendMessage:timeout: 3.9% {8ms} DBusMessageMethodCall(DBusMessage)>>serial: **Leaves** 31.7% {62ms} DBusMessageMethodCall(DBusMessage)>>serial: 16.7% {33ms} Process>>resume 8.9% {17ms} SystemWindow(Morph)>>valueOfProperty:ifAbsent: 4.4% {9ms} Rectangle>>left **Memory** old +109,772 bytes young -187,040 bytes used -77,268 bytes free +77,268 bytes **GCs** full 0 totalling 0ms (0.0% uptime) incr 4 totalling 13ms (7.0% uptime), avg 3.0ms tenures 1 (avg 4 GCs/tenure) root table 0 overflows _______________________________________________ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel