117061 - DHTML Perf regression since 0.9.7, related to timeout

Status: VERIFIED FIXED

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

Description

[Fabian Guisset]

From Bugzilla Helper:
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:0.9.7) Gecko/20011221
BuildID:    2001122106 and 2001122606

The testcase at the above URL is simple: 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. Results from many people in #mozilla look like this:
0.9.7: 900ms
Nightly: 1800ms.
Your mileage may vary, but it is reproduceable everytime on my computer.
Parameters affecting the performance:
* Faster computers tend to show a larger difference (twice as slow), than slower
computers (only 20% slower or some such)
* Longer timeouts (100ms instead of the current 10ms) are less subject to this
regression.

In the light of those findings, I'm assigning this to pavlov because this
regression is most likely due to his timer checkin. Note that lots of dynamic
menus and animations use setTimeout with short intervals and this really kills
the perf.

Reproducible: Always
Steps to Reproduce:
1. Load the testcase at http://guisset.tripod.com/mozilla/testcase/timer.html
2. Click on 'test me'. The text will move to the right of the screen.
3. When the text reaches the right of the screen, an alert pops up telling you
about the elapsed time.

Actual Results:  A nightly takes twice as long as 0.9.7 to complete the animation.

Expected Results:  It should be at least as fast.

Note that in this bug I am not comparing the performance with IE. Indeed the
testcase will not work in IE because it doesn't know about window.innerWidth.

Comment 1

[Markus Hübner]

New XP timer code - bug 78611

Comment 2

[Randell Jesup [:jesup] (needinfo me)]

The text moves faster (under X) if you move the mouse around over the mozilla
window (close to twice as fast).  This tells me that the problem is almost
certainly due to not setting the timeout correctly - i.e. something like mouse
events are waking us up, and we're noticing that the timer has gone off before
going to sleep again and servicing it.

Interestingly, I tried setting breakpoints in the new timer code
(TimerThread.cpp and nsTimerImpl.cpp) and got NO hits.  It turned out that I
still had libtimer_gtk.so hanging around since I hadn't clobbered.

