25406 - Bad timer output on above URL

Status: VERIFIED FIXED

(Core :: Layout, defect, P3)

Description

[Nisheeth Ranjan]

The QA scripts report negative numbers for the above URL.  Here's the timing 
output for this page:

*** Timing layout processes on url: 'http://www.xoom.com/', webshell: 015E2008
Content creation time (this=00650100): Real time 0:0:0, CP time 0.063
Reflow time (this=015DB5B0): Real time 0:0:0, CP time 0.250
Frame construction plus style resolution time (this=015DB5B0): Real time 0:0:0, 
CP time 0.188
Style resolution time (this=015DB5B0): Real time 0:0:0, CP time 0.234
Parse Time (this=015E0BC8): Real time 0:0:0, CP time 0.109
DTD Time: Real time 0:0:0, CP time 0.266
Tokenize Time: Real time 0:0:0, CP time 0.031
Total (Layout + Page Load) Time (webshell=015E2008): Real time 0:0:2, CP time 
1.547
WEBSHELL- = 0
Going to destroy the event queue

For some reason the style resolution time is more than the sum of the frame 
creation and style resolution time.  That's why we end up with negative numbers.  
Filing this bug against myself to explore this further.

Comment 1

[Nisheeth Ranjan]

Adding ekrock to the cc list and setting milestone to M14...

Comment 2

[Nisheeth Ranjan]

Attachment: The debug output from the timers.

Comment 3

[Nisheeth Ranjan]

Here's the problem in a nutshell.  Some code changes have happened since I put 
in the timers that cause style resolution to happen in places outside of frame 
creation.  So, the (frame creation + style resolution) number ends up becoming 
less than the style resolution number.

Comment 4

[Nisheeth Ranjan]

The GFX scrollbar frame is calling SetAttribute on the XUL content object.  Each 
of these calls result in an attribute changed notification to the document which 
passes it on to the pres shell which passes it to the frame constructor.  The 
frame constructor calls ResolveStyleFor() a bunch of times to resolve the style 
contexts for frames affected by the attribute change.

CCing Eric and Troy for input...

Eric, will your changes to coalesce reflows in the GFX scroll frame change this 
behavior?  

Comment 5

[troy]

Why are the frames setting attributes on the content object? That's not supposed 
to happen. If you're doing it so you can realize style changes, then you should 
be using a pseudo-class instead

Comment 6

[leger]

Moving [PERF] to keyword field.

Comment 7

[Nisheeth Ranjan]

Marc, I'm re-assigning this bug to you as you are the new owner of layout 
timers.  Kevin mentioned in yesterday's meeting that the SetAttribute() call by 
the gfx scroll frame is also causing other problems and that he will work 
towards fixing it.  So, maybe this bug will just go away once Kevin checks in 
his changes.

Adding Kevin and myself to the cc list.

Comment 8

[Marc Attinasi]

Kevin says he is not going to change the GfxScrollFrame behaviour, so his change 
will not fix this. To be safe I am thinking that the best approach is to assume 
that style resolution may occur outside of frame creation and to take measures 
to ensure that the perf data is not munged by it. To that end I would like to 
make it so that style resolution timing metrics are only accumulated when inside 
the context of frame creation. This is easily handled by putting the style 
system into a 'mode' at the start of frame creation, and taking it out of that 
'mode' at the end of Frame Creation. If we are not in the mode then style timers 
are not updated. That should fix this problem and insulate us from any other 
cases where style resolution occurs outside of frame construction. 

NOTE: the PresShell already manages the Style System timers in BeginLoad and 
EndLoad via the nsITimeRecorder interface implemented by the StyleSet. The mode 
can be managed via this interface (new methods).

Comment 9

[Nisheeth Ranjan]

Yes, I think this approach makes a lot of sense.  Go for it...

Comment 10

[Marc Attinasi]

Fixed and tested. r=nisheeth,pierre,troy

Comment 11

[Chris Petersen]

Fixed in the Feb 17 build.