The dhtml animation (which is very nice!) at the URL http://www.html-online.de/niko.temp/time/time.html runs fairly slowly in mozilla, and pegs the cpu when it is "idle". The original, not-working-in-mozilla version was at http://12.13.171.162/time/time.htm) This was originally noted in a post to n.p.m.seamonkey asking how to modify it to work in mozilla with the w3c dom. After I made the needed changes (basically to use the event's .screenX/Y property, and retrieving nodes with .getElementById), it was noted that the animation ran much slower in mozilla than in Nav4 or IE (with their respective document.layers and document.all collections). There are really two parts to this bug (and perhaps I should have filed separate bugs, but...): (1) when the mouse is moved to a new location, and the animation is in process (the clock elements are flowing to the new mouse location), when I broke in the debugger, it was mainly style resolution and layout reflow code that was in action (no typical stack, just lots of layout and style system in action). (2) after you have triggered the animation, and the animation has "caught up" with the mouse, there is still a prolonged period when the the CPU is at 100%, as if it is still trying to deal with a backlog of timeouts. I broke in the debugger with an optimized build, and the most common stack was like the one below, with the pivotal function being 'SetCSS2PropertiesProperty' nsDocument::AttributeChanged(nsDocument * const 0x02da9e50, nsIContent * 0x02e8ef18, int 0, nsIAtom * 0x00c0c820, int 0) line 1682 + 47 bytes nsDOMCSSAttributeDeclaration::ParseDeclaration(nsDOMCSSAttributeDeclaration * const 0x02da9ee0, const basic_nsAReadableString<unsigned short> & {...}, int 1, int 0) line 338 + 22 bytes nsDOMCSSDeclaration::SetProperty(nsDOMCSSDeclaration * const 0x02ea3df8, const basic_nsAReadableString<unsigned short> & {...}, const basic_nsAReadableString<unsigned short> & {...}, const basic_nsAReadableString<unsigned short> & {...}) line 247 + 22 bytes nsDOMCSSDeclaration::SetTop(nsDOMCSSDeclaration * const 0x02ea3df8, const basic_nsAReadableString<unsigned short> & {...}) line 1599 + 44 bytes SetCSS2PropertiesProperty(JSContext * 0x02c748e8, JSObject * 0x02e95a80, long -223, long * 0x0012f900) line 3055 + 19 bytes js_SetProperty(JSContext * 0x02de4490, JSObject * 0x00000005, long 13801632, long * 0x0012f900) line 2419 + 109 bytes js_Interpret(JSContext * 0x02c748e8, long * 0x0012fa8c) line 2518 js_Execute(JSContext * 0x00000000, JSObject * 0x02ccd3e0, JSScript * 0x02ccd3e0, JSStackFrame * 0x00000000, unsigned int 0, long * 0x0012fa8c) line 958 JS_EvaluateUCScriptForPrincipals(JSContext * 0x02c748e8, JSObject * 0x02ccd3e0, JSPrincipals * 0x02d858f0, const unsigned short * 0x0012faf8, unsigned int 6, const char * 0x02eadbe0, unsigned int 143, long * 0x0012fa8c) line 3221 + 17 bytes nsJSContext::EvaluateString(nsJSContext * const 0x00000000, const basic_nsAReadableString<unsigned short> & {...}, void * 0x02ccd3e0, nsIPrincipal * 0x0012faf8, const char * 0x02eadbe0, unsigned int 143, const char * 0x002a11e0 `string', basic_nsAWritableString<unsigned short> & {...}, int * 0x0012fc6c) line 609 + 57 bytes GlobalWindowImpl::RunTimeout(GlobalWindowImpl * const 0x02da9ee0, nsTimeoutImpl * 0x02d6191c) line 3927 nsGlobalWindow_RunTimeout(nsITimer * 0x041b6e28, void * 0x02eadb70) line 4201 + 14 bytes nsTimer::Fire(nsTimer * const 0x02da9ee0) line 194 + 6 bytes nsTimerManager::FireNextReadyTimer(nsTimerManager * const 0x00c20b50, unsigned int 0) line 117 FireTimeout(HWND__ * 0x00000000, unsigned int 275, unsigned int 31549, unsigned long 267251187) line 88 + 12 bytes USER32! 77e13eb0() USER32! 77e14092() USER32! 77e192da() nsAppShellService::Run(nsAppShellService * const 0x00b5ff30) line 408 main1(int 1, char * * 0x00372ba8, nsISupports * 0x00372bc8) line 978 + 9 bytes main(int 1, char * * 0x00372ba8) line 1270 + 25 bytes WinMain(HINSTANCE__ * 0x00400000, HINSTANCE__ * 0x00400000, char * 0x00132c81, HINSTANCE__ * 0x00400000) line 1288 + 21 bytes MOZILLA! WinMainCRTStartup + 308 bytes KERNEL32! 77e87903()