After correcting that (and still having the same behavior), I found that setting
ACCEPT_WRONG_TIMES in TimerThread.cpp made the animation fast (and mouse
movements didn't affect it).  It appears that with lots of short timeouts, the
time/overhead to cycle into and out of PR_WaitCondVar() is a problem, or if the
time is too short a distance in the future pthreads isn't waking us up correctly
(or is doing something else inefficient, like not sleeping for less than N,
where N is >>3ms).  I actually got the smoothest results with 4ms.  Note this
may not be the correct solution, but it strongly points to where the problem may
lie.

I'll attach a patch for people to play with.

Note that there's some fundamental skew in timing because of:
  absolute timeout -> relative time -> (processing, mutexes, locks) -> absolute
time.

(PR_WaitCondVar takes a relative time, while timers and pthread_cond_timedwait
use absolute time.)

Comment 3

[Randell Jesup [:jesup] (needinfo me)]

Attachment: possible patch

Not sure if we'd want to commit this as-is - maybe.  Also cleaned up some
stuff.

Comment 4

[Brendan Eich [:brendan]]

rjesup, anyone who can build with this bug's patch: does the patch cure the
regression since 0.9.7 seen with
http://guisset.tripod.com/mozilla/testcase/timer.html ?

/be

Comment 5

[Randell Jesup [:jesup] (needinfo me)]

brendan: yes, that's the test I used.  With ACCEPT_WRONG_TIMES of 3 or 4ms, the
animation runs twice as fast roughly, and isn't affected by mouse movement.

Comment 6

[Christopher Aillon (sabbatical, not receiving bugmail)]

Comment 2 from rjesup:
> The text moves faster (under X) if you move the mouse around over the mozilla
> window (close to twice as fast).

See bug 115808 for eerily similar behaviour.

Comment 7

[Markus Hübner]

Will this also cure the effect described in bug 107746 seen on my PIII,500MHZ 
that there is no animation (happened after pav's new timer code checkin), just 
the final positioned elements are being displayed.

Comment 8

[Randell Jesup [:jesup] (needinfo me)]

I see them moving in with this patch, but slowly (see comments in bug 107746 for
detailed analysis from a machine without my patch).

Comment 9

[Markus Hübner]

Just discovered this:
When going to http://www.formula-one.nu/dhtml/3d.htm
on my PIII,500MHZ,327RAM the cube is positioned, then a few seconds
nothing, then postioned somewhere else, and so on.
But when clicking in the URL location bar and typing something with
every click the cube is being displayed ... and so I can arrange
a somewhat smooth animation ;)

With this URL location bar trick I can also manage to see the menu
items being sliding in on bug 107746.

Comment 10

[Randell Jesup [:jesup] (needinfo me)]

I wonder if (on some OS's) very short delays are causing the wakeup time to be
in the past, and instead of sleeping for no time, it's sleeping forever, and
getting woken up when someone else adds or removes a timer event (like on a
mousemove or keyboard click).  Hmmm.  

Comment 11

[Peter Nilsson]

I've made a testcase where an image is moved on the screen.
www.formula-one.nu/dhtml/dhtmltest.htm

It runs 20 times with different timeouts and then counts an average time.

I have found that IE and moz handles the timeouts different. Moz uses the
timeouts 1,2,3,4 and so on while IE is just using 10, 20, 30, 40.....

Maybe that's why IE doesn't have problems with DHTML scripts using very short
timeouts (1ms).... ?

Here are the results: (Win XP, PII, 450MHz)


Mozilla (2001122703)
1ms timeout : 1582ms.
2ms timeout : 1582ms.
3ms timeout : 1592ms.
4ms timeout : 1583ms.
5ms timeout : 2523ms.
6ms timeout : 2544ms.
7ms timeout : 2604ms.
8ms timeout : 2714ms.
9ms timeout : 4797ms.
10ms timeout : 4907ms.
11ms timeout : 4967ms.
12ms timeout : 5017ms.
13ms timeout : 5027ms.
14ms timeout : 5057ms.
15ms timeout : 5158ms.
16ms timeout : 5057ms.
17ms timeout : 5178ms.
18ms timeout : 5147ms.
19ms timeout : 7251ms.
20ms timeout : 7470ms.
Average time: 4087.85ms.

IE6
1ms timeout : 2563ms.
2ms timeout : 2544ms.
3ms timeout : 2534ms.
4ms timeout : 2523ms.
5ms timeout : 2534ms.
6ms timeout : 2524ms.
7ms timeout : 2533ms.
8ms timeout : 2534ms.
9ms timeout : 2534ms.
10ms timeout : 2533ms.
11ms timeout : 4987ms.
12ms timeout : 5038ms.
13ms timeout : 5027ms.
14ms timeout : 5027ms.
15ms timeout : 5027ms.
16ms timeout : 5028ms.
17ms timeout : 5027ms.
18ms timeout : 5027ms.
19ms timeout : 5027ms.
20ms timeout : 5028ms.
Average time: 3779.95ms.

Comment 12

[Markus Hübner]

Results from that testcase with 0.9.5/0.9.6/0.9.7 are in bug 117436

Comment 13

[Randell Jesup [:jesup] (needinfo me)]

Doesn't surprise me.  Precise millisecond timeouts aren't likely to matter in
javascript, even if being used for a game, since screens rarely refresh more
often than about every 12ms, and js isn't being used for hardware control.

In general, with timers, the guarantee is for "on or after" the time specified.

Comment 14

[Johnny Stenback (:jst)]

Pav, any progress on fixing this regression?

Comment 15

[Brendan Eich [:brendan]]

I have a patch that needs to be unrotted, and that filters feedback into its
estimate of the delay needed so as to minimize skew.  I'm removing the 0.9.8
dependency.  I'll leave this on pav's list and stop short of taking the bug; I'm
just a patch provider here.

/be

Comment 16

[Brendan Eich [:brendan]]

Attachment: digital filter to adaptively underestimate timeout schedule for on-time timers

Please try this patch out, pound on it, report all problems in the bug.  It
needs tuning; mTimeoutAdjustment probably should be clamped (I get very large
values at startup -- is Gecko hogging the event loop?  The filter smooths them
eventually, but the next timer after such a huge delay will run early).

/be

Comment 17

[Brendan Eich [:brendan]]

Attachment: better filter initialization: don't apply feedback until the delay line fills

I demo'ed this to pav, he likes.  Anyone else try the last patch?  Try this
one, it'll avoid overlarge adjustments at startup.

/be

Comment 18

[Stuart Parmenter]

Comment on attachment 66961 [details] [diff] [review]
better filter initialization: don't apply feedback until the delay line fills

r=pavlov

Comment 19

[Johnny Stenback (:jst)]

Comment on attachment 66961 [details] [diff] [review]
better filter initialization: don't apply feedback until the delay line fills

sr=jst

Comment 20

[Fabian Guisset]

On my debug build (linux cvs from today) the last patch makes things worse. The
time until the alert pops up is more random and generally longer than without
the patch  (1800ms without the patch, avg 2000ms with the patch). Sometimes the
picture animates faster sometimes much slower sometimes it completely stops for
half a second or so.

Comment 21

[Brendan Eich [:brendan]]

Ok, I'm not going to check in without some better results -- Fabian's feedback
is bad news that stops the patch.  I'm unsure what the problem is, however. 
Fabian, can you set NSPR_LOG_MODULES=nsTimerImpl:5 and
NSPR_LOG_FILE=/tmp/timer.log in the environment and run without the patch, then
apply the patch, rebuild, and run with the same NSPR_LOG_MODULES envar, but with
NSPR_LOG_FILE=/tmp/timer2.log (making the same mouse moves and clicks, as much
as possible)?  Attach the logs here and I'll analyze.  Thanks,

/be

Comment 22

[Mike Nicholls]

I'm running 0.9.7 on Windows and am getting times in the testcase at
http://guisset.tripod.com/mozilla/testcase/timer.html of about 5000 - 6000ms,
but if I waggle the mouse over the Mozilla window the time goes down to about
1500ms.  Perhaps this isn't a regression?

Comment 23

[Ronald van Kuijk]

With build 2002020412 on linux on my PII-266/256MB I get around 2050 ms always
(besides the 1st time which is around 1920 ms. I does not matter how fast I move
the mouse.

Comment 24

[Jean-Marc Desperrier]

Everyone in the comments seems to say that the regression is only the fact the
animation will run slower.

But when trying to access the following page http://eurofont.de/ that uses DHTML
on multiple elements, I've found that the problem is also that Mozilla uses so
much CPU that everything comes to a stand-still in Windows.

Mozilla is at 99% CPU, very bad system response, IE is only around 80 %, its
very high too but it makes a lot of difference for user interaction, my system
is still responding with IE, even if slower, but it looks almost blocked with
Mozilla.

Comment 25

[Julien Wajsberg [:julienw]]

It will run very very slower... In fact, if you had a P5 8 Ghz, it should work
fine ;)
It's a regression because it's significantly slower than before, that's all.

Comment 26

[Markus Hübner]

Well, as you can see it's also causing bug 116252 (Hang on DHTML examples).

Comment 27

[andreww]

is this getting checked in soon? looks like it has r/sr or are there 
outstanding issues?

Comment 28

[Brendan Eich [:brendan]]

Fabian was going to help gather some log files for me, but I haven't heard back.
 Unless there's a bug in my code that I can't see, the problem could be that the
feedback loop needs some amplification.  I'll refresh the patch (it rotted) and
add a multiplier.

/be

Comment 29

[Brendan Eich [:brendan]]

Attachment: refreshed patch with feedback multiplier (1.3 for now, total hack)

Comment 30

[Fabian Guisset]

Brendan, I got the following error when applying your latest patch:
nsTimerImpl.cpp: In method `void nsTimerImpl::SetDelayInternal
(unsigned int)':
nsTimerImpl.cpp:362: `now' undeclared (first use this function)
nsTimerImpl.cpp:362: (Each undeclared identifier is reported only once
for each function it appears in.)

Also I tried to set the env vars as you told me to, but the log files are empty
(0 bytes), although they are created.

Comment 31

[Brendan Eich [:brendan]]

Attachment: oops, refresh patch, then test before attaching!

Fabian, I don't know why you didn't get log info -- of course you need a debug
build, but beyond that, I'm not sure what could be wrong.  Can anyone else try
this patch, set the NSPR_LOG_* envariables, and report results?

/be

Comment 32

[piglet]

Please can someone tell me how to get off email notification of every amendment 
to this [e-mail]

Thanks

Comment 33

[Fabian Guisset]

was able to build and test on a cvs opt build on linux... the time to run the
animation went from 1800 without the patch to 1600 with the patch. I'm sorry but
it will take a few more days for me to build a debug build and be able to run
with the env vars set (I'll be away due to the EU Mozilla meeting), so if
someone could do it, that would be great.
Anyway I'm no longer seeing the regression caused by the old patch (wasn't on
the same build, though), so that's good news at least.
I say, if it fixes it for you (brendan) and pavlov, check it in and let it bake
for a while on the trunk to get some more testing.

Comment 34

[Jaime Rodriguez, Jr.]

Removing nsbeta1 nomination because this bug has been plussed.

Comment 35

[Brendan Eich [:brendan]]

Ok, patch is in (I tweaked the fudge factor amplifying feedback to 1.5 from 1.3,
based on very noisy testing -- we need an optimized build to report lateness and
filtered feedback).  As Fabian says, let's bake this in 0.9.9 and see what else
needs work.

Some of the comments in this bug are too vague -- 100% CPU running DHTML is a
known problem that is not related to the timers-using-threads change.  Also, the
mouse-waving effects seem independent of native-timers vs. timers-using-threads
per comment #22.

/be

Comment 36

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Looks like this patch caused a significant drop in page load times.  Any idea if
the effect is real or if it's an interaction with the design of the test?

Comment 37

[Markus Hübner]

The hang on DHTML examples (bug 116252) still occurs.
As outlined in bug 117436 the animation now takes longer than.

Comment 38

[Brendan Eich [:brendan]]

This bug is not bug 116252 for a reason, and I don't claim to have addressed any
problem reported in that bug.  Let's stick to the testcase and problem developed
here, please.

/be

Comment 39

[John Morrison]

dbaron! You read my mind :-]. Yeah, I was looking at this last night, and will 
be poking around some more today to figure out if the change in pageload time
is "real" or an artifact (or an error).

Comment 40

[Markus Hübner]

Brendan, I was too eager to test (had a build without the patch).
Just see my comment in http://bugzilla.mozilla.org/show_bug.cgi?id=117436#c21
The testcase works fine now! :))

