Bug 151899 – Web Inspector: Add JSContext Script Profiling

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

[Joseph Pecoraro]

* SUMMARY
Add JSContext Script Profiling.

Currently Web Inspector's profiling is tied to the Timeline domain, which is only available in the Web. This means that JSContext inspection doesn't get script profiling. We want to extract script profiling down into JavaScriptCore for a few reasons:

  - Give JSContext inspection Performance Profiling tools
    - eventually we can extract this entirely from TimelineAgent and just use/wrap the JSC version with Web information

  - Move to a more compartmentalized Timeline design to allow turning on/off different kinds of Timeline Profiling (Instruments)
    - Initial idea is new domains with startTracking/stopTracking Commands and trackingStart/trackingUpdate/trackingComplete Events
    - trackingUpdate = data to show UI while recording, trackingComplete = complete data to show when recording finishes
    - Ideas: Script Profiler/Sampling, Heap Size tracking, Energy tracking, CPU tracking, Memory tracking

[Radar WebKit Bug Importer]

<rdar://problem/23770597>

[Joseph Pecoraro]

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

This is a work in progress. Still to come:

  1. Tweaks to the UI handling for JSContext inspection script profiling
  2. Test the new ScriptProfiler domain (may not be possible until we profile more things from WebCore)
  3. Follow-up work to move Web Inspection (Timeline domain) to use ScriptProfiler, removing any profiling stuff from Timeline

[Joseph Pecoraro]

Created attachment 266691 [details]
[IMAGE] Work In Progress Image

This shows we get profiling data for a JSContext:

  1. API calls, like: -[JSContext evaluteScript:]
  2. Promise Reactions triggered by JavaScriptCore (Promise.then JSJob)

Not shown but working, we show GC events, which come to the frontend via the Heap domain.

[Joseph Pecoraro]

Created attachment 267061 [details]
[PATCH] Proposed Fix

[Joseph Pecoraro]

Created attachment 267062 [details]
[IMAGE] JSContext Script Profiling

[WebKit Commit Bot]

Attachment 267061 [details] did not pass style-queue:


ERROR: Source/JavaScriptCore/inspector/agents/InspectorScriptProfilerAgent.h:63:  Should be indented on a separate line, with the colon or comma first on that line.  [whitespace/indent] [4]
Total errors found: 1 in 50 files


If any of these errors are false positives, please file a bug against check-webkit-style.

[Joseph Pecoraro]

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

[Build Bot]

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

Attachment 267061 [details] did not pass mac-ews (mac):
Output: http://webkit-queues.webkit.org/results/539213

New failing tests:
inspector/script-profiler/event-type-API.html

[Build Bot]

Created attachment 267066 [details]
Archive of layout-test-results from ews100 for mac-yosemite

The attached test failures were seen while running run-webkit-tests on the mac-ews.
Bot: ews100  Port: mac-yosemite  Platform: Mac OS X 10.10.5

[Build Bot]

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

Attachment 267061 [details] did not pass mac-debug-ews (mac):
Output: http://webkit-queues.webkit.org/results/539212

New failing tests:
inspector/script-profiler/event-type-API.html

[Build Bot]

Created attachment 267067 [details]
Archive of layout-test-results from ews112 for mac-yosemite

The attached test failures were seen while running run-webkit-tests on the mac-debug-ews.
Bot: ews112  Port: mac-yosemite  Platform: Mac OS X 10.10.5

[Blaze Burg]

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

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

Preliminary review. Overall it's looking pretty good, with a few questions. Setting r- until it passes EWS.

> LayoutTests/inspector/script-profiler/event-type-API.html:40
> +    // FIXME: Debugger should not need to be enabled for ScriptProfiling to work.

Bugzilla number?

> LayoutTests/inspector/script-profiler/event-type-Microtask.html:31
> +                ProtocolTest.expectThat(Array.isArray(messageObject.params.profiles), "Should be profiles when complete.");