->perf keyword

dveditz wrote in news://news.mozilla.org/3A9ABF17.5901F753%40netscape.com "I did a quantify run on this in winembed, timing the actions between the clock starting at one position, moving the mouse across the window, and stopping quantify when the clock was reformed at the new position. On my machine in Communicator this takes about 1.5 seconds; in winEmbed and Mozilla this takes 6 or 7 seconds. At the highest level, 60% of the time was spent in 71 reflow events, 36% was spent in the 71 times the timeout function fired (mostly property setting that triggered style stuff), and 4% in 35 calls to paint the window (of which half is our rendering code, and half is the OS calls to do the actual painting). - 4% of time (190msec) was spent in 35 calls to nsWindow::WindowProc, essentially in painting of the screen - Down several layers the bulk of that (172msec) is eventually spent in nsViewManager2::Refresh - 74% (128msec) spent in 35 calls to nsViewManager2::RenderViews - 25% (43msec) spent in 35 calls to nsRenderingContextWin::CopyOffScreenBits - 37% of time (1755 msec) spent in 71 calls to FireTimeout, of which most was spent in 69 script executions. Those 69 js_interpret calls generated 1696 js_SetProperty calls, which in turn called SetCSS2PropertiesProperty 1530 times (1600 msec). - 9% of that (145msec) spent in 1530 calls to nsJSUtils::nsConvertJSValToString--more time than in RenderViews! - 88% (1412msec) total spent in 765 calls each to nsDOMCSSDeclaration methods SetLeft and SetTop, which each call SetProperty. Nearly all of this time is spent in nsDOMCSSAttributeDeclaration::ParseDeclaration - 10% (146msec) in 1530 calls to CSSParserImpl::ParseAndAppendDeclaration about half of which comes down to an equal number of nsCSSScanner::ParseNumber calls. Most of that time is spent in nsString::ToFloat, but there are an astounding 26,804 calls to nsCString::AppendWithConversion - 86% (1203msec) in 1530 calls to nsDocument::AttributeChanged, the bulk of which (1021msec) eventually ends up in NS_NewStyleContext. A large part of the time spent here is eventually down in 1399 calls to nsDeviceContextWin::CheckFontExistence (708msec) where we actually query the OS (GetDC, EnumFontFamiliesA, ReleaseDC) each time. We need to guard against people who install fonts hundreds of times a second? For those not following the math, this is a little over 14% of the total time spent checking things that aren't going to change - 59% of the total time (2850msec) spent in 71 calls to md_EventReceiverProc, which turns out to be ReflowEvent::HandleEvent (we lose 58msec getting down to that level, though). This got fairly confusing to follow because the totals didn't add up (due to cycles or recursion), but at the bottom 30% of the total time, 1525msec, was spent in **11,681** calls to the Win API InvalidateRect. Other than some of the hot-spots noted above, in this 5 second or so run other notable function calls were 47,055 calls to "new" (260msec -- 5%) 43,911 calls to "delete" (254msec --5%) 113,173 calls each to PR_Lock and PR_Unlock (160msec together -- 3%) 127,855 calls to ftol (88msec) 13,386 calls to malloc (58msec) 12,357 calls to free (56msec) 508,872 calls to AccumulateCRC (43msec) 82,411 calls to memcpy (43msec) 46,344 calls to memset (34msec) That's an insane number of function calls to move 22 objects on the screen 35 times."