Comment 41

[John Morrison]

Hate to retract (an earlier comment I made to brendan), but where earlier 
this evening I thought that the drop in pageload times was bona fide, I have 
to step back to a neutral position now. I am seeing (on win2k) a little more 
"fuzz" in the data collected in that test, and in some other ad hoc tests. 
I have to think some more about what it really means. For a start, I think
I should read this bug report and/or patch :-]

Comment 42

[Stuart Parmenter]

moving this out to 1.0 for any other problems that still need to be adjusted or 
tweeked.

Comment 43

[Markus Hübner]

just4info: the testcase at
http://www.world-direct.com/mozilla/dhtml/index.html
with build 2002022308 still shows this behaviour of just displaying the final 
positioned elements. (testing this time on computers at the UCSD)

Comment 44

[Markus Hübner]

http://www.formula-one.nu/mozilla/domtestcase2/

especially on the second testcase there is nothing displayed ... just the 
final positioned elements (when the alert box appears).

Comment 45

[Ronald van Kuijk]

On build 2002030206 on linux I do see all the intermediate steps.... Maybe
platform specific...

Comment 46

[Stig Nygaard]

I haven't studiet the code behind the testcases, but I have done som thoughts
about what might be going on. I have my own "testcase", an application I'm
building on (or rather somebody elses DHTML-app which I'm making cross-browser
compatible. Before it only worked in IE4+ and N4.x).

