User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.6b) Gecko/20031208 Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.6b) Gecko/20031208 This 3D example of a rotating cube, that runs much slower in Mozilla1.6b than in IE6 on my AMD 800Mhz / win2000 with 99% cpu consumption compared to 75-80% with ie. Reproducible: Always Steps to Reproduce: 1. open the url 2. just click on start/stop Actual Results: slow performance, high memory usage Expected Results: smother rendering of cube

Wow, yeah, we're really slow on this. Would be nice to get a profile. And a more accurate testcase to measure it. This test seems to involve a lot of adding and removing elements and positioning them, so it might even be quite a realistic test.

(o133885)

Profile is at bug 195408 comment 17.

Simon: If you want to make a testcase out of this, see http://www.hixie.ch/tests/adhoc/perf/dom/artificial/000.html ...for a template of sorts. You can look at other tests in that directory to see what some other performance tests look like. That would help us get actual numbers here, which make testing this a lot easier and accurate. Note that when comparing browsers, it is critical to: 1. Not have the mouse cursor in the window 2. Have windows the same size The following page can help with the second of those: http://www.hixie.ch/tests/adhoc/perf/prepare.html

The top item in the profile is this AlreadyInQueue thing... That could be made better by having the queue not be an array (since then building up the queue would not be O(N^2) in the length of the queue). That makes it somewhat difficult to guarantee in-order processing of the queue, however... Perhaps one could use a hashtable to guarantee uniqueness and an array for the ordering and add to both? As for the rest of the profile, it looks like standard stuff -- style reresolution, mostly. I assume the testcase sets a bunch of style properties one right after another all off a single timeout?

Ian, I would like to create a testcase, but give me some time, I will be gone snowboarding the next days. I tried to reduce the creation/destroying of elements and the setting of style properties to a minimum. I basically create 368 div elements at the beginning (pixels) and then start the timeout, which only moves the elements around (set top/left properties).

See also the post I just made to n.p.m.style with a proposal that may end up helping out a good bit here.

Hi everyone I created a testcase. Go to the url above and click the link to the mozilla testcase. Here are my measurements on an AMD 900Mhz, Windows 2000: *** Moz1.6b *** small cube: Elapsed time: 12'447 ms Average per loop: 248.94 ms Fastest loop: 210 ms Slowest loop: 290 ms big cube: Elapsed time: 30'916 ms Average per loop: 618.32 ms Fastest loop: 421 ms Slowest loop: 761 ms *** IE6 *** small cube: Elapsed time: 3'475 ms Average per loop: 69.50 ms Fastest loop: 60 ms big cube: Elapsed time: 7'009 ms Average per loop: 140.18 ms Fastest loop: 120 ms Slowest loop: 161 ms Slowest loop: 91 ms

Alternate version (thanks Simon!): http://www.hixie.ch/tests/adhoc/perf/dom/real-world/006.html

