Bug 160095 – Web Inspector: Frontend should have access to Resource Timing information

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

[Johan K. Jensen]

The frontend needs access to a resource’s load timing information to show data or any visualizations.

[Radar WebKit Bug Importer]

<rdar://problem/27499970>

[Johan K. Jensen]

Created attachment 284369 [details]
WIP Patch - Timing info

This patch will get timing information for a resource and add it as a property on the resource. End time is currently unused, and should probably be set from a did-finish method.

[Joseph Pecoraro]

Would be good to get some eyes on this from networking folks. This should get us closer to having reasonable Resource Timing data.

[Joseph Pecoraro]

Comment on attachment 284369 [details]
WIP Patch - Timing info

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

Inspector parts and test look good to me. I'd like to see another patch addressing the comments, and then get some kind of nod from reviewers more experienced with networking. So r- while waiting for an updated patch.

> Source/WebCore/loader/ResourceLoader.cpp:353
> +    m_resourceStartTime = monotonicallyIncreasingTime();

Seems this could be moved up a bit. There are two failure reasons above (content extensions, null request) that we may want to include in resource timing data.

Further, ResourceLoader::init, seems like it might be best, given that also happens before other internal cancels, or even applicationCache checks (which are more timestamps we would eventually want to add for resource timing).

> Source/WebCore/loader/ResourceLoader.cpp:464
> +    m_resourceEndTime = monotonicallyIncreasingTime();

Again, there are two failures above that could bail before setting this end time. It might be better to move this up.

> Source/WebCore/loader/ResourceLoader.h:232
> +    double m_resourceStartTime;
> +    double m_resourceEndTime;

You should initialize these to some reasonable value. Such as 0.

    double m_resourceStartTime { 0 };

Currently, because they are not initialized in the constructor, they are "uninitialized" and hold random values until assigned.

> Source/WebCore/platform/network/ResourceLoadTiming.h:97
>      // These are millisecond deltas from the navigation start.

This comment is wrong. They are not from navigation start, they are from the resource's start time.

> Source/WebInspectorUI/UserInterface/Models/Resource.js:62
> +        this._timing = timing || {};

Same comment here as below.

> Source/WebInspectorUI/UserInterface/Models/Resource.js:476
> +        this._timing = timing || {};

We actually may want to be careful here. We were sending this timing data in the past (iOS 7-9 backends), but it was wrong. So we probably want to do something like this:

    this._timing = timing || {};

    // COMPATIBILITY (iOS 10): Resource Timing data was incomplete and incorrect. Do not use it.
    // iOS 7 sent a requestTime and iOS 8-9.3 sent a navigationStart time.
    if (typeof this._timing.requestTime === "number" || typeof this._timing.navigationStart === "number")
        this._timing = {};

Or, because it was incomplete/inaccurate we might even want to just remove it from legacy backend protocols:

    Source/WebInspectorUI/Versions/Inspector-iOS-7.0.json
    Source/WebInspectorUI/Versions/Inspector-iOS-8.0.json
    Source/WebInspectorUI/Versions/Inspector-iOS-9.0.json
    Source/WebInspectorUI/Versions/Inspector-iOS-9.3.json

Either way, we want to protect against incorrect backend data.

[Alex Christensen]

Comment on attachment 284369 [details]
WIP Patch - Timing info

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

Instead of doing this, I think we should finish implementing the resource timing api and use that data in the inspector instead of collecting data just for the inspector.  This would also require collecting new timing points, so it would be conceptually similar.

> Source/WebCore/inspector/InspectorNetworkAgent.cpp:187
> +Ref<Inspector::Protocol::Network::ResourceTiming> InspectorNetworkAgent::buildObjectForTiming(const ResourceLoadTiming& timing, ResourceLoader* resourceLoader)

This should be a ResourceLoader&

> Source/WebCore/platform/network/ResourceLoadTiming.h:98
> -    int secureConnectionStart;
> +    double domainLookupStart;

This is an unrelated change that should be in a different patch.  It changes the resolution of the navigation timing api.

[Blaze Burg]

Comment on attachment 284369 [details]
WIP Patch - Timing info

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

> Source/WTF/wtf/Stopwatch.h:85
> +inline double Stopwatch::elapsedTimeForMonotonicTime(double monotonicTime)

