Closed Bug 117436 Opened 20 years ago Closed 15 years ago

Steady perf regression in DHTML since 0.9.5

Categories

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

defect

Tracking

()

RESOLVED WORKSFORME

People

(Reporter: markushuebner, Unassigned)

References

(Blocks 1 open bug, )

Details

(Keywords: perf, regression, testcase)

Attachments

(3 files)

When viewing the page http://www.formula-one.nu/dhtml/3d.htm in 0.9.4 I 
discovered that the perf is a 0.9.4 was considerably better than in 0.9.7.

So I ran tests with major releases with Fabian's page at 
http://guisset.tripod.com/mozilla/testcase/timer.html
It moves a single <div><img></div> from
the left to the right of the screen, using div.style.left, calling itself
recursively using setTimeout.

The workstation is a PIII,500MHZ,327 RAM and screen resolution set to 1280x1024.

10 tests / release - here are the average results:

0.9.4: 1350.9
0.9.5: 1320
0.9.6: 1428
0.9.7: 1774.9

This is just a simple testcase, and the more complex the DHTML will be the 
bigger the time difference.
Blocks: 21762, 113492
Keywords: perf, regression
reassign
Component: Browser-General → DOM Core
argh.
QA Contact: doronr → stummala
The test case is bogus, because it does not control the window width; make your
window wider, and it takes longer.
Different testers will get different results, but all will reach the same
conclusion: a nightly is slower than 0.9.7 which is slower than 0.9.6 which is
slower than 0.9.5. I can modify the testcase to have a constant width, but I
don't see how it matters, as long as people test the different milestones with
the same screen width each times.
I've tested both the testcase (
http://guisset.tripod.com/mozilla/testcase/timer.html ) and the other link (
http://www.formula-one.nu/dhtml/3d.htm ) with the latest Mozilla nightly (
2001-12-29-08 ) and K-Meleon 0.6 (based on Mozilla 0.9.5, Gecko/2001-10-11) and
it's true, the Mozilla 0.9.5-based product was faster.

Test case: It took Mozilla 0.9.7+ 1432 milliseconds where it took K-Meleon only
1152 milliseconds.
I tested mozilla release builds 9.4, 9.5, 9.6, 9.7 and kmelon 0.6, on win2k / 
500MHz / 128MB for the testcase 
  http://guisset.tripod.com/mozilla/testcase/timer.html, 
with a  window.innerWidth=700; window.innerHeight=500, running each test ~10 
times (and ignoring the first result, which has a different starting condition 
than the subsequent iterations).

They all produced the _same_ time, approx. 1078ms.
It does _not_ make sense that tests with two different screen widths yield the
_same_ results because as sfraser pointed out, the testcase does not control the
window width, it just goes all the way to the end of it.
For example if, on the same machine, using 0.9.7, you get results like this:
window.innerWidth == 500 -> Elapsed time: 1078ms
window.innerWidth == 700 -> Elpased time: 1078ms
then something is definitely wrong with the elapsed time you get.
In my tests on 0.9.7, when I reduce the window size by a factor of two (by
resizing the window), the elapsed time shown in the alert is divided by two.
> with a  window.innerWidth=700; window.innerHeight=500, ...

Who said anything about testing with two different window widths? Not me.
Sorry for the misunderstanding. I misread your (jrgm) comment, thinking you had
tested with two different window sizes. That'll teach me.
OS: Windows 2000 → All
Hardware: PC → All
Petern made a nice testcase at http://www.formula-one.nu//dhtml/dhtmltest.htm
(see also in bug 117061).

Running the tests yielded the following results (win-xp,pIII,1.1GHZ)

0.9.5: 3758.4
0.9.6: 3756.9
0.9.7: 3865.05


Keywords: testcase
2001-12-23-08, Win32: Average time: 4686.25ms.
Forgot to add that my machine is slower though. Athlon/500 MHz, 416 Megs of RAM,
Windows XP Pro.
2001-12-31-03, Win32: 3612.2ms. That's more than a second less?! The other URLs
also seemed "smoother".

On IE 6 (if that matters), it's 3846.55ms, btw.
Keywords: mozilla0.9.8
Did again a test with build 2002012008 (win-xp,pIII,1.1GHZ)
3850,5ms
Probably a profile would bring light to where we lost performance.
WinXP, Athlon, 500 MHz, Build 2002-01-20-09 (SVG):


