Hi All, we are simulating a full block Pharo image derived from Pharo 6. On startup we see a very sad loss of cycles due to a very slow rebuild of the selector table in Symbol class. Why is this done at each startup? Here is the stack: 16r107154 M ByteString class(ProtoObject)>identityHash 16r786AE8: a(n) ByteString class 16r10716C M ByteString class(Object)>hash 16r786AE8: a(n) ByteString class 16r10718C M ByteSymbol(String)>hash 16rE6A5C8: a(n) ByteSymbol 16r1071B0 M WeakSet>scanForEmptySlotFor: 16r26B968: a(n) WeakSet 16r1071DC M WeakSet>noCheckNoGrowFillFrom: 16r26B968: a(n) WeakSet 16r1071FC M WeakSet>growTo: 16r26B968: a(n) WeakSet 16r10721C M WeakSet>grow 16r26B968: a(n) WeakSet 16r107234 M WeakSet(HashedCollection)>fullCheck 16r26B968: a(n) WeakSet 16r10724C M WeakSet(HashedCollection)>atNewIndex:put: 16r26B968: a(n) WeakSet 16r107274 M WeakSet>add: 16r26B968: a(n) WeakSet 16r107294 M [] in Symbol class>(nil) 16r1D319A8: a(n) Symbol class 16r1072B8 M Array(SequenceableCollection)>do: 16r3C17370: a(n) Array 16r1072E8 I CompiledMethod class(Behavior)>allInstancesDo: 16r164E260: a(n) CompiledMethod class 16r10730C I Symbol class>initSelectorTable 16r1D319A8: a(n) Symbol class 16r10732C I Symbol class>selectorTable 16r1D319A8: a(n) Symbol class 16r107350 I Symbol class>internSelector: 16r1D319A8: a(n) Symbol class 16r10737C I CompiledMethod>selector: 16r26AB58: a(n) CompiledMethod 16r1073A4 I IRMethod>generate: 16r25A030: a(n) IRMethod 16r1073CC I FFICalloutMethodBuilder>generateMethodFromSpec: 16r255580: a(n) FFICalloutMethodBuilder 16r1073F0 I FFICalloutMethodBuilder>generate 16r255580: a(n) FFICalloutMethodBuilder 16r1030C8 I FFICalloutMethodBuilder>build: 16r255580: a(n) FFICalloutMethodBuilder 16r1030F4 I FFICalloutAPI>function:module: 16r255568: a(n) FFICalloutAPI 16r10311C I UnixEnvironment(Object)>ffiCall:module: 16r3816180: a(n) UnixEnvironment 16r103144 I UnixEnvironment(OSEnvironment)>getEnv: 16r3816180: a(n) UnixEnvironment 16r103168 I UnixEnvironment(OSEnvironment)>at:ifAbsent: 16r3816180: a(n) UnixEnvironment 16r10318C M [] in MacOSResolver>(nil) 16r241170: a(n) MacOSResolver 16r1031A4 M FullBlockClosure(BlockClosure)>on:do: 16r2553F0: a(n) FullBlockClosure 16r1031D0 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed:or: 16r241170: a(n) MacOSResolver 16r1031F8 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed: 16r241170: a(n) MacOSResolver 16r10321C I MacOSResolver>home 16r241170: a(n) MacOSResolver 16r10323C I MacOSResolver>userLibrary 16r241170: a(n) MacOSResolver 16r103254 M MacOSResolver>userApplicationSupport 16r241170: a(n) MacOSResolver 16r10326C M MacOSResolver(FileSystemResolver)>resolve: 16r241170: a(n) MacOSResolver 16r103288 M SystemResolver(FileSystemResolver)>unknownOrigin: 16r240D30: a(n) SystemResolver 16r1032A4 M SystemResolver(FileSystemResolver)>resolve: 16r240D30: a(n) SystemResolver 16r1032C4 M InteractiveResolver>unknownOrigin: 16r240CF0: a(n) InteractiveResolver 16r1032E4 M [] in InteractiveResolver>(nil) 16r240CF0: a(n) InteractiveResolver 16r103300 M IdentityDictionary(Dictionary)>at:ifAbsent: 16r240D00: a(n) IdentityDictionary 16r103320 M InteractiveResolver>resolve: 16r240CF0: a(n) InteractiveResolver 16r10333C M FileLocator>resolve 16r255258: a(n) FileLocator 16r103354 M FileLocator(AbstractFileReference)>exists 16r255258: a(n) FileLocator 16r10337C M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r103398 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r1033B0 M FullBlockClosure(BlockClosure)>on:do: 16r255190: a(n) FullBlockClosure 16r1033D0 M FullBlockClosure(BlockClosure)>ifError: 16r255190: a(n) FullBlockClosure 16r1033EC M PharoFilesOpener>ignoreIfFail: 16rE79FD8: a(n) PharoFilesOpener 16r102188 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r1021AC M Array(SequenceableCollection)>do: 16r2495E8: a(n) Array 16r1021DC I PharoFilesOpener>openSources:forImage: 16rE79FD8: a(n) PharoFilesOpener 16r102204 I PharoFilesOpener>openSources 16rE79FD8: a(n) PharoFilesOpener 16r102228 I PharoFilesOpener>sourcesFileOrNil 16rE79FD8: a(n) PharoFilesOpener 16r10224C I SourceFileArray>ensureOpen 16r8AA128: a(n) SourceFileArray 16r10226C I SmalltalkImage>openSourceFiles 16rA58A28: a(n) SmalltalkImage 16r10228C I SmalltalkImage class>startUp: 16rFDA6A8: a(n) SmalltalkImage class 16r1022A8 M ClassSessionHandler>startup: 16r8B8978: a(n) ClassSessionHandler 16r1022C8 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r1022EC M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r102304 M FullBlockClosure(BlockClosure)>on:do: 16r245640: a(n) FullBlockClosure 16r102328 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r10234C M Array(SequenceableCollection)>do: 16r1A47B8: a(n) Array 16r102370 I WorkingSession>runList:do: 16r1A45D0: a(n) WorkingSession 16r102398 I WorkingSession>runStartup: 16r1A45D0: a(n) WorkingSession 16r1023BC I WorkingSession>start: 16r1A45D0: a(n) WorkingSession 16r1023E8 I SessionManager>snapshot:andQuit: 16r17AA950: a(n) SessionManager You'll see that Symbol class>selectorTable calls Symbol class> initSelectorTable which then calls CompiledMethod class(Behavior)>allInstancesDo: to enumerate over all methods. This takes a significant amount of time, even on a fast machine. For example, on a 2.%GHz machine this takes about 70 milliseconds. That's a /lot/ of time to squander on startup. And it will grow the larger the image is. The selector table seems to be discarded on shut-down, which seems pointless. If one wants to recompute the table then before or after methods are added or removed seems like a better choice, not on every image startup. In around 2000 we were able to startup VisualWorks images in about 40 milliseconds on the hardware available at the time. I hope someone reconsiders this code and a avoids recomputing the selector table on each startup. _,,,^..^,,,_ best, Eliot
2016-09-05 18:37 GMT+02:00 Eliot Miranda <eliot.miranda@gmail.com>:
Hi All,
we are simulating a full block Pharo image derived from Pharo 6. On startup we see a very sad loss of cycles due to a very slow rebuild of the selector table in Symbol class. Why is this done at each startup? Here is the stack:
16r107154 M ByteString class(ProtoObject)>identityHash 16r786AE8: a(n) ByteString class 16r10716C M ByteString class(Object)>hash 16r786AE8: a(n) ByteString class 16r10718C M ByteSymbol(String)>hash 16rE6A5C8: a(n) ByteSymbol 16r1071B0 M WeakSet>scanForEmptySlotFor: 16r26B968: a(n) WeakSet 16r1071DC M WeakSet>noCheckNoGrowFillFrom: 16r26B968: a(n) WeakSet 16r1071FC M WeakSet>growTo: 16r26B968: a(n) WeakSet 16r10721C M WeakSet>grow 16r26B968: a(n) WeakSet 16r107234 M WeakSet(HashedCollection)>fullCheck 16r26B968: a(n) WeakSet 16r10724C M WeakSet(HashedCollection)>atNewIndex:put: 16r26B968: a(n) WeakSet 16r107274 M WeakSet>add: 16r26B968: a(n) WeakSet 16r107294 M [] in Symbol class>(nil) 16r1D319A8: a(n) Symbol class 16r1072B8 M Array(SequenceableCollection)>do: 16r3C17370: a(n) Array 16r1072E8 I CompiledMethod class(Behavior)>allInstancesDo: 16r164E260: a(n) CompiledMethod class 16r10730C I Symbol class>initSelectorTable 16r1D319A8: a(n) Symbol class 16r10732C I Symbol class>selectorTable 16r1D319A8: a(n) Symbol class 16r107350 I Symbol class>internSelector: 16r1D319A8: a(n) Symbol class 16r10737C I CompiledMethod>selector: 16r26AB58: a(n) CompiledMethod 16r1073A4 I IRMethod>generate: 16r25A030: a(n) IRMethod 16r1073CC I FFICalloutMethodBuilder>generateMethodFromSpec: 16r255580: a(n) FFICalloutMethodBuilder 16r1073F0 I FFICalloutMethodBuilder>generate 16r255580: a(n) FFICalloutMethodBuilder 16r1030C8 I FFICalloutMethodBuilder>build: 16r255580: a(n) FFICalloutMethodBuilder 16r1030F4 I FFICalloutAPI>function:module: 16r255568: a(n) FFICalloutAPI 16r10311C I UnixEnvironment(Object)>ffiCall:module: 16r3816180: a(n) UnixEnvironment 16r103144 I UnixEnvironment(OSEnvironment)>getEnv: 16r3816180: a(n) UnixEnvironment 16r103168 I UnixEnvironment(OSEnvironment)>at:ifAbsent: 16r3816180: a(n) UnixEnvironment 16r10318C M [] in MacOSResolver>(nil) 16r241170: a(n) MacOSResolver 16r1031A4 M FullBlockClosure(BlockClosure)>on:do: 16r2553F0: a(n) FullBlockClosure 16r1031D0 I MacOSResolver(PlatformResolver)> directoryFromEnvVariableNamed:or: 16r241170: a(n) MacOSResolver 16r1031F8 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed: 16r241170: a(n) MacOSResolver 16r10321C I MacOSResolver>home 16r241170: a(n) MacOSResolver 16r10323C I MacOSResolver>userLibrary 16r241170: a(n) MacOSResolver 16r103254 M MacOSResolver>userApplicationSupport 16r241170: a(n) MacOSResolver 16r10326C M MacOSResolver(FileSystemResolver)>resolve: 16r241170: a(n) MacOSResolver 16r103288 M SystemResolver(FileSystemResolver)>unknownOrigin: 16r240D30: a(n) SystemResolver 16r1032A4 M SystemResolver(FileSystemResolver)>resolve: 16r240D30: a(n) SystemResolver 16r1032C4 M InteractiveResolver>unknownOrigin: 16r240CF0: a(n) InteractiveResolver 16r1032E4 M [] in InteractiveResolver>(nil) 16r240CF0: a(n) InteractiveResolver 16r103300 M IdentityDictionary(Dictionary)>at:ifAbsent: 16r240D00: a(n) IdentityDictionary 16r103320 M InteractiveResolver>resolve: 16r240CF0: a(n) InteractiveResolver 16r10333C M FileLocator>resolve 16r255258: a(n) FileLocator 16r103354 M FileLocator(AbstractFileReference)>exists 16r255258: a(n) FileLocator 16r10337C M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r103398 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r1033B0 M FullBlockClosure(BlockClosure)>on:do: 16r255190: a(n) FullBlockClosure 16r1033D0 M FullBlockClosure(BlockClosure)>ifError: 16r255190: a(n) FullBlockClosure 16r1033EC M PharoFilesOpener>ignoreIfFail: 16rE79FD8: a(n) PharoFilesOpener 16r102188 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r1021AC M Array(SequenceableCollection)>do: 16r2495E8: a(n) Array 16r1021DC I PharoFilesOpener>openSources:forImage: 16rE79FD8: a(n) PharoFilesOpener 16r102204 I PharoFilesOpener>openSources 16rE79FD8: a(n) PharoFilesOpener 16r102228 I PharoFilesOpener>sourcesFileOrNil 16rE79FD8: a(n) PharoFilesOpener 16r10224C I SourceFileArray>ensureOpen 16r8AA128: a(n) SourceFileArray 16r10226C I SmalltalkImage>openSourceFiles 16rA58A28: a(n) SmalltalkImage 16r10228C I SmalltalkImage class>startUp: 16rFDA6A8: a(n) SmalltalkImage class 16r1022A8 M ClassSessionHandler>startup: 16r8B8978: a(n) ClassSessionHandler 16r1022C8 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r1022EC M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r102304 M FullBlockClosure(BlockClosure)>on:do: 16r245640: a(n) FullBlockClosure 16r102328 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r10234C M Array(SequenceableCollection)>do: 16r1A47B8: a(n) Array 16r102370 I WorkingSession>runList:do: 16r1A45D0: a(n) WorkingSession 16r102398 I WorkingSession>runStartup: 16r1A45D0: a(n) WorkingSession 16r1023BC I WorkingSession>start: 16r1A45D0: a(n) WorkingSession 16r1023E8 I SessionManager>snapshot:andQuit: 16r17AA950: a(n) SessionManager
You'll see that Symbol class>selectorTable calls Symbol class> initSelectorTable which then calls CompiledMethod class(Behavior)>allInstancesDo: to enumerate over all methods. This takes a significant amount of time, even on a fast machine. For example, on a 2.%GHz machine this takes about 70 milliseconds. That's a /lot/ of time to squander on startup. And it will grow the larger the image is.
Hm, I didn't thought about that.
The selector table seems to be discarded on shut-down, which seems pointless. If one wants to recompute the table then before or after methods are added or removed seems like a better choice, not on every image startup.
I think I wanted to be on the save side and just discard on shutdown and rebuild on startup to be sure to have the correct set of selector symbols.
In around 2000 we were able to startup VisualWorks images in about 40 milliseconds on the hardware available at the time. I hope someone reconsiders this code and a avoids recomputing the selector table on each startup.
I will take a look and try to find a better way. nicolai
_,,,^..^,,,_ best, Eliot
On 05 Sep 2016, at 19:52, Nicolai Hess <nicolaihess@gmail.com> wrote:
2016-09-05 18:37 GMT+02:00 Eliot Miranda <eliot.miranda@gmail.com <mailto:eliot.miranda@gmail.com>>: Hi All,
we are simulating a full block Pharo image derived from Pharo 6. On startup we see a very sad loss of cycles due to a very slow rebuild of the selector table in Symbol class. Why is this done at each startup? Here is the stack:
16r107154 M ByteString class(ProtoObject)>identityHash 16r786AE8: a(n) ByteString class 16r10716C M ByteString class(Object)>hash 16r786AE8: a(n) ByteString class 16r10718C M ByteSymbol(String)>hash 16rE6A5C8: a(n) ByteSymbol 16r1071B0 M WeakSet>scanForEmptySlotFor: 16r26B968: a(n) WeakSet 16r1071DC M WeakSet>noCheckNoGrowFillFrom: 16r26B968: a(n) WeakSet 16r1071FC M WeakSet>growTo: 16r26B968: a(n) WeakSet 16r10721C M WeakSet>grow 16r26B968: a(n) WeakSet 16r107234 M WeakSet(HashedCollection)>fullCheck 16r26B968: a(n) WeakSet 16r10724C M WeakSet(HashedCollection)>atNewIndex:put: 16r26B968: a(n) WeakSet 16r107274 M WeakSet>add: 16r26B968: a(n) WeakSet 16r107294 M [] in Symbol class>(nil) 16r1D319A8: a(n) Symbol class 16r1072B8 M Array(SequenceableCollection)>do: 16r3C17370: a(n) Array 16r1072E8 I CompiledMethod class(Behavior)>allInstancesDo: 16r164E260: a(n) CompiledMethod class 16r10730C I Symbol class>initSelectorTable 16r1D319A8: a(n) Symbol class 16r10732C I Symbol class>selectorTable 16r1D319A8: a(n) Symbol class 16r107350 I Symbol class>internSelector: 16r1D319A8: a(n) Symbol class 16r10737C I CompiledMethod>selector: 16r26AB58: a(n) CompiledMethod 16r1073A4 I IRMethod>generate: 16r25A030: a(n) IRMethod 16r1073CC I FFICalloutMethodBuilder>generateMethodFromSpec: 16r255580: a(n) FFICalloutMethodBuilder 16r1073F0 I FFICalloutMethodBuilder>generate 16r255580: a(n) FFICalloutMethodBuilder 16r1030C8 I FFICalloutMethodBuilder>build: 16r255580: a(n) FFICalloutMethodBuilder 16r1030F4 I FFICalloutAPI>function:module: 16r255568: a(n) FFICalloutAPI 16r10311C I UnixEnvironment(Object)>ffiCall:module: 16r3816180: a(n) UnixEnvironment 16r103144 I UnixEnvironment(OSEnvironment)>getEnv: 16r3816180: a(n) UnixEnvironment 16r103168 I UnixEnvironment(OSEnvironment)>at:ifAbsent: 16r3816180: a(n) UnixEnvironment 16r10318C M [] in MacOSResolver>(nil) 16r241170: a(n) MacOSResolver 16r1031A4 M FullBlockClosure(BlockClosure)>on:do: 16r2553F0: a(n) FullBlockClosure 16r1031D0 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed:or: 16r241170: a(n) MacOSResolver 16r1031F8 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed: 16r241170: a(n) MacOSResolver 16r10321C I MacOSResolver>home 16r241170: a(n) MacOSResolver 16r10323C I MacOSResolver>userLibrary 16r241170: a(n) MacOSResolver 16r103254 M MacOSResolver>userApplicationSupport 16r241170: a(n) MacOSResolver 16r10326C M MacOSResolver(FileSystemResolver)>resolve: 16r241170: a(n) MacOSResolver 16r103288 M SystemResolver(FileSystemResolver)>unknownOrigin: 16r240D30: a(n) SystemResolver 16r1032A4 M SystemResolver(FileSystemResolver)>resolve: 16r240D30: a(n) SystemResolver 16r1032C4 M InteractiveResolver>unknownOrigin: 16r240CF0: a(n) InteractiveResolver 16r1032E4 M [] in InteractiveResolver>(nil) 16r240CF0: a(n) InteractiveResolver 16r103300 M IdentityDictionary(Dictionary)>at:ifAbsent: 16r240D00: a(n) IdentityDictionary 16r103320 M InteractiveResolver>resolve: 16r240CF0: a(n) InteractiveResolver 16r10333C M FileLocator>resolve 16r255258: a(n) FileLocator 16r103354 M FileLocator(AbstractFileReference)>exists 16r255258: a(n) FileLocator 16r10337C M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r103398 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r1033B0 M FullBlockClosure(BlockClosure)>on:do: 16r255190: a(n) FullBlockClosure 16r1033D0 M FullBlockClosure(BlockClosure)>ifError: 16r255190: a(n) FullBlockClosure 16r1033EC M PharoFilesOpener>ignoreIfFail: 16rE79FD8: a(n) PharoFilesOpener 16r102188 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r1021AC M Array(SequenceableCollection)>do: 16r2495E8: a(n) Array 16r1021DC I PharoFilesOpener>openSources:forImage: 16rE79FD8: a(n) PharoFilesOpener 16r102204 I PharoFilesOpener>openSources 16rE79FD8: a(n) PharoFilesOpener 16r102228 I PharoFilesOpener>sourcesFileOrNil 16rE79FD8: a(n) PharoFilesOpener 16r10224C I SourceFileArray>ensureOpen 16r8AA128: a(n) SourceFileArray 16r10226C I SmalltalkImage>openSourceFiles 16rA58A28: a(n) SmalltalkImage 16r10228C I SmalltalkImage class>startUp: 16rFDA6A8: a(n) SmalltalkImage class 16r1022A8 M ClassSessionHandler>startup: 16r8B8978: a(n) ClassSessionHandler 16r1022C8 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r1022EC M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r102304 M FullBlockClosure(BlockClosure)>on:do: 16r245640: a(n) FullBlockClosure 16r102328 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r10234C M Array(SequenceableCollection)>do: 16r1A47B8: a(n) Array 16r102370 I WorkingSession>runList:do: 16r1A45D0: a(n) WorkingSession 16r102398 I WorkingSession>runStartup: 16r1A45D0: a(n) WorkingSession 16r1023BC I WorkingSession>start: 16r1A45D0: a(n) WorkingSession 16r1023E8 I SessionManager>snapshot:andQuit: 16r17AA950: a(n) SessionManager
You'll see that Symbol class>selectorTable calls Symbol class> initSelectorTable which then calls CompiledMethod class(Behavior)>allInstancesDo: to enumerate over all methods. This takes a significant amount of time, even on a fast machine. For example, on a 2.%GHz machine this takes about 70 milliseconds. That's a /lot/ of time to squander on startup. And it will grow the larger the image is.
Hm, I didn't thought about that.
me neither. I think this is wrong behaviour⦠we need to check why it happens, but it smells bad. Esteban
The selector table seems to be discarded on shut-down, which seems pointless. If one wants to recompute the table then before or after methods are added or removed seems like a better choice, not on every image startup.
I think I wanted to be on the save side and just discard on shutdown and rebuild on startup to be sure to have the correct set of selector symbols.
In around 2000 we were able to startup VisualWorks images in about 40 milliseconds on the hardware available at the time. I hope someone reconsiders this code and a avoids recomputing the selector table on each startup.
I will take a look and try to find a better way.
nicolai
_,,,^..^,,,_ best, Eliot
Rewriting the implementation of #initSelectorTable to: SelectorTable := WeakSet withAll: (CompiledMethod allInstances collect: [:m | m selector] as: IdentitySet). Makes it 20ms faster, so it looks like there is some overhead when using WeakSet compared to first use a normal set to remove duplicates. Another possibility could be to store the selectors in an IdentityDictionary as #selector->count which keep track of how many users of a selector there is itself, instead of using a WeakArray. Best regards, Henrik From: Pharo-dev [mailto:pharo-dev-bounces@lists.pharo.org] On Behalf Of Nicolai Hess Sent: Monday, September 5, 2016 7:52 PM To: Pharo Development List <pharo-dev@lists.pharo.org> Subject: Re: [Pharo-dev] Cycles lost on startup 2016-09-05 18:37 GMT+02:00 Eliot Miranda <eliot.miranda@gmail.com<mailto:eliot.miranda@gmail.com>>: Hi All, we are simulating a full block Pharo image derived from Pharo 6. On startup we see a very sad loss of cycles due to a very slow rebuild of the selector table in Symbol class. Why is this done at each startup? Here is the stack: 16r107154 M ByteString class(ProtoObject)>identityHash 16r786AE8: a(n) ByteString class 16r10716C M ByteString class(Object)>hash 16r786AE8: a(n) ByteString class 16r10718C M ByteSymbol(String)>hash 16rE6A5C8: a(n) ByteSymbol 16r1071B0 M WeakSet>scanForEmptySlotFor: 16r26B968: a(n) WeakSet 16r1071DC M WeakSet>noCheckNoGrowFillFrom: 16r26B968: a(n) WeakSet 16r1071FC M WeakSet>growTo: 16r26B968: a(n) WeakSet 16r10721C M WeakSet>grow 16r26B968: a(n) WeakSet 16r107234 M WeakSet(HashedCollection)>fullCheck 16r26B968: a(n) WeakSet 16r10724C M WeakSet(HashedCollection)>atNewIndex:put: 16r26B968: a(n) WeakSet 16r107274 M WeakSet>add: 16r26B968: a(n) WeakSet 16r107294 M [] in Symbol class>(nil) 16r1D319A8: a(n) Symbol class 16r1072B8 M Array(SequenceableCollection)>do: 16r3C17370: a(n) Array 16r1072E8 I CompiledMethod class(Behavior)>allInstancesDo: 16r164E260: a(n) CompiledMethod class 16r10730C I Symbol class>initSelectorTable 16r1D319A8: a(n) Symbol class 16r10732C I Symbol class>selectorTable 16r1D319A8: a(n) Symbol class 16r107350 I Symbol class>internSelector: 16r1D319A8: a(n) Symbol class 16r10737C I CompiledMethod>selector: 16r26AB58: a(n) CompiledMethod 16r1073A4 I IRMethod>generate: 16r25A030: a(n) IRMethod 16r1073CC I FFICalloutMethodBuilder>generateMethodFromSpec: 16r255580: a(n) FFICalloutMethodBuilder 16r1073F0 I FFICalloutMethodBuilder>generate 16r255580: a(n) FFICalloutMethodBuilder 16r1030C8 I FFICalloutMethodBuilder>build: 16r255580: a(n) FFICalloutMethodBuilder 16r1030F4 I FFICalloutAPI>function:module: 16r255568: a(n) FFICalloutAPI 16r10311C I UnixEnvironment(Object)>ffiCall:module: 16r3816180: a(n) UnixEnvironment 16r103144 I UnixEnvironment(OSEnvironment)>getEnv: 16r3816180: a(n) UnixEnvironment 16r103168 I UnixEnvironment(OSEnvironment)>at:ifAbsent: 16r3816180: a(n) UnixEnvironment 16r10318C M [] in MacOSResolver>(nil) 16r241170: a(n) MacOSResolver 16r1031A4 M FullBlockClosure(BlockClosure)>on:do: 16r2553F0: a(n) FullBlockClosure 16r1031D0 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed:or: 16r241170: a(n) MacOSResolver 16r1031F8 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed: 16r241170: a(n) MacOSResolver 16r10321C I MacOSResolver>home 16r241170: a(n) MacOSResolver 16r10323C I MacOSResolver>userLibrary 16r241170: a(n) MacOSResolver 16r103254 M MacOSResolver>userApplicationSupport 16r241170: a(n) MacOSResolver 16r10326C M MacOSResolver(FileSystemResolver)>resolve: 16r241170: a(n) MacOSResolver 16r103288 M SystemResolver(FileSystemResolver)>unknownOrigin: 16r240D30: a(n) SystemResolver 16r1032A4 M SystemResolver(FileSystemResolver)>resolve: 16r240D30: a(n) SystemResolver 16r1032C4 M InteractiveResolver>unknownOrigin: 16r240CF0: a(n) InteractiveResolver 16r1032E4 M [] in InteractiveResolver>(nil) 16r240CF0: a(n) InteractiveResolver 16r103300 M IdentityDictionary(Dictionary)>at:ifAbsent: 16r240D00: a(n) IdentityDictionary 16r103320 M InteractiveResolver>resolve: 16r240CF0: a(n) InteractiveResolver 16r10333C M FileLocator>resolve 16r255258: a(n) FileLocator 16r103354 M FileLocator(AbstractFileReference)>exists 16r255258: a(n) FileLocator 16r10337C M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r103398 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r1033B0 M FullBlockClosure(BlockClosure)>on:do: 16r255190: a(n) FullBlockClosure 16r1033D0 M FullBlockClosure(BlockClosure)>ifError: 16r255190: a(n) FullBlockClosure 16r1033EC M PharoFilesOpener>ignoreIfFail: 16rE79FD8: a(n) PharoFilesOpener 16r102188 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener 16r1021AC M Array(SequenceableCollection)>do: 16r2495E8: a(n) Array 16r1021DC I PharoFilesOpener>openSources:forImage: 16rE79FD8: a(n) PharoFilesOpener 16r102204 I PharoFilesOpener>openSources 16rE79FD8: a(n) PharoFilesOpener 16r102228 I PharoFilesOpener>sourcesFileOrNil 16rE79FD8: a(n) PharoFilesOpener 16r10224C I SourceFileArray>ensureOpen 16r8AA128: a(n) SourceFileArray 16r10226C I SmalltalkImage>openSourceFiles 16rA58A28: a(n) SmalltalkImage 16r10228C I SmalltalkImage class>startUp: 16rFDA6A8: a(n) SmalltalkImage class 16r1022A8 M ClassSessionHandler>startup: 16r8B8978: a(n) ClassSessionHandler 16r1022C8 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r1022EC M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r102304 M FullBlockClosure(BlockClosure)>on:do: 16r245640: a(n) FullBlockClosure 16r102328 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession 16r10234C M Array(SequenceableCollection)>do: 16r1A47B8: a(n) Array 16r102370 I WorkingSession>runList:do: 16r1A45D0: a(n) WorkingSession 16r102398 I WorkingSession>runStartup: 16r1A45D0: a(n) WorkingSession 16r1023BC I WorkingSession>start: 16r1A45D0: a(n) WorkingSession 16r1023E8 I SessionManager>snapshot:andQuit: 16r17AA950: a(n) SessionManager You'll see that Symbol class>selectorTable calls Symbol class> initSelectorTable which then calls CompiledMethod class(Behavior)>allInstancesDo: to enumerate over all methods. This takes a significant amount of time, even on a fast machine. For example, on a 2.%GHz machine this takes about 70 milliseconds. That's a /lot/ of time to squander on startup. And it will grow the larger the image is. Hm, I didn't thought about that. The selector table seems to be discarded on shut-down, which seems pointless. If one wants to recompute the table then before or after methods are added or removed seems like a better choice, not on every image startup. I think I wanted to be on the save side and just discard on shutdown and rebuild on startup to be sure to have the correct set of selector symbols. In around 2000 we were able to startup VisualWorks images in about 40 milliseconds on the hardware available at the time. I hope someone reconsiders this code and a avoids recomputing the selector table on each startup. I will take a look and try to find a better way. nicolai _,,,^..^,,,_ best, Eliot
2016-09-06 11:47 GMT+02:00 Henrik Nergaard <henrik.nergaard@uia.no>:
Rewriting the implementation of #initSelectorTable to:
SelectorTable := WeakSet withAll: (CompiledMethod allInstances collect: [:m | m selector] as: IdentitySet).
Makes it 20ms faster, so it looks like there is some overhead when using WeakSet compared to first use a normal set to remove duplicates.
Another possibility could be to store the selectors in an IdentityDictionary as #selector->count which keep track of how many users of a selector there is itself, instead of using a WeakArray.
Best regards,
Henrik
Maybe we can just move the rebuilding to the image shutdown instead of the image startup ?
*From:* Pharo-dev [mailto:pharo-dev-bounces@lists.pharo.org] *On Behalf Of *Nicolai Hess *Sent:* Monday, September 5, 2016 7:52 PM *To:* Pharo Development List <pharo-dev@lists.pharo.org> *Subject:* Re: [Pharo-dev] Cycles lost on startup
2016-09-05 18:37 GMT+02:00 Eliot Miranda <eliot.miranda@gmail.com>:
Hi All,
we are simulating a full block Pharo image derived from Pharo 6. On startup we see a very sad loss of cycles due to a very slow rebuild of the selector table in Symbol class. Why is this done at each startup? Here is the stack:
16r107154 M ByteString class(ProtoObject)>identityHash 16r786AE8: a(n) ByteString class
16r10716C M ByteString class(Object)>hash 16r786AE8: a(n) ByteString class
16r10718C M ByteSymbol(String)>hash 16rE6A5C8: a(n) ByteSymbol
16r1071B0 M WeakSet>scanForEmptySlotFor: 16r26B968: a(n) WeakSet
16r1071DC M WeakSet>noCheckNoGrowFillFrom: 16r26B968: a(n) WeakSet
16r1071FC M WeakSet>growTo: 16r26B968: a(n) WeakSet
16r10721C M WeakSet>grow 16r26B968: a(n) WeakSet
16r107234 M WeakSet(HashedCollection)>fullCheck 16r26B968: a(n) WeakSet
16r10724C M WeakSet(HashedCollection)>atNewIndex:put: 16r26B968: a(n) WeakSet
16r107274 M WeakSet>add: 16r26B968: a(n) WeakSet
16r107294 M [] in Symbol class>(nil) 16r1D319A8: a(n) Symbol class
16r1072B8 M Array(SequenceableCollection)>do: 16r3C17370: a(n) Array
16r1072E8 I CompiledMethod class(Behavior)>allInstancesDo: 16r164E260: a(n) CompiledMethod class
16r10730C I Symbol class>initSelectorTable 16r1D319A8: a(n) Symbol class
16r10732C I Symbol class>selectorTable 16r1D319A8: a(n) Symbol class
16r107350 I Symbol class>internSelector: 16r1D319A8: a(n) Symbol class
16r10737C I CompiledMethod>selector: 16r26AB58: a(n) CompiledMethod
16r1073A4 I IRMethod>generate: 16r25A030: a(n) IRMethod
16r1073CC I FFICalloutMethodBuilder>generateMethodFromSpec: 16r255580: a(n) FFICalloutMethodBuilder
16r1073F0 I FFICalloutMethodBuilder>generate 16r255580: a(n) FFICalloutMethodBuilder
16r1030C8 I FFICalloutMethodBuilder>build: 16r255580: a(n) FFICalloutMethodBuilder
16r1030F4 I FFICalloutAPI>function:module: 16r255568: a(n) FFICalloutAPI
16r10311C I UnixEnvironment(Object)>ffiCall:module: 16r3816180: a(n) UnixEnvironment
16r103144 I UnixEnvironment(OSEnvironment)>getEnv: 16r3816180: a(n) UnixEnvironment
16r103168 I UnixEnvironment(OSEnvironment)>at:ifAbsent: 16r3816180: a(n) UnixEnvironment
16r10318C M [] in MacOSResolver>(nil) 16r241170: a(n) MacOSResolver
16r1031A4 M FullBlockClosure(BlockClosure)>on:do: 16r2553F0: a(n) FullBlockClosure
16r1031D0 I MacOSResolver(PlatformResolver)> directoryFromEnvVariableNamed:or: 16r241170: a(n) MacOSResolver
16r1031F8 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed: 16r241170: a(n) MacOSResolver
16r10321C I MacOSResolver>home 16r241170: a(n) MacOSResolver
16r10323C I MacOSResolver>userLibrary 16r241170: a(n) MacOSResolver
16r103254 M MacOSResolver>userApplicationSupport 16r241170: a(n) MacOSResolver
16r10326C M MacOSResolver(FileSystemResolver)>resolve: 16r241170: a(n) MacOSResolver
16r103288 M SystemResolver(FileSystemResolver)>unknownOrigin: 16r240D30: a(n) SystemResolver
16r1032A4 M SystemResolver(FileSystemResolver)>resolve: 16r240D30: a(n) SystemResolver
16r1032C4 M InteractiveResolver>unknownOrigin: 16r240CF0: a(n) InteractiveResolver
16r1032E4 M [] in InteractiveResolver>(nil) 16r240CF0: a(n) InteractiveResolver
16r103300 M IdentityDictionary(Dictionary)>at:ifAbsent: 16r240D00: a(n) IdentityDictionary
16r103320 M InteractiveResolver>resolve: 16r240CF0: a(n) InteractiveResolver
16r10333C M FileLocator>resolve 16r255258: a(n) FileLocator
16r103354 M FileLocator(AbstractFileReference)>exists 16r255258: a(n) FileLocator
16r10337C M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r103398 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r1033B0 M FullBlockClosure(BlockClosure)>on:do: 16r255190: a(n) FullBlockClosure
16r1033D0 M FullBlockClosure(BlockClosure)>ifError: 16r255190: a(n) FullBlockClosure
16r1033EC M PharoFilesOpener>ignoreIfFail: 16rE79FD8: a(n) PharoFilesOpener
16r102188 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r1021AC M Array(SequenceableCollection)>do: 16r2495E8: a(n) Array
16r1021DC I PharoFilesOpener>openSources:forImage: 16rE79FD8: a(n) PharoFilesOpener
16r102204 I PharoFilesOpener>openSources 16rE79FD8: a(n) PharoFilesOpener
16r102228 I PharoFilesOpener>sourcesFileOrNil 16rE79FD8: a(n) PharoFilesOpener
16r10224C I SourceFileArray>ensureOpen 16r8AA128: a(n) SourceFileArray
16r10226C I SmalltalkImage>openSourceFiles 16rA58A28: a(n) SmalltalkImage
16r10228C I SmalltalkImage class>startUp: 16rFDA6A8: a(n) SmalltalkImage class
16r1022A8 M ClassSessionHandler>startup: 16r8B8978: a(n) ClassSessionHandler
16r1022C8 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r1022EC M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r102304 M FullBlockClosure(BlockClosure)>on:do: 16r245640: a(n) FullBlockClosure
16r102328 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r10234C M Array(SequenceableCollection)>do: 16r1A47B8: a(n) Array
16r102370 I WorkingSession>runList:do: 16r1A45D0: a(n) WorkingSession
16r102398 I WorkingSession>runStartup: 16r1A45D0: a(n) WorkingSession
16r1023BC I WorkingSession>start: 16r1A45D0: a(n) WorkingSession
16r1023E8 I SessionManager>snapshot:andQuit: 16r17AA950: a(n) SessionManager
You'll see that Symbol class>selectorTable calls Symbol class> initSelectorTable which then calls CompiledMethod class(Behavior)>allInstancesDo: to enumerate over all methods. This takes a significant amount of time, even on a fast machine. For example, on a 2.%GHz machine this takes about 70 milliseconds. That's a /lot/ of time to squander on startup. And it will grow the larger the image is.
Hm, I didn't thought about that.
The selector table seems to be discarded on shut-down, which seems pointless. If one wants to recompute the table then before or after methods are added or removed seems like a better choice, not on every image startup.
I think I wanted to be on the save side and just discard on shutdown and rebuild on startup to be sure to have the correct set of selector symbols.
In around 2000 we were able to startup VisualWorks images in about 40 milliseconds on the hardware available at the time. I hope someone reconsiders this code and a avoids recomputing the selector table on each startup.
I will take a look and try to find a better way.
nicolai
_,,,^..^,,,_
best, Eliot
On Sep 6, 2016, at 12:25 PM, Nicolai Hess <nicolaihess@gmail.com> wrote:
2016-09-06 11:47 GMT+02:00 Henrik Nergaard <henrik.nergaard@uia.no>:
Rewriting the implementation of #initSelectorTable to:
SelectorTable := WeakSet withAll: (CompiledMethod allInstances collect: [:m | m selector] as: IdentitySet).
Makes it 20ms faster, so it looks like there is some overhead when using WeakSet compared to first use a normal set to remove duplicates.
Another possibility could be to store the selectors in an IdentityDictionary as #selector->count which keep track of how many users of a selector there is itself, instead of using a WeakArray.
Best regards,
Henrik
Maybe we can just move the rebuilding to the image shutdown instead of the image startup ?
That's a much better idea. But only if the image snapshots. There is no point doing it on an exit without saving. And just to drive home the point, 70ms is an age in a web server. This kind of thing really damages Pharo performance in web servers. One wants startup times in the few tens of milliseconds or better.
From: Pharo-dev [mailto:pharo-dev-bounces@lists.pharo.org] On Behalf Of Nicolai Hess Sent: Monday, September 5, 2016 7:52 PM To: Pharo Development List <pharo-dev@lists.pharo.org> Subject: Re: [Pharo-dev] Cycles lost on startup
2016-09-05 18:37 GMT+02:00 Eliot Miranda <eliot.miranda@gmail.com>:
Hi All,
we are simulating a full block Pharo image derived from Pharo 6. On startup we see a very sad loss of cycles due to a very slow rebuild of the selector table in Symbol class. Why is this done at each startup? Here is the stack:
16r107154 M ByteString class(ProtoObject)>identityHash 16r786AE8: a(n) ByteString class
16r10716C M ByteString class(Object)>hash 16r786AE8: a(n) ByteString class
16r10718C M ByteSymbol(String)>hash 16rE6A5C8: a(n) ByteSymbol
16r1071B0 M WeakSet>scanForEmptySlotFor: 16r26B968: a(n) WeakSet
16r1071DC M WeakSet>noCheckNoGrowFillFrom: 16r26B968: a(n) WeakSet
16r1071FC M WeakSet>growTo: 16r26B968: a(n) WeakSet
16r10721C M WeakSet>grow 16r26B968: a(n) WeakSet
16r107234 M WeakSet(HashedCollection)>fullCheck 16r26B968: a(n) WeakSet
16r10724C M WeakSet(HashedCollection)>atNewIndex:put: 16r26B968: a(n) WeakSet
16r107274 M WeakSet>add: 16r26B968: a(n) WeakSet
16r107294 M [] in Symbol class>(nil) 16r1D319A8: a(n) Symbol class
16r1072B8 M Array(SequenceableCollection)>do: 16r3C17370: a(n) Array
16r1072E8 I CompiledMethod class(Behavior)>allInstancesDo: 16r164E260: a(n) CompiledMethod class
16r10730C I Symbol class>initSelectorTable 16r1D319A8: a(n) Symbol class
16r10732C I Symbol class>selectorTable 16r1D319A8: a(n) Symbol class
16r107350 I Symbol class>internSelector: 16r1D319A8: a(n) Symbol class
16r10737C I CompiledMethod>selector: 16r26AB58: a(n) CompiledMethod
16r1073A4 I IRMethod>generate: 16r25A030: a(n) IRMethod
16r1073CC I FFICalloutMethodBuilder>generateMethodFromSpec: 16r255580: a(n) FFICalloutMethodBuilder
16r1073F0 I FFICalloutMethodBuilder>generate 16r255580: a(n) FFICalloutMethodBuilder
16r1030C8 I FFICalloutMethodBuilder>build: 16r255580: a(n) FFICalloutMethodBuilder
16r1030F4 I FFICalloutAPI>function:module: 16r255568: a(n) FFICalloutAPI
16r10311C I UnixEnvironment(Object)>ffiCall:module: 16r3816180: a(n) UnixEnvironment
16r103144 I UnixEnvironment(OSEnvironment)>getEnv: 16r3816180: a(n) UnixEnvironment
16r103168 I UnixEnvironment(OSEnvironment)>at:ifAbsent: 16r3816180: a(n) UnixEnvironment
16r10318C M [] in MacOSResolver>(nil) 16r241170: a(n) MacOSResolver
16r1031A4 M FullBlockClosure(BlockClosure)>on:do: 16r2553F0: a(n) FullBlockClosure
16r1031D0 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed:or: 16r241170: a(n) MacOSResolver
16r1031F8 I MacOSResolver(PlatformResolver)>directoryFromEnvVariableNamed: 16r241170: a(n) MacOSResolver
16r10321C I MacOSResolver>home 16r241170: a(n) MacOSResolver
16r10323C I MacOSResolver>userLibrary 16r241170: a(n) MacOSResolver
16r103254 M MacOSResolver>userApplicationSupport 16r241170: a(n) MacOSResolver
16r10326C M MacOSResolver(FileSystemResolver)>resolve: 16r241170: a(n) MacOSResolver
16r103288 M SystemResolver(FileSystemResolver)>unknownOrigin: 16r240D30: a(n) SystemResolver
16r1032A4 M SystemResolver(FileSystemResolver)>resolve: 16r240D30: a(n) SystemResolver
16r1032C4 M InteractiveResolver>unknownOrigin: 16r240CF0: a(n) InteractiveResolver
16r1032E4 M [] in InteractiveResolver>(nil) 16r240CF0: a(n) InteractiveResolver
16r103300 M IdentityDictionary(Dictionary)>at:ifAbsent: 16r240D00: a(n) IdentityDictionary
16r103320 M InteractiveResolver>resolve: 16r240CF0: a(n) InteractiveResolver
16r10333C M FileLocator>resolve 16r255258: a(n) FileLocator
16r103354 M FileLocator(AbstractFileReference)>exists 16r255258: a(n) FileLocator
16r10337C M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r103398 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r1033B0 M FullBlockClosure(BlockClosure)>on:do: 16r255190: a(n) FullBlockClosure
16r1033D0 M FullBlockClosure(BlockClosure)>ifError: 16r255190: a(n) FullBlockClosure
16r1033EC M PharoFilesOpener>ignoreIfFail: 16rE79FD8: a(n) PharoFilesOpener
16r102188 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r1021AC M Array(SequenceableCollection)>do: 16r2495E8: a(n) Array
16r1021DC I PharoFilesOpener>openSources:forImage: 16rE79FD8: a(n) PharoFilesOpener
16r102204 I PharoFilesOpener>openSources 16rE79FD8: a(n) PharoFilesOpener
16r102228 I PharoFilesOpener>sourcesFileOrNil 16rE79FD8: a(n) PharoFilesOpener
16r10224C I SourceFileArray>ensureOpen 16r8AA128: a(n) SourceFileArray
16r10226C I SmalltalkImage>openSourceFiles 16rA58A28: a(n) SmalltalkImage
16r10228C I SmalltalkImage class>startUp: 16rFDA6A8: a(n) SmalltalkImage class
16r1022A8 M ClassSessionHandler>startup: 16r8B8978: a(n) ClassSessionHandler
16r1022C8 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r1022EC M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r102304 M FullBlockClosure(BlockClosure)>on:do: 16r245640: a(n) FullBlockClosure
16r102328 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r10234C M Array(SequenceableCollection)>do: 16r1A47B8: a(n) Array
16r102370 I WorkingSession>runList:do: 16r1A45D0: a(n) WorkingSession
16r102398 I WorkingSession>runStartup: 16r1A45D0: a(n) WorkingSession
16r1023BC I WorkingSession>start: 16r1A45D0: a(n) WorkingSession
16r1023E8 I SessionManager>snapshot:andQuit: 16r17AA950: a(n) SessionManager
You'll see that Symbol class>selectorTable calls Symbol class> initSelectorTable which then calls CompiledMethod class(Behavior)>allInstancesDo: to enumerate over all methods. This takes a significant amount of time, even on a fast machine. For example, on a 2.%GHz machine this takes about 70 milliseconds. That's a /lot/ of time to squander on startup. And it will grow the larger the image is.
Hm, I didn't thought about that.
The selector table seems to be discarded on shut-down, which seems pointless. If one wants to recompute the table then before or after methods are added or removed seems like a better choice, not on every image startup.
I think I wanted to be on the save side and just discard on shutdown and rebuild on startup to be sure to have the correct set of selector symbols.
In around 2000 we were able to startup VisualWorks images in about 40 milliseconds on the hardware available at the time. I hope someone reconsiders this code and a avoids recomputing the selector table on each startup.
I will take a look and try to find a better way.
nicolai
_,,,^..^,,,_
best, Eliot
Very interesting, especially with ephemeral runs. Phil On Tue, Sep 6, 2016 at 12:34 PM, Eliot Miranda <eliot.miranda@gmail.com> wrote:
On Sep 6, 2016, at 12:25 PM, Nicolai Hess <nicolaihess@gmail.com> wrote:
2016-09-06 11:47 GMT+02:00 Henrik Nergaard <henrik.nergaard@uia.no>:
Rewriting the implementation of #initSelectorTable to:
SelectorTable := WeakSet withAll: (CompiledMethod allInstances collect: [:m | m selector] as: IdentitySet).
Makes it 20ms faster, so it looks like there is some overhead when using WeakSet compared to first use a normal set to remove duplicates.
Another possibility could be to store the selectors in an IdentityDictionary as #selector->count which keep track of how many users of a selector there is itself, instead of using a WeakArray.
Best regards,
Henrik
Maybe we can just move the rebuilding to the image shutdown instead of the image startup ?
That's a much better idea. But only if the image snapshots. There is no point doing it on an exit without saving.
And just to drive home the point, 70ms is an age in a web server. This kind of thing really damages Pharo performance in web servers. One wants startup times in the few tens of milliseconds or better.
*From:* Pharo-dev [mailto:pharo-dev-bounces@lists.pharo.org] *On Behalf Of *Nicolai Hess *Sent:* Monday, September 5, 2016 7:52 PM *To:* Pharo Development List <pharo-dev@lists.pharo.org> *Subject:* Re: [Pharo-dev] Cycles lost on startup
2016-09-05 18:37 GMT+02:00 Eliot Miranda <eliot.miranda@gmail.com>:
Hi All,
we are simulating a full block Pharo image derived from Pharo 6. On startup we see a very sad loss of cycles due to a very slow rebuild of the selector table in Symbol class. Why is this done at each startup? Here is the stack:
16r107154 M ByteString class(ProtoObject)>identityHash 16r786AE8: a(n) ByteString class
16r10716C M ByteString class(Object)>hash 16r786AE8: a(n) ByteString class
16r10718C M ByteSymbol(String)>hash 16rE6A5C8: a(n) ByteSymbol
16r1071B0 M WeakSet>scanForEmptySlotFor: 16r26B968: a(n) WeakSet
16r1071DC M WeakSet>noCheckNoGrowFillFrom: 16r26B968: a(n) WeakSet
16r1071FC M WeakSet>growTo: 16r26B968: a(n) WeakSet
16r10721C M WeakSet>grow 16r26B968: a(n) WeakSet
16r107234 M WeakSet(HashedCollection)>fullCheck 16r26B968: a(n) WeakSet
16r10724C M WeakSet(HashedCollection)>atNewIndex:put: 16r26B968: a(n) WeakSet
16r107274 M WeakSet>add: 16r26B968: a(n) WeakSet
16r107294 M [] in Symbol class>(nil) 16r1D319A8: a(n) Symbol class
16r1072B8 M Array(SequenceableCollection)>do: 16r3C17370: a(n) Array
16r1072E8 I CompiledMethod class(Behavior)>allInstancesDo: 16r164E260: a(n) CompiledMethod class
16r10730C I Symbol class>initSelectorTable 16r1D319A8: a(n) Symbol class
16r10732C I Symbol class>selectorTable 16r1D319A8: a(n) Symbol class
16r107350 I Symbol class>internSelector: 16r1D319A8: a(n) Symbol class
16r10737C I CompiledMethod>selector: 16r26AB58: a(n) CompiledMethod
16r1073A4 I IRMethod>generate: 16r25A030: a(n) IRMethod
16r1073CC I FFICalloutMethodBuilder>generateMethodFromSpec: 16r255580: a(n) FFICalloutMethodBuilder
16r1073F0 I FFICalloutMethodBuilder>generate 16r255580: a(n) FFICalloutMethodBuilder
16r1030C8 I FFICalloutMethodBuilder>build: 16r255580: a(n) FFICalloutMethodBuilder
16r1030F4 I FFICalloutAPI>function:module: 16r255568: a(n) FFICalloutAPI
16r10311C I UnixEnvironment(Object)>ffiCall:module: 16r3816180: a(n) UnixEnvironment
16r103144 I UnixEnvironment(OSEnvironment)>getEnv: 16r3816180: a(n) UnixEnvironment
16r103168 I UnixEnvironment(OSEnvironment)>at:ifAbsent: 16r3816180: a(n) UnixEnvironment
16r10318C M [] in MacOSResolver>(nil) 16r241170: a(n) MacOSResolver
16r1031A4 M FullBlockClosure(BlockClosure)>on:do: 16r2553F0: a(n) FullBlockClosure
16r1031D0 I MacOSResolver(PlatformResolver )>directoryFromEnvVariableNamed:or: 16r241170: a(n) MacOSResolver
16r1031F8 I MacOSResolver(PlatformResolver )>directoryFromEnvVariableNamed: 16r241170: a(n) MacOSResolver
16r10321C I MacOSResolver>home 16r241170: a(n) MacOSResolver
16r10323C I MacOSResolver>userLibrary 16r241170: a(n) MacOSResolver
16r103254 M MacOSResolver>userApplicationSupport 16r241170: a(n) MacOSResolver
16r10326C M MacOSResolver(FileSystemResolver)>resolve: 16r241170: a(n) MacOSResolver
16r103288 M SystemResolver(FileSystemResolver)>unknownOrigin: 16r240D30: a(n) SystemResolver
16r1032A4 M SystemResolver(FileSystemResolver)>resolve: 16r240D30: a(n) SystemResolver
16r1032C4 M InteractiveResolver>unknownOrigin: 16r240CF0: a(n) InteractiveResolver
16r1032E4 M [] in InteractiveResolver>(nil) 16r240CF0: a(n) InteractiveResolver
16r103300 M IdentityDictionary(Dictionary)>at:ifAbsent: 16r240D00: a(n) IdentityDictionary
16r103320 M InteractiveResolver>resolve: 16r240CF0: a(n) InteractiveResolver
16r10333C M FileLocator>resolve 16r255258: a(n) FileLocator
16r103354 M FileLocator(AbstractFileReference)>exists 16r255258: a(n) FileLocator
16r10337C M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r103398 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r1033B0 M FullBlockClosure(BlockClosure)>on:do: 16r255190: a(n) FullBlockClosure
16r1033D0 M FullBlockClosure(BlockClosure)>ifError: 16r255190: a(n) FullBlockClosure
16r1033EC M PharoFilesOpener>ignoreIfFail: 16rE79FD8: a(n) PharoFilesOpener
16r102188 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r1021AC M Array(SequenceableCollection)>do: 16r2495E8: a(n) Array
16r1021DC I PharoFilesOpener>openSources:forImage: 16rE79FD8: a(n) PharoFilesOpener
16r102204 I PharoFilesOpener>openSources 16rE79FD8: a(n) PharoFilesOpener
16r102228 I PharoFilesOpener>sourcesFileOrNil 16rE79FD8: a(n) PharoFilesOpener
16r10224C I SourceFileArray>ensureOpen 16r8AA128: a(n) SourceFileArray
16r10226C I SmalltalkImage>openSourceFiles 16rA58A28: a(n) SmalltalkImage
16r10228C I SmalltalkImage class>startUp: 16rFDA6A8: a(n) SmalltalkImage class
16r1022A8 M ClassSessionHandler>startup: 16r8B8978: a(n) ClassSessionHandler
16r1022C8 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r1022EC M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r102304 M FullBlockClosure(BlockClosure)>on:do: 16r245640: a(n) FullBlockClosure
16r102328 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r10234C M Array(SequenceableCollection)>do: 16r1A47B8: a(n) Array
16r102370 I WorkingSession>runList:do: 16r1A45D0: a(n) WorkingSession
16r102398 I WorkingSession>runStartup: 16r1A45D0: a(n) WorkingSession
16r1023BC I WorkingSession>start: 16r1A45D0: a(n) WorkingSession
16r1023E8 I SessionManager>snapshot:andQuit: 16r17AA950: a(n) SessionManager
You'll see that Symbol class>selectorTable calls Symbol class> initSelectorTable which then calls CompiledMethod class(Behavior)>allInstancesDo: to enumerate over all methods. This takes a significant amount of time, even on a fast machine. For example, on a 2.%GHz machine this takes about 70 milliseconds. That's a /lot/ of time to squander on startup. And it will grow the larger the image is.
Hm, I didn't thought about that.
The selector table seems to be discarded on shut-down, which seems pointless. If one wants to recompute the table then before or after methods are added or removed seems like a better choice, not on every image startup.
I think I wanted to be on the save side and just discard on shutdown and rebuild on startup to be sure to have the correct set of selector symbols.
In around 2000 we were able to startup VisualWorks images in about 40 milliseconds on the hardware available at the time. I hope someone reconsiders this code and a avoids recomputing the selector table on each startup.
I will take a look and try to find a better way.
nicolai
_,,,^..^,,,_
best, Eliot
2016-09-06 12:34 GMT+02:00 Eliot Miranda <eliot.miranda@gmail.com>:
On Sep 6, 2016, at 12:25 PM, Nicolai Hess <nicolaihess@gmail.com> wrote:
2016-09-06 11:47 GMT+02:00 Henrik Nergaard <henrik.nergaard@uia.no>:
Rewriting the implementation of #initSelectorTable to:
SelectorTable := WeakSet withAll: (CompiledMethod allInstances collect: [:m | m selector] as: IdentitySet).
Makes it 20ms faster, so it looks like there is some overhead when using WeakSet compared to first use a normal set to remove duplicates.
Another possibility could be to store the selectors in an IdentityDictionary as #selector->count which keep track of how many users of a selector there is itself, instead of using a WeakArray.
Best regards,
Henrik
Maybe we can just move the rebuilding to the image shutdown instead of the image startup ?
That's a much better idea. But only if the image snapshots. There is no point doing it on an exit without saving.
Is there a way to see whether we are just quitting or "quit & save" in Pharos Session/Shutdown list "shutDown:" method ?
And just to drive home the point, 70ms is an age in a web server. This kind of thing really damages Pharo performance in web servers. One wants startup times in the few tens of milliseconds or better.
*From:* Pharo-dev [mailto:pharo-dev-bounces@lists.pharo.org] *On Behalf Of *Nicolai Hess *Sent:* Monday, September 5, 2016 7:52 PM *To:* Pharo Development List <pharo-dev@lists.pharo.org> *Subject:* Re: [Pharo-dev] Cycles lost on startup
2016-09-05 18:37 GMT+02:00 Eliot Miranda <eliot.miranda@gmail.com>:
Hi All,
we are simulating a full block Pharo image derived from Pharo 6. On startup we see a very sad loss of cycles due to a very slow rebuild of the selector table in Symbol class. Why is this done at each startup? Here is the stack:
16r107154 M ByteString class(ProtoObject)>identityHash 16r786AE8: a(n) ByteString class
16r10716C M ByteString class(Object)>hash 16r786AE8: a(n) ByteString class
16r10718C M ByteSymbol(String)>hash 16rE6A5C8: a(n) ByteSymbol
16r1071B0 M WeakSet>scanForEmptySlotFor: 16r26B968: a(n) WeakSet
16r1071DC M WeakSet>noCheckNoGrowFillFrom: 16r26B968: a(n) WeakSet
16r1071FC M WeakSet>growTo: 16r26B968: a(n) WeakSet
16r10721C M WeakSet>grow 16r26B968: a(n) WeakSet
16r107234 M WeakSet(HashedCollection)>fullCheck 16r26B968: a(n) WeakSet
16r10724C M WeakSet(HashedCollection)>atNewIndex:put: 16r26B968: a(n) WeakSet
16r107274 M WeakSet>add: 16r26B968: a(n) WeakSet
16r107294 M [] in Symbol class>(nil) 16r1D319A8: a(n) Symbol class
16r1072B8 M Array(SequenceableCollection)>do: 16r3C17370: a(n) Array
16r1072E8 I CompiledMethod class(Behavior)>allInstancesDo: 16r164E260: a(n) CompiledMethod class
16r10730C I Symbol class>initSelectorTable 16r1D319A8: a(n) Symbol class
16r10732C I Symbol class>selectorTable 16r1D319A8: a(n) Symbol class
16r107350 I Symbol class>internSelector: 16r1D319A8: a(n) Symbol class
16r10737C I CompiledMethod>selector: 16r26AB58: a(n) CompiledMethod
16r1073A4 I IRMethod>generate: 16r25A030: a(n) IRMethod
16r1073CC I FFICalloutMethodBuilder>generateMethodFromSpec: 16r255580: a(n) FFICalloutMethodBuilder
16r1073F0 I FFICalloutMethodBuilder>generate 16r255580: a(n) FFICalloutMethodBuilder
16r1030C8 I FFICalloutMethodBuilder>build: 16r255580: a(n) FFICalloutMethodBuilder
16r1030F4 I FFICalloutAPI>function:module: 16r255568: a(n) FFICalloutAPI
16r10311C I UnixEnvironment(Object)>ffiCall:module: 16r3816180: a(n) UnixEnvironment
16r103144 I UnixEnvironment(OSEnvironment)>getEnv: 16r3816180: a(n) UnixEnvironment
16r103168 I UnixEnvironment(OSEnvironment)>at:ifAbsent: 16r3816180: a(n) UnixEnvironment
16r10318C M [] in MacOSResolver>(nil) 16r241170: a(n) MacOSResolver
16r1031A4 M FullBlockClosure(BlockClosure)>on:do: 16r2553F0: a(n) FullBlockClosure
16r1031D0 I MacOSResolver(PlatformResolver )>directoryFromEnvVariableNamed:or: 16r241170: a(n) MacOSResolver
16r1031F8 I MacOSResolver(PlatformResolver )>directoryFromEnvVariableNamed: 16r241170: a(n) MacOSResolver
16r10321C I MacOSResolver>home 16r241170: a(n) MacOSResolver
16r10323C I MacOSResolver>userLibrary 16r241170: a(n) MacOSResolver
16r103254 M MacOSResolver>userApplicationSupport 16r241170: a(n) MacOSResolver
16r10326C M MacOSResolver(FileSystemResolver)>resolve: 16r241170: a(n) MacOSResolver
16r103288 M SystemResolver(FileSystemResolver)>unknownOrigin: 16r240D30: a(n) SystemResolver
16r1032A4 M SystemResolver(FileSystemResolver)>resolve: 16r240D30: a(n) SystemResolver
16r1032C4 M InteractiveResolver>unknownOrigin: 16r240CF0: a(n) InteractiveResolver
16r1032E4 M [] in InteractiveResolver>(nil) 16r240CF0: a(n) InteractiveResolver
16r103300 M IdentityDictionary(Dictionary)>at:ifAbsent: 16r240D00: a(n) IdentityDictionary
16r103320 M InteractiveResolver>resolve: 16r240CF0: a(n) InteractiveResolver
16r10333C M FileLocator>resolve 16r255258: a(n) FileLocator
16r103354 M FileLocator(AbstractFileReference)>exists 16r255258: a(n) FileLocator
16r10337C M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r103398 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r1033B0 M FullBlockClosure(BlockClosure)>on:do: 16r255190: a(n) FullBlockClosure
16r1033D0 M FullBlockClosure(BlockClosure)>ifError: 16r255190: a(n) FullBlockClosure
16r1033EC M PharoFilesOpener>ignoreIfFail: 16rE79FD8: a(n) PharoFilesOpener
16r102188 M [] in PharoFilesOpener>(nil) 16rE79FD8: a(n) PharoFilesOpener
16r1021AC M Array(SequenceableCollection)>do: 16r2495E8: a(n) Array
16r1021DC I PharoFilesOpener>openSources:forImage: 16rE79FD8: a(n) PharoFilesOpener
16r102204 I PharoFilesOpener>openSources 16rE79FD8: a(n) PharoFilesOpener
16r102228 I PharoFilesOpener>sourcesFileOrNil 16rE79FD8: a(n) PharoFilesOpener
16r10224C I SourceFileArray>ensureOpen 16r8AA128: a(n) SourceFileArray
16r10226C I SmalltalkImage>openSourceFiles 16rA58A28: a(n) SmalltalkImage
16r10228C I SmalltalkImage class>startUp: 16rFDA6A8: a(n) SmalltalkImage class
16r1022A8 M ClassSessionHandler>startup: 16r8B8978: a(n) ClassSessionHandler
16r1022C8 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r1022EC M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r102304 M FullBlockClosure(BlockClosure)>on:do: 16r245640: a(n) FullBlockClosure
16r102328 M [] in WorkingSession>(nil) 16r1A45D0: a(n) WorkingSession
16r10234C M Array(SequenceableCollection)>do: 16r1A47B8: a(n) Array
16r102370 I WorkingSession>runList:do: 16r1A45D0: a(n) WorkingSession
16r102398 I WorkingSession>runStartup: 16r1A45D0: a(n) WorkingSession
16r1023BC I WorkingSession>start: 16r1A45D0: a(n) WorkingSession
16r1023E8 I SessionManager>snapshot:andQuit: 16r17AA950: a(n) SessionManager
You'll see that Symbol class>selectorTable calls Symbol class> initSelectorTable which then calls CompiledMethod class(Behavior)>allInstancesDo: to enumerate over all methods. This takes a significant amount of time, even on a fast machine. For example, on a 2.%GHz machine this takes about 70 milliseconds. That's a /lot/ of time to squander on startup. And it will grow the larger the image is.
Hm, I didn't thought about that.
The selector table seems to be discarded on shut-down, which seems pointless. If one wants to recompute the table then before or after methods are added or removed seems like a better choice, not on every image startup.
I think I wanted to be on the save side and just discard on shutdown and rebuild on startup to be sure to have the correct set of selector symbols.
In around 2000 we were able to startup VisualWorks images in about 40 milliseconds on the hardware available at the time. I hope someone reconsiders this code and a avoids recomputing the selector table on each startup.
I will take a look and try to find a better way.
nicolai
_,,,^..^,,,_
best, Eliot
participants (5)
-
Eliot Miranda -
Esteban Lorenzano -
Henrik Nergaard -
Nicolai Hess -
phil＠highoctane.be