Oh, looks like a neat feature. I note it for future use.
To figure out where time is spent, I have runned MessageTally over a 10 time commit
MessageTally spyOn: [10 timesRepeat: [self learner recordAchievements: self veryDeepCopy]]
I have to admit the MessageTally output looks like chinese for me (hum chinese is eaiser) as I don't know much about Magma internal. I have enclosed there the MessageTally output, there are big tension on IdentitySet>>ScanFor: not sure what it exactly mean.
Chris your are doing great providing info about the use of Magma. I would like to give a hand to collect info posted there in a FAQ on the swiki. If other want to help it will be great.
Hilaire
- 63026 tallies, 64099 msec.
**Tree** 95.1% {60958ms} IFILearner>>recordAchievements: |83.3% {53394ms} IFIDbSession class>>commit: | |83.3% {53394ms} IFIDbSession>>commit: | | 83.3% {53394ms} MagmaSession>>commit: | | 83.2% {53330ms} MagmaSession>>commit | | 83.2% {53330ms} MagmaSession>>commitAndBegin: | | 42.4% {27178ms} MagmaSession>>submit: | | |42.4% {27178ms} MaLocalServerLink>>submit: | | | 42.4% {27178ms} MaLocalRequestServer(MaRequestServer)>>processRequest: | | | 42.4% {27178ms} MagmaRepositoryController>>value: | | | 42.4% {27178ms} MagmaRepositoryController>>processRequest: | | | 42.4% {27178ms} MaWriteRequest>>process | | | 42.4% {27178ms} MaObjectRepository>>submitAll:for:beginAnother: | | | 41.3% {26473ms} MaObjectRepository>>write: | | | 34.0% {21794ms} MaRecoveryManager>>log:flush: | | | |33.3% {21345ms} MaObjectSerializer>>serializeGraph: | | | | 33.3% {21345ms} MaObjectSerializer>>serializeGraph:do: | | | | 33.3% {21345ms} MaObjectSerializer>>appendGraph:do: | | | | 28.9% {18525ms} MaCommitLogEntry(Object)>>maGraphDo:using: | | | | |28.9% {18525ms} UndefinedObject(ProtoObject)>>maValueGraphNode:index:using:with:path:with: | | | | | 28.9% {18525ms} MaCommitLogEntry(ProtoObject)>>maGraphDo:using:path:with: | | | | | 28.9% {18525ms} MaCommitLogEntry(ProtoObject)>>maValueGraphNode:index:using:with:path:with: | | | | | 28.9% {18525ms} MaCommitPackage(ProtoObject)>>maGraphDo:using:path:with: | | | | | 28.9% {18525ms} MaCommitPackage(ProtoObject)>>maValueGraphNode:index:using:with:path:with: | | | | | 28.7% {18396ms} Dictionary>>maGraphDo:using:path:with: | | | | | 28.7% {18396ms} Dictionary(ProtoObject)>>maValueGraphNode:index:using:with:path:with: | | | | | 11.0% {7051ms} IdentitySet(Set)>>add: | | | | | |9.4% {6025ms} IdentitySet(Set)>>findElementOrNil: | | | | | | 9.3% {5961ms} IdentitySet>>scanFor: | | | | | 9.6% {6154ms} IdentitySet(Set)>>includes: | | | | | |9.5% {6089ms} IdentitySet(Set)>>findElementOrNil: | | | | | | 9.5% {6089ms} IdentitySet>>scanFor: | | | | | 7.8% {5000ms} SmallInteger(ProtoObject)>>maGraphDo:using:path:with: | | | | | 7.7% {4936ms} MaFixedObjectBuffer(ProtoObject)>>maValueGraphNode:index:using:with:path:with: | | | | | 4.1% {2628ms} IdentitySet(Set)>>includes: | | | | | |4.1% {2628ms} IdentitySet(Set)>>findElementOrNil: | | | | | | 4.1% {2628ms} IdentitySet>>scanFor: | | | | | 3.5% {2243ms} IdentitySet(Set)>>add: | | | | | 3.1% {1987ms} IdentitySet(Set)>>findElementOrNil: | | | | | 3.1% {1987ms} IdentitySet>>scanFor: | | | | 4.2% {2692ms} MaObjectSerializer>>append: | | | | 3.9% {2500ms} MaObjectSerializer>>bufferFor:storageObject:startingAt: | | | 4.7% {3013ms} MaObjectRepository>>applyToCache: | | | 4.3% {2756ms} MaObjectFiler>>write:index: | | | 2.1% {1346ms} MaObjectFiler>>index:at: | | | 2.1% {1346ms} MaLargeArrayOfNumbers>>at:put: | | 28.8% {18461ms} MagmaSession>>newCommitPackageFor: | | |22.6% {14486ms} MaTransaction>>changedObjects | | | |22.5% {14422ms} MaTransaction>>addChangesFromReadSet | | | | 22.0% {14102ms} MaTransaction>>didChange:from: | | | | 13.5% {8653ms} MaFixedObjectBuffer>>isDifferent:using: | | | | |5.0% {3205ms} MaObjectSerializer>>oidFor: | | | | | |4.8% {3077ms} MagmaOidManager(MaOidManager)>>oidFor: | | | | | | 4.6% {2949ms} MagmaOidManager>>oidFor:ifAbsent: | | | | | | 2.9% {1859ms} MagmaOidManager(MaOidManager)>>oidFor:ifAbsent: | | | | |3.8% {2436ms} MaFixedObjectBuffer(MaObjectBuffer)>>maInstVarAt: | | | | | 2.5% {1602ms} MaFixedObjectBuffer(MaObjectBuffer)>>uint:at: | | | | | 2.3% {1474ms} ByteArray>>maUint:at: | | | | | 2.0% {1282ms} ByteArray>>maUnsigned48At: | | | | 6.2% {3974ms} MaByteObjectBuffer(MaVariableBuffer)>>isDifferent:using: | | | | |3.3% {2115ms} Array>>maIsChangedFrom:using: | | | | | 2.6% {1667ms} Array(Object)>>maIsChangedFrom:using: | | | | 2.1% {1346ms} MaTransaction>>useWriteBarrierOn: | | |6.2% {3974ms} MaCommitPackage>>serializeObjectsUsing: | | | 6.0% {3846ms} MaObjectSerializer>>serializeGraph:do: | | | 6.0% {3846ms} MaObjectSerializer>>appendGraph:do: | | | 5.1% {3269ms} MaObjectSerializer>>append: | | | 4.6% {2949ms} MaObjectSerializer>>bufferFor:storageObject:startingAt: | | 12.1% {7756ms} MagmaSession>>refreshViewUsing: | | 12.1% {7756ms} MaCommitResult>>refresh: | | 10.4% {6666ms} MagmaSession>>assignPermanentOidsFrom: | | 9.8% {6282ms} MaObjectSerializer>>oidOf:is: | | 9.8% {6282ms} MagmaOidManager>>oidOf:is: | | 9.8% {6282ms} MagmaOidManager(MaOidManager)>>oidOf:is: | | 9.3% {5961ms} MaWeakValueDictionary(MaDictionary)>>at:put: | | 8.1% {5192ms} WeakValueDictionary(Dictionary)>>includesKey: | | 8.0% {5128ms} WeakValueDictionary(Dictionary)>>at:ifAbsent: | | 8.0% {5128ms} WeakValueDictionary(Set)>>findElementOrNil: | | 7.9% {5064ms} WeakValueDictionary(Dictionary)>>scanFor: |9.1% {5833ms} IFILearner>>propagateSuffisanceFrom: | 5.1% {3269ms} IFILearner>>propagateSuffisanceFrom: | |2.7% {1731ms} IFILearner>>propagateSuffisanceFrom: | 3.4% {2179ms} MagmaCollectionReader>>do: | 2.9% {1859ms} MagmaCollectionReader>>at: | 2.9% {1859ms} MagmaCollectionReader>>at:ifOutOfBounds: | 2.9% {1859ms} MagmaCollectionReader>>primAt:ifOutOfBounds: | 2.9% {1859ms} MagmaCollectionReader>>loadFromIndex:pageSize: | 2.9% {1859ms} MagmaCollectionReader>>segmentContaining: | 2.9% {1859ms} MagmaCollectionReader>>refreshSegment:loadObjects: | 2.9% {1859ms} MagmaCollection>>refreshSegment:where:...ze:using:loadObjects: | 2.9% {1859ms} MagmaSession>>refreshSegment:of:where...ize:using:loadObjects: | 2.4% {1538ms} MagmaSession>>materializeObjectsIn: | 2.4% {1538ms} MagmaSession>>materializeObject: | 2.4% {1538ms} MaObjectSerializer>>materializeGraph:do: | 2.4% {1538ms} MaObjectSerializer>>materializeGraphDo: | 2.3% {1474ms} MaObjectSerializer>>newSkeletonFor:fromProxy: | 2.3% {1474ms} MaObjectSerializer>>oidOf:is: | 2.3% {1474ms} MagmaOidManager>>oidOf:is: | 2.3% {1474ms} MagmaOidManager(MaOidManager)>>oidOf:is: | 2.2% {1410ms} MagmaOidManager>>removeGarbageCollectedObjectEntries | 2.2% {1410ms} MagmaOidManager(MaOidManager)>>removeGarbageCollectedObjectEntries | 2.2% {1410ms} MaWeakValueDictionary(MaDictionary)>>reject: | 2.2% {1410ms} MaWeakValueDictionary(MaDictionary)>>add: 2.6% {1667ms} MagmaSession>>initializeSerializer **Leaves** 28.2% {18076ms} IdentitySet>>scanFor: 13.1% {8397ms} WeakValueDictionary(Dictionary)>>scanFor: 2.4% {1538ms} IdentityDictionary(Dictionary)>>at:ifAbsent: 2.2% {1410ms} MethodDictionary(Set)>>findElementOrNil: 2.1% {1346ms} WeakIdentityKeyDictionary>>scanFor:
**Memory** old +9,660,444 bytes young +59,280 bytes used +9,719,724 bytes free -940,764 bytes
**GCs** full 6 totalling 1,420ms (2.0% uptime), avg 237.0ms incr 7900 totalling 6,562ms (10.0% uptime), avg 1.0ms tenures 244 (avg 32 GCs/tenure) root table 0 overflows