Benchmark for widget creation times

[rj...@google.com]

Reviewers: jaimeyap,

Message:
Review requested

Description:
For a change I'm trying to measure thing before messing with them. To
that end, here's a micro benchmark of various styles of widget creation.
Jaime, I'm hoping you can de-incompetent this for me, and hopefully hint
at how I can make it easier to explore with Speed Tracer.

In the two "pure dom" cases, I'm trying to follow the advice you gave
about creating things detached from the Dom--do they look right on that
front?

One interesting result: at the suggestion of Dan Danilatos, I'm
measuring what happens if use crawling to bind specific dom elements
rather getElementById, and it looks like it's a good bit faster. (My
guess is that the hit for creating dom handles is less than the hit for
attaching to the dom an extra time.) But does it look like I'm actually
comparing apples to apples there?

Please review this at http://gwt-code-reviews.appspot.com/127801

Affected files:

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/Microbenchmarks.gwt.xml

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/EmptyBinder.java

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/EmptyBinder.ui.xml

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/MicroBenchmark.java

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/Microbenchmarks.java

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestDom.java

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestDomBinder.java

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestDomBinder.ui.xml

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestDomCrawl.java

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestFlows.java

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestWidget.java

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestWidgetBinder.java

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestWidgetBinder.ui.xml

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/UiBinderInputElements.ui.xml

reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/WidgetCreation.java
reference/Microbenchmarks/war/Microbenchmarks.html
reference/Microbenchmarks/war/WEB-INF/web.xml

[rj...@google.com]

I've uploaded various tweaks, most recent to allow you to choose how
many instances to make.

http://gwt-code-reviews.appspot.com/127801

[t.br...@gmail.com]

Wearing my "nitpicker" hat ;-)

How about replacing the VerticalPanel and HorizontalPanel with
FlowPanels too? (replace the HTML() label with InlineHTML() to make it
show on the same line as the ListBox and Button)
Or even use UiBinder to create the UI? (people might look at "reference"
applications as examples or even best-practices)

http://gwt-code-reviews.appspot.com/127801/diff/1101/1102
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/Microbenchmarks.gwt.xml
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1102#newcode2
Line 2: <!DOCTYPE module PUBLIC "-//Google Inc.//DTD Google Web Toolkit
0.0.999//EN"
"http://google-web-toolkit.googlecode.com/svn/tags/0.0.999/distro-source/core/src/gwt-module.dtd">
0.0.999 ?
Better remove the DOCTYPE altogether, no?

http://gwt-code-reviews.appspot.com/127801/diff/1101/1106
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/Microbenchmarks.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1106#newcode59
Line 59: horizontalPanel.remove(runningLabel);
runningLabel probably won't ever be visible in this synchronous
scenario.
How about moving the run() and remove(runningLabel) in a
DeferredCommand?

http://gwt-code-reviews.appspot.com/127801/diff/1101/1108
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestDom.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1108#newcode38
Line 38: private static final DivElement detachedDiv =
Document.get().createDivElement();
Isn't this creating a clinit, when accessing TestDom.HTML from other
widgets (e.g. TestCursorDomCrawl).
Shouldn't make much of a difference on the benchmark results but
still...