The code in this application used "recursively" call of the setTimeout()
function with a delay of only 1 ms (problably meaning: do it as fast as
possible) to a scrolling effect. I managed to get the app running well in
Mozilla, Netscape 6+, Konqueror 2.2.1+ and Opera 6 some moths ago, but recently
it started behaving weird in my Mozilla browser (Moz 0.9.7 or 0.9.8, not sure).
It behaved like described elsewhere above: You didn't see it scroll, but sudenly
it appeared in the end of the scroll, so it looked like it had skipped alle the
intervening steps. I tried rewriting the code using setInterval() instead, but
still same behavoir. Then I started experimenting with the interval-size, and
setting it to 100ms solved the problem at my PC (but the scrolling effect is now
slower than before).

My teori is that normally (old Mozilla and other browsers) a new "thread"
initiated by setTimeout() or setInterval() isn't started until the previous
"thread" has finished. But this behavoir is broken in recently Mozilla builds,
so a new "thread" is  started before the previous one has finished, and this
either disturbs the previous "thread(s)" or destroys them.

I guess the behavoir is proplably depending on the speed of the computer. Mine
is a AMD K6-2 400MHz. Problably faster computers are more tolerant ? (I haven't
tested my app on faster PCs).

BTW. http://guisset.tripod.com/mozilla/testcase/timer.html works fine on my PC,
so my PC might be to fast for this testcase ?

Comment 47

[Stig Nygaard]

I forgot to mention that my current Mozilla is nightly build 2002022703 (Windows).

Comment 48

[Markus Hübner]

The intermediate steps at http://www.world-direct.com/mozilla/dhtml/index.html 
as well as on the testcases at http://www.formula-one.nu/mozilla/domtestcase2/ 
are missing on PIII, model 7, stepping 3, 256ram, winnt using build 2002030308

Comment 49

[Markus Hübner]

The checkin of this one seems to have caused the regression stated in bug 
129953.

Comment 50

[Samuel Sieb]

It seems that bugzilla (or mozilla) accidently removed the dependancy.

Comment 51

[Markus Hübner]

A very fine testcase from Peter for playing around
http://www.formula-one.nu/mozilla/timeouttest.htm

You can test with different timeouts and number of elements.
You can see that a small timeout causes frame-drop.
You can also see that a big timeout but with many elements causes the same 
problem.

Comment 52

[Markus Hübner]

Results from the new testcase with build 2002032003 on win-xp (1.1ghz).

Actual time :: Time between setTimeout and function
====================================================

251 :: 251
521 :: 260
762 :: 241
1012 :: 240
1263 :: 241
1513 :: 240
1764 :: 241
2024 :: 250
2275 :: 251
2515 :: 240
2545 :: 20
2565 :: 20
2586 :: 21
2826 :: 240
2856 :: 20
2876 :: 20
3127 :: 251
3367 :: 240
3618 :: 241
3868 :: 240
4129 :: 251
4369 :: 240
4620 :: 241
4870 :: 240
5121 :: 241
5371 :: 240
5622 :: 241
5872 :: 240
6123 :: 241
6143 :: 10
6163 :: 10
6413 :: 240
6433 :: 10
6453 :: 10
6724 :: 251
6984 :: 260
7235 :: 251
7486 :: 251
7736 :: 250
7987 :: 241
8237 :: 250
8488 :: 251
8738 :: 250
8989 :: 251
9239 :: 250
9490 :: 251
9740 :: 250
9991 :: 251
10011 :: 20
10031 :: 20

