Bug 152727 – Web Inspector: Migrate Page Timeline recording to ScriptProfiler

• Component: Web Inspector
• Status: RESOLVED FIXED

[Joseph Pecoraro]

* SUMMARY
Migrate Page Timeline recording to ScriptProfiler.

* NOTES
- Use the ScriptProfiler domain in Page Timeline recordings.

[Radar WebKit Bug Importer]

<rdar://problem/24052220>

[Joseph Pecoraro]

Created attachment 268261 [details]
[PATCH] Work In Progress

This was a very rough work in progress that got things working with some debugging still left in to play with. The actual patch will likely be much smaller, but I wanted to get this up tonight so I didn't forget.

[Joseph Pecoraro]

Created attachment 268412 [details]
[PATCH] Proposed Fix

[Joseph Pecoraro]

Created attachment 268413 [details]
[IMAGE] After

This shows a Script & Events TimelineView after moving it to ScriptProfiler.

Note that Safari evaluates some scripts in the page via API, and those now show up with the "API Script Evaluation" look.

After this change the frontend continues to update the Graph / Overview views during recording, but does not update the TimelineView / DataGrid until recording stops. I'm putting off re-working that UI until a larger Timelines UI modification.

[Joseph Pecoraro]

Created attachment 268418 [details]
[PATCH] Proposed Fix

Adds a test for EventDispatch.

[Saam Barati]

Comment on attachment 268418 [details]
[PATCH] Proposed Fix

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

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:354
> +            var record;

maybe "let"?

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:400
> +            var record;

maybe "let"?

[Joseph Pecoraro]

Comment on attachment 268418 [details]
[PATCH] Proposed Fix

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

>> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:354
>> +            var record;
> 
> maybe "let"?

Unfortunately, this is (already) inside of a switch case. So it gets tricky, and just using var was stylistically simpler. I could go all the way to the top and do a `let record` once though. Anyone have style opinions?

[Blaze Burg]

Comment on attachment 268418 [details]
[PATCH] Proposed Fix

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

Looks pretty close to being ready. I will take a look at the record merging code when I have some more coffee in my brain.

