375225 - Creating table with DOM noticeably slower since Firefox 2

Status: RESOLVED FIXED

(Core :: DOM: Core & HTML, defect, P2)

Description

[José Jeria]

Build id: Latest trunk build using Windows XP SP 2

Creating a table using the DOM seems noticeable slower in Alpha 3 compared to Firefox 2

Steps to reproduce
1. Visit http://www.jeria.net/performance_test/
2. Run the test using "DOM solution"
3. Compare results with Firefox 2 and a trunk build

Comment 1

[Olli Pettay [:smaug][[e-mail]]]

Any chance to find the regression range.

Comment 2

[Martijn Wargers (dead)]

These are some builds I tested with:
2007-03-21 branch  1.219 seconds
2006-10-01 trunk   1.25 seconds
2006-12-31 trunk   1.344 seconds
2007-01-02 trunk   1.312 seconds
2007-01-04 trunk   1.25 seconds
2007-01-05 trunk   1.578 seconds
2007-01-10 trunk   1.672 seconds
2007-03-23 trunk   1.531 seconds

So I think there is a performance regression at least between 2007-01-04 and 2007-01-05, which is when the xpcom cycle collector was checked in (bug 333078).

Comment 3

[Boris Zbarsky [:bzbarsky]]

Attachment: The testcase

Comment 4

[Boris Zbarsky [:bzbarsky]]

I profiled this, and nothing jumps out at me.  The cycle collector's impact on addref/release slows things down by about 10% here (but my times are in the 12-15 second range to start with, of course), not 2x.  Might be worth retesting once those bugs are addressed.

Comment 5

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

Lets wait with this one until we've landed some of the cycle collector performance fixes that are in the works.

Comment 6

[Olli Pettay [:smaug][[e-mail]]]

Using opt-builds (-O3) built today, 1.8 is ~0.93secs, 1.9 ~0.83secs on 
my machine. This is after the CC/AddRef patch was checked in.

Comment 7

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

Based on smaugs comment I'm marking this non-blocking for now.

Would be great if someone could retest and if we're still worse renominate as blocker, and if we're as good or better close as FIXED

Comment 8

[François Gagné]

New profiles:

Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9a5pre) Gecko/20070503 Minefield/3.0a5pre

0.812
0.891
0.859
0.843
0.828
0.906
0.829
0.906
0.828
0.906

avg 0.8608


Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.4pre) Gecko/20070504 BonEcho/2.0.0.4pre

0.735
0.75
0.766
0.734
0.719
0.75
0.765
0.75
0.75
0.766

avg 0.7485

Comment 9

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

It would be great to test both modifications done to nodes that are in the Document, and orphaned nodes that has been removed from the document.

This way we can determine if the slowdown is in the DOM or the layout code.

Comment 10

[José Jeria]

Re-requesting blocking 1.9. This is still much slower using the latest trunk build on Windows 2000/XP compared to Firefox 2.

Comment 11

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

Still looking for better testcases here so that we can figure out what got slower.

Comment 12

[Johnny Stenback (:jst)]

Peter, could you spend some time on this? We may need profiling tools etc to find anything useful here, but we need to start somewhere.

Comment 13

[Johnny Stenback (:jst)]

Also, if someone can work on more testcases for this that would be immensly helpful to us. See comment #9.

Comment 14

[Mike Schroepfer]

Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.4; en-US; rv:1.9a9pre) Gecko/2007110604 Minefield/3.0a9pre ID:2007110604

Confirming .89s on trunk .78s on branch.   CAPs/Security checks maybe?

Comment 15

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

could anyone try to remove the use of global variables here and see if that makes a difference? At least iLength is global, and probably other ones too.

We have a known bug on global variable access getting slower sometimes, due to added security checks. We're working on removing those in bug 395993

Comment 16

[Mike Schroepfer]

Attachment: Moving iLength + iLength2 to local vars

Moved iLength + iLength2 to local vars.  Made things worse (.94s vs .9s).  Anything else you want me to try?

Comment 17

[Mike Schroepfer]

Attachment: Shark profile

Shark profile of trunk with the first test.  I moved the array size to 30k elements and removed the final append to the DOM to excempt any reflow/repaint time.

+ 11.7% nsScriptSecurityManager::CanAccess(unsigned, nsIXPCNativeCallContext*, JSContext*, JSObject*, nsISupports*, nsIClassInfo*, long, void**) (XUL)
6.5% XPC_XOW_GetOrSetProperty

Both look like areas to look at...

Comment 18

[Mike Schroepfer]

Attachment: Simplified testcase to only create nodes

Simplified the trestcase so the inner loop is just:

document.createTextNode("a")

To isolate reflows and other operations.  Profile coming up

Comment 19

[Mike Schroepfer]

Attachment: Shark Summary report

Comment 20

[Mike Schroepfer]

Full Shark profile shows a number of interesting things:

1) XOW is here all over the place as is IsWrapperSameOrigin
2) Lots of time spent in NativeInterface2JSObject

This test runs:

Trunk 6.5s
FF2009 5.2s
Safari 3.0.4 1.1s

So we should clean up all the XOW and security checks stuff - that would get us back to FF2 speed, but there looks to be plenty of other room for opt (if it is 4-5x slower than safari).  In particular the data conversion seems suspect.

Can find it here:
 
http://people.mozilla.com/~schrep/shark.mshark

Comment 21

[Mike Schroepfer]

With the patches from bug 406671 and bug 406692 I'm seeing trunk around 5.7s (around a 15% improvement).  nice quick work JST! Still plenty of room for opt but awesome to see us get closer...

