Bug 168415

Summary: [Resource Timing] El Capitan NetworkLoadTiming values are sometimes jumbled
Product: WebKit Reporter: Joseph Pecoraro <joepeck>
Component: WebCore Misc.Assignee: Joseph Pecoraro <joepeck>
Status: RESOLVED WONTFIX    
Severity: Normal CC: achristensen, ap, beidson, joepeck, mcatanzaro, webkit-bug-importer, youennf
Priority: P2 Keywords: InRadar
Version: WebKit Nightly Build   
Hardware: Unspecified   
OS: Unspecified   
Bug Depends on: 175674    
Bug Blocks:    

Description Joseph Pecoraro 2017-02-15 23:12:27 PST
[Resource Timing] El Capitan NetworkLoadTiming values are sometimes jumbled

See discussion on: bug 168086

I'm not exactly sure how to interpret the numbers. They are not as consistently numbered as they are on Sierra.

----

    $ sw_vers
    ProductName:	Mac OS X
    ProductVersion:	10.11.6
    BuildVersion:	15G31

    --- stderr from test ---

    2017-02-15 21:42:30.349 com.apple.WebKit.Networking.Development[41618:151126] >>> TIMING DATA: {
        "_kCFNTimingDataConnectEnd" = "508916550.347444";
        "_kCFNTimingDataConnectStart" = "508916550.347444";
        "_kCFNTimingDataConnectionReused" = 1;
        "_kCFNTimingDataDomainLookupEnd" = "508916550.346444";
        "_kCFNTimingDataDomainLookupStart" = "508916550.346444";
        "_kCFNTimingDataFetchStart" = "508916550.328835";
        "_kCFNTimingDataRedirectCount" = 3;
        "_kCFNTimingDataRedirectCountW3C" = 0;
        "_kCFNTimingDataRedirectEnd" = 0;
        "_kCFNTimingDataRedirectStart" = 0;
        "_kCFNTimingDataRequestStart" = "508916550.330722";
        "_kCFNTimingDataResponseEnd" = "508916550.349124";
        "_kCFNTimingDataResponseStart" = "508916550.331586";
        "_kCFNTimingDataSecureConnectionStart" = 0;
        "_kCFNTimingDataTimingDataInit" = "508916550.346192";
    }

Note in this example the ordered by timestamps we get:

    FetchStart:         508916550.328835
    RequestStart:       508916550.330722
    ResponseStart:      508916550.331586
    TimingDataInit:     508916550.346192
    DomainLookupStart:  508916550.346444
    DomainLookupEnd:    508916550.346444
    ConnectStart:       508916550.347444
    ConnectEnd:         508916550.347444
    ResponseEnd:        508916550.349124

This is whacky. For starters, TimingDataInit/FetchStart should be the earliest value that all other values are measured relative to. But here it isn't even the earliest value.

A different entry looks like:

    TimingDataInit:     508916550.058271
    DomainLookupEnd:    508916550.058545
    DomainLookupStart:  508916550.058545
    FetchStart:         508916550.057944
    ConnectEnd:         508916550.059545
    ConnectStart:       508916550.059545
    RequestStart:       508916550.059958
    ResponseStart:      508916550.060892
    ResponseEnd:        508916550.061163

It is suspicious that _kCFNTimingDataConnectionReused is reused. Maybe in that case we should ignore DNS/Connect numbers.
Comment 1 Radar WebKit Bug Importer 2017-02-15 23:13:05 PST
<rdar://problem/30551923>
Comment 2 Michael Catanzaro 2017-08-18 08:48:54 PDT
Reopening, sorry for closing it. The tests marked against this bug are passing for GTK+ now, see bug #175674. But I don't know about other platforms. It's worth checking if this is still a problem on El Capitan.
Comment 3 Alex Christensen 2017-08-18 11:03:38 PDT
It's likely this is something that changed in CFNetwork between El Capitan and Sierra, and won't be fixed in WebKit anyways.
Comment 4 Joseph Pecoraro 2017-08-18 13:06:33 PDT
(In reply to Alex Christensen from comment #3)
> It's likely this is something that changed in CFNetwork between El Capitan
> and Sierra, and won't be fixed in WebKit anyways.

Correct. The values from CFNetwork were jumbled. Ultimately that got addressed in Sierra when CFNetwork introduced NSURLSessionTaskTransactionMetrics and improved and corrected handling of all the loading metrics, very much in-line with the W3C Resource Timing data.

Since that data comes from a component underneath WebKit I think its unlikely to get addressed for an older OS. As a result, El Capitan won't have ResourceTiming enabled but newer OSes will.