Bug 146168

Summary: Web Inspector: Reduce rendering frames "Other" time by instrumenting compositing
Product: WebKit Reporter: Matt Baker <mattbaker>
Component: Web InspectorAssignee: Matt Baker <mattbaker>
Status: RESOLVED FIXED    
Severity: Normal CC: agomez, burg, commit-queue, graouts, joepeck, jonowells, mattbaker, nvasilyev, simon.fraser, timothy, webkit-bug-importer
Priority: P2 Keywords: InRadar
Version: 528+ (Nightly build)   
Hardware: All   
OS: All   
Attachments:
Description Flags
[Patch] WIP
none
[Patch] Proposed Fix
none
[Patch] Proposed Fix
none
[Patch] Proposed Fix none

Description Matt Baker 2015-06-19 16:25:25 PDT
* 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.
Comment 1 Radar WebKit Bug Importer 2015-06-19 16:26:14 PDT
<rdar://problem/21470258>
Comment 2 Matt Baker 2015-06-19 17:45:50 PDT
Created attachment 255256 [details]
[Patch] WIP
Comment 3 Timothy Hatcher 2015-06-22 09:50:31 PDT
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?
Comment 4 Brian Burg 2015-06-22 10:00:36 PDT
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?
Comment 5 Timothy Hatcher 2015-06-22 11:29:22 PDT
<rdar://problem/21148110>
Comment 6 Matt Baker 2015-06-22 12:32:15 PDT
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.
Comment 7 Matt Baker 2015-06-23 12:57:09 PDT
Created attachment 255423 [details]
[Patch] Proposed Fix
Comment 8 Simon Fraser (smfr) 2015-06-23 14:17:03 PDT
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.
Comment 9 Timothy Hatcher 2015-06-23 14:18:28 PDT
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.
Comment 10 Matt Baker 2015-06-26 14:05:24 PDT
Created attachment 255663 [details]
[Patch] Proposed Fix
Comment 11 Simon Fraser (smfr) 2015-06-26 14:12:59 PDT
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.
Comment 12 Matt Baker 2015-06-26 14:44:13 PDT
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.
Comment 13 Matt Baker 2015-06-26 14:49:30 PDT
(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.
Comment 14 Matt Baker 2015-06-26 14:52:23 PDT
Created attachment 255668 [details]
[Patch] Proposed Fix
Comment 15 Brian Burg 2015-06-29 10:32:19 PDT
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;
Comment 16 Matt Baker 2015-06-30 13:09:09 PDT
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.
Comment 17 Brian Burg 2015-06-30 13:58:33 PDT
Comment on attachment 255668 [details]
[Patch] Proposed Fix

r=me

This is looking nice. Great work!
Comment 18 WebKit Commit Bot 2015-06-30 14:46:51 PDT
Comment on attachment 255668 [details]
[Patch] Proposed Fix

Clearing flags on attachment: 255668

Committed r186133: <http://trac.webkit.org/changeset/186133>
Comment 19 WebKit Commit Bot 2015-06-30 14:46:55 PDT
All reviewed patches have been landed.  Closing bug.
Comment 20 Timothy Hatcher 2015-06-30 15:08:53 PDT
(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.
Comment 21 Matt Baker 2015-06-30 16:41:32 PDT
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.