As long as I was playing with making an example for the Skeletal
Animation project, I thought that I would profile the model and skeleton loading process, since for bigger models it seems to take a long time. Here are the statements in the world #initialize method that did the profile: fileName := FileDirectory pathFromURI: 'Content/exampleAvatars/Blender/Cube.mesh.xml'. MessageTally spyOn: [ mesh := (TLoadOgreMesh initializeWithFileName: fileName scale: 0.4) frame. ]. and here is the report for the simple model I have been playing with: - 9239 tallies, 9302 msec. **Tree** 74.7% {6949ms} EventSensor>>installEventTickler |74.7% {6949ms} EventSensor>>eventTickler | 74.7% {6949ms} Delay>>wait | 74.7% {6949ms} Semaphore>>wait 22.6% {2102ms} TLoadOgreMesh class>>initializeWithFileName:scale: |22.6% {2102ms} TLoadOgreMesh>>initializeWithFileName:scale: | 22.5% {2093ms} TLoadOgreMesh>>parseStream: | 22.5% {2093ms} XMLDOMParser class>>parseDocumentFrom: | 22.5% {2093ms} XMLDOMParser class(SAXHandler class)>>parseDocumentFrom: | 22.5% {2093ms} XMLDOMParser(SAXHandler)>>parseDocument | 22.3% {2074ms} SAXDriver(XMLTokenizer)>>nextEntity | 16.7% {1553ms} SAXDriver(XMLTokenizer)>>nextNode | |16.6% {1544ms} SAXDriver(XMLTokenizer)>>nextTag | | 8.9% {828ms} SAXDriver(XMLTokenizer)>>nextAttributeInto:namespaces: | | |5.7% {530ms} SAXDriver(XMLTokenizer)>>nextAttributeValue | | | 4.0% {372ms} primitives | | 2.1% {195ms} SAXDriver(XMLTokenizer)>>nextName | 5.3% {493ms} SAXDriver(XMLTokenizer)>>nextWhitespace | 2.8% {260ms} WriteStream>>nextPut: | 2.7% {251ms} primitives 2.4% {223ms} TMessageRouterClient(Object)>>fork:at: **Leaves** 76.5% {7116ms} Semaphore>>wait 4.0% {372ms} SAXDriver(XMLTokenizer)>>nextAttributeValue 3.3% {307ms} SAXDriver(XMLTokenizer)>>next 3.0% {279ms} WriteStream>>nextPut: **Memory** old +1,777,420 bytes young +198,080 bytes used +1,975,500 bytes free +441,240 bytes **GCs** full 1 totalling 1,475ms (16.0% uptime), avg 1475.0ms incr 461 totalling 535ms (6.0% uptime), avg 1.0ms tenures 46 (avg 10 GCs/tenure) root table 0 overflows I don't understand why most of the time is spent in Semaphore>>wait. Why is that? |
> I don't understand why most of the time is spent in Semaphore>>wait.
> Why is that? See the discussion starting here: http://lists.squeakfoundation.org/pipermail/vm-dev/2007-June/001410.html The problem is that profiling doesn't actually measure what is going on with very odd side effects. Cheers, - Andreas David Faught wrote: > As long as I was playing with making an example for the Skeletal > Animation project, I thought that I would profile the model and > skeleton loading process, since for bigger models it seems to take a > long time. Here are the statements in the world #initialize method > that did the profile: > > > fileName := FileDirectory pathFromURI: > 'Content/exampleAvatars/Blender/Cube.mesh.xml'. > MessageTally spyOn: [ > mesh := (TLoadOgreMesh initializeWithFileName: fileName scale: 0.4) frame. > ]. > > and here is the report for the simple model I have been playing with: > > - 9239 tallies, 9302 msec. > > **Tree** > 74.7% {6949ms} EventSensor>>installEventTickler > |74.7% {6949ms} EventSensor>>eventTickler > | 74.7% {6949ms} Delay>>wait > | 74.7% {6949ms} Semaphore>>wait > 22.6% {2102ms} TLoadOgreMesh class>>initializeWithFileName:scale: > |22.6% {2102ms} TLoadOgreMesh>>initializeWithFileName:scale: > | 22.5% {2093ms} TLoadOgreMesh>>parseStream: > | 22.5% {2093ms} XMLDOMParser class>>parseDocumentFrom: > | 22.5% {2093ms} XMLDOMParser class(SAXHandler class)>>parseDocumentFrom: > | 22.5% {2093ms} XMLDOMParser(SAXHandler)>>parseDocument > | 22.3% {2074ms} SAXDriver(XMLTokenizer)>>nextEntity > | 16.7% {1553ms} SAXDriver(XMLTokenizer)>>nextNode > | |16.6% {1544ms} SAXDriver(XMLTokenizer)>>nextTag > | | 8.9% {828ms} > SAXDriver(XMLTokenizer)>>nextAttributeInto:namespaces: > | | |5.7% {530ms} SAXDriver(XMLTokenizer)>>nextAttributeValue > | | | 4.0% {372ms} primitives > | | 2.1% {195ms} SAXDriver(XMLTokenizer)>>nextName > | 5.3% {493ms} SAXDriver(XMLTokenizer)>>nextWhitespace > | 2.8% {260ms} WriteStream>>nextPut: > | 2.7% {251ms} primitives > 2.4% {223ms} TMessageRouterClient(Object)>>fork:at: > > **Leaves** > 76.5% {7116ms} Semaphore>>wait > 4.0% {372ms} SAXDriver(XMLTokenizer)>>nextAttributeValue > 3.3% {307ms} SAXDriver(XMLTokenizer)>>next > 3.0% {279ms} WriteStream>>nextPut: > > **Memory** > old +1,777,420 bytes > young +198,080 bytes > used +1,975,500 bytes > free +441,240 bytes > > **GCs** > full 1 totalling 1,475ms (16.0% uptime), avg 1475.0ms > incr 461 totalling 535ms (6.0% uptime), avg 1.0ms > tenures 46 (avg 10 GCs/tenure) > root table 0 overflows > > > I don't understand why most of the time is spent in Semaphore>>wait. > Why is that? > |
Free forum by Nabble | Edit this page |