On the testcase in comment 9, of the total 3216 jprof hits, we have: 244 under PresShell::ProcessReflowCommands 143 under nsArraySH::GetProperty (mostly GetItemAt and classinfo's WrapNative) 719 under CSS2PropertiesTearoff::SetTop 670 under CSS2PropertiesTearoff::SetLeft 164 under CSS2PropertiesTearoff::SetVisibility 281 under nsScriptSecurityManager::CanAccess (see bug 213946 for where most of that time is) The rest is in minor other stuff, JS engine itself, etc. Under SetTop and company, the breakdown is: 1552 total under nsDOMCSSDeclaration::SetProperty 323 of that under CSSParserImpl::ParseProperty 513 of that under FrameManager::ComputeStyleChangeFor 303 of that under ApplyRenderingChangeToTree 161 of that under PresShell::AppendReflowCommand that last one, 2/3 is the AlreadyInQueue check mentioned in comment 5 and 1/3 PostReflowEvent (event queue getting, monitors, etc, etc). So the testcase is showing mostly the things we already knew: 1) Security manager could be improved a bit 2) Batching style reresolves would help a _lot_ in cases when multiple style props are all set in a row 3) AlreadyInQueue() can make posting of reflow commands O(N^2) in the number of commands

I filed bug 230170 on the style reresolution stuff that's been talked about recently.

AlreadyInQueue sure could use a hash queue. One implementation idea: drop the nsVoidArray, create a PLHashTable whose entry struct derives from PLHashEntry but mixes in PRCList, so live entries can be kept in a doubly-linked list; both unlink and search are thus O(1). /be

I checked with the new Mozilla 1.8a4, Mozilla is still behind IE6, see test results on same machine as #8. Remark: Overall speed is way better an closer to IE now, but rendering seems to happen in bursts. *** Moz 1.8.a *** small cube (369 div): Elapsed time: 4'919 ms Average per loop: 98.38 ms Fastest loop: 80 ms Slowest loop: 120 ms big cube (729 div): Elapsed time: 10'033 ms Average per loop: 200.66 ms Fastest loop: 150 ms Slowest loop: 290 ms *** IE 6 *** small cube: Elapsed time: 3'334 ms Average per loop: 66.68 ms Fastest loop: 50 ms big cube: Elapsed time: 6'751 ms Average per loop: 135.02 ms Fastest loop: 110 ms Slowest loop: 160 ms Slowest loop: 90 ms

OK, I just did a profile of the large cube in a current (last night's, so it should include the view update batching changes) build. Ccing roc, since some of the view stuff comes up.... The basic info: Total hits: 242221. Of these: 21395 under PresShell::ProcessReflowCommands. Of these 12648 are under nsViewManager::MoveViewTo, mostly calling into nsRegionGTK::Union. Bug 243726 covers this last part, mostly. 16678 under nsCSSFrameConstructor::ProcessPendingRestyles. 18316 under nsScriptSecurityManager::CanAccess (covered by bug 213946 already) 70760 under nsDOMCSSDeclaration::SetPropertyValue The rest.... Of the total 180927 hits under js_Execute, only 89000 are accounted for above. The rest are in JS, XPConnect, classinfo. Of particular note are: 14741 under js_NumberToString 11468 under nsXPConnect::WrapNative 13834 under js_LookupPropertyWithFlags I'll attach the profile to this bug for people's perusal. I looked a bit further into nsDOMCSSDeclaration::SetPropertyValue. The breakdown under that is: 35089 under CSSParserImpl::ParseProperty 27745 under nsDOMCSSAttributeDeclaration::DeclarationChanged which fritters along minor things, then calls AttributeChanged (15000 hits under that). Of particular interest under this last part is 6294 under nsEventQueueServiceImpl::GetSpecialEventQueue (bug 240874) The property parsing is about a third under nsCSSScanner::ParseNumber and another third initing/releasing scanners and decompressing/recompressing/transferring the style data. The rest is scattered here and there.

It seems to me that making "foo.style = ..." go through parsing and the full style reresolution mechanism is rather a waste. Can't we detect when the inline style is the most specific, and then treat such assignments as directly setting the style data?

Even directly setting the style data involves parsing, though... Furthermore, depending on which properties are being set, other properties' values will need to change (eg float affects display, position affects float, font-size affects the meaning of em units for everything in sight, etc). Add to this the fact that we have to clear out cached style data, possibly, and that changing .style.foo on a node can affect its kids. Once all that's taken into account, what we end up with may not be much faster than just reresolving... :( On an unrelated note, I just realized that I never said how much time painting took on that testcase. There were about 3500 hits under UpdateIdle().

This bug seems to be a dupe of bug 195408. But I won't touch it. Also the testcase is 404.

#18 Testcase should work again. Website was down temporarily (provider migrated website...)

Simon, the testcases seems to be gone again (I just get a blank blue page, more or less)....

Boris, Testcase should be up and running again. Sorry for the inconvenience. Simon

The patch I checked in today for bug 288369 should help with the jerkiness pointed out in comment 13...

I downloaded the latest build today [Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.8b2) Gecko/20050521]. Here my results for the big cube (unfortunately on a new machine): --- Moz 1.8b2 --- Elapsed time: 3'362 ms Average per loop: 67.24 ms Fastest loop: 47 ms Slowest loop: 109 ms -- Ie 6.0 --- Elapsed time: 2'527 ms Average per loop: 50.54 ms Fastest loop: 31 ms Slowest loop: 63 ms --- Fox 1.0.4 --- Elapsed time: 10'514 ms Average per loop: 210.28 ms Fastest loop: 140 ms Slowest loop: 250 ms Yes, getting faster and faster.

Simon, I'd be curious in seeing what tomorrow's trunk nightlies look like on your machine... Also, I recommend comparing to Opera, not just IE -- in my experience Opera is a _lot_ faster than we are... :(

--- Opera 8.5 --- Elapsed time: 2'107 ms Average per loop: 42.14 ms Fastest loop: 31 ms Slowest loop: 47 ms --- Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.9a1) Gecko/20051116 Firefox/1.6a1 --- Elapsed time: 3'032 ms Average per loop: 60.64 ms Fastest loop: 46 ms Slowest loop: 94 ms --- IE 6 --- Elapsed time: 2'639 ms Average per loop: 52.78 ms Fastest loop: 46 ms Slowest loop: 63 ms Boris, as you guessed. Opera beats IE. Hope I downloaded the right nightly.

Yeah, that looks like the right nightly. OK. So we're doing OK, not great. Thank you!

Out of curiousity, what effect, if any, did the fix for bug 317375 have on this? That is, how does a trunk build from 2006-01-24 or earlier compare to a current trunk build?

Hi Boris I'm not sure if I understand the terminology right (trunk build?). So if I download a nightly build from http://ftp.mozilla.org/pub/mozilla.org/seamonkey/nightly/2006-01-23-11-trunk/ run the test and then download a build from http://ftp.mozilla.org/pub/mozilla.org/seamonkey/nightly/2006-02-01-11-trunk/ and run the test again that would help you ?

Simon, that's exactly right. Thanks!

Here are the numbers. I repeated it 3 times. There seems to be no difference between the builds... Gecko/20060123 Gecko/20060201 Opera 8.51/7712 3'359 ms 3'471 ms 2'312 ms 67.18 ms 69.42 ms 46.24 ms 46 ms 47 ms 31 ms 94 ms 94 ms 78 ms 3'563 ms 3'515 ms 2'094 ms 71.26 ms 70.30 ms 41.88 ms 46 ms 46 ms 31 ms 110 ms 140 ms 47 ms 3'250 ms 3'454 ms 2'375 ms 65.00 ms 69.08 ms 47.50 ms 46 ms 46 ms 31 ms 125 ms 109 ms 78 ms

OK, great. That patch wasn't expected to make things immediately faster or anything; just making sure it didn't get slower. ;)

I'd be interested in how today's builds (which have bug 326273 fixed) do.

Unfortunately, I never tested this bug in a build prior to today, but here are my results for the big cube. Current 5-11-2006 Trunk: Elapsed time: 1'905 ms Average per loop: 38.10 ms Fastest loop: 31 ms Slowest loop: 62 ms IE6: Elapsed time: 1'405 ms Average per loop: 28.10 ms Fastest loop: 15 ms Slowest loop: 32 ms

Interesting. Either we got a lot slower, or the hardware matters; see comment 27.... fwiw, you can get builds from day before yesterday off FTP easily enough.

Never mind comment 36; I misread comment 27.

Aren't these post-cairo-turnon numbers?

More data for you: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9a1) Gecko/20060507 Minefield/3.0a1 Elapsed time: 2'500 ms Average per loop: 50.00 ms Fastest loop: 40 ms Slowest loop: 80 ms Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9a1) Gecko/20060511 Minefield/3.0a1 Elapsed time: 2'153 ms Average per loop: 43.06 ms Fastest loop: 30 ms Slowest loop: 51 ms So yeah, a definite speed win.

Crap, forgot the IE numbers Elapsed time: 1'904 ms Average per loop: 38.08 ms Fastest loop: 30 ms Slowest loop: 61 ms Sorry for the spam.

So I did a profile of this with a current build on Linux (with threadmanager changes and all). Rough breakdown of where time is spent: 15% recomputing style data 14.5% parsing CSS 10.6% changing the inline style rule. About 1/3 of this is in nsCSSFrameConstructor::AttributeChanged; the rest is Begin/EndUpdate, copying observer lists, setting the nsAttrValue, etc. 7% converting numbers to strings in JS 6.7% under js_LookupProperty; a bit more than half of this is in XPConnect 6.6% layout 6.1% getting properties from a nodelist (presumably getting at divs?). About 2/3 of this is spent creating XPConnect wrappers for the native objects. 5.3% security checks 4.6% painting 1.7% JS GC Of the remaining 20% or so, at least 3/4 is mostly scattered in JS and XPConnect as far as I can tell...

The animated 3d box at provided URL also shows the same, exact painting symptoms as described in a similar bugfile (bug 30782: Animation with some text have some problem drawing pixels). At both URLs of these bugs and at http://www.taboca.com/worlds/gek/webfilmed/intro2/3dcircle3.html we can see small streak of pixels not being repainted, small lines of residual pixels.

> also shows the same, exact painting symptoms This bug's testcase shows those symptoms in all browsers (or at least Konqueror, Opera, IE/Windows, and Gecko), leading me to think that the page is just coded to have that effect. > http://www.taboca.com/worlds/gek/webfilmed/intro2/3dcircle3.html I don't see the problem there on Linux, for what it's worth. It probably depends on the invalidation differences between the platforms...

To #42/43: I never checked if the streaks of pixels not beeing repainted is a bug or lies in my coding (I think it's the latter, but I havn't had the time to check...). But it was certainly not the reason to post this bug, which is about speed.

I made a comparison with the current browsers and the latest seamonkey build Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9a1) Gecko/20061124 SeaMonkey/1.5a. Still same machine as #25 but on Windows XP not Win2000. OP 9.02 Elapsed time: 1'968 ms Average per loop: 39.36 ms Fastest loop: 31 ms Slowest loop: 62 ms IE 7.0 Elapsed time: 2'595 ms Average per loop: 51.90 ms Fastest loop: 31 ms Slowest loop: 63 ms FF 2.0 Elapsed time: 3'638 ms Average per loop: 72.76 ms Fastest loop: 47 ms Slowest loop: 109 ms SM 1.5a Elapsed time: 3'643 ms Average per loop: 72.86 ms Fastest loop: 47 ms Slowest loop: 94 ms To #42-44: Residual pixels are not a bug. For speed reasons 729 pixels (divs) are created at once at the beginning and then just moved around. No DOM node manipulation (appendChild, removeChild). So depending on the position of the cube more or less pixels out of the initially created ones are reused. BTW: Inline spell check is great, especially for nonnative speakers, I mean writers...