> LayoutTests/inspector/script-profiler/event-type-Other.html:6
> +function triggerScriptEvalution() {

Nit: 'evaluation'

> Source/WebCore/ChangeLog:7
> +

Please add the "why do we want to do this?" rationale here, for people besides you and me.

> Source/WebCore/ChangeLog:29
> +        These were nearly all already classified for the Timeline, we added

Nit: grammar (Timeline, we added)

> Source/WebCore/ChangeLog:40
> +        TimelineAgent no longer needs to start/stop the Legacy Profiler

Wohoo!

> Source/WebCore/bindings/js/JSMutationCallback.cpp:93
>      InspectorInstrumentation::didCallFunction(cookie, context);

Now that this instrumentation doesn't have anything to do with profiling, maybe we could come up with a better name. didExecuteCallback? It seems to always be some sort of callback from native DOM code.

> Source/WebInspectorUI/ChangeLog:10
> +        New [S] image for API initiated script evaluates.

Nit: 'evaluations'

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:45
> +        this._hasWrappedScriptProfileRecords = WebInspector.debuggableType !== WebInspector.DebuggableType.JavaScript;

Seems awkward as an property, can't it just be a getter? Actually, it's only used in one place, so just inline it.

>>> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:354
>>> +            var record;
>> 
>> maybe "let"?
> 
> Unfortunately, this is (already) inside of a switch case. So it gets tricky, and just using var was stylistically simpler. I could go all the way to the top and do a `let record` once though. Anyone have style opinions?

Meh, let's not get carried away.

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:650
> +    _scriptProfilerTypeToScriptTimelineRecordType(type)

This could be a static method.

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:657
> +        case ScriptProfilerAgent.EventType.Other:

So, the frontend doesn't distinguish script evaluations from function callbacks? I thought it did.. or is it disambiguated based on context/parent record?

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:677
> +        if (type !== ScriptProfilerAgent.EventType.Other)

I would add a comment here to clarify what we do with EventType.Other, in case it isn't obvious locally.

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:683
> +        console.assert(!this._webScriptProfileRecordWrappers || this._scriptProfileRecords.length >= this._webScriptProfileRecordWrappers.length);

I don't like Wrappers in the name because they are actual profile records, not some other type of wrapper object. Maybe this._placeholderScriptProfileRecords? this._unmergedScriptProfileRecords? this._scriptProfileRecordsWithPendingPayloads?

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:710
> +        let recordContainsRecord = function(record1, record2) {

recordEnclosesRecord?

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:719
> +            // FIXME: Backend should just not send nested profilable things?

...what's the test case for this?

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:734
> +                // FIXME: Backend should better wrap each script execution.

...oh, I see. Yuck!

> Source/WebInspectorUI/UserInterface/Views/NavigationSidebarPanel.js:811
> +WebInspector.NavigationSidebarPanel.SuppressFilteringSymbol = Symbol("supress-filtering");

typo: 'suppress'

[Blaze Burg]

Comment on attachment 268418 [details]
[PATCH] Proposed Fix

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

r=me, but please post another version of the patch.

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:709
> +        let nextScriptProfilerRecord = nextRecord.bind(null, this._scriptProfileRecords);

My intuition would be to call these 'nextWebTimelineRecord' and 'nextSamplePayloadRecord', but it's also fine as-is once the names are memorized.

>> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:710
>> +        let recordContainsRecord = function(record1, record2) {
> 
> recordEnclosesRecord?

recordsHaveParentChildRelationship?

>> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:734
>> +                // FIXME: Backend should better wrap each script execution.
> 
> ...oh, I see. Yuck!

Please file a bug for this FIXME.

> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:757
> +        // NOTE: Skipping the remaining ScriptProfiler events to match the current UI for handling Timeline records.

What would these unassociated events correspond to? API records that happened to occur after the last Web Timeline Record? Please add a FIXME if its something we plan to fix.

[Joseph Pecoraro]

Comment on attachment 268418 [details]
[PATCH] Proposed Fix

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

>> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:650
>> +    _scriptProfilerTypeToScriptTimelineRecordType(type)
> 
> This could be a static method.

I never know when to make it static and when not to. Is there a good reason to go one way or the other? We do this in a lot of agents and its been kind of different each time.

>> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:657
>> +        case ScriptProfilerAgent.EventType.Other:
> 
> So, the frontend doesn't distinguish script evaluations from function callbacks? I thought it did.. or is it disambiguated based on context/parent record?

In Page inspection it happens based on the parent record. But only for "Other" evaluations.

The API / Microtask evaluations will always stand on their own.

>> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:719
>> +            // FIXME: Backend should just not send nested profilable things?
> 
> ...what's the test case for this?

<script>document.write("<script src="..."><\/script>");</script>

>>> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:734
>>> +                // FIXME: Backend should better wrap each script execution.
>> 
>> ...oh, I see. Yuck!
> 
> Please file a bug for this FIXME.

This case, I believe, is a Mutation Observer microtask firing at the end of script evaluation checkpoint, which happens before the Timeline completes the ScriptEvaluated record.

<script>
var observer = new MutationObserver(function(mutations) {
    sleepAndLog("MutationObserver callback");
}); 
var config = { attributes: true, childList: true, characterData: true };
observer.observe(document.body, config);
document.body.appendChild(document.createElement("span"));
</script>

>> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:757
>> +        // NOTE: Skipping the remaining ScriptProfiler events to match the current UI for handling Timeline records.
> 
> What would these unassociated events correspond to? API records that happened to occur after the last Web Timeline Record? Please add a FIXME if its something we plan to fix.

They would correspond to Web Timeline Records, but (currently) we drop the Web Timeline Records on the floor when the frontend can't keep up with ingesting them.

This is what happens when you record cnn.com, and the graphs get way behind the recording, and you manually stop the recording. The frontend receives all the records for the time between the lagging graphs and current time, but it drops them on the floor. Here we are matching that UI and dropping the ScriptProfiler events that would correspond to those Web Timeline Records and drops them on the floor. My goal is to eliminate this issue.

>> Source/WebInspectorUI/UserInterface/Views/NavigationSidebarPanel.js:811
>> +WebInspector.NavigationSidebarPanel.SuppressFilteringSymbol = Symbol("supress-filtering");
> 
> typo: 'suppress'

lol, how did I miss that, its on the left!

[Blaze Burg]

Comment on attachment 268418 [details]
[PATCH] Proposed Fix

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

> LayoutTests/inspector/script-profiler/event-type-Other-expected.txt:13
> +PASS: Event type should be Other.

Test, please ignore this comment.

[Blaze Burg]

Comment on attachment 268418 [details]
[PATCH] Proposed Fix

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

> LayoutTests/inspector/script-profiler/event-type-Other-expected.txt:14
> +ScriptProfiler.trackingUpdate

Another test, please ignore.

[Joseph Pecoraro]

Created attachment 268553 [details]
[PATCH] Proposed Fix

[Blaze Burg]

Comment on attachment 268553 [details]
[PATCH] Proposed Fix

r=me, delicious!

[WebKit Commit Bot]

Comment on attachment 268553 [details]
[PATCH] Proposed Fix

Clearing flags on attachment: 268553

Committed r194871: <http://trac.webkit.org/changeset/194871>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.

[Joseph Pecoraro]

*** Bug 151434 has been marked as a duplicate of this bug. ***