The reason this animation is slow seems to be exactly the same as what's described in bug 64516, duping. *** This bug has been marked as a duplicate of 64516 ***

I'm reopening -- this example is slow in part due to the same SetCSS2PropertiesProperty stuff described in bug 64516, but it mostly shows a completely separate problem. In bug 64514 SetCSS2PropertiesProperty and children accounts for 74% of the time; here it's only about 30%. ReflowEvent::HandleEvent is nearly nothing in bug 64516, here it accounts for more than half the time. InvalidateRect doesn't even show in bug 64516, here that one call accounts for 30% of the time. The weird font enum stuff doesn't take much time in bug 64516, here we call GetDC and EnumFontFamiliesA thousands of times. The outward appearance (slow DHTML) may be the same, but the time appears to be spent in entirely different places.

I still think the biggest problem here is exectly the same as in bug 64516, looking at this in quantify I do see the EnumFontFamiliesA function being called thousands of times (same for GetDC n' friends), but that's due to the same problem, excessive style re-reolution. The numbers in the clock in the animation have a style rule that changes the font that the numbers are shown with and that results in the style system calling EnumFontFamiliesA a bunch of times... Either way, this is not a DOM problem, IMO it's to a great deal the same problem as bug 64516 describes, or if that's not true, then the it's a layout reflow problem, both those problems belong with attinasi AFAIK, so he'll get to be the next proud owner of this bug. Reassigning.

I'll check it out. It does smell like bug 64516, even thought the stacks and profiels are different, because it has to do with making a lot of rapid changes to an elements style data, and that causes lots of style resolution/reflow and that is too slow. Anyway, I'll dig in and see what I can learn. BTW: that is one cool clock!

So one reason for the reflow code shows up more in this profile than in the other one is that in this bug everything is triggerd from a mouse move, and for every mouse move on this page we call FlushPendingNotifications() on the pres shell and that causes all the reflow to be done there and then in stead of later when there's more time to do it... And yes, the clock is awesome :-)

The major difference here is the 1400 calls to the sequence GetDC-EnumFontFamiliesA-ReleaseDC which eat up a large chunk of time -- we should be caching that data. jst-- The mouse was moved exactly once. The mouse was moved off-screen before the timing was started, and I poked it just over the edge to start the clock travelling to the new position and immediately moved it out of the window again. There were zero calls to FlushPendingNotifications(), or any function with "flush" or "notification" in the function name other than 3 calls to js_FlushPropertyCache.

spam: cc'ing me

dveditz, bug 64516 is the reason we do all those GetDC-EnumFontFamiliesA-ReleaseDC calls.

How so? bug 64516 doesn't even show EnumFontFamiliesA in the attached quantify trace, and GetDC is only called a reasonable 7 times. I'm sure the style stuff is affecting the sheer number of calls, but why do we need to *ever* call more than once? Installing fonts is rare, we should be caching that information.

Bug 64516 doesn't show EnumFontFamiliesA since there are no style rules in that testcase that contain font info. Sure, maybe it should be cached...

Slow on my linux build from yesterday too. All/All. Nominating for 0.9.2.

*** Bug 66881 has been marked as a duplicate of this bug. ***

For the suggested caching idea, maybe it might be possible to leverage on the nsIDeviceContext::mFontCache. mFontCache stores basically an array of nsIFontMetrics, and a nsIFontMetrics provides a hook from where to peek at the global list of all installed fonts, and this list 'is' (or 'will be') automatically kept up-to-date if new fonts are installed (see bug 69117). The global list of installed fonts is needed for the Prefs -> Fonts dialog anyway (it is also needed for other tricks in the font sub-system). So leveraging on that list for CheckFontExistence() might be faster without introducing too much overhead.

Updating target and priority.

*** Bug 76299 has been marked as a duplicate of this bug. ***

Copying keyword and status spammage from duplicate bug. See also: http://timeless.student.umd.edu/mozilla/css/

URL http://timeless.student.umd.edu cannot be found - guess it went away?

*** Bug 83852 has been marked as a duplicate of this bug. ***

Bug 91956 covers part of this; some of the Font Cache stuff (if this used the font cache). Someone should retest/quantify this testcase!

*** Bug 95072 has been marked as a duplicate of this bug. ***

I have experimented with the script and found indeed that Mozilla continues to use considerable amounts of CPU after the display has caught up with the mouse. This got me thinking about whether the style settings were being changed too often. I added the following test before resetting the left & top values: if (Math.abs(parseInt(oDivs[i][0].left) -(oDivs[i][1] + oDivs[i][3]))>=1 || Math.abs(parseInt(oDivs[i][0].top)-(oDivs[i][2] + oDivs[i][4]))>=1) { oDivs[i][0].left = oDivs[i][1] + oDivs[i][3]; oDivs[i][0].top = oDivs[i][2] + oDivs[i][4]; } This caused the CPU (post catching up) to collapse by 80%. In this particular dhtml animation left/top are given lots of fractional value that eventually converge to integer values. Does the fact that the CPU rate collapses after the introduction of this simple test on whether the change in value is significant suggest that adding that sort of test before "changing" the value would improve overall performance of the DHTML?

I stole an URL from one of the newsgroups that demonstrates this rather dramatically. The site is her: http://www.dynamic-core.net/widgetx/ And a direct link to one example is: http://www.dynamic-core.net/widgetx/examples/vectorsine.htm It uses 256 different layers to simulate a 3D rotating sine wave structure.

*** Bug 78103 has been marked as a duplicate of this bug. ***

Grey, demos from http://www.dynamic-core.net/widgetx/ are being addressed in bug 98828 I think.

comparing this with msie and mozilla is tough :-/ http://www.dynamicdrive.com/dynamicindex3/leaves.htm

http://www.world-direct.com/mozilla/moz_sliding.htm just click on the top-navigation to start the animation. msie, opera and ns4.x do very fine at this!

cc'ed me.

The original URL doesn't do anything for me anymore, running build 2001112308 on linux. It used to 'work'

The animation stopped working with build of Sept. 09, from a checkin by dbaron for handling doctypes and strict vs. quirks mode. <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN" "http://www.w3.org/TR/1999/REC-html401-19991224/loose.dtd"> That document has the above doctype, which is triggering strict mode (should it, dbaron? hixie? Comments in bug 55264 suggest that that is intended). Given strict mode, then units are required for lengths, e.g., 'top:10px' vs. 'top:10'. This diff "fixes" the animation: @@ -41,8 +42,8 @@ for (i=0; i<iDivs; i++) { oDivs[i][1] = oDivs[i][1] * 0.5 + x * 0.5; oDivs[i][2] = oDivs[i][2] * 0.5 + y * 0.5; - oDivs[i][0].left = oDivs[i][1] + oDivs[i][3]; - oDivs[i][0].top = oDivs[i][2] + oDivs[i][4]; + oDivs[i][0].left = oDivs[i][1] + oDivs[i][3] + 'px'; + oDivs[i][0].top = oDivs[i][2] + oDivs[i][4] + 'px'; x = oDivs[i][1]; y = oDivs[i][2]; } [plus one other place where inline style sez 'top:135' for div id='yo0' (although that doesn't break the animation).]

Sorry. Didn't intend to remove original URL. And, that's still just a gorgeous animation :-]

