Bug 160095 - Web Inspector: Frontend should have access to Resource Timing information
Summary: Web Inspector: Frontend should have access to Resource Timing information
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: Web Inspector (show other bugs)
Version: WebKit Nightly Build
Hardware: All All
: P2 Normal
Assignee: Nobody
URL:
Keywords: InRadar
Depends on:
Blocks: 160062
  Show dependency treegraph
 
Reported: 2016-07-22 13:18 PDT by Johan K. Jensen
Modified: 2016-08-26 17:32 PDT (History)
19 users (show)

See Also:


Attachments
WIP Patch - Timing info (28.57 KB, patch)
2016-07-22 13:45 PDT, Johan K. Jensen
no flags Details | Formatted Diff | Diff
Patch (18.35 KB, patch)
2016-08-25 17:42 PDT, Johan K. Jensen
no flags Details | Formatted Diff | Diff
Patch (15.41 KB, patch)
2016-08-26 11:31 PDT, Johan K. Jensen
no flags Details | Formatted Diff | Diff
Patch (15.21 KB, patch)
2016-08-26 13:47 PDT, Johan K. Jensen
no flags Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Johan K. Jensen 2016-07-22 13:18:19 PDT
The frontend needs access to a resource’s load timing information to show data or any visualizations.
Comment 1 Radar WebKit Bug Importer 2016-07-22 13:18:42 PDT
<rdar://problem/27499970>
Comment 2 Johan K. Jensen 2016-07-22 13:45:46 PDT
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.
Comment 3 Joseph Pecoraro 2016-07-27 14:54:14 PDT
Would be good to get some eyes on this from networking folks. This should get us closer to having reasonable Resource Timing data.
Comment 4 Joseph Pecoraro 2016-07-27 14:58:01 PDT
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.
Comment 5 Alex Christensen 2016-07-28 13:11:01 PDT
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.
Comment 6 BJ Burg 2016-07-29 11:07:03 PDT
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'
Comment 7 Alex Christensen 2016-08-10 11:22:21 PDT
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.
Comment 8 Alex Christensen 2016-08-10 11:24:23 PDT
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.
Comment 9 Alex Christensen 2016-08-10 11:27:06 PDT
DocumentLoadTiming::markRedirectStart is never used :(
It should be
Comment 10 Johan K. Jensen 2016-08-25 17:42:47 PDT
Created attachment 287053 [details]
Patch
Comment 11 Alex Christensen 2016-08-25 18:38:24 PDT
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& ?
Comment 12 Joseph Pecoraro 2016-08-25 19:12:09 PDT
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.
Comment 13 Johan K. Jensen 2016-08-26 11:31:26 PDT
Created attachment 287127 [details]
Patch
Comment 14 Johan K. Jensen 2016-08-26 13:47:36 PDT
Created attachment 287140 [details]
Patch
Comment 15 Johan K. Jensen 2016-08-26 14:40:50 PDT
(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.
Comment 16 WebKit Commit Bot 2016-08-26 17:31:50 PDT
Comment on attachment 287140 [details]
Patch

Clearing flags on attachment: 287140

Committed r205062: <http://trac.webkit.org/changeset/205062>
Comment 17 WebKit Commit Bot 2016-08-26 17:32:00 PDT
All reviewed patches have been landed.  Closing bug.