Help with profiling some code?

Joshua 'Schwa' Gargus schwa at cc.gatech.edu
Thu May 15 21:15:25 UTC 2003


On Thu, May 15, 2003 at 11:08:27PM +0200, Andreas Raab wrote:
> Hi Josh,
> 
> Couple of guesses:
> 
> #1: You might have some full GC issue in there. A single full GC can change
> the entire picture in the below. Make sure that there are no full GCs in the
> entire measure or else you will have to weigh in these factors.

According to the tally, there isn't.

> 
> #2: Make sure there aren't any other processes doing wild stuff while you're
> measuring. MessageTally will attribute any time spent in other processes in
> the place that got suspended.
> 

I'm running this from a Workspace, and I'm not spawning any new processes
myself, so this shouldn't be a problem.

> #3: Check if you're using the same combinations of VMs/plugins.

How do I check the plugins?  The results from "Smalltalk listLoadedModules"
match, but that doesn't seem definitive.  Anyway, I'm launching the images
by double-clicking in the same Windows directory, so I think they're getting
the same plugins.

Thanks for the help,
Joshua


> 
> Cheers,
>   - Andreas
> 
> > -----Original Message-----
> > From: squeak-dev-bounces at lists.squeakfoundation.org 
> > [mailto:squeak-dev-bounces at lists.squeakfoundation.org] On 
> > Behalf Of Joshua 'Schwa' Gargus
> > Sent: Thursday, May 15, 2003 10:48 PM
> > To: Squeak Mailing List
> > Subject: Help with profiling some code?
> > 
> > 
> > Hi,
> > 
> > I'm having a weird performance discrepancy between code in two
> > different images.  The code is not the same, but the the part that is
> > causing the performance hotspot should be.  Here are message tallies
> > of the weird parts:
> > 
> > 	|      43.1% {1162ms} Transform>>transformTransform:
> > 	|        29.3% {790ms} B3DRotation>>*
> > 	|          |9.0% {243ms} B3DVector3>>cross:
> > 	|          |  |3.0% {81ms} B3DVector3>>z
> > 	|          |  |2.4% {65ms} B3DVector3>>x
> > 	|          |8.4% {226ms} B3DRotation class>>a:b:c:d:
> > 	|          |  |7.2% {194ms} B3DRotation>>a:b:c:d:
> > 	|          |  |  6.0% {162ms} B3DRotation>>normalize
> > 	|          |  |    2.4% {65ms} B3DRotation>>b
> > 	|          |5.4% {146ms} B3DRotation>>bcd
> > 	|          |  |3.0% {81ms} B3DVector3 class>>x:y:z:
> > 	|          |4.2% {113ms} B3DRotation>>a
> > 	|        12.6% {340ms} Transform>>transformVector:
> > 	|          6.0% {162ms} B3DRotation>>asMatrix4x4
> > 	|          3.6% {97ms} B3DMatrix4x4>>localDirToGlobal:
> > 	|          2.4% {65ms} B3DVector3(FloatArray)>>*=
> > 
> > (and the other one)
> > 
> > 	|        65.8% {4223ms} Transform>>transformTransform:
> > 	|          35.4% {2272ms} B3DRotation>>*
> > 	|            |13.6% {873ms} B3DVector3>>cross:
> > 	|            |  |4.3% {276ms} B3DVector3 class>>x:y:z:
> > 	|            |  |  |2.9% {186ms} primitives
> > 	|            |  |4.1% {263ms} B3DVector3>>z
> > 	|            |  |3.5% {225ms} B3DVector3>>x
> > 	|            |11.3% {725ms} B3DRotation class>>a:b:c:d:
> > 	|            |  |10.4% {667ms} B3DRotation>>a:b:c:d:
> > 	|            |  |  9.6% {616ms} B3DRotation>>normalize
> > 	|            |  |    2.6% {167ms} Float(Number)>>squared
> > 	|            |3.5% {225ms} B3DRotation>>bcd
> > 	|            |  2.9% {186ms} B3DVector3 class>>x:y:z:
> > 	|          27.0% {1733ms} Transform>>transformVector:
> > 	|            |14.8% {950ms} B3DRotation>>asMatrix4x4
> > 	|            |  |4.6% {295ms} B3DRotation>>matrixClass
> > 	|            |  |2.3% {148ms} B3DMatrix4x4>>a11:
> > 	|            |11.0% {706ms} B3DMatrix4x4>>localDirToGlobal:
> > 	|            |  2.6% {167ms} B3DMatrix4x4>>a31
> > 	|            |  2.3% {148ms} B3DVector3 class>>x:y:z:
> > 	|          2.6% {167ms} Transform>>translation:
> > 
> > The method Transform>>tranformTransform: is a double dispatch that
> > you needn't concern yourself with.  The code for the method is the
> > same in both images.  Notice that even though #* is called on 
> > B3DRotation the same number of times (I verified this), it takes
> > more than twice as long to run in the second image.
> > 
> > I decided to try to exercise just that method with the following code:
> > 
> > | b1 b2 |
> > b1 := B3DRotation axis: (1 at 4@3) normalized angle: 56.
> > b2 := B3DRotation axis: (2 at 5@7) normalized angle: 22.222.
> > [30000 timesRepeat: [b1 * b2 * b1 * b2]] timeToRun
> > 
> > I ran the snippet a bunch of times in both images, and they both
> > took roughly the same time.
> > 
> > I tried garbage-collecting, and restarting each image.  Neither
> > made any difference.  Does anyone have any hints about how to 
> > approach this?
> > 
> > 
> > Thanks,
> > Joshua
> > 
> 



More information about the Squeak-dev mailing list