> That document has the above doctype, which is triggering strict mode (should > it, dbaron? hixie? Comments in bug 55264 suggest that that is intended). Bug 42525 shows even more clearly that it was intended. Furthermore, before my checkin that DOCTYPE declaration would have triggered strict mode if the word "loose" had appeared within the first 25 characters of the system identifier, rather than at 48 as it does. That's why I always argued with rickg that his method of parsing doctypes was wrong...

Heh. Nice scroll test (er, well aside from the time). [We may be in danger of overloading this bug with examples that, while still dhtml, have different root causes. But since attinasi widened my initial summary from 'a' to 'some', then I'll let him decide if he wants separate bugs for these examples].

Is it just me or did the animated clock stop working in mozilla?

Hello. Hello? Is this thing on? http://bugzilla.mozilla.org/show_bug.cgi?id=70156#c33

Ah, heh, yeah :-) I was playing around with a local copy of the old testcase...

sorry, i graduated so my .edu dns entry expired.

*** Bug 120417 has been marked as a duplicate of this bug. ***

Seems this has also an impact on bug 107746.

*** Bug 107746 has been marked as a duplicate of this bug. ***

perf --> 1.0

Moving to Moz1.1. Engineers are overloaded with higher priority bugs.

Marking nsbeta1-

top100, topperf, severity: major ... this seems to have a great impact on DHTML in general - shouldn't this be tried to fix for 1.0 ?

