Bug 146168 – Web Inspector: Reduce rendering frames "Other" time by instrumenting compositing

• Status: RESOLVED
• Resolution: FIXED
• Component: Web Inspector

[Matt Baker]

* SUMMARY
Reduce rendering frames "Other" time by instrumenting compositing time.

Compositing begins when a scheduled layer flush occurs, at which point zero or more paint events (currently instrumented) may occur. Determining the point when compositing completes is more difficult, but as the layer flush is scheduled at the very end of the runloop we can assume that the end of the runloop coincides with completion of compositing.

* NOTE
Paint events that occur during compositing shouldn't count toward the total painting time for that runloop.

[Radar WebKit Bug Importer]

<rdar://problem/21470258>

[Matt Baker]

Created attachment 255256 [details]
[Patch] WIP

[Timothy Hatcher]

Comment on attachment 255256 [details]
[Patch] WIP

View in context: https://bugs.webkit.org/attachment.cgi?id=255256&action=review

Looks good to me.

> Source/WebInspectorUI/UserInterface/Models/RenderingFrameTimelineRecord.js:119
> +                // Paint events which occur during compositing must be subracted from the total painting time to
> +                // prevent the time from being counted twice.

Not sure I follow this. Can you explain more?

[Brian Burg]

Comment on attachment 255256 [details]
[Patch] WIP

View in context: https://bugs.webkit.org/attachment.cgi?id=255256&action=review

> Source/WebCore/inspector/InspectorTimelineAgent.cpp:746
> +    , m_didFlushLayers(false)

please initialize this in the class declaration.

> Source/WebCore/inspector/InspectorTimelineAgent.h:257
> +    bool m_didFlushLayers;

... here.

bool m_didFlushLayers { false };

> Source/WebCore/page/FrameView.cpp:1085
> +    InspectorInstrumentation::didFlushLayers(frame());

I tend to prefer more ObjC-like names these days, but that's just me. e.g.,

InspectorInstrumentation::didFlushLayersForFrame(Frame&)

The disambiguation is more useful when there's multiple important-looking parameters.

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:278
> +            console.log("Rendering Frame payload & children", recordPayload, children);

oops

> Source/WebInspectorUI/UserInterface/Models/RenderingFrameTimelineRecord.js:110
> +                // Layout events which were synchronously triggered from JavaScript must be subracted from the total

speling

> Source/WebInspectorUI/UserInterface/Models/RenderingFrameTimelineRecord.js:118
> +                // Paint events which occur during compositing must be subracted from the total painting time to

speling