1ms timeout : 5007ms.
2ms timeout : 2454ms.
3ms timeout : 2403ms.
4ms timeout : 2434ms.
5ms timeout : 2454ms.
6ms timeout : 2453ms.
7ms timeout : 2594ms.
8ms timeout : 2704ms.
9ms timeout : 2954ms.
10ms timeout : 3215ms.
11ms timeout : 3424ms.
12ms timeout : 3715ms.
13ms timeout : 3946ms.
14ms timeout : 4166ms.
15ms timeout : 4566ms.
16ms timeout : 4687ms.
17ms timeout : 4957ms.
18ms timeout : 5187ms.
19ms timeout : 5448ms.
20ms timeout : 5688ms.
Average time: 3722.8ms.

The first one choked a lot in the middle; perhaps there was another task happening.

Interesting to see that it's (only slightly, but anyways) _faster_ on my machine
while it should be around half as fast, just looking at clockrate. Perhaps you
have little RAM? (I have 416 MB) Can't see any other cause for this. Or,
alternatively, your profile is stuffed.
On Moz .9.8 with a K6-2/450 and 192 megs of RAM

1ms timeout : 3485ms.
2ms timeout : 3485ms.
3ms timeout : 3475ms.
4ms timeout : 3485ms.
5ms timeout : 3485ms.
6ms timeout : 3535ms.
7ms timeout : 3475ms.
8ms timeout : 3485ms.
9ms timeout : 3475ms.
10ms timeout : 3495ms.
11ms timeout : 4727ms.
12ms timeout : 5028ms.
13ms timeout : 5017ms.
14ms timeout : 5057ms.
15ms timeout : 5057ms.
16ms timeout : 5128ms.
17ms timeout : 5868ms.
18ms timeout : 7531ms.
19ms timeout : 7541ms.
20ms timeout : 7531ms.
Average time: 4668.25ms.

IE 5.5 on the same system.

1ms timeout : 2514ms.
2ms timeout : 2524ms.
3ms timeout : 2503ms.
4ms timeout : 2504ms.
5ms timeout : 2503ms.
6ms timeout : 2504ms.
7ms timeout : 2504ms.
8ms timeout : 2503ms.
9ms timeout : 2504ms.
10ms timeout : 2573ms.
11ms timeout : 5008ms.
12ms timeout : 5007ms.
13ms timeout : 5007ms.
14ms timeout : 5007ms.
15ms timeout : 5007ms.
16ms timeout : 5008ms.
17ms timeout : 5007ms.
18ms timeout : 5007ms.
19ms timeout : 5007ms.
20ms timeout : 5007ms.
Average time: 3760.4ms.
A quick Quantify test shows that we spend ~70% of the time painting the image
when it's moved, the rest seems fairly ok in Quantify, about 65% of the time is
spent in MaskBlt().

Pavlov, is this something that would be improved by the stuff you're working on?
Did again a test with build 2002021303 (win-xp,pIII,1.1GHZ)
3853.35ms
The test with build 2002012008 took 3850,5ms 

[for comparison]
0.9.5: 3758.4
0.9.6: 3756.9
0.9.7: 3865.05
0.9.8: 3833.35
Tried today with patch from bug 117061 and times got worse:
Average time: 3864.2ms.

That's quite the exact time we have had for 0.9.7
Markus, are you sure that the patch checked in for bug 117061, and only that
change to your sources, caused a further slowdown?

There's lots to go wrong here, and I repeat that my attempt to adapt timer
scheduling to cancel skew through feedback will not fix all the DHTML ills
plaguing mozilla (especially image drawing being too slow!).

/be
Keywords: mozilla0.9.8
puhh ... I was obviously so eager to test that I got somewhat confused. I ran 
the test with build 2002021708 (so without the patch). Running today with 
build 2002021803 yielded the following result:
Average time: 3202.6ms

[just for comparison]
0.9.5: 3758.4
0.9.6: 3756.9
0.9.7: 3865.05
0.9.8: 3833.35

This is a considerable perf boost! :))
changing priority to P2
Priority: -- → P2
Keywords: mozilla1.0+
Now that we have released 0.9.9, are we back to 0.9.5 numbers or how does it
look (wanna know if this bug became wfm)? Markus, anyone?
I'm waiting till bug 117061 gets fixed properly for detailed reviewing. There 
is a recent regression causing frame-drop offs (bug 129953).
If you take a look at
http://bugzilla.mozilla.org/show_bug.cgi?id=117061#c79
we are still doing worse than 0.9.7 in the provided testcases.

