Support Resource Timing in Workers - PerformanceResourceTiming class should be available. - Performance.setResourceTimingBufferSize, etc should be available. - PerformanceObserver should be available. - Timeline should include "resource" entryTypes for resources requested through the Worker (importScript, XHR, Fetch, etc)
<rdar://problem/30430117>
Tests not-yet-experimental runtime-enabled-features are a bit of a kerfuffle. For these cases we should use a <!-- Test Option --> to enable the feature before the page loads. We should not use Internals methods to enable the feature after the page has loaded. So I think I'll tackle this separately while I continue to work on this patch. However my hope is that soon we will be able to make this an experimental feature and we can drop this complexity in Tests.
Created attachment 301580 [details] [PATCH] Proposed Fix
Created attachment 301581 [details] [PATCH] For Bots (Since its taking longer then expected for other blocking patches to get reviewed)
Attachment 301580 [details] did not pass style-queue: ERROR: Source/WebCore/loader/DocumentThreadableLoader.cpp:52: "ResourceTiming.h" already included at Source/WebCore/loader/DocumentThreadableLoader.cpp:51 [build/include] [4] Total errors found: 1 in 92 files If any of these errors are false positives, please file a bug against check-webkit-style.
Attachment 301581 [details] did not pass style-queue: ERROR: Source/WebCore/loader/DocumentThreadableLoader.cpp:52: "ResourceTiming.h" already included at Source/WebCore/loader/DocumentThreadableLoader.cpp:51 [build/include] [4] Total errors found: 1 in 103 files If any of these errors are false positives, please file a bug against check-webkit-style.
Created attachment 301582 [details] [PATCH] For Bots
Comment on attachment 301582 [details] [PATCH] For Bots Attachment 301582 [details] did not pass mac-ews (mac): Output: http://webkit-queues.webkit.org/results/3120010 New failing tests: imported/w3c/web-platform-tests/resource-timing/rt-resource-errors.html js/dom/global-constructors-attributes-dedicated-worker.html imported/w3c/web-platform-tests/resource-timing/rt-cors.html
Created attachment 301583 [details] Archive of layout-test-results from ews102 for mac-elcapitan The attached test failures were seen while running run-webkit-tests on the mac-ews. Bot: ews102 Port: mac-elcapitan Platform: Mac OS X 10.11.6
Comment on attachment 301582 [details] [PATCH] For Bots Attachment 301582 [details] did not pass mac-wk2-ews (mac-wk2): Output: http://webkit-queues.webkit.org/results/3120017 New failing tests: imported/w3c/web-platform-tests/resource-timing/rt-resource-errors.html js/dom/global-constructors-attributes-dedicated-worker.html imported/w3c/web-platform-tests/resource-timing/rt-cors.html
Created attachment 301584 [details] Archive of layout-test-results from ews105 for mac-elcapitan-wk2 The attached test failures were seen while running run-webkit-tests on the mac-wk2-ews. Bot: ews105 Port: mac-elcapitan-wk2 Platform: Mac OS X 10.11.6
Comment on attachment 301582 [details] [PATCH] For Bots Attachment 301582 [details] did not pass ios-sim-ews (ios-simulator-wk2): Output: http://webkit-queues.webkit.org/results/3120026 New failing tests: imported/w3c/web-platform-tests/resource-timing/rt-resource-errors.html imported/w3c/web-platform-tests/resource-timing/rt-shared-resource-in-frames.html js/dom/global-constructors-attributes-dedicated-worker.html
Created attachment 301585 [details] Archive of layout-test-results from ews121 for ios-simulator-wk2 The attached test failures were seen while running run-webkit-tests on the ios-sim-ews. Bot: ews121 Port: ios-simulator-wk2 Platform: Mac OS X 10.11.6
Comment on attachment 301582 [details] [PATCH] For Bots Attachment 301582 [details] did not pass mac-debug-ews (mac): Output: http://webkit-queues.webkit.org/results/3120023 New failing tests: imported/w3c/web-platform-tests/resource-timing/rt-resource-errors.html js/dom/global-constructors-attributes-dedicated-worker.html imported/w3c/web-platform-tests/resource-timing/rt-cors.html
Created attachment 301586 [details] Archive of layout-test-results from ews112 for mac-elcapitan The attached test failures were seen while running run-webkit-tests on the mac-debug-ews. Bot: ews112 Port: mac-elcapitan Platform: Mac OS X 10.11.6
Good news is that everything worked! Bad news is that random URLs used to ensure non-cached resources cause an issue in at least one test. This is still reviewable while I clean up the tests a bit.
Created attachment 301596 [details] [PATCH] Proposed Fix
Comment on attachment 301596 [details] [PATCH] Proposed Fix Attachment 301596 [details] did not pass mac-ews (mac): Output: http://webkit-queues.webkit.org/results/3120865 New failing tests: imported/w3c/web-platform-tests/resource-timing/rt-cors.html
Created attachment 301601 [details] Archive of layout-test-results from ews102 for mac-elcapitan The attached test failures were seen while running run-webkit-tests on the mac-ews. Bot: ews102 Port: mac-elcapitan Platform: Mac OS X 10.11.6
Comment on attachment 301596 [details] [PATCH] Proposed Fix Attachment 301596 [details] did not pass mac-wk2-ews (mac-wk2): Output: http://webkit-queues.webkit.org/results/3120868 New failing tests: imported/w3c/web-platform-tests/resource-timing/rt-cors.html
Created attachment 301602 [details] Archive of layout-test-results from ews105 for mac-elcapitan-wk2 The attached test failures were seen while running run-webkit-tests on the mac-wk2-ews. Bot: ews105 Port: mac-elcapitan-wk2 Platform: Mac OS X 10.11.6
Comment on attachment 301596 [details] [PATCH] Proposed Fix Attachment 301596 [details] did not pass mac-debug-ews (mac): Output: http://webkit-queues.webkit.org/results/3120878 New failing tests: imported/w3c/web-platform-tests/resource-timing/rt-cors.html
Created attachment 301603 [details] Archive of layout-test-results from ews116 for mac-elcapitan The attached test failures were seen while running run-webkit-tests on the mac-debug-ews. Bot: ews116 Port: mac-elcapitan Platform: Mac OS X 10.11.6
Comment on attachment 301596 [details] [PATCH] Proposed Fix View in context: https://bugs.webkit.org/attachment.cgi?id=301596&action=review imported/w3c/web-platform-tests/resource-timing/rt-cors.html isn't doing very well. > Source/WebCore/ChangeLog:79 > + (WebCore::ResourceTiming::ResourceTiming): > + Class that encapsulates all of the data needed for a PerformanceResourceTiming entry. Yet another class that contains timing data? Can't we use this instead of one of the existing classes that contains timing data? > Source/WebCore/loader/SubresourceLoader.cpp:677 > + SecurityOrigin& origin = m_origin ? *m_origin : document->securityOrigin(); I'm not sure we want to continue if m_origin is null. > Source/WebCore/loader/WorkerThreadableLoader.cpp:233 > + Ref<ThreadableLoaderClientWrapper> protectedWorkerClientWrapper = *m_workerClientWrapper; > + m_loaderProxy.postTaskForModeToWorkerGlobalScope([protectedWorkerClientWrapper = WTFMove(protectedWorkerClientWrapper), resourceTiming = resourceTiming.isolatedCopy()] (ScriptExecutionContext& context) mutable { protectedWorkerClientWrapper = makeRef(m_workerClientWrapper) in the lambda capture. No need to make a local variable. > Source/WebCore/loader/cache/CachedResourceLoader.cpp:779 > + } else if (document() && RuntimeEnabledFeatures::sharedFeatures().resourceTimingEnabled()) { RuntimeEnabledFeatures::sharedFeatures().resourceTimingEnabled looks like it's used inconsistently in this patch. For example, is it intentional that this is only checked for Documents and not workers? > Source/WebCore/page/Performance.cpp:175 > + RefPtr<PerformanceResourceTiming> entry = PerformanceResourceTiming::create(m_timeOrigin, WTFMove(resourceTiming)); auto, which would make this a Ref.
Its possible that El Capitan's data is different from Sierra (what I'm testing). All of these failures are El-Capitan complaining that requestStart is not after connectEnd. I'll need to test on El Capitan. That said, this patch is still reviewable as is.
Comment on attachment 301596 [details] [PATCH] Proposed Fix View in context: https://bugs.webkit.org/attachment.cgi?id=301596&action=review > Source/WebCore/page/PerformanceResourceTiming.cpp:175 > - return networkLoadTimeToDOMHighResTimeStamp(m_timing.requestStart); > + // requestStart is 0 when a network request is not made. > + if (m_networkLoadTiming.requestStart <= 0) > + return connectEnd(); > + > + return networkLoadTimeToDOMHighResTimeStamp(m_networkLoadTiming.requestStart); Oh interesting. The old code was using m_timing.requestStart and not networkLoadTiming's requestStart.
Comment on attachment 301596 [details] [PATCH] Proposed Fix View in context: https://bugs.webkit.org/attachment.cgi?id=301596&action=review >> Source/WebCore/ChangeLog:79 >> + Class that encapsulates all of the data needed for a PerformanceResourceTiming entry. > > Yet another class that contains timing data? Can't we use this instead of one of the existing classes that contains timing data? Yeah, this is rather unfortunate and they are beginning to clash. Here is a list of all the Timing classes and their purposes: DocumentTiming: - WebContentProcess timestamps (event times) - Used for Navigation Timing fields - Owned by Document LoadTiming - WebContentProcess collected timestamps (start time, redirects) - Used for both Resource Timing and Navigation Timing (these fields ^) - Owned by Loaders (CachedResourceLoader DocumentLoader, ResourceLoader) and eventually passed to a Performance*Timing NetworkLoadTiming - NetworkProcess collected timestamps (dnsStart ... connectStart ... responseStart) - Used for both Resource Timing and Navigation Timing (these fields ^) - Owned by ResourceResponse (gross) and now a ResourceTiming and eventually passed to a Performance*Timing - As part of ResourceResponse this is how it gets serialized to the WebContentProcess and used by Loaders (gross) -- ResourceTiming - Used only for Resource Timing. - Encapsulates all necessary data for a Resource Timing entry - Serializable so it can be assembled on the loading thread and then passed to Workers - Carries a LoadTiming and NetworkLoadTiming since both are needed for all Resource Timing fields - Owned by nobody, this is just a struct passed around to get the data to a PerformanceResourceTiming object in the right context -- PerformanceTiming - The Navigation Timing object (PerformanceTiming instance) - Uses a DocumentTiming, LoadTiming, and NetworkLoadTiming PerformanceResourceTiming - A Resource Timing entry (PerformanceResourceTiming instance) - Uses a LoadTiming and NetworkLoadTiming ----- I do think LoadTiming and NetworkLoadTiming being separate has an advantage. Because the NetworkLoadTiming data comes from the NetworkProcess keeping it small and specific is a nice cognitive separation. I plan on adding a new message from the NetworkLoad -> ResourceLoader message that only contains the NetworkLoadTiming data (and some more metrics). I do think ResourceTiming should be separate from the others. Resource Timing entries are created for all kinds of loads (cache, load, synchronous load). I think packaging all the necessary data together, which may be assembled differently for the different loads is useful. Likewise passing this package along instead of the individual pieces. >> Source/WebCore/loader/SubresourceLoader.cpp:677 >> + SecurityOrigin& origin = m_origin ? *m_origin : document->securityOrigin(); > > I'm not sure we want to continue if m_origin is null. This was a very confusing area for me. My understanding is that m_origin is only set when we are loading via a ThreadableLoader (XHR, Fetch, EventSource). These kinds of loads originate from either a Document or Worker and they pass their SecurityOrigin over to the loader thread so it can be used to handle Cross Origin behavior for these loads. I arrived at this conclusion because m_origin is initialized from CachedResource::origin() which comes from CachedResourceRequest::origin() which is only set by DocumentThreadableLoader. Other, non-ThreadableLoader loads that use SubResourceLoader do not set this origin. The original Resource Timing used document->securityOrigin here and I kept that unchanged. -- Probably the best solution would be to ensure m_origin is always set for any load in a SubResourceLoader, so there is never confusion. That would probably be best done as a targeted cleanup patch. What do you think? >> Source/WebCore/loader/WorkerThreadableLoader.cpp:233 >> + m_loaderProxy.postTaskForModeToWorkerGlobalScope([protectedWorkerClientWrapper = WTFMove(protectedWorkerClientWrapper), resourceTiming = resourceTiming.isolatedCopy()] (ScriptExecutionContext& context) mutable { > > protectedWorkerClientWrapper = makeRef(m_workerClientWrapper) in the lambda capture. No need to make a local variable. Neat! I was not aware of makeRef. I'll convert this and the other bridge methods. >> Source/WebCore/loader/cache/CachedResourceLoader.cpp:779 >> + } else if (document() && RuntimeEnabledFeatures::sharedFeatures().resourceTimingEnabled()) { > > RuntimeEnabledFeatures::sharedFeatures().resourceTimingEnabled looks like it's used inconsistently in this patch. For example, is it intentional that this is only checked for Documents and not workers? Good catch! >> Source/WebCore/page/Performance.cpp:175 >> + RefPtr<PerformanceResourceTiming> entry = PerformanceResourceTiming::create(m_timeOrigin, WTFMove(resourceTiming)); > > auto, which would make this a Ref. A Ref does not easily get converted into a RefPtr when appending to m_resourceTimingBuffer. That is why existing code used RefPtr.
I created an El Capitan partition and it does look like it was possible for a requestStart to happen before connectionEnd in El Capitan: $ 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 completely whacky. For starters, TimingDataInit 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 Which is more reasonable. Still I'm not sure how I can make sense of the data. I'm going to compare more closely to data in Sierra and try to make a decision about what to do. This feature may just need to be disabled on El Capitan if we can't ensure its accuracy (I don't want websites gathering metrics that are inaccurate).
Yes, Sierra has better numbers: Raw dictionary (from copyTimingData): 2017-02-15 22:40:43.872 com.apple.WebKit.Networking.Development[2486:91984] >>> TIMING DATA: { "_kCFNTimingDataConnectEnd" = "508920043.870083"; "_kCFNTimingDataConnectStart" = "508920043.869083"; "_kCFNTimingDataConnectionReused" = 0; "_kCFNTimingDataDomainLookupEnd" = "508920043.869083"; "_kCFNTimingDataDomainLookupStart" = "508920043.869083"; "_kCFNTimingDataFetchStart" = "508920043.86863"; "_kCFNTimingDataLocalAddressAndPort" = "127.0.0.1:49622"; "_kCFNTimingDataRedirectCount" = 0; "_kCFNTimingDataRedirectCountW3C" = 0; "_kCFNTimingDataRedirectEnd" = 0; "_kCFNTimingDataRedirectStart" = 0; "_kCFNTimingDataRemoteAddressAndPort" = "127.0.0.1:8801"; "_kCFNTimingDataRequestEnd" = "508920043.870279"; "_kCFNTimingDataRequestStart" = "508920043.870251"; "_kCFNTimingDataResponseEnd" = "508920043.871618"; "_kCFNTimingDataResponseStart" = "508920043.871418"; "_kCFNTimingDataSecureConnectionStart" = 0; "_kCFNTimingDataTimingDataInit" = "508920043.868856"; } Ordered by Time: FetchStart: 508920043.86863 TimingDataInit: 508920043.868856 ? ConnectStart: 508920043.869083 ConnectEnd: 508920043.870083 DomainLookupStart: 508920043.869083 DomainLookupEnd: 508920043.869083 RequestStart: 508920043.870251 RequestEnd: 508920043.870279 ResponseStart: 508920043.871418 ResponseEnd: 508920043.871618 I'm not surprised, because access to timing data became Public API in Sierra (NSURLSessionTaskTransactionMetrics) and this aligns with the graphic there: https://docs-assets.developer.apple.com/published/df414fd961/23287374-c86a-4b5c-80d4-c1d596f20f85.png --- I wonder if the El Capitan numbers were skewed because the "Connection Reused", and so maybe it is reporting the connection numbers from a previous request. If that is the case we could clear out the numbers.
Hmm, no that still doesn't make sense just looking at the raw numbers. I'm going to start by skipping this test on El Capitan. If I can't make sense of the numbers and can't guarantee accuracy we may have to disable on that OS.
(In reply to comment #30) > Hmm, no that still doesn't make sense just looking at the raw numbers. I'm > going to start by skipping this test on El Capitan. If I can't make sense of > the numbers and can't guarantee accuracy we may have to disable on that OS. Filed Bug 168415.
Created attachment 301715 [details] [PATCH] Proposed Fix
Attachment 301715 [details] did not pass style-queue: ERROR: LayoutTests/platform/mac/TestExpectations:1532: Path does not exist. [test/expectations] [5] Total errors found: 1 in 95 files If any of these errors are false positives, please file a bug against check-webkit-style.
Comment on attachment 301715 [details] [PATCH] Proposed Fix Attachment 301715 [details] did not pass ios-sim-ews (ios-simulator-wk2): Output: http://webkit-queues.webkit.org/results/3126892 New failing tests: imported/w3c/web-platform-tests/resource-timing/rt-shared-resource-in-frames.html
Created attachment 301726 [details] Archive of layout-test-results from ews121 for ios-simulator-wk2 The attached test failures were seen while running run-webkit-tests on the ios-sim-ews. Bot: ews121 Port: ios-simulator-wk2 Platform: Mac OS X 10.11.6
Hmm, rt-shared-resource-in-frames.html is sometimes flakey in all browsers. That said, I do believe this test is correct. I'm going to preemptively mark it as flakey and file a bug to follow up on this.
<https://trac.webkit.org/changeset/212449>