On Sun, Mar 18, 2018 at 12:56 AM, Eliot Miranda <eliot.miranda@gmail.com> wrote:
Hi Cyril,
Hi Eliot,
can you use the profiler (either MessageTally, or better still, AndreasSystemProfiler) to get a better understanding?
e.g.
AndreasSystemProfiler spyOn: [SystemNavigation new browseMethodsWithSourceString: 'Method source with it' matchCase: false]
I already did it and most of the time is spent in ZnCharacterReadStream>>nextElement. This is why I said it was probably linked to the recent changes on Pharo's streams to use Zinc ones. I don't have enough knowledge on the streams and time to help more. Here is the profiler: - 132607 tallies, 132646 msec. **Tree** -------------------------------- Process: (40s) Morphic UI Process: nil -------------------------------- 99.7% {132298ms} SystemNavigation>>browseMethodsWithSourceString:matchCase: 99.7% {132239ms} SystemNavigation>>allMethodsWithSourceString:matchCase: 99.7% {132235ms} ByteString(String)>>displayProgressFrom:to:during: 99.7% {132235ms} MorphicUIManager(UIManager)>>displayProgress:from:to:during: 99.7% {132235ms} Job>>run 99.7% {132235ms} BlockClosure>>ensure: 99.7% {132221ms} Job>>run 99.7% {132219ms} CurrentJob class(DynamicVariable class)>>value:during: 99.7% {132219ms} CurrentJob(DynamicVariable)>>value:during: 99.7% {132219ms} BlockClosure>>ensure: 99.7% {132219ms} CurrentJob(DynamicVariable)>>value:during: 99.7% {132219ms} Job>>run 99.7% {132219ms} BlockClosure>>cull: 99.7% {132219ms} SystemNavigation>>allMethodsWithSourceString:matchCase: 99.7% {132219ms} SystemNavigation>>allBehaviorsDo: 94.8% {125787ms} SystemDictionary>>allClassesDo: |94.8% {125787ms} OrderedCollection>>do: | 94.8% {125783ms} SystemDictionary>>allClassesDo: | 94.8% {125774ms} SystemNavigation>>allBehaviorsDo: | 94.8% {125759ms} SystemNavigation>>allMethodsWithSourceString:matchCase: | 88.5% {117424ms} AColorSelectorMorph class(Behavior)>>selectorsDo: | |88.5% {117418ms} MethodDictionary>>keysDo: | | 88.4% {117317ms} SystemNavigation>>allMethodsWithSourceString:matchCase: | | 88.4% {117239ms} AColorSelectorMorph class(Behavior)>>sourceCodeAt: | | 88.3% {117157ms} CompiledMethod>>sourceCode | | 88.2% {117055ms} CompiledMethod>>getSourceFromFile | | 88.2% {117053ms} BlockClosure>>on:do: | | 88.2% {117051ms} CompiledMethod>>getSourceFromFile | | 88.2% {117029ms} SourceFileArray>>sourceCodeAt: | | 88.2% {117027ms} SourceFileArray>>readStreamAt:ifPresent:ifAbsent: | | 88.2% {117019ms} SourceFileArray>>readStreamAtFileIndex:atPosition:ifPresent:ifAbsent: | | 87.9% {116565ms} SourceFileArray>>sourceCodeAt: | | 87.8% {116486ms} ChunkReadStream>>next | | 87.2% {115615ms} ChunkReadStream>>basicNextChunk | | 85.0% {112685ms} SourceFile>>next | | 84.8% {112484ms} ZnCharacterReadStream(ZnEncodedReadStream)>>next | | 84.6% {112251ms} ZnCharacterReadStream>>nextElement | | 45.5% {60313ms} primitives | | 39.1% {51860ms} ZnUTF8Encoder(ZnCharacterEncoder)>>nextFromStream: | | 39.0% {51675ms} ZnUTF8Encoder>>nextCodePointFromStream: | | 38.8% {51492ms} BinaryFileStream(AbstractBinaryFileStream)>>next | | 38.1% {50479ms} ByteArray(Collection)>>ifEmpty:ifNotEmpty: | | 37.1% {49198ms} primitives | 5.9% {7822ms} ClassOrganization>>classComment | 5.9% {7822ms} ClassOrganization>>comment | 5.9% {7822ms} RemoteString>>string | 5.9% {7820ms} SourceFileArray>>readStreamAtFileIndex:atPosition:ifPresent:ifAbsent: | 5.9% {7779ms} RemoteString>>string | 5.9% {7777ms} ChunkReadStream>>next | 5.8% {7734ms} ChunkReadStream>>basicNextChunk | 5.7% {7535ms} SourceFile>>next | 5.7% {7517ms} ZnCharacterReadStream(ZnEncodedReadStream)>>next | 5.7% {7503ms} ZnCharacterReadStream>>nextElement | 3.0% {3941ms} primitives | 2.7% {3553ms} ZnUTF8Encoder(ZnCharacterEncoder)>>nextFromStream: | 2.7% {3547ms} ZnUTF8Encoder>>nextCodePointFromStream: | 2.7% {3519ms} BinaryFileStream(AbstractBinaryFileStream)>>next | 2.6% {3446ms} ByteArray(Collection)>>ifEmpty:ifNotEmpty: | 2.5% {3361ms} primitives 4.8% {6432ms} SystemDictionary>>allTraitsDo: 4.8% {6428ms} OrderedCollection>>do: 4.8% {6428ms} SystemDictionary>>allTraitsDo: 4.8% {6428ms} SystemNavigation>>allBehaviorsDo: 4.8% {6426ms} SystemNavigation>>allMethodsWithSourceString:matchCase: 4.8% {6370ms} ClyTraitChild1 classTrait(Behavior)>>selectorsDo: 4.8% {6370ms} MethodDictionary>>keysDo: 4.8% {6362ms} SystemNavigation>>allMethodsWithSourceString:matchCase: 4.8% {6356ms} ClyTraitChild1 classTrait(Behavior)>>sourceCodeAt: 4.8% {6350ms} CompiledMethod>>sourceCode 4.8% {6344ms} CompiledMethod>>getSourceFromFile 4.8% {6344ms} BlockClosure>>on:do: 4.8% {6344ms} CompiledMethod>>getSourceFromFile 4.8% {6342ms} SourceFileArray>>sourceCodeAt: 4.8% {6342ms} SourceFileArray>>readStreamAt:ifPresent:ifAbsent: 4.8% {6342ms} SourceFileArray>>readStreamAtFileIndex:atPosition:ifPresent:ifAbsent: 4.7% {6299ms} SourceFileArray>>sourceCodeAt: 4.7% {6292ms} ChunkReadStream>>next 4.7% {6238ms} ChunkReadStream>>basicNextChunk 4.6% {6078ms} SourceFile>>next 4.6% {6063ms} ZnCharacterReadStream(ZnEncodedReadStream)>>next 4.6% {6055ms} ZnCharacterReadStream>>nextElement 2.5% {3256ms} primitives 2.1% {2797ms} ZnUTF8Encoder(ZnCharacterEncoder)>>nextFromStream: 2.1% {2785ms} ZnUTF8Encoder>>nextCodePointFromStream: 2.1% {2779ms} BinaryFileStream(AbstractBinaryFileStream)>>next 2.1% {2727ms} ByteArray(Collection)>>ifEmpty:ifNotEmpty: 2.0% {2667ms} primitives **Leaves** 51.6% {68474ms} ZnCharacterReadStream>>nextElement 42.3% {56100ms} ByteArray(Collection)>>ifEmpty:ifNotEmpty: **Memory** old +0 bytes young -1,076,072 bytes used -1,076,072 bytes free +1,076,072 bytes **GCs** full 0 totalling 0ms (0.0% uptime) incr 691 totalling 859ms (1.0% uptime), avg 1.0ms tenures 0 root table 0 overflows
-- _,,,^..^,,,_ best, Eliot
-- Cyril Ferlicot https://ferlicot.fr