http://gwt-code-reviews.appspot.com/127801/diff/1101/1117
File reference/Microbenchmarks/war/Microbenchmarks.html (right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1117#newcode1
Line 1: <!DOCTYPE>
Er, you probably rather meant <!DOCTYPE html> ?

http://gwt-code-reviews.appspot.com/127801

[jaim...@google.com]

Initial run through. Ill take a deeper look after I finish up some year
end todo's.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1106
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/Microbenchmarks.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1106#newcode35
Line 35: public class Microbenchmarks implements EntryPoint {
Consistent CamelCasing -> MicroBenchmarks.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1108
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestDom.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1108#newcode25
Line 25: static final String HTML = "<div>"
jgw found that white space (new lines count) can introduce noise into
the tests (at significant performance penalty) since they stick text
nodes into the tree.

To make sure you are comparing apples to apples DOM structure wise,
Please use a predictable string with known amounts of whitespace
(preferrably non since it is hard to count whitespace). I would
recommend just having a string on a single line with some random text
inside some nodes, and then letting eclipse autoformat handle the string
wrapping.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1110
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestDomBinder.ui.xml
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1110#newcode1
Line 1: <ui:UiBinder xmlns:ui='urn:ui:com.google.gwt.uibinder'>
Again, comment about whitespace. Not sure if UiBinder trims it or not.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1111
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestFlows.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1111#newcode7
Line 7: public class TestFlows extends Composite {
Is flow panel nothing more than a thin wrapper around a DIV?

Should probably document this so we know what we are comparing.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1115
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestWidgetBinder.ui.xml
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1115#newcode2
Line 2: xmlns:gwt='urn:import:com.google.gwt.user.client.ui'>
Double check this to make sure the resulting DOM + whitespace is
comparable to the other tests.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/WidgetCreation.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116#newcode63
Line 63: }, new Maker("FlowPanel") {
Should probably also include these textual descriptions in the
individual test case classes. Makes looking through them easier.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116#newcode75
Line 75: }, new Maker("Complex UI, pure dom, get children by id") {
Pure DOM? This test seems to use innerHTML to create the DOM structure
on an unattached div. Why not call it InnerHTML on unnattached div,
getChildrenById.

Maybe writting a name and a longer description and exposing them as
String constants in the test files would be nice.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116#newcode178
Line 178: long start = System.currentTimeMillis();
For a time sensitive benchmark framework, I snub my nose at looping in
the long emulation. Why not just have a simple private utility method:

private static native double currentTimeMillis() /*-{
return (new Date()).getTime();
}-*/;

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116#newcode181
Line 181: r.add(widgets[i]);
There are several things that you may want to measure here.

1. Synchronous Time to add X instances.

2. Time with the end time taken via setTimeout(grabEndTime,0) as an
attempt to include the deferred work that can happen after the JS runs,
but before the user has a chance to interact. This can be drastically
affected by removing the widget since the subsequent deferred style
matching doesnt have any work to do.

3. The time to add and remove a widget synchronously.

I would argue that 1 and 2 are more important than 3. It would be nice
if each test run included all 3 measurements.

http://gwt-code-reviews.appspot.com/127801

[j...@google.com]

Not so much a review, as just a few (hopefully) useful comments:

I was really surprised by the fact that the cursor-based DOM-walking
code was faster than getElementById(). I've added this case to some of
my own tests, and saw (somewhat) similar results. From what I can tell,
it appears that the double-attachment (in the id-based case) is the
lion's share of the difference. If we can find a way to get rid of that,
they'll be a lot closer.

Jaime's point about measuring layout time (referred to as the "deferred
work after JS") is valid. In my own tests, instead of using
setTimeout(0), I just force a layout by measuring the offsetTop of the
bottom-most widget I create. This won't capture paint, but layout seems
to be the real monster most of the time.

One comment on the structure of the benchmark: It's a little confusing
to see a bunch of measurements on things that create *different*
resulting structures. It would be much clearer if these benchmarks were
grouped into clusters of tests that produce the same structures.

I've also got some similar benchmarks on various mechanisms for creating
a Wave list. They're a bit more from the Javascript perspective (only a
couple of GWT tests), trying to determine the fastest absolute mechanism
for creating a bunch of widget-like structures. But I'll merge them into
your own benchmarks once they're checked in.

http://gwt-code-reviews.appspot.com/127801

[rj...@google.com]

Thanks, Joel. The intent here is that the resulting structures are as
near identical as I can make them. Did you see something else?

http://gwt-code-reviews.appspot.com/127801

[rj...@google.com]

http://gwt-code-reviews.appspot.com/127801/diff/1101/1102
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/Microbenchmarks.gwt.xml
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1102#newcode2
Line 2: <!DOCTYPE module PUBLIC "-//Google Inc.//DTD Google Web Toolkit
0.0.999//EN"
"http://google-web-toolkit.googlecode.com/svn/tags/0.0.999/distro-source/core/src/gwt-module.dtd">

On 2009/12/22 14:56:08, t.broyer wrote:
> 0.0.999 ?
> Better remove the DOCTYPE altogether, no?

Done.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1106
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/Microbenchmarks.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1106#newcode35
Line 35: public class Microbenchmarks implements EntryPoint {

I went the other way, Microbenchmarks all around.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1106#newcode59
Line 59: horizontalPanel.remove(runningLabel);

I've done this, and it has a drastic effect on the IE numbers.

When the tests run synchronously in the click handler, succeeding tests
that rely on getElementById roughly double in length on each click of
the run button. (!) By adding this deferred command, that pathology goes
away.

I'm not sure what to do with this information.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1108
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestDom.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1108#newcode25
Line 25: static final String HTML = "<div>"

As we discussed offline, UIBinder strips whitespace. Collapsing it here
can only make the dom cases faster. But, yes, clearly right thing to do.
Fixed.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1108#newcode38
Line 38: private static final DivElement detachedDiv =
Document.get().createDivElement();

Negligible, mirrors what would happen in an automated implementation,
and happens before the tests are run.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1110
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestDomBinder.ui.xml
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1110#newcode1
Line 1: <ui:UiBinder xmlns:ui='urn:ui:com.google.gwt.uibinder'>

It does. And trying to be realistic about usage.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1111
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestFlows.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1111#newcode7
Line 7: public class TestFlows extends Composite {

On 2009/12/22 19:38:26, jaimeyap wrote:
> Is flow panel nothing more than a thin wrapper around a DIV?

> Should probably document this so we know what we are comparing.

Done.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1115
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/TestWidgetBinder.ui.xml
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1115#newcode2
Line 2: xmlns:gwt='urn:import:com.google.gwt.user.client.ui'>

On 2009/12/22 19:38:26, jaimeyap wrote:
> Double check this to make sure the resulting DOM + whitespace is
comparable to
> the other tests.

Done.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/WidgetCreation.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116#newcode63
Line 63: }, new Maker("FlowPanel") {

On 2009/12/22 19:38:26, jaimeyap wrote:
> Should probably also include these textual descriptions in the
individual test
> case classes. Makes looking through them easier.

Done.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116#newcode75
Line 75: }, new Maker("Complex UI, pure dom, get children by id") {

Just beefing up the descriptions, and moving them to the test cases.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116#newcode178
Line 178: long start = System.currentTimeMillis();

On 2009/12/22 19:38:26, jaimeyap wrote:
> For a time sensitive benchmark framework, I snub my nose at looping in
the long
> emulation. Why not just have a simple private utility method:

> private static native double currentTimeMillis() /*-{
> return (new Date()).getTime();
> }-*/;

Done.

http://gwt-code-reviews.appspot.com/127801/diff/1101/1116#newcode181
Line 181: r.add(widgets[i]);

I've uploaded the various cosmetic fixes. Will tackle this timing issue
next.

http://gwt-code-reviews.appspot.com/127801

[jaim...@google.com]

http://gwt-code-reviews.appspot.com/127801/diff/1101/1106
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/Microbenchmarks.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/1101/1106#newcode59
Line 59: horizontalPanel.remove(runningLabel);
Here is a wild guess. Whatever structure IE uses for ID lookups (im
assuming a hash table with chaining) depends on GC to run before
cleaning up the IDs.

Settimeout is a cue for IE to run GC.

Things to try to test:
1. Give the things random ID's to see if the performance degredation is
due to hash collisions on IDs.

2. Keep clicking the tests to see if somewhere along the line a GC
happens and the numbers suddenly "get faster" after getting slower for a
long time.

[rj...@google.com]

The IE bug was actually due to using <span/> instead of <span></span> in
the innerHTML (and appears to have been fixed in IE8.

I've fixed the timing so that it now includes layout. I used Joel's
trick of calling getOffsetTop rather than setTimeout(0) so that I could
keep the code synchronous.

Also unified the innerHTML calls a bit to ensure I'm not accidentally
doing things differently in different tests.

Still haven't explored super-wide-and-shallow and super-deep cases with
crawling, but the year seems to have ended...

http://gwt-code-reviews.appspot.com/127801

[rj...@google.com]

Oh, and the punchline: crawling is still consistently winning, maybe
even more so now that I'm forcing layout.

http://gwt-code-reviews.appspot.com/127801

[t.br...@gmail.com]

Last nit and I'll shut up ;-)

http://gwt-code-reviews.appspot.com/127801/diff/2005/2021
File
reference/Microbenchmarks/src/com/google/gwt/reference/microbenchmark/client/WidgetCreation.java
(right):

http://gwt-code-reviews.appspot.com/127801/diff/2005/2021#newcode58
Line 58: return (new Date()).getTime();
That's actually the exact equivalent of GWT's
Duration.currentTimeMillis()

http://gwt-code-reviews.appspot.com/127801

[j...@google.com]

On 2009/12/23 01:24:21, Ray Ryan wrote:
> Thanks, Joel. The intent here is that the resulting structures are as
near
> identical as I can make them. Did you see something else?

I was referring to the fact that, e.g., EmptyBinder creates a different
structure than TestWidget. Looking back over them in detail, maybe
that's the only one that's different...

http://gwt-code-reviews.appspot.com/127801