Can someone do a new profile on this one?

For what it's worth, there's no point to running this test or profiling it at least until the reflow branch has landed. Possibly also not until the textframe rewrite has landed, though this test may not be too sensitive to that. Until that happens, this is pretty much guaranteed to be like it was on the 1.8 branch (as the test in comment 45 shows).

I hope I got it right, that the current GrandParadiso 3.0a3 [Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9a3) Gecko/20070322 GranParadiso/3.0a3] contains the reflow branch [see #47], otherwise sorry for bothering everyone. Its a bit slower, but whats worse is, that now many frames are just dropped. Sometimes only about 15 out of 50 frames are displayed, all the others are skipped (especially if I have another program open). The numbers: Elapsed time: 3'905 ms Average per loop: 78.10 ms Fastest loop: 62 ms Slowest loop: 94 ms

1.9a3 does contain reflow branch. That said, I spent some time testing this testcase with reflow branch builds, and never saw frame dropping (on a P3-733, at that). I still don't see it on trunk (on Linux)... If you _do_ see it on Windows, please file a regression bug? And maybe see whether you can narrow down the first nightly when it started?

Boris, I did see the skipping on Windows with the same machine as #45. But I realized, that I had some extensions installed... ... I removed all my extensions (Firebug, Html Validator, Adblock) and then the frame dropping was gone. But interestingly, as soon as I had a few extensions installed (although they were automatically disabled by GranParadiso), the frame dropping occurred again. The dropping didn't seem to cone from a specific extension, but I couldn't find out exactly on what it depended.

Interesting! Can you file a bug on that? And maybe hunt down a regression range? Frame dropping is a serious issue that should be blocking 1.9, imo.

JavaScript performance in general seems to have taken a hit (bug 375225, bug 375227) since bug 333078 was checked in.

Yes, but the frame dropping is not necessarily a performance issue. For what it's worth, I'm working on getting those bugs profiled...

#51: Can someone give me a hint where/how I would get the necessary files (file naming)? First in the range - last in range ? Ok, I'll file a bug in the next few days.

Simon, ftp://ftp.mozilla.org/pub/mozilla.org/firefox/nightly has dated directories... If you need older builds, http://archive.mozilla.org

I filed new bug 377380.

Boris, I did some testing to hunt down a regression range. I published the results in bug 377380.

it's WFM on Windows XP with latest nightly vs. IE7. Fx3beta4pre Elapsed time: 1'366 ms Average per loop: 27.32 ms Fastest loop: 23 ms Slowest loop: 29 ms IE7 Elapsed time: 1'611 ms Average per loop: 32.22 ms Fastest loop: 16 ms Slowest loop: 47 ms reopen if needed

Comparing performance to IE7 is not that useful nowadays. How do Opera and Safari do?

new machine (not same as in #45) Opera 9.26 Elapsed time: 1'016 ms Average per loop: 20.32 ms Fastest loop: 15 ms Slowest loop: 32 ms IE7 Elapsed time: 1'126 ms Average per loop: 22.52 ms Fastest loop: 15 ms Slowest loop: 32 ms FF 3.0b5pre Elapsed time: 1'148 ms Average per loop: 22.96 ms Fastest loop: 19 ms Slowest loop: 25 ms

Oh well, I'm sorry, but I found out, that I didn't measure the overall time correctly. What I measured was the overall time spent in the Loop() function, but this did not include the time spent between the setTimeout() calls (even though the timeout was set to zero. But, only in an ideal world setTimeout("Loop()", 0); would actually take no time to call the Loop function again...). As a consequence I added a new test parameter, the new 'Time in Loop' is the former 'Elapsed time' and 'Elapsed time' is now the overall time spent for the whole animation. 'Average per loop', 'Fastest loop' and 'Slowest Loop' are the same as before. So here are the new numbers : Minefield/3.0b5pr Gecko/2008030607 Elapsed time: 1'816 ms Time in Loop: 1'173 ms Average per loop: 23.46 ms Fastest loop: 19 ms Slowest loop: 25 ms Opera 9.26 Elapsed time: 2'469 ms Time in Loop: 942 ms Average per loop: 18.84 ms Fastest loop: 15 ms Slowest loop: 32 ms Safari 3.04 Win Beta Elapsed time: 2'484 ms Time in Loop: 686 ms Average per loop: 13.72 ms Fastest loop: 0 ms Slowest loop: 16 ms FF 2.0.0.12 Elapsed time: 2'875 ms Time in Loop: 1'812 ms Average per loop: 36.24 ms Fastest loop: 31 ms Slowest loop: 47 ms BTW: This script is also used in the webkit's Sunspider 0.9 benchmark.

Yeah, and we do just fine on that script in the SunSpider context; profiling is going to be needed to drive actual improvements here (as it was in the pure-script case, quite successfully).

Oh, so the original testcase was excluding the actual time needed to recompute the layout (since UAs do that async), right? I was profiling the full animation, so I think my profiles were picking up your new "Elapsed time" metric. As for profiling, last profile I did here indicated that the main costs were the expensive double-to-string and string-to-double conversions when setting top/left, XPConnect overhead, CSS parsing in general. I'll do another profile sometime in June, probably. I do think we should reopen this bug. Resummarizing while I'm at it.

Boris, I do not understand enough of the subject to really confirm what you are saying, but I think you are right. The whole animation is done by calling the setTimeout('Loop()', 0) function from inside the Loop() function with a delay of 0 miliseconds. All the calculations of the pixel's coordinates and the setting of their positions (e.g. div.style.top/left) are also done from within the Loop() function by calling other functions such as Rotate(), Translate(), DrawCube(), etc. 'Time in Loop' (= 'Elapsed time' in original testcase) is measured by calling new Date() inside the Loop() function at the beginning and again at the ending, and then adding the difference up everytime Loop() is called. pseudocode: Loop() { Start measure time; // for 'time in Loop' Calculate cube's position; Draw cube; Stop measure time and add it to previously measured time; setTimeout('Loop()', 0); ; So, do I get it right by saying: *If* the layout was computed in sync, then 'Time in Loop' would become the same as 'Elapsed time', because nothing outside of the setTimeout would happen (e.g. finish recomputing layout) ?

If layout (and painting, etc) were sync, then elapsed time would be time in loop plus (10ms * (number of loops)), since setTimeouts for times smaller than 10ms are set for 10ms from now. Sounds like we're on the same page. I'm actually pretty impressed that we're managing to beat Opera for total time, even with the handicap from the time in loop! Once we fix some of the issues impacting that, life will be pretty sweet. ;)

I've been working with the sunspider tests recently and while working with 3d-cube i came across this bug. And since the last numbers posted are pre Chrome, IE 8 and many other browsers. I went through and ran the numbers. http://cznp.com/3d-cube-04.06.2009.txt Hope it helps some. Thanks.

just some new numbers with FF 3.6b3: FF 3.5.5 FF 3.6b3 Opera 10 Safari 4 Chrome 3 Elapsed time 1702 1288 672 981 822 Time in loop 1003 580 343 425 504 Average per loop 20.26 11.6 6.86 8.5 10.08 Fastest loop 17 9 0 7 8 Slowes loop 23 13 16 10 24

Testing the big cube from the new link: Nightly 27 Elapsed time: 3'798 ms Time in Loop: 1'515 ms Average per loop: 30.30 ms Fastest loop: 24 ms Slowest loop: 49 ms Chrome 29 Elapsed time: 1'397 ms Time in Loop: 199 ms Average per loop: 3.98 ms Fastest loop: 3 ms Slowest loop: 11 ms IE 10 Elapsed time: 2'536 ms Time in Loop: 1'580 ms Average per loop: 31.60 ms Fastest loop: 26 ms Slowest loop: 63 ms

Would be useful to have a testcase here that runs for a controllable period of time, to aid profiling....

@Boris: Can you explain what you mean/need for the test case. I have vacation starting this weekend and will take time to update the test case. Btw: Nice to see that this test case is still useful after 10 year!

Simon, what I'd like to be able to do is have the cube keep rotating for 30 seconds or so, so that I can profile it. Also useful would be a cube that keeps rotating for 30 seconds or so but doesn't do it off setTimeout: so basically a while loop that keeps updating the positions but not yielding to paint. That would allow isolating the update times and paint times from each other.

I guess it defeats the purpose of this testcase, if I replace the setting of the style properties with just setting a class, e.g. // replace el.style.top = Y + 'px'; el.style.left = X + 'px'; el.style.visibility = 'visible'; el.style.height = '1px'; el.style.width = '1px'; el.style.margin = '0px'; el.style.padding = '0px'; el.style.position = 'absolute'; el.style.border = '0px'; el.style.backgroundColor = '#000000'; // with el.style.top = Y + 'px'; el.style.left = X + 'px'; el.className = 'point'; // where point is all of the above

Yes, that would significantly change the behavior.

I created a revised testcase, which lets you set the time or the number of iterations as well as if setTimeout() should be called or not. Here are some numbers of FF 24 vs Chrome 30: // Firefox 24 test method:time, using timeout of 0 cube size:medium (729 divs) elapsed time:10025 ms time in Loop:5092 ms average per loop:20 ms fastest loop:16 ms slowest loop:31 ms # of loops:261 test method:time cube size:medium (729 divs) elapsed time:10018 ms time in Loop:10016 ms average per loop:19 ms fastest loop:15 ms slowest loop:23 ms # of loops:524 // Google Chrome test method:time, using timeout of 0 cube size:medium (729 divs) elapsed time:10016 ms time in Loop:1152 ms average per loop:2 ms fastest loop:1 ms slowest loop:4 ms # of loops:600 test method:time cube size:medium (729 divs) elapsed time:10001 ms time in Loop:9992 ms average per loop:1 ms fastest loop:1 ms slowest loop:7 ms # of loops:7032

Dropping qawanted based on comment 74.