-------------------

and MSIE6.0

100 :: 100
200 :: 100
301 :: 101
411 :: 100
511 :: 100
611 :: 100
711 :: 100
812 :: 101
912 :: 100
1012 :: 100
1112 :: 100
1212 :: 100
1313 :: 101
1413 :: 100
1513 :: 100
1613 :: 100
1713 :: 100
1814 :: 101
1914 :: 100
2014 :: 100
2114 :: 100
2214 :: 100
2315 :: 101
2415 :: 100
2515 :: 100
2615 :: 100
2715 :: 100
2816 :: 101
2916 :: 100
3016 :: 100
3116 :: 100
3216 :: 100
3317 :: 101
3417 :: 100
3517 :: 100
3617 :: 100
3717 :: 100
3818 :: 101
3918 :: 100
4018 :: 100
4118 :: 100
4219 :: 101
4319 :: 100
4419 :: 100
4519 :: 100
4619 :: 100
4720 :: 101
4820 :: 100
4920 :: 100
5020 :: 100

Comment 53

[Randell Jesup [:jesup] (needinfo me)]

This test now shows we have serious problems with the SetTimeout processing,
perhaps partly due to the previous attempt to fix timers.  With a SetTimeout of
100ms (which is what matic used, the default settings), you shouldn't see a
pattern of sometimes 250ms, sometimes 10ms.  Now, the 250 may be largely due to
bug 129115, but we shouldn't be seeing 10 or 20, and especially not several of
them in a row.

Comment 54

[Ere Maijala (slow)]

While in the process of fixing bug 138791 I bumped on a problem that the patch 
here seems to cause. For existing timers, SetDelayInternal will not always 
update mTimeout, causing the timeout to be set to past (therefore the timer 
will never fire). I don't really understand why this was made. Could someone 
shed some light on this one (Brendan?). 

Comment 55

[Brendan Eich [:brendan]]

> SetDelayInternal will not always update mTimeout...

nsTimerImpl::SetDelayInternal always updates mTimeout, but it updates
differently according to whether it is being called the first time, and
depending on mType if not called the first time.  In no case will it fail to +=
mTimeout by the delay, appropriately scaled.  So I'm not sure what you mean by
"will not always update mTimeout".

I'll take a look at bug 138791.

/be

Comment 56

[Ere Maijala (slow)]

Sorry, I wasn't really clear. I meant that it doesn't always update it to |now|.
Therefore there's quite a big chance that adding aDelay to it isn't enough to
make it > now.

Comment 57

[Markus Hübner]

Bug 12761 and its example at http://www.narain.com/gecko/ might give some nice 
input. Quite a long time ago :)

Comment 58

[Brendan Eich [:brendan]]

Ere, I got that.  The 'if (mTimeout < now) mTimeout = 0xffffffff;' after
mTimeout += delta; is just wrong.  I sr'd that, but wasn't thinking.  More in
bug 138791.

/be

Comment 59

[Ere Maijala (slow)]

I would have tested my changes (related to bug 138791) against bug 12761, but
www.narain.com doesn't seem to exist :(

Comment 60

[Markus Hübner]

The domain works fine here! Please try via another ISP if it still doesn't 
work.

Comment 61

[Markus Hübner]

It's a revelation if you go with Mozilla 0.9.9 to http://www.narain.com/gecko/
That already rocked!

Comment 62

[Ere Maijala (slow)]

My trunk debug build is clearly too slow. I'm doing an optimized build to see
how it works.

Comment 63

[Stuart Parmenter]

you can't test debug builds on any of this stuff :(  you have to do opt builds
to get any sort of real feel for them.

Comment 64

[Ere Maijala (slow)]

Mozilla with my patch from bug 138791 (Win2k under Terminal Services):

Actual time :: Time between setTimeout and function:
110 :: 110
220 :: 110
330 :: 110
440 :: 110
550 :: 110
660 :: 110
771 :: 111
871 :: 100
971 :: 100
1071 :: 100
1171 :: 100
1271 :: 100
1371 :: 100
1472 :: 101
1582 :: 110
1682 :: 100
1782 :: 100
1892 :: 110
1992 :: 100
2102 :: 110
2213 :: 111
2323 :: 110
2433 :: 110
2543 :: 110
2653 :: 110
2763 :: 110
2864 :: 101
2974 :: 110
3084 :: 110
3184 :: 100
3294 :: 110
3404 :: 110
3514 :: 110
3625 :: 111
3735 :: 110
3845 :: 110
3955 :: 110
4055 :: 100
4165 :: 110
4265 :: 100
4366 :: 101
4466 :: 100
4566 :: 100
4666 :: 100
4766 :: 100
4876 :: 110
4976 :: 100
5087 :: 111
5187 :: 100
5297 :: 110