'Profiles should exist when complete'

> Source/JavaScriptCore/ChangeLog:8
> +        Extend JSC::Debugger to include a profiling client interface

Will hanging the profiling interface off of Debugger make it more difficult later to decouple profiling from debugging?

> Source/JavaScriptCore/ChangeLog:10
> +        entry and exit points. Add new profiledCall/Evalute/Construct

typo: 'Evaluate'

> Source/JavaScriptCore/ChangeLog:18
> +        the correct inspector interfaces.

Nit: grammar

> Source/JavaScriptCore/ChangeLog:23
> +        Handle new files.

Unnecessary comment.

> Source/JavaScriptCore/ChangeLog:37
> +        available, this will automatically tell inform it of entry/exit. Include a reason

Nit: grammar

> Source/JavaScriptCore/debugger/Debugger.h:46
> +class JS_EXPORT_PRIVATE DebuggerProfilingClient {

I would put it inside Debugger, so it's Debugger::ProfilingClient. Unless you plan to move it somewhere else anyway.

> Source/JavaScriptCore/debugger/DebuggerScriptProfiling.h:13
> + * THIS SOFTWARE IS PROVIDED BY APPLE INC. ``AS IS'' AND ANY

Wrong block.

> Source/JavaScriptCore/debugger/DebuggerScriptProfiling.h:85
> +    JSGlobalObject* m_globalObject;

Nit: initializer { nullptr }

> Source/JavaScriptCore/debugger/DebuggerScriptProfiling.h:86
> +    double m_startTime { NAN };

It might be less hassle to use Optional<double> here since NaN is hard to work with.

> Source/JavaScriptCore/inspector/agents/InspectorScriptProfilerAgent.cpp:60
> +void InspectorScriptProfilerAgent::startTracking(ErrorString&, const bool* profile)

'profile' is not a very good parameter name. shouldCollectProfile?

> Source/JavaScriptCore/inspector/agents/InspectorScriptProfilerAgent.cpp:124
> +        return Inspector::Protocol::ScriptProfiler::EventType::Other;

Maybe 'Unspecified' is better than Other. In WebCore cases, we know what it is, but it's just not specified explicitly. The frontend will soon figure out what it was by looking at surrounding events.

> Source/JavaScriptCore/runtime/CallData.h:62
> +enum ProfilingReason {

Why not an enum class?

> Source/WebInspectorUI/UserInterface/Views/ScriptTimelineView.js:221
> +        // FIXME: Provide a "During Recording" UI for TimelineViews.

Bugzilla number, please.

> Source/WebInspectorUI/UserInterface/Views/TimelineRecordTreeElement.js:82
> +            case WebInspector.ScriptTimelineRecord.EventType.MicrotaskDispatched:

Looking at this, it makes me think that we should emit MicrotaskDispatched as a separate event from ScriptEvaluated. The frontend can deduce that ScriptEvaluated after MicrotaskDispatched means it was run by the script. That also makes it possible to attach dispatch-related data to the MicrotaskDispatched record instead of the profiling data.

[Joseph Pecoraro]

(In reply to comment #12)
> > Source/JavaScriptCore/ChangeLog:8
> > +        Extend JSC::Debugger to include a profiling client interface
> 
> Will hanging the profiling interface off of Debugger make it more difficult
> later to decouple profiling from debugging?

Nope! We can just have a boolean on JSC::Debugger for whether or not debugging is enabled. Or, like ProfilingClient there could be another Client interface (instead of ScriptDebugServer subclasses). A boolean is good enough for now.
<https://webkit.org/b/152193> Web Inspector: Separate Debugger enable state from being attached

> > Source/JavaScriptCore/debugger/Debugger.h:46
> > +class JS_EXPORT_PRIVATE DebuggerProfilingClient {
> 
> I would put it inside Debugger, so it's Debugger::ProfilingClient. Unless
> you plan to move it somewhere else anyway.

Good idea.

> > Source/JavaScriptCore/inspector/agents/InspectorScriptProfilerAgent.cpp:60
> > +void InspectorScriptProfilerAgent::startTracking(ErrorString&, const bool* profile)
> 
> 'profile' is not a very good parameter name. shouldCollectProfile?

Okay. I think this will change soon to "samplingInterval".

> > Source/JavaScriptCore/inspector/agents/InspectorScriptProfilerAgent.cpp:124
> > +        return Inspector::Protocol::ScriptProfiler::EventType::Other;
> 
> Maybe 'Unspecified' is better than Other. In WebCore cases, we know what it
> is, but it's just not specified explicitly. The frontend will soon figure
> out what it was by looking at surrounding events.

"Unspecified" sounds like it might be API or Microtask. In this case we know it is something else. I'm sure there is something better than "Other" but I am bad at naming things.

> > Source/WebInspectorUI/UserInterface/Views/ScriptTimelineView.js:221
> > +        // FIXME: Provide a "During Recording" UI for TimelineViews.
> 
> Bugzilla number, please.

[Joseph Pecoraro]

Created attachment 267226 [details]
[PATCH] Proposed Fix

[WebKit Commit Bot]

Attachment 267226 [details] did not pass style-queue:


WARNING: Not running on native Windows.
ERROR: Source/JavaScriptCore/inspector/agents/InspectorScriptProfilerAgent.h:63:  Should be indented on a separate line, with the colon or comma first on that line.  [whitespace/indent] [4]
ERROR: Source/JavaScriptCore/runtime/CallData.h:63:  enum members should use InterCaps with an initial capital letter or initial 'k' for C-style enums.  [readability/enum_casing] [4]
Total errors found: 2 in 51 files


If any of these errors are false positives, please file a bug against check-webkit-style.

[Blaze Burg]

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

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

r=me with some naming suggestions and nits. I would like Saam to do a second review the JSC changes as well, and Matt to look at the Instrument/Timeline parts.

Please fix GTK/Win/EFL builds before landing.

> LayoutTests/inspector/script-profiler/event-type-API.html:18
> +            InspectorProtocol.eventHandler["ScriptProfiler.trackingStart"] = (messageObject) => {

(applies throughout) Please convert to InspectorProtocol.await{Command,Event} (for Promises) or InspectorProtocol.addEventListener (for callbacks). I am trying to make the eventHandler array an implementation detail instead of the public API.

> Source/JavaScriptCore/debugger/Debugger.cpp:242
> +void Debugger::didEvaluateScript(JSGlobalObject& globalObject, double startTime, ProfilingReason reason)

is it possible to use std::chrono here, at least for the sake of telling apart the units? Just by looking at the signature and code I'm not sure if this is milliseconds, monotonic or not, etc.

> Source/JavaScriptCore/debugger/Debugger.h:136
> +        virtual void didEvaluateScript(JSGlobalObject&, double, ProfilingReason) = 0;

second argument needs a name.

> Source/JavaScriptCore/debugger/Debugger.h:142
> +    double willEvaluateScript(JSGlobalObject&);

Same comments as above re: double.

> Source/JavaScriptCore/debugger/DebuggerScriptProfiling.h:87
> +    Optional<double> m_startTime;

Nice.

> Source/JavaScriptCore/runtime/CallData.cpp:57
> +    DebuggerScriptProfiling profile(exec->vmEntryGlobalObject(), reason);

Based on the usage, maybe it should be called ScriptProfilingScope.

> Source/WebCore/ChangeLog:27
> +        Correct types.

Nit: 'Disambiguate' since now it is ambiguous?

> Source/WebInspectorUI/UserInterface/Models/ScriptInstrument.js:40
> +            super.startInstrumentation();

What's the rule here? Do we always need to call the overridden method, or only when bailing?

> Source/WebInspectorUI/UserInterface/Views/ScriptTimelineView.js:221
> +        if (WebInspector.timelineManager.scriptProfilerIsTracking())

It seems conceivable that when WebCore support lands, we want to revisit this bailout for cases where we want records to be progressive. For example, we could start with minimal live data like CPU%, then later be filled in with full profiles.

[Joseph Pecoraro]

(In reply to comment #16)
> Comment on attachment 267226 [details]
> > Source/JavaScriptCore/debugger/Debugger.cpp:242
> > +void Debugger::didEvaluateScript(JSGlobalObject& globalObject, double startTime, ProfilingReason reason)
> 
> is it possible to use std::chrono here, at least for the sake of telling
> apart the units? Just by looking at the signature and code I'm not sure if
> this is milliseconds, monotonic or not, etc.

Until I have time to learn std::chromo some more I'm going to leave this as double.
Really this just comes from WTF::Stopwatch, so once that gets converted this can
easily follow suit.

> > Source/JavaScriptCore/runtime/CallData.cpp:57
> > +    DebuggerScriptProfiling profile(exec->vmEntryGlobalObject(), reason);
> 
> Based on the usage, maybe it should be called ScriptProfilingScope.

Great idea.

> > Source/WebInspectorUI/UserInterface/Models/ScriptInstrument.js:40
> > +            super.startInstrumentation();
> 
> What's the rule here? Do we always need to call the overridden method, or
> only when bailing?

Any new Instruments would implement this themselves. For Legacy instruments (Script, Layout, FPS) the base class does TimelineAgent.start/stop in a multi-instrument safe way.


> > Source/WebInspectorUI/UserInterface/Views/ScriptTimelineView.js:221
> > +        if (WebInspector.timelineManager.scriptProfilerIsTracking())
> 
> It seems conceivable that when WebCore support lands, we want to revisit
> this bailout for cases where we want records to be progressive. For example,
> we could start with minimal live data like CPU%, then later be filled in
> with full profiles.

This is only for the TimelineView (the DataGrid). The graph at the top updates during recording.

But yes, we have many changes in mind for the TimelineViews during recording. I wanted to cut down on any unnecessary work at the moment.

[Joseph Pecoraro]

Created attachment 267436 [details]
[PATCH] Proposed Fix - Addressed Comments

Checking other builds, and also this can get a look over from JSC folks.

[Joseph Pecoraro]

Created attachment 267438 [details]
[PATCH] Proposed Fix - Addressed Comments

[Joseph Pecoraro]

Created attachment 267448 [details]
[PATCH] Proposed Fix - Addressed Comments

Trying another patch.

[WebKit Commit Bot]

Attachment 267448 [details] did not pass style-queue:


WARNING: Not running on native Windows.
ERROR: Source/JavaScriptCore/inspector/agents/InspectorScriptProfilerAgent.h:63:  Should be indented on a separate line, with the colon or comma first on that line.  [whitespace/indent] [4]
ERROR: Source/JavaScriptCore/runtime/CallData.h:63:  enum members should use InterCaps with an initial capital letter or initial 'k' for C-style enums.  [readability/enum_casing] [4]
ERROR: Source/JavaScriptCore/runtime/Completion.cpp:29:  Alphabetical sorting problem.  [build/include_order] [4]
ERROR: Source/JavaScriptCore/runtime/ConstructData.cpp:29:  Alphabetical sorting problem.  [build/include_order] [4]
ERROR: Source/JavaScriptCore/runtime/CallData.cpp:29:  Alphabetical sorting problem.  [build/include_order] [4]
Total errors found: 5 in 51 files


If any of these errors are false positives, please file a bug against check-webkit-style.

[Saam Barati]

Comment on attachment 267448 [details]
[PATCH] Proposed Fix - Addressed Comments

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

> Source/JavaScriptCore/runtime/Completion.h:43
> +

nit: newline

[Joseph Pecoraro]

<http://trac.webkit.org/changeset/194242>