Comment 22

[Mike Schroepfer]

Moving prio to P2 since this is an obvious perf regression...

Comment 23

[Mike Schroepfer]

Just a quick note - on today's nightly I'm seeing 5.1s on trunk, 5.2s on branch.  So we've made up the difference - but don't let that stop you JST :-) as we know we can do way better...

Comment 24

[Johnny Stenback (:jst)]

Nice! But yeah, there's some more coming...

Comment 25

[Mike Schroepfer]

(In reply to comment #24)
> Nice! But yeah, there's some more coming...
> 


Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US; rv:1.9b3pre) Gecko/2008012204 Minefield/3.0b3pre

Today's trunk on mac: 4.45s
2009 on mac:  5.18
Safari 3.0.0.4: 1.092s

So we are now definitely better trunk v branch but have some more room to go :-)

Comment 26

[Mike Schroepfer]

Today's trunk vs branch on vista;

Trunk 2.4s
Branch 3.5s

So now 1.45x faster.

Comment 27

[Mike Schroepfer]

(In reply to comment #26)
> Today's trunk vs branch on vista;
> 
> Trunk 2.4s
> Branch 3.5s
> 
> So now 1.45x faster.
> 

Similar results on Mac.  Should we close this bug?

Comment 28

[Johnny Stenback (:jst)]

Yeah, might as well.

Comment 29

[Kai de Leeuw]

I have very closely been following the progress on the time that it takes to execute the three buttons, almost daily for the last three weeks.

I have noticed that about one week ago the tests executed approximately 10% faster. So something must have regressed performance wise here.

This bug is closed, I know that, I am just adding some more info if anyone wants to do something about it.

Comment 30

[Olli Pettay [:smaug][[e-mail]]]

Kai, could you find the regression range using nightly builds and file
a new bug.

Comment 31

[Kai de Leeuw]

Sorry for wasting your time, I disabled an extension I installed lately, and the lost performance came back.

Comment 32

[Mike Schroepfer]

Which extension?

Comment 33

[Kai de Leeuw]

Operator 0.9g

Comment 34

[Jesse Ruderman]

Mike Kaply, you might find the last few comments interesting.

Comment 35

[Mike Kaply [:mkaply]]

I just ran some tests on FF B3 with my latest Operator (the same as G as far as this is concerned) and I only see an impact of maybe .1 or .2 of a second over no Operator.

Operator is listening to DOMNodeInserted messages, so we are getting a lot of those, but what we do in response is stop and kick off a 100 millisecond timer each time so that in the end we "stack" all the messages and parse the document at once.

This is working pefectly in this case (we only actually try to parse the document at the end).

But the act of starting and stopping 12000 timers probably isn't great, but there isn't a better way to do this that I know of. There's no way to know when a document is done messing with the DOM.

Note that for future reference, you should always turn off all extensions when doing any performance testing.

Comment 36

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

The sheer fact of installing a mutation event listener will also slow us down. We don't fire that event unless someone is listening.

Comment 37

[Brendan Eich [:brendan]]

(In reply to comment #35)
> But the act of starting and stopping 12000 timers probably isn't great, but
> there isn't a better way to do this that I know of. There's no way to know when
> a document is done messing with the DOM.

What about using DOMContentLoaded?

http://lxr.mozilla.org/mozilla/search?string=DOMContentLoaded

/be

Comment 38

[Mike Kaply [:mkaply]]

DOMContentLoaded is only send on the initial load.

The issue here is how to know when AJAXy stuff has happened (DOM nodes added/removed) so you can reparse the document and know if the microformats in the document have changed based on the add/removal of DOM nodes.

What DOM really needs is a message that a DHTML web page can send that says "I'm done" so that extensions and other things can listen for that message.

Comment 39

[Jesse Ruderman]

Would it work for Operator to remove its DOMNodeInserted listener the first time it fires, and then re-add it once the 100ms timer fires?

Comment 40

[Mike Shaver (:shaver emeritus)]

Perhaps you would be interested in a setInterval?  Have the mutation listeners just mark that they were fired (set some global "dirty" flag), have the 100ms setInterval clear dirty and return if it's set, or do the roll-up work if it's not (meaning that there was no mutation in the last 100ms).

Likely cheaper than using many individual timers.

Comment 41

[Mike Shaver (:shaver emeritus)]

(Are we really still 45% slower at this than the branch?  That's unfortunate!)

Comment 42

[Martijn Wargers (dead)]

(In reply to comment #38)
> What DOM really needs is a message that a DHTML web page can send that says
> "I'm done" so that extensions and other things can listen for that message.

I think you mean bug 347174, right?

Comment 43

[Johnny Stenback (:jst)]

(In reply to comment #41)
> (Are we really still 45% slower at this than the branch?  That's unfortunate!)

What? See comment #27, we were a good bit faster on trunk than branch when we closed this bug.

Comment 44

[Mike Shaver (:shaver emeritus)]

Not my finest reading-comprehension moment, I admit.

Comment 45

[Kai de Leeuw]

Is it just me or has this gotten approximately 10% slower in the last few days?
I don't have any extension active in my profile.

I could easily (on my machine) get 0.8x seconds repeatedly. Now I get 0.9x seconds instead. Even killing as many apps as possible from task manager doesn't make a difference.

Comment 46

[Kai de Leeuw]

To be more clear, I meant the "DOM solution" button.

Comment 47

[Martijn Wargers (dead)]

Kai, could you please file a new bug for that (and mention the bug number here)?

Comment 48

[Kai de Leeuw]

I just filed bug 426854.