608495 - The IE test drive helicopter demo is glacially slow

Status: RESOLVED INCOMPLETE

(Core :: SVG, defect)

Description

[Boris Zbarsky [:bzbarsky]]

See bug 608072 comment 4.  There's some attr parsing there, and more stuff happenig in frame land.

Comment 1

[Robert Longson [:longsonr]]

These two lines in Demo.js

270 this.dx += this.width/this.numClouds;
271 this.smokeGroup.setAttributeNS(null,"transform",this.dx);

are a bug in the program that cause us to create a proxy. I'm guessing that line 271 needs to be something like this...

271 this.smokeGroup.setAttributeNS(null,"transform","translate(" + this.dx + ",0)"); 

I wonder how much fixing that affects performance? If it is significant then we can look to remove the proxy when it is no longer required. Could also see whether Microsoft will fix this bug in their program.

Comment 2

[Boris Zbarsky [:bzbarsky]]

I'm happy to test a fixed version....

Comment 3

[Robert Longson [:longsonr]]

bug 690486 fixes this. It's just landed on inbound.

Comment 4

[Robert Longson [:longsonr]]

Or more accurately bug 690486 fixes the comment 1 issue. The attr parsing should be fixed by bug 629200.

Comment 5

[Brian Birtles (:birtles)]

Bug 629200 doesn't apply here. For the helicopter demo the time spent inside nsGenericElement::SetAttrAndNotify is almost entirely in nsNodeUtils::AttributeChanged (and subsequently PresShell::AttributeChanged). i.e. there's no serialisation going on which is what bug 629200 fixes.

There is some time spent in nsGenericElement::SetAttr but it's minor (<2%) and it's mostly parsing / triggering reflow and so unrelated to bug 629200.

Comment 6

[Boris Zbarsky [:bzbarsky]]

Brian, where does AttributeChanged spend its time in this case?

Comment 7

[Brian Birtles (:birtles)]

(In reply to Boris Zbarsky (:bz) from comment #6)
> Brian, where does AttributeChanged spend its time in this case?

With an Win 7 build I did a few days ago I was seeing the following break-down in xperf:

nsGenericElement::SetAttrAndNotify                      14%
  nsNodeUtils::AttributeChanged                         14%
    PresShell::AttributeChanged                         13%
      nsSVGUtils::UpdateGraphic                         11%
        nsIFrame::InvalidateWithFlags                   7%
          nsIFrame::InvalidateInternal                  7%
          ...
        nsSVGOuterSVGFrame::UpdateAndInvalidateCoveredRegion  4%
          nsSVGPathGeometryFrame::UpdateCoveredRegion         3%
          nsSVGUtils::FindFilterInvalidation                  1%
          ...
        ...
      nsCSSFrameConstructor::AttributeChanged            1%
      ...

All percentages are absolute percentages of samples inside firefox.exe.

Re-doing the test with the most recent nightly the breakdown is slightly different, but still it's mostly invalidation.

There's a little bit of time spent in parsing transform lists (about 1.6%) but I'm not seeing any time spent in serialisation so bug 629200 isn't going to help here.

Comment 8

[Boris Zbarsky [:bzbarsky]]

Ah, yes.  So should this depend on display-list-based invalidation?

Comment 9

[Brian Birtles (:birtles)]

With Boris' help I've looked into this a bit more. I added some logging to nsSVGPathGeometryFrame to see if we ever call nsSVGUtils::UpdateGraphic more often than we get calls to nsSVGPathGeometryFrame::PaintSVG.

It seems like we sometimes make 2 calls to nsSVGUtils::UpdateGraphic between subsequent calls to PaintSVG. Once as a result of a call to nsSVGPathGeometryFrame::AttributeChanged and once as a result of a call to nsSVGPathGeometryFrame::NotifySVGChanged (called by nsSVGGFrame::AttributeChanged iterating over its children).

Occasionally we make up to 33 calls to UpdateGraphic per paint but generally we average about 1.25. One idea Boris suggested is to lazily update the graphic using a hashtable and thereby coalesce those calls.

Currently we're getting about 20fps.

The test calculates a "speed" using a formula something like:

 speed = fps * 5 / (maxdt/16)

Where maxdt is the maximum time between samples for the current second (calculated as new Date() - lastTime). This is to punish uneven framerates. It is reset every second.

The 16 is because the animation is updated using setInterval with an interval of 16ms.

I'm currently seeing a speed of about 30mph where maxdt is generally in the range of 50 or 60 but sometimes up to 400 or so. IE9 gives me ~1000mph.

(Interestingly there's a bug in setting the transform attribute for the smoke that uses the wrong syntax causing us to produce a console warning which has a very minor impact on our performance. It's not significant at this stage.)

Comment 10

[Boris Zbarsky [:bzbarsky]]

> IE9 gives me ~1000mph.

Given the formula above, that involves IE having an fps of about 200 or a maxdt on the order of 5ms or some combination thereof, right?  I mean... if the benchmark is using a 16ms timeout then maxdt ought to be at least 16 and fps ought to be about 60, for a speed of 300....

Comment 11

[Brian Birtles (:birtles)]

(In reply to Boris Zbarsky (:bz) from comment #10)
> Given the formula above, that involves IE having an fps of about 200 or a
> maxdt on the order of 5ms or some combination thereof, right?  I mean... if
> the benchmark is using a 16ms timeout then maxdt ought to be at least 16 and
> fps ought to be about 60, for a speed of 300....

Actually, the maxdt has a minimum value of 16. Anything less is scaled up to 16. So they have to be getting 200fps.

I double-checked. In "auto-play mode", which is what I was using, they use setInterval(autoPlay_drawFrame, 0).

Comment 12

[Brian Birtles (:birtles)]

In normal playing mode (where it is setInterval with 16ms) I get about 250mph.

Comment 13

[Jonathan Watt [:jwatt]]

The fix for bug 766429 has made a _huge_ difference here. For me the autoplay mode has gone from 2 mph to ~300 mph, so something like a 150x speedup.

Comment 14

[Mayank Bansal]

FWIW, on the latest nightly, i get ~ 34FPS with HWA on.
On the same hardware, on IE10 , i get 800-900 FPS 

Profile : http://people.mozilla.com/~bgirard/cleopatra/#report=614e613ecbd60eb2bf4afe5c21e406f5bf8d3bef

Comment 15

[Jonathan Watt [:jwatt]]

For me, bug 869611 sped up the IE Test Drive Helicopter demo from 15-20 "fps" to 30-35 "fps".

Comment 16

[Jonathan Watt [:jwatt]]

Massively regressed between Release 32 and current Nightly. Now unplayable. The only way to get FPS number is to click the "autoplay" link at the bottom of the page and wait about 30 seconds before it decides that the FPS is zero.

Comment 17

[Jonathan Watt [:jwatt]]

Regressed by bug 982338.

Comment 18

[Robert Longson [:longsonr]]

Seems OK on windows.

Comment 19

[Boris Zbarsky [:bzbarsky]]

I filed bug 1078109 on comment 16, since we'll want to remeasure once that's fixed.

Comment 20

[Robert Longson [:longsonr]]

The demo was really fast last time I tried it but it's gone now.