Re: [abc] mystery of ajhotdraw ???

I think that since we already say that we try to remove AWT
overhead - that we should minimize the window and really remove that
overhead.

What I don't understand properly yet is why the AWT overhead
should get larger just because the underlying computation gets
a bit slower. There must be some wierd interaction with
the display windows such that more updates are done to the display
if it sits there for a longer time.

My measurements do show that there is realy tm overhead and a slow
down of 3x to 4x is reasonable due to that overhead.

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
+----------------------------------------------------------------

On Mon, 13 Mar 2006, Pavel Avgustinov wrote:

> Prof. Laurie HENDREN wrote:
>
> >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
> >
> >
> Those numbers are so incredibly different from the ones I'm taking on
> cardinal that I took the time to investigate some more.
>
> First of all, I tried to modify the tracematch code so that it didn't do
> any locking. Perhaps I didn't do it right (Julian -- does it make sense
> to have a debug switch for that? After all, the aspect version doesn't
> lock), but that, surprisingly, didn't give any noticeable change in runtime.
>
> Then I tried minimising the window while the benchmark is running.
>
> For TMNoIndex (the only measurement I've taken yet -- Eric technically
> has the cardinal lock), the runtime falls from 150s to 40s. Still using
> VNC, but programmatically minimising the main window before starting the
> animation.
>
> I can only assume that our problem is subtle differences in the AWT/GUI
> backend. Merely redirecting output to a VNC server doesn't nullify the
> AWT overhead, but minimising the window seemingly does.
>
> Interestingly, the aspectJ version of ajhotdraw ran about as quickly
> minimised as non-minimised (7s).
>
> However, if we minimise the window, TMs are only 6 times slower than
> aspects, rather than 20-30 times.
>
> The much lower overhead that Laurie measured could be explained with a
> more efficient AWT/GUI backend under Windows.
>
> The question is, of course, which numbers to include in the paper. What
> do people think? Since it seems clear the overheads are due to calling
> AWT's display drawing routines, should we just consistently take
> "minimised window" numbers for ajhotdraw? We say we run it on a VNC to
> remove the drawing overhead, but my experiment suggests that's not quite
> enough.
>
> What do people think?
>
> (Eric: Please do not leave cardinal idle, there are still too many
> measurements to take. Either use it or release the lock.)
>
> - P
>
>
> >
> >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 11:54:18 2006