Stuart suggested strongly to fix bug 139986 that will boost many DHTML things 
(seems timeout so far has been tweaked enough). 
nsbeta1-

Before you renominate, please query bugs marked nsbeta1+ keyword with [ADT# RTM]
in status whiteboard (where # is a number between 1 and 3) and make sure that
this bug is at least as important as those.
Keywords: nsbeta1nsbeta1-
Keywords: nsbeta1-
No longer blocks: 113492
Interesting is ere's comment at http://bugzilla.mozilla.org/show_bug.cgi?
id=117061#c70

Note that the last sentence in that comment is bogus. The image was still
acceidentally different size than the attributes given. Probably specifying
width and height that are the same as the image dimensions is optimized. 
I'm unable to reproduce anything similar to the results Markus got, on my 1.06GHz 
Celeron laptop with Intel 830M graphics controller (1024x768x32bit) running
WinXP Pro. It performs quite well even with 100 balls, but seems to be unable to
do timeouts <50 ms without jumping around. 

Okay, then I tried it on another machine (Pentium III 500MHz, Intel 810 chipset,
Windows 2000) and got some interesting results. First when I launched it, it was
slower than the laptop, which didn't quite surprise me because it was a slower
machine and running a higher resolution (1280x1024x16bit), although with less
colors. I then switched to 1024x768x16bit and tried again (without restarting
Mozilla) and it worked well. Changed the resolution back up again, and it still
worked.. Restarted Mozilla, slow again. Changed color depth (up) and it became
fast. Restarted Moz again and it was slow. Started the test and changed color
depth in the middle and it had an immediate effect. This is quite weird. I've no
idea what causes this, but there seems to be something that is affected by the
change in display mode. On the laptop I couldn't get anything like this to happen.
dcone will know more in that regard - cc'ing.

Interesting is jesup's comment in bug 136688 comment 14
---
Most of the time not spent in reflow is spent in repaint (25% of total hits),
2/3rds of it in nsImageFrame::Paint, most of that in DrawScaledImage, the rest
in GetImageMap
---
Ere, a great investigation!
When running the testcase with 16bit color depth the numbers are cut in half!
(32bit color depth had on average 230ms with 16bit color depth it's 125ms).
Testing with latest trunk a modified version of the testcase at
www.world-direct.com/mozilla/timeouttest.htm
(resized the 3dball image in photoshop so that Mozilla doesn't need to scale) -
 then I get quite the same numbers as MSIE6! :)
Missing the assignment of mSizeImage in ::Init, so that particular theory
from the log is invalid.
Hmm, I found out another thing about those DHTML perf bugs: jesup said in bug
117061 comment #2 that in http://guisset.tripod.com/mozilla/testcase/timer.html
the text moves faster for him if he moves the moves the mouse around over the
Mozilla window.

I still see this happening on a current trunk nightly (2002-07-01 cvs build) on
Linux here.
I also observed that without moving the mouse I see almost no CPU activity (and
have around 1600 ms as test result), while CPU usage goes up with mouse moving
over the window (I tried "hunting" the image with my mouse cursor and got around
1200 ms as test result). It seems we're using our resources better when the
mouse is moved here. Perhaps this is even similar to that color depth problem
also talked about here...
Are we being affected by the parser (or content sink) timers somehow, even after
the page has loaded?  (Does that particular testcase invoke the parser by doing
things like setting innerHTML?  I couldn't find anything at a quick glance.)
There is really no innerHTML or document.write() in the testcase at
http://guisset.tripod.com/mozilla/testcase/timer.html - any other idea that
could cause the "behaviour" jesup & robert described?
re: comment #36, we have special code for parser that sets the parser chunk size
to be small when the user is moving the mouse in the window, on the theory that
the user wants to interact with the page and wants responsiveness more than
quick pageload times.  But I don't see how that affects this.
jkeiser: if parser chunk size affects this, your comment would mean that smaller
parser chunk size makes the DHTML 25% faster, how could this happen?
Depends on: x-files
"But I don't see how that affects this."

It shouldn't, but it might give people a place to look.
re comment 39, comment 36. I don't think the parser interuption code has
anything to do with the speed up when moving the mouse. The speed up is probably
caused by flushing of the pending reflows that is triggered whenever the mouse
is moved.
The code which flushes the pending notifications is in the EventStateManager.
I would start looking there:
http://lxr.mozilla.org/seamonkey/source/content/events/src/nsEventStateManager.cpp#382
Nominating for nsbeta1 as this a regression of DHTML performnace.
Keywords: mozilla1.1, nsbeta1
Whiteboard: [adt3]
so I'm a bit confused about this bug... is it now about the difference between
http://www.formula-one.nu/mozilla/timeouttest.htm and
http://www.world-direct.com/mozilla/timeouttest.htm ? (scale&move vs. only move)?
(not like I can see such a difference, linux, recent cvs build)

if so, we should change the summary.
else, we should file a new bug for that.
Depends on: 159512
biesi: filed bug 159512 and made dependend.
a profile with a recent build of
http://guisset.tripod.com/mozilla/testcase/timer.html 
would help here.
You see considerable perf loses till 0.9.7
regarding comment #42 this seems to relate to bug 157144
Depends on: 157144
Recent results on testcase (win-xp pro sp1,1.1ghz,512ram):

Mozilla trunk 2002121908
1ms timeout : 4206ms.
2ms timeout : 4296ms.
3ms timeout : 4276ms.
4ms timeout : 4286ms.
5ms timeout : 4306ms.
6ms timeout : 4287ms.
7ms timeout : 4276ms.
8ms timeout : 4296ms.
9ms timeout : 4316ms.
10ms timeout : 4306ms.
11ms timeout : 4677ms.
12ms timeout : 5007ms.
13ms timeout : 5007ms.
14ms timeout : 5008ms.
15ms timeout : 5017ms.
16ms timeout : 5097ms.
17ms timeout : 5508ms.
18ms timeout : 5899ms.
19ms timeout : 6349ms.
20ms timeout : 6820ms.
Average time: 4862ms


MSIE6 SP1
1ms timeout : 2503ms.
2ms timeout : 2554ms.
3ms timeout : 2544ms.
4ms timeout : 2543ms.
5ms timeout : 2544ms.
6ms timeout : 2544ms.
7ms timeout : 2543ms.
8ms timeout : 2544ms.
9ms timeout : 2544ms.
10ms timeout : 2543ms.
11ms timeout : 5027ms.
12ms timeout : 5038ms.
13ms timeout : 5037ms.
14ms timeout : 5037ms.
15ms timeout : 5037ms.
16ms timeout : 5038ms.
17ms timeout : 5037ms.
18ms timeout : 5037ms.
19ms timeout : 5037ms.
20ms timeout : 5038ms.
Average time: 3788.45ms

Can we get a profile of this (quantify/jprof) ?
comparing Mozilla here with IE is inappropriate because IE handles the timeouts
completely different than Mozilla.  comparing with earlier versions of Mozilla
doesn't work any better because current builds refuse to do timeouts less than 10ms.

it would be nice to have a test that worked each browser similarly.

FYI: my PII-450 MHz running linux wins with 4266.95ms.
Well, as far as I know MSIE also has a 10ms timeout as the least value. But no 
matter what timeout result we compare - all are slower in Mozilla.
Changing the URL field and posting results for yet another testcase doesn't seem
like it will make this bug any easier to understand.  (What about results
earlier that don't mention a URL in the comment either?)  How about keeping one
bug per issue?
Under linux, there is no apparent perf difference beyond 0.9.8.  0.9.9 was
significantly better than 0.9.8, and current trunk is the same as 0.9.9.
I just updated the URL field as the one wasn't valid anymore.
And the testcase isn't new - it's the one that was mostly talked about in this 
bug!

The problems for the testcases 
http://guisset.tripod.com/mozilla/testcase/timer.html
http://www.world-direct.com/mozilla/timeouttest.htm
[which have been mentioned during this bug]
have been fixed by bug 170272 (those testcases have used scaled images).

So the best thing would be to do a profile to get an idea what could be 
optimized.
 
Is this bug for a regression with the testcase since 0.9.5, or is it just for
general improvenet for the performance of the testcase?  Whatever loss occurred
with 0.9.{6,7} has been fixed, or at least is not going to be found at this point.
On the one hand previous builds did better on the testcase - on the other hand 
it would be desired that we achieve the same performance as for example MSIE 
does on it.
Depends on: 186133
Testcase with timeout from 10ms to 20ms
http://www.world-direct.com/mozilla/dhtml/funo/dhtmltest_10ms.htm

Using trunk build 2003022709 the thing is that the 10ms run is 3925ms in 
Mozilla and just 2503ms in MSIE6 !

Complete results:

Mozilla (trunk build 2003022709)
10ms timeout : 3925ms.
11ms timeout : 4617ms.
12ms timeout : 5007ms.
13ms timeout : 5007ms.
14ms timeout : 5008ms.
15ms timeout : 5017ms.
16ms timeout : 5157ms.
17ms timeout : 5548ms.
18ms timeout : 5979ms.
19ms timeout : 6369ms.
20ms timeout : 6790ms

MSIE6
10ms timeout : 2503ms.
11ms timeout : 5038ms.
12ms timeout : 5037ms.
13ms timeout : 5037ms.
14ms timeout : 5037ms.
15ms timeout : 5038ms.
16ms timeout : 5037ms.
17ms timeout : 5037ms.
18ms timeout : 5047ms.
19ms timeout : 5048ms.
20ms timeout : 5037ms.
Depends on: 157681
Sorry Marcus, but You probably made a mistake. My results:

Mozilla 20030226:
10ms timeout : 4109ms.
11ms timeout : 4735ms.
12ms timeout : 5062ms.
13ms timeout : 5578ms.
14ms timeout : 5891ms.
15ms timeout : 6391ms.
16ms timeout : 6734ms.
17ms timeout : 7125ms.
18ms timeout : 7562ms.
19ms timeout : 7813ms.
20ms timeout : 7781ms.
Average time: NaNms.

IE6
10ms timeout : 3906ms.
11ms timeout : 3937ms.
12ms timeout : 3922ms.
13ms timeout : 3922ms.
14ms timeout : 3922ms.
15ms timeout : 3922ms.
16ms timeout : 7031ms.
17ms timeout : 7813ms.
18ms timeout : 7812ms.
19ms timeout : 7813ms.
20ms timeout : 7812ms.
Average time: NaNms.

Humm... Look at IE6 results...
I guess I made the same mistake then. 

Mozilla trunk 2003022814:
10ms timeout : 4326ms.
11ms timeout : 4687ms.
12ms timeout : 4997ms.
13ms timeout : 5007ms.
14ms timeout : 5007ms.
15ms timeout : 5007ms.
16ms timeout : 5158ms.
17ms timeout : 5638ms.
18ms timeout : 5989ms.
19ms timeout : 6399ms.
20ms timeout : 6800ms.

IE6 SP1:
10ms timeout : 2504ms.
11ms timeout : 4997ms.
12ms timeout : 5008ms.
13ms timeout : 5007ms.
14ms timeout : 5007ms.
15ms timeout : 5007ms.
16ms timeout : 5007ms.
17ms timeout : 5008ms.
18ms timeout : 5007ms.
19ms timeout : 5007ms.
20ms timeout : 5007ms.

Without better knowledge, it seems to me that IE sucks with 10ms making it
something very little, such as 0. It's about the same as with 1ms timeout.
Can we get a profile of this testcase?
Maybe this also depends to some extend on the used graphic card - see bug 
194627 for example.
Mass-reassigning bugs to dom_bugs@netscape.com
Assignee: jst → dom_bugs
adt: nsbeta1-
Keywords: nsbeta1nsbeta1-
Whiteboard: [adt3]
I've attached a patch in bug 213813 that might help with some of these DHTML
issues. I don't expect tremendous gains, but it might be a small step in
improving performance. I'm going to try and get some numbers, but I wanted to
get this out to others that might have more time than I have current. The patch
is at http://bugzilla.mozilla.org/attachment.cgi?id=128862&action=edit
Testing on the attached url, I get a better results in Mozilla 20031116, than IE 6. 

Mozilla: 3453.45ms.
IE 6: 3764.45ms.
Marking WFM, and still hoping to see bug 157681 fixed soon.
Status: NEW → RESOLVED
Closed: 15 years ago
Resolution: --- → WORKSFORME
Component: DOM: Core → DOM: Core & HTML
QA Contact: stummala → general
You need to log in before you can comment on or make changes to this bug.