[abc] mystery of ajhotdraw ???

I have spent the day trying to figure out what is going on with
jhotdraw. I have done the experiments on my laptop and mostly
used -Xprof which gives you a low cost flat profile.

I let the window just display in the foreground as it made
the simulation.

Here are some approximate numbers:

Summary total approx gc tm exec. unaccounted
                                           overhead overhead

  aspect version 12.8 sec .62 sec
  naive tracematch 187.8 sec 15.39 sec 147 sec 25 sec
  opt tracematch 53.3 sec 3.65 sec 29 sec 21 sec

Naive tracematches allocate a lot more objects, opt tracematches
 allocate fewer, but still pay a gc penalty.

One can identify methods that clearly belong to tracematch
machinery, which I have summarized under tm exec. overhead.

There is some unaccounted overhead, which seems to come mostly
from increased execution time of

javax.swing.RepaintManager.addDirtyRegion.

I don't know why this should be, but it seems that by just leaving
the animation running longer (because of the tm overheads) we also
get increased overhead due to swing stuff. I can only speculate that
there are some complex interactions with the low-level AWT
code that takes care of refreshing the display.

Below are the key methods in the tm opt implementation. Perhaps the
tm boys can verify that these look like methods that are
introduced by the tm implementation (except of course the addDirtyRegion
one and a couple that are jhotdraw methods).

    Compiled + native Method
 37.7% 0 + 1598 javax.swing.RepaintManager.addDirtyRegion
  6.9% 245 + 48 java.util.HashMap.<init>
  3.2% 114 + 20
observdrawchange.Constraint$tracematch$4.addBindingsForSymbolfigureInvalidated
  3.2% 119 + 15 java.util.LinkedHashMap.createEntry
  2.7% 86 + 29 java.util.LinkedHashMap.newKeyIterator
  2.5% 76 + 32 observdrawchange.Constraint$tracematch$4.or
  2.0% 62 + 22 java.util.LinkedHashMap.init
  1.7% 71 + 0
java.util.LinkedHashMap$LinkedHashIterator.hasNext
  1.5% 65 + 0 org.jhotdraw.standard.AbstractFigure.listener
  1.5% 65 + 0 vtable chunks
  1.5% 62 + 0 observdrawchange.Disjunct$tracematch$4.hashCode
  1.4% 54 + 5 java.util.HashSet.iterator
  1.4% 58 + 0
java.util.LinkedHashMap$LinkedHashIterator.<init>
  1.3% 55 + 0 java.util.HashMap.put
  1.2% 52 + 0 java.util.HashMap.hash
  1.0% 42 + 0 org.jhotdraw.contrib.PolygonFigure.bounds
  1.0% 42 + 0
java.util.LinkedHashMap$LinkedHashIterator.nextEntry
  1.0% 41 + 0 java.util.HashMap.removeEntryForKey
  0.9% 37 + 0 java.lang.Math.max
  0.8% 35 + 0
observdrawchange.DrawChangeNotify.tracematch$4$body
  0.8% 34 + 0 java.awt.Rectangle.add
  0.8% 27 + 5
observdrawchange.Disjunct$tracematch$4.addBindingsForSymbolfigureInvalidated
  0.7% 27 + 1 java.util.AbstractCollection.toArray
  0.6% 23 + 3
observdrawchange.DrawChangeNotify.tracematch$4$body_real
  0.6% 24 + 0 java.util.HashSet.size
 89.5% 1981 + 1814 Total compiled (including elided)

         Stub + native Method
  6.9% 60 + 232 java.lang.System.identityHashCode
  1.5% 7 + 55 java.lang.Object.notify
  0.1% 1 + 5 java.lang.Object.hashCode
  0.0% 0 + 2 java.lang.Object.notifyAll
  8.5% 68 + 294 Total stub

----------------------------------------------------------

So, in summary, there do seem to be some significant overheads, even
for the tm opt version, but the direct overheads should only cause
a 3x to 4x slowdown. There are also some indirect effects that
I can only speculate about and I think those effects will vary
depending on the VM implementation and in particular the
implemenation of the awt stuff.

Comparing the naive tm to the opt tm does show that the opt version
saves a lot on gc and on direct tm overhead.

I don't think we will be able to say anything more detailed than
that.

Cheers, Laurie

+-----------------------------------------------------------------
| Laurie Hendren --- laurie.hendren@mcgill.ca
| Associate Dean (Academic), Faculty of Science,
| Dawson Hall, McGill University, 853 Sherbrooke St W,
| Montreal QC H3A 2T6 Canada, 514-398-7179, fax 514-398-1774
+----------------------------------------------------------------
| For contact and home page info as Professor, Computer Science:
| http://www.sable.mcgill.ca/~hendren --- hendren@cs.mcgill.ca
| Research: http://www.sable.mcgill.ca http://aspectbench.org
+----------------------------------------------------------------
Received on Mon Mar 13 02:02:48 2006