Comment 65

[Markus Hübner]

Testing latest 1.0 branch bulid (2002042708) on win-xp,1.1ghz,512RAM I still 
get the following results:

Actual time :: Time between setTimeout and function:
281 :: 281
521 :: 230
761 :: 230
1002 :: 241
1242 :: 240
1482 :: 240
1713 :: 231
1953 :: 230
2193 :: 240
2434 :: 241
2674 :: 230
2915 :: 241
3155 :: 240
3395 :: 240
3636 :: 241
3886 :: 250
4126 :: 230
4387 :: 251
4627 :: 240
4877 :: 250
5118 :: 231
5358 :: 230
5599 :: 241
5839 :: 240
6079 :: 240
6320 :: 241
6550 :: 230
6790 :: 230
7041 :: 241
7271 :: 230
7511 :: 230
7752 :: 231
7992 :: 230
8232 :: 240
8473 :: 241
8713 :: 240
8954 :: 241
9194 :: 240
9434 :: 240
9665 :: 231
9905 :: 230
10145 :: 230
10386 :: 241
10626 :: 240
10866 :: 240
11107 :: 241
11347 :: 240
11577 :: 230
11828 :: 240
12058 :: 230

Comment 66

[Ere Maijala (slow)]

I got similar results when I ran it on my Windows 2000 console, but for some
strange reason it works much better when running it in under Terminal Services.
I suspect we are doing something slow such as repainting the whole window all
the time because making the window smaller seems to help a lot also. I don't
think this is anymore timer related.

Comment 67

[Stuart Parmenter]

as I it has been said many times, this patch is *not* checked in to the 1.0
branch so any numbers you see there are meaningless.

Comment 68

[Stuart Parmenter]

er, i'm sorry, the patch from bug 129953 is not on the 1.0 branch.  without that
patch your numbers are meaningless.

Comment 69

[Ere Maijala (slow)]

I should have said that I'm always using trunk builds and see numbers similar to
the ones reported by Markus.

Comment 70

[Ere Maijala (slow)]

I think we have two problems here. 

1. We are painting too much. Making the window smaller or moving something on
top of it makes it work much faster. Changing the script to only initialize 10
images makes it again a lot faster (it will display, and seemingly also repaint,
the 100 balls even if only 10 are moved). The biggest difference in speed seems
to come from moving a window on top of the pile of balls below the run button
while others are moving. This also supports the idea that the static balls get
repainted all the time.

2. It seems that we're reloading and resizing the images all the time. I tried a
local copy of  timeouttest.htm without the gif, and the image placeholders moved
quite smoothly on the screen. Then resized the gif to 32x32 and took away width
and height settings from the script. Again quite smooth. Leaving width and
height in place reduced the speed a lot even though the image was already right
size.

Comment 71

[Marc Boullet]

I did what Ere suggests with the testcase of comment #22 (i.e. I covered
the browser window by another window as soon as the testcase was run).

I got very strange numbers (see attached screenshot). After the window has
lost visibility, the measurements are under 100ms (i.e. 80). How is that
possible ?
MY machine is a slow PII 300 MHz NT4 20020428

Comment 72

[Marc Boullet]

Attachment: results

Sorry, I meant comment #51 in my previous comment

Comment 73

[Ere Maijala (slow)]

That's because timer tries to adjust to the extra load by adjusting the timeout
accordingly when it sees that timers fire too late. When the load goes quickly
down it takes a few fires to resume "normal" operation.

Comment 74

[Randell Jesup [:jesup] (needinfo me)]

