136688 - Too much painting slows down DHTML example by a ratio of 5

Status: RESOLVED WORKSFORME

(Core :: Web Painting, defect, P3)

Description

[Marc Boullet]

I was testing the new patch to bug #129953.
I modified slightly the supplied test case (reduced the number
of iterations to 20 and erased the results after each run).
I will attach two testcases:
1. original testcase with number of iterations reduced to 20
2. testcase1 + erase of results after each run

I found some interesting results:
With testcase 1
1. Run the testcase. Wait for the results. The results
partially paint but if you cover the browser window they finally
appear. This didn't happen with the original testcase since the
number of iterations was 50 and the balls were further on the right.

The results with my old PII 300MHz are ~740. watch time to complete
the test is roughly 20s.
2. Run the test a second time. Whooo 4s. Results are 140. Watch time: 4s
3. subsequent runs: same as 2

With testcase 2:
in testcase 2, there is the following statement before each run
   document.getElementById('resultDiv').innerHTML=""

Runs 1 and sunsequent are always the same time: 740 same as in testcase1
run 1.

Conclusion: when the div is empty, the browser is 5 times slower.

This is always reproducible.

Comment 1

[Marc Boullet]

OK, I had to split the textarea to be able to submit (this really sucks).

If you have a faster machine, you can increase the number of balls or decrease
the set timeout interval (knowing that the test can't be faster that the
timeout interval).
The invalidation problem can be filled in a separate bug if necessarY.

Finally I will only supply one testcase. testcase1 is with the checkbox
unchecked while testcase2 is with the checkbox checked.

Comment 2

[Marc Boullet]

Attachment: test case

Comment 3

[Marc Boullet]

Notice also the final move of the group of balls after the
results are displayed

cc'ing roc+moz

Comment 4

[Adam D. Moss]

Does this better belong in the 'Layout'
component than 'Views'?  Haven't seen any
evidence that this can be blamed on the view
manager, though your intuition may beat mine. :)

Comment 5

[Marc Boullet]

Needs bug #129953 fix back again to show significant numbers.

Comment 6

[David Baron :dbaron:]

comment 0 refers to "testcase 1" and "testcase 2".  I only see one testcase on
the bug.

Comment 7

[Markus Hübner]

David, please see comment #1 - "Finally I will only supply one testcase. 
testcase1 is with the checkbox unchecked while testcase2 is with the checkbox 
checked."

Comment 8

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

Reassigning to layout, which is a better first guess than views.  CCing pavlov
and former owner kmccluskey.

Comment 9

[Marc Boullet]

I worked more on this bug and found that the problem
seems to be a "too much paint" problem.

The summary of the bug is not correct. Actually, the "empty div"
is not the primary cause of the slow down, it just let the non-moving
balls at a place that causes them to be repainted.

I'll attach a new testcase. In this testcase, two consecutive runs are:
 - 1st: with the <div> empty
 - 2nd: with the <div> filled. 

Comment 10

[Marc Boullet]

Attachment: testcase 2

Comment 11

[Marc Boullet]

Hereafter are some tests with testcase2:

Test1
-----
Just make two runs. On my 300MHz PII, the ratio is 4.6 (note that the ratios
include the timeouts, but it's enough).

Test2
-----
Set the number of lines filling the div to 7.
Reperform the test.
Note that the second run starts as fast as in test1 but slows down
as soon as the moving balls reach (vartically) the area where the non
moving balls are.

Test3
-----
Reset the number of lines to 15.
Set the total number of balls to 500.
Re-perform the test.
Ratio is still 4.5 but it is much slower.
Note thet the only thing that have changed is the number of non moving balls.

Test4
-----
Set the total number of balls to 10.
Reperform the test.

Now, we have no difference between the first and the second runs since
there are no non-moving balls left.


Tentative explanation: When we move the balls, it seems that we repaint all the
non moving balls (in the first run). When there are 500 balls, this means
repainting 490 times the same image at the same position.

I think this bug may be similar to bug #115247.

However, in this bug, we repaint the non moving balls even if the moving
balls are in an area that does not overlap the original area of the balls.

Comment 12

[Boris Zbarsky [:bzbarsky]]

Re: comment 11.  I just tried this in a Linux debug build with paint flashing
turned on (so I could actually see what's being painted).  We never paint the
stationary balls unless the non-stationary ones are actually overlapping them. 
This part _could_ be windows-only (but not very likely).  Someone on Win32 with
a debug build should test.

Furthermore,  I did not see the slowdown Marc reports in his test2.  The motion
was at the same speed throughout in the "filled div" test.  I _do_ agree that
the "empty div" is a red herring and the real issue is the moving balls
overlapping the stationary ones.

jprof profile coming up....

Comment 13

[Boris Zbarsky [:bzbarsky]]

Attachment: Jprof of a full run -- 500 balls, 10 moving, 100ms timeout, one line in div

Comment 14

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

Around 60% is spent in nsAbsoluteContainingBlock::ReflowAbsoluteFrame (no surprise).

Interestingly, almost half of that (about 25+% of the total) is spent in
nsHTMLReflowState::nsHTMLReflowState.  Of that, most is spent in
InitAbsoluteConstraints, most of that in in CalculateHypotheticalBox, and most
of that in FindLineFor() (FindLineFor alone is about 9% of the total time).

Close to 20% of the total was spent in
nsContainerFrame::SyncFrameViewAfterReflow, and around 15% of the total in
nsContainerFrame::PositionFrameView.  nsFrame::GetView() is called from
PositionFrameView and from ReflowAbsoluteFrame, and accounts for about 10% of
total hits.  I seem to remember from another bug that nsFrame::GetView isn't
very efficient.

5% are direct hits in nsViewManager::IsViewInserted() called indirectly from
SyncFrameViewAfterReload().

5% are in GetStyleData()

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

Comment 15

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

Taking bug - I've done some investigation, and I don't think Marc will be
working on it now...

Comment 16

[Markus Hübner]

Attachment: Testcase3

Updated URL for 3dball.gif

Comment 17

[Markus Hübner]

Attachment: Testcase 3

sorry - now in html format :)

Comment 18

[Robert O'Callahan (:roc) (email my personal email if necessary)]

taking as requested by Markus

Comment 19

[Garrett Smith]

Mozilla/5.0 (Macintosh; U; PPC Mac OS X Mach-O; en-US; rv:1.0.1) Gecko/20021220 
Chimera/0.6+
Mozilla/5.0 (Macintosh; U; PPC Mac OS X; en-US; rv:1.2.1) Gecko/20021130

DHTML in quirks mode.


Testcase 3 (attachment 107289 [details])
-------------------------------------------------------------------------------------------------------------

Settings

 Timeout(ms): 100
 Total number of balls:  200 Number of moving balls: 10 
_____________________________________________

Results

   Chimera)
   Total time to execute the run with the <div> empty 4097
   Total time to execute the run with the <div> filled 1588
   Ratio: 2.6
  
   Mozilla)
   Total time to execute the run with the <div> empty 2588
   Total time to execute the run with the <div> filled 2732 
   Ratio: 0.9
_____________________________________________
-------------------------------------------------------------------------------------------------------------

Chimera has a noticeable delay. Mozilla performs better on an empty div. 

Comment 20

[Samir Gehani]

adt: nsbeta1-

Comment 21

[Zibi Braniecki [:zbraniecki][:gandalf]]

I was able to reproduce it with latest Firefox 3 beta5 pre on WinXP, but only if I set up everything to maximum (500 balls, 100 moving, 15 lines), then the results were

Fx3trunk - 1156
IE7 - 437

other than that, the results were identical for IE7 and Fx3

Comment 22

[Guilherme Lima]

Maybe it's needed a more stressing test? Right now 500 balls, 100 moving balls and 15 lines give the same result on Nightly, IE9 and Chrome 24. All around 2000 (maybe Firefox is a bit slower) with empty and filled div.

Comment 23

[Zibi Braniecki [:zbraniecki][:gandalf]]

we have to think if we overall want to keep this bug open. The testcases use the API's that are discouraged for animations these days, but they still show slowdowns.

In Chrome 26 I was able to reproduce a stable 2-5ms in first testcase with 1ms timout and 100 "balls"

In Firefox nightly I got 5-30ms spread in the same scenario.

Comment 24

[Gregory Pappas [:gregp]]

Performance is the same in Firefox and Chrome now.