I would prefer 'elapsedTimeSinceMonotonicTime'

[Alex Christensen]

Comment on attachment 284369 [details]
WIP Patch - Timing info

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

> Source/WebCore/loader/ResourceLoader.h:144
> +    double resourceStartTime() { return m_resourceStartTime; }
> +    double resourceEndTime() { return m_resourceEndTime; }

We will need to keep track of redirect times, too.  Instead of having two doubles, make DocumentLoadTiming not main-resource-load-specific and use that.

[Alex Christensen]

Comment on attachment 284369 [details]
WIP Patch - Timing info

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

>> Source/WebCore/loader/ResourceLoader.cpp:353
>> +    m_resourceStartTime = monotonicallyIncreasingTime();
> 
> Seems this could be moved up a bit. There are two failure reasons above (content extensions, null request) that we may want to include in resource timing data.
> 
> Further, ResourceLoader::init, seems like it might be best, given that also happens before other internal cancels, or even applicationCache checks (which are more timestamps we would eventually want to add for resource timing).

Yep, ResourceLoader::init is the place to mark the start time.  This is also used for redirects.
We also want to keep track of redirect times for the ResourceTiming API, and probably also for the web inspector.

[Alex Christensen]

DocumentLoadTiming::markRedirectStart is never used :(
It should be

[Johan K. Jensen]

Created attachment 287053 [details]
Patch

[Alex Christensen]

Comment on attachment 287053 [details]
Patch

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

> Source/WebCore/inspector/InspectorNetworkAgent.cpp:190
> +    double startTimeInInspector = m_environment.executionStopwatch()->elapsedTimeSinceMonotonicTime(monotonicTime);

Why does executionStopwatch() return a Ref<Stopwatch> instead of a Stopwatch& ?

[Joseph Pecoraro]

Comment on attachment 287053 [details]
Patch

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

r- to see another patch without the WebInspectorUI changes.

> Source/WebInspectorUI/ChangeLog:11
> +        * UserInterface/Controllers/FrameResourceManager.js:
> +        (WebInspector.FrameResourceManager.prototype.resourceRequestWasServedFromMemoryCache):
> +        (WebInspector.FrameResourceManager.prototype.resourceRequestDidReceiveResponse):
> +        Push timing data to the Resource.

This looks like it should be done as a separate patch. updateResource doesn't do anything with this parameter yet.

When we do this, we will want to include a test for it.

>> Source/WebCore/inspector/InspectorNetworkAgent.cpp:190
>> +    double startTimeInInspector = m_environment.executionStopwatch()->elapsedTimeSinceMonotonicTime(monotonicTime);
> 
> Why does executionStopwatch() return a Ref<Stopwatch> instead of a Stopwatch& ?

No reason, we should change it to return a Stopwatch&.

> Source/WebCore/inspector/InspectorNetworkAgent.cpp:399
> +    double elapsedFinishTime = timestamp();
> +    if (finishTime)
> +        elapsedFinishTime = m_environment.executionStopwatch()->elapsedTimeSinceMonotonicTime(finishTime);

Lets use s ternary to avoid potentially always calling timestamp():

    double elapsedFinishTime = finishTime ? m_environment.executionStopwatch()->elapsedTimeSinceMonotonicTime(finishTime) : timestamp();

> Source/WebCore/inspector/InspectorNetworkAgent.h:54
> +class NetworkLoadTiming;

Nit: Should be sorted.

[Johan K. Jensen]

Created attachment 287127 [details]
Patch

[Johan K. Jensen]

Created attachment 287140 [details]
Patch

[Johan K. Jensen]

(In reply to comment #11)
> Why does executionStopwatch() return a Ref<Stopwatch> instead of a
> Stopwatch& ?

Changing the Ref<StopWatch> to a StopWatch& involves quite a few changes. The changes even leaks into the JavaScriptCore/runtime/SamplingProfiler which in some cases takes a StopWatch::create and at other times the executionStopWatch().
This change seems orthogonal to the original issue, it would become the majority of this patch and it should probably be changed in another patch.

[WebKit Commit Bot]

Comment on attachment 287140 [details]
Patch

Clearing flags on attachment: 287140

Committed r205062: <http://trac.webkit.org/changeset/205062>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.