Specifying width and height (if they don't match the actual width and height)
causes a lot of extra work to be done to scale the images.

Comment 75

[Adam D. Moss]

Hmm, still Randell, I'd have thought that imglib
would/could have cached scaled versions of the
images.  I wonder if it is supposed to -- I know
that there has been a lot of vascillation on that
point over the various design iterations of imglib,
the image-cache and the fe's.

Comment 76

[Randell Jesup [:jesup] (needinfo me)]

I don't think scaled images are cached.  I know they didn't used to be, which
was why we put in specific optimization cases for totally transparent scaled
images.  They migth be though.

Comment 77

[Stuart Parmenter]

we do not keep cached versions of scaled images in the cache for a number of
reasons (short version: we don't want 300 copies of a spacer gif in memory at
different sizes).  We scale on the fly at drawing time so that we are able to
instantly rescale images.  If we kept cached copies of the scaled images, we
would also have to keep the original image and this would greatly increase the
amount of memory used by images.

Comment 78

[Stuart Parmenter]

this bug is fixed now due to numerous other patches (129953, 138791, etc).

using today's nightly build (2002042908) and IE6 on Win2k, when I run 
http://www.formula-one.nu/dhtml/dhtmltest.htm I get:
Mozilla
1ms timeout : 2403ms.
2ms timeout : 2374ms.
3ms timeout : 2393ms.
4ms timeout : 2383ms.
5ms timeout : 2033ms.
6ms timeout : 2043ms.
7ms timeout : 2364ms.
8ms timeout : 2523ms.
9ms timeout : 2714ms.
10ms timeout : 3055ms.
11ms timeout : 3445ms.
12ms timeout : 3825ms.
13ms timeout : 4176ms.
14ms timeout : 4527ms.
15ms timeout : 4887ms.
16ms timeout : 5007ms.
17ms timeout : 5007ms.
18ms timeout : 5017ms.
19ms timeout : 5198ms.
20ms timeout : 5568ms.
Average time: 3547.1ms

IE6
1ms timeout : 2504ms.
2ms timeout : 2524ms.
3ms timeout : 2523ms.
4ms timeout : 2584ms.
5ms timeout : 2523ms.
6ms timeout : 2524ms.
7ms timeout : 2524ms.
8ms timeout : 2523ms.
9ms timeout : 2554ms.
10ms timeout : 2524ms.
11ms timeout : 4997ms.
12ms timeout : 5017ms.
13ms timeout : 5017ms.
14ms timeout : 5018ms.
15ms timeout : 5017ms.
16ms timeout : 5017ms.
17ms timeout : 5077ms.
18ms timeout : 5017ms.
19ms timeout : 5018ms.
20ms timeout : 5017ms.
Average time: 3775.95ms.

Comment 79

[Markus Hübner]

Reopening. Stuart, would be nice if you consider the orther tests where we are 
still doing worse too.

test 1)
http://guisset.tripod.com/mozilla/testcase/timer.html
trunk build 2002042908  |  1433
0.9.7                   |  1272


test 2) http://www.formula-one.nu/mozilla/timeouttest.htm

trunk 2002042908	0.9.7

290 :: 290	|	181 :: 181
561 :: 271	|	351 :: 170
811 :: 240	|	511 :: 150
1051 :: 240	|	672 :: 161
1302 :: 251	|	812 :: 140
1542 :: 240	|	962 :: 140
1783 :: 231	|	1112 :: 150
2033 :: 240	|	1253 :: 141
2273 :: 240	|	1403 :: 140
2514 :: 241	|	1553 :: 150
2764 :: 240	|	1703 :: 150
3015 :: 241	|	1844 :: 141
3255 :: 240	|	2004 :: 150
3496 :: 241	|	2154 :: 150
3746 :: 250	|	2294 :: 140
3986 :: 240	|	2445 :: 141
4237 :: 241	|	2595 :: 150
4487 :: 250	|	2735 :: 140
4728 :: 241	|	2885 :: 140
4968 :: 240	|	3036 :: 151
5218 :: 240	|	3176 :: 140
5459 :: 241	|	3336 :: 150
5709 :: 250	|	3486 :: 140
5950 :: 241	|	3637 :: 151
6200 :: 240	|	3777 :: 140
6441 :: 241	|	3927 :: 140
6691 :: 250	|	4077 :: 140
6931 :: 240	|	4228 :: 151
7182 :: 241	|	4368 :: 140
7432 :: 250	|	4518 :: 140
7683 :: 251	|	4668 :: 150
7923 :: 240	|	4809 :: 141
8173 :: 250	|	4959 :: 140
8414 :: 241	|	5109 :: 150
8664 :: 250	|	5249 :: 140
8905 :: 241	|	5400 :: 141
9155 :: 250	|	5550 :: 150
9396 :: 241	|	5690 :: 140
9646 :: 250	|	5840 :: 140
9886 :: 240	|	5991 :: 151
10137 :: 241	|	6131 :: 140
10377 :: 240	|	6281 :: 140
10628 :: 251	|	6431 :: 150
10868 :: 240	|	6572 :: 141
11118 :: 250	|	6722 :: 140
11359 :: 241	|	6872 :: 150
11609 :: 240	|	7022 :: 150
11850 :: 241	|	7163 :: 141
12100 :: 240	|	7313 :: 150
12341 :: 241	|	7453 :: 140


test 3)
http://www.formula-one.nu/mozilla/domtestcase2/moveTextDivs.htm

trunk build 2002042908  |  26680
0.9.7                   |  24722

Comment 80

[Sören 'Chucker' Kuklau (gone)]

Same procedure, different specs: Athlon 500 with WinXP.

test 1)
http://guisset.tripod.com/mozilla/testcase/timer.html
trunk build 2002042908  |  1242
K-Meleon (0.9.5)        |  942


test 2) http://www.formula-one.nu/mozilla/timeouttest.htm

trunk 2002042908

511 :: 501
972 :: 441
1472 :: 490
1923 :: 441
2384 :: 441
2864 :: 470
3335 :: 451
3806 :: 461
4266 :: 440
4757 :: 470
5228 :: 451
5709 :: 471
6199 :: 480
6680 :: 461
7151 :: 451
7731 :: 560
8222 :: 471
8713 :: 481
9164 :: 441
9664 :: 480
10125 :: 441
10616 :: 471
11066 :: 440
11557 :: 471
12008 :: 431
12508 :: 480
12969 :: 451
13480 :: 491
13930 :: 430
14411 :: 471
14892 :: 471
15352 :: 450
15823 :: 451
16294 :: 451
16784 :: 480
17225 :: 431
17716 :: 471
18166 :: 440
18677 :: 491
19118 :: 431
19609 :: 481
20059 :: 430
20550 :: 471
21011 :: 451
21491 :: 470
21952 :: 441
22453 :: 491
22903 :: 430
23364 :: 451
23845 :: 461

K-Meleon (0.9.5)

291 :: 281
571 :: 260
861 :: 230
1122 :: 241
1442 :: 300
1773 :: 311
2033 :: 250
2494 :: 451
2714 :: 210
2834 :: 100
2944 :: 100
3065 :: 101
3175 :: 100
3285 :: 100
3415 :: 120
3766 :: 321
3996 :: 220
4256 :: 240
4597 :: 321
4937 :: 320
5188 :: 231
5448 :: 250
5718 :: 260
5989 :: 261
6229 :: 230
6490 :: 241
6780 :: 270
7030 :: 230
7271 :: 231
7571 :: 280
7821 :: 240
8072 :: 231
8322 :: 230
8623 :: 271
8873 :: 230
9123 :: 240
9374 :: 241
9644 :: 260
9894 :: 220
10155 :: 241
10415 :: 250
10696 :: 271
10956 :: 250
11216 :: 250
11507 :: 281
11847 :: 320
12118 :: 261
12388 :: 260
12678 :: 280
12939 :: 251

IE 6

130 :: 120
240 :: 100
340 :: 100
440 :: 100
540 :: 100
641 :: 101
741 :: 100
841 :: 100
941 :: 100
1041 :: 100
1141 :: 100
1241 :: 100
1342 :: 101
1442 :: 100
1542 :: 100
1642 :: 100
1742 :: 100
1842 :: 100
1942 :: 100
2043 :: 101
2143 :: 100
2243 :: 100
2343 :: 100
2443 :: 100
2543 :: 100
2643 :: 100
2744 :: 101
2844 :: 100
2944 :: 100
3044 :: 100
3144 :: 100
3244 :: 100
3344 :: 100
3445 :: 101
3545 :: 100
3645 :: 100
3745 :: 100
3845 :: 100
3945 :: 100
4045 :: 100
4146 :: 101
4246 :: 100
4346 :: 100
4446 :: 100
4546 :: 100
4646 :: 100
4746 :: 100
4847 :: 101
4947 :: 100
5047 :: 100


test 3)
http://www.formula-one.nu/mozilla/domtestcase2/moveTextDivs.htm

trunk build 2002042908  |  102157
K-Meleon (0.9.5)        |  59986
IE 6                    |  8032 (eek!)

Comment 81

[Ronald van Kuijk]

When you run test 3 in the experimental build of bug 129115, I get the following
result on my 899MHz/256MB linux laptop:

trunk build (2002042910)    49379
exp-129155  (20020422)      8310  (eek! to?)

So not al poor results here are caused by this bug and the results of this
experimental build are in some cases, not all, promising... (see bug 140789)

Comment 82

[Stuart Parmenter]

re-marking fixed.  the problems matic is seeing are due to 139986 and other
dhtml problems.

Comment 83

[Stig Nygaard]

Regarding my earlier comment 46, the problem seem to be fixed in trunk build
2002043008. I haven't tried any other trunk-builds lately, so I'm not sure when
exactly the problem was fixed and if it was a checkin related to this bug or
maybe to bug #129953 which solved it. But it works in the trunk.
I hope the fixes will make it to the 1.0 release.

Comment 84

[Stig Nygaard]

...also a page like http://www.cross-browser.com/ss/solar_system.html have newer
been running very well in Mozilla. At least not for a VERY long time. It used to
run extremely slow, but it seems to bring RC1 totally to its knees on my AMD
k6-400 PC. But latest trunk build runs fast and smoothly like a dream. I love
you guys ! :-)

Comment 85

[andreww]

Here's another page to test out:

http://www.domapi.com/examples/

Lots of DHTML examples here... 

Comment 86

[Markus Hübner]

The bug for the performance regression in DHTML (since 0.9.5) is bug 117436.

Comment 87

[Heikki Toivonen (remove -bugzilla when emailing directly)]

Are you trying to get this to the branch? If so, you'd need to add adt1.0.0 keyword.

Comment 88

[Stuart Parmenter]

no, the things in this bug are already there.

Comment 89

[Paul Wyskoczka]

Marking verified (rs)