> Source/WebInspectorUI/UserInterface/Models/RenderingFrameTimelineRecord.js:123
> +                    for (var compositeRecord of compositeRecords) {

How often does this code get called? It seems kinda scary to be doing O(n^2) summary like this, if it's used, say, in a requestAnimationFrame. Couldn't the compositing record durations be adjusted when unpacking the record tree payload?

[Timothy Hatcher]

<rdar://problem/21148110>

[Matt Baker]

Comment on attachment 255256 [details]
[Patch] WIP

View in context: https://bugs.webkit.org/attachment.cgi?id=255256&action=review

>> Source/WebInspectorUI/UserInterface/Models/RenderingFrameTimelineRecord.js:123
>> +                    for (var compositeRecord of compositeRecords) {
> 
> How often does this code get called? It seems kinda scary to be doing O(n^2) summary like this, if it's used, say, in a requestAnimationFrame. Couldn't the compositing record durations be adjusted when unpacking the record tree payload?

During unpacking we could flag Paint records that are children of a Composite. Alternatively we could add a parent property to TimelineRecord. Having this information after the event hierarchy has been unpacked might be useful elsewhere in the front end. I prefer the latter, but either way we still need to check all paint records for a given rendering frame, subtracting those that are flagged or are children of a Composite.

[Matt Baker]

Created attachment 255423 [details]
[Patch] Proposed Fix

[Simon Fraser (smfr)]

Comment on attachment 255423 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=255423&action=review

> Source/WebCore/ChangeLog:11
> +        compositing finishes, so currently we consider this to coincide with the end of the runloop.

I think this is wrong. I think we should use another observer, or some other API to know when the commit is done.

[Timothy Hatcher]

Comment on attachment 255423 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=255423&action=review

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:272
> +                record.__occurredDuringComposite = true;

This should just be a public property on the LayoutTimelineRecord.

> Source/WebInspectorUI/UserInterface/Models/RenderingFrameTimelineRecord.js:122
> +                    return currentValue.__occurredDuringComposite ? previousValue + currentValue.duration : previousValue;

... Since you use it in another file here, and that is fragile.

[Matt Baker]

Created attachment 255663 [details]
[Patch] Proposed Fix

[Simon Fraser (smfr)]

Comment on attachment 255663 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=255663&action=review

I don't see the RLO for when addCommitHandler: is not available.

> Source/WebCore/inspector/InspectorTimelineAgent.h:243
> +    int m_callStackDepth { 1 };

This used to be initialized to 0.

> Source/WebInspectorUI/UserInterface/Models/LayoutTimelineRecord.js:43
> +        this._duringComposite = duringComposite || false;

|| false?

> Source/WebKit2/WebProcess/WebPage/mac/RemoteLayerTreeDrawingArea.mm:367
> +    [CATransaction addCommitHandler:^{
> +        m_webPage.corePage()->inspectorController().didComposite(m_webPage.mainFrameView()->frame());
> +    } forPhase:kCATransactionPhasePostCommit];
> +

This needs OS guards, right?

> Source/WebKit2/WebProcess/WebPage/mac/TiledCoreAnimationDrawingArea.mm:395
> +        [CATransaction addCommitHandler:^{
> +            m_webPage.corePage()->inspectorController().didComposite(m_webPage.mainFrameView()->frame());
> +        } forPhase:kCATransactionPhasePostCommit];

Ditto.

[Matt Baker]

Comment on attachment 255663 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=255663&action=review

>> Source/WebInspectorUI/UserInterface/Models/LayoutTimelineRecord.js:43
>> +        this._duringComposite = duringComposite || false;
> 
> || false?

duringComposite is an optional parameter.

[Matt Baker]

(In reply to comment #11)
> I don't see the RLO for when addCommitHandler: is not available.
 
The frame end RLO uses an order of CoreAnimationCommit + 1 and will mark a pending composite record as complete.

[Matt Baker]

Created attachment 255668 [details]
[Patch] Proposed Fix

[Brian Burg]

Comment on attachment 255663 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=255663&action=review

>>> Source/WebInspectorUI/UserInterface/Models/LayoutTimelineRecord.js:43
>>> +        this._duringComposite = duringComposite || false;
>> 
>> || false?
> 
> duringComposite is an optional parameter.

another idiom that might be ok:

this._duringComposite = !!duringComposite;

[Matt Baker]

Comment on attachment 255663 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=255663&action=review

>>>> Source/WebInspectorUI/UserInterface/Models/LayoutTimelineRecord.js:43
>>>> +        this._duringComposite = duringComposite || false;
>>> 
>>> || false?
>> 
>> duringComposite is an optional parameter.
> 
> another idiom that might be ok:
> 
> this._duringComposite = !!duringComposite;

I think ORing with false is more widely used throughout the Inspector, but I prefer the double-not idiom: more concise and also more familiar to C/C++ programmers.

[Brian Burg]

Comment on attachment 255668 [details]
[Patch] Proposed Fix

r=me

This is looking nice. Great work!

[WebKit Commit Bot]

Comment on attachment 255668 [details]
[Patch] Proposed Fix

Clearing flags on attachment: 255668

Committed r186133: <http://trac.webkit.org/changeset/186133>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.

[Timothy Hatcher]

(In reply to comment #16)
> Comment on attachment 255663 [details]
> [Patch] Proposed Fix
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=255663&action=review
> 
> >>>> Source/WebInspectorUI/UserInterface/Models/LayoutTimelineRecord.js:43
> >>>> +        this._duringComposite = duringComposite || false;
> >>> 
> >>> || false?
> >> 
> >> duringComposite is an optional parameter.
> > 
> > another idiom that might be ok:
> > 
> > this._duringComposite = !!duringComposite;
> 
> I think ORing with false is more widely used throughout the Inspector, but I
> prefer the double-not idiom: more concise and also more familiar to C/C++
> programmers.

I tend to prefer double-not when it is inline with other things or a return. I still use or-false when dealing with optional parameters, since it is clear what the default is.

[Matt Baker]

Comment on attachment 255663 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=255663&action=review

>>>>>> Source/WebInspectorUI/UserInterface/Models/LayoutTimelineRecord.js:43
>>>>>> +        this._duringComposite = duringComposite || false;
>>>>> 
>>>>> || false?
>>>> 
>>>> duringComposite is an optional parameter.
>>> 
>>> another idiom that might be ok:
>>> 
>>> this._duringComposite = !!duringComposite;
>> 
>> I think ORing with false is more widely used throughout the Inspector, but I prefer the double-not idiom: more concise and also more familiar to C/C++ programmers.
> 
> I tend to prefer double-not when it is inline with other things or a return. I still use or-false when dealing with optional parameters, since it is clear what the default is.

Good point.