How can this bug be targeted to 1.1 when bug 21762 is targeted to 0.9.9?

sorry my computer is having firewall issues, same testcases are now temporarily hosted by dcran.

This contains the profiles for the 4 testcases attached to this bug, created using the "Profile" feature of venkman.

I tweaked the fishcam dhtml script to be a bit more pathological, it now has 12 animated objects with alpha blended pngs, see <http://www.hacksrus.com/~ginda/animator/circles.html>.

reinstating original URL for version of time is on the move, which works in Nav4x: http://www.html-online.de/niko.temp/time/time.html (why was this changed in the first place?). A version adjusted to work in mozilla is http://bugzilla.mozilla.org/attachment.cgi?id=59020&action=view

This works quite well under the reflow tree branch (bug 129115).

The dhtml performance is getting better :) But it's still very slow compared to IE. (Using 2002050508 / Win 2000) One slow example: http://www.formula-one.nu/dhtml/fish/fish2.htm If you block the images from loading it's much faster.

Also with the lastest build (with patch for bug 129115) things are quite the same.

Using trunk build 2002052308 on win-xp,1.1ghz,512RAM this little and simple animation (ticker text) is bringing my system nearly down. 100% CPU usage and a very sluggish responding Mozilla. http://www.frantschach.com

Taking bug, at least for the time being.

I've read through a few of these dhtml performance bugs and done some testing myself (some results in http://bugzilla.mozilla.org/show_bug.cgi?id=117436#c30 and http://bugzilla.mozilla.org/show_bug.cgi?id=117061#c70). In conclusion, for me it looks like all the symptoms finally lead to two problems: 1. painting is too slow (for example resizing images all the time) 2. we paint too much (static pieces) There seems to be also some weird stuff going on with painting that is affected by changes in display mode on at least one system of mine (see the first comment above).

Exaclty - testing with trunk build 2002062808 on win-xp pro,1.1ghz,512ram the testcase at http://www.formula-one.nu/dhtml/fish/fish2.htm is very choppy at 32bit but running great in 16bit color depth, if I change the color mode and don't restart Mozilla. If I restart Mozilla then the testcase is same slow in 16bit mode. That's the same Ere reported in bug 117436 comment #30

Jprofs are needed with latest trunk (perhaps with and without images blocked?)

the "fish testcase" is now located at http://www.world-direct.com/mozilla/dhtml/fish2.htm seems we still have no clue what is going wrong here. cc'ing a few people.

Basing on Comment #65 - WFM. Mozilla 2002121008. Mozilla is smoother and faster than IE here.

With build 2002121204, Windows 2000 this is still extremly slow. Just check out the URL attach to this bug, results: - Mozilla 29 seconds (+ CPU going up to 100%) - IE 3.5 seconds!

Right, this one is still very slow. But testcase from Comment #65 works now.

adt: nsbeta1-

bug@annevankesteren.nl, is this truly no longer 4xp?

Yes. Since NN 4.x doesn't have market share anymore the keyword has been deprecated.

With latest Firefox 3beta5pre the URL gives around 3.888, and with IE7 - 4.0x but we still get CPU up to 40-50% while IE7 keeps it at 0% during this test

Build ID: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.3a1pre) Gecko/20091113 Minefield/3.7a1pre Testcase faster in Firefox than IE. CPU usage 15.

The issue in description 0 is no longer visible. Testcase is faster in Firefox than Chrome and IE. Marking this as WFM. I believe that it would be better to open a new bug for a specific issue instead of having a bug description that applies to "some" "slow" "animations".