Fix workerStart and fetchStart implementation and timing |
|||||||
Issue descriptionUpdate (2018-06-11, bashi@ on comment 21): Let me leave some comments of current status and the next step: - Currently PerformanceNavigationTiming#workerStart isn't set properly. It doesn't contain SW startup time. We need to fix it. - We are going to fix it as a part of service worker servicification (S13nServiceWorker). Original description: This is for requests intercepted by a service worker. From code inspection and some reports, I think we've got some bugs here. * (based on https://github.com/w3c/resource-timing/issues/119) workerStart should be <= than fetchStart, which we try to do, but seems sometimes we don't * we're not setting workerStart on network fallback * we probably have fetchStart wrong on network fallback This could be high P1 as sites are expecting to get useful data from workerStart/fetchStart.
,
Nov 9 2017
I'm not quite familiar with that API, but fetchStart seems marked before starting network request which is possibly intercepted by a service worker. https://cs.chromium.org/chromium/src/content/browser/frame_host/navigation_request.cc?type=cs&sq=package:chromium&l=1022 workerStart looks right. https://cs.chromium.org/chromium/src/content/browser/service_worker/service_worker_url_request_job.cc?type=cs&l=1011
,
Nov 9 2017
Although we set worker_start_time_, it's not actually used when the request falls back to network: https://cs.chromium.org/chromium/src/content/browser/service_worker/service_worker_url_request_job.cc?l=941&rcl=516ae0d2cab5f33ddfbaef3c1199a239d6fdf9f5
,
Nov 9 2017
,
Nov 9 2017
fetchStart may be different for PerformanceNavigationTiming vs PerformanceResourceTiming. For resource timing, it comes from PerformanceResourceTiming::fetchStart: https://cs.chromium.org/chromium/src/third_party/WebKit/Source/core/timing/PerformanceResourceTiming.cpp?l=185&rcl=cccda43345d0c7ff7fd680882a9478de8dd0ceec We take worker_ready_time if it's available, which gets plumbed from ServiceWorkerURLRequestJob's |worker_ready_time| which is set right before dispatching the fetch event, but it's also not used when network fallback occurred. Probably our behavior on redirects/fallback have to be examined more closely.
,
Feb 16 2018
,
Feb 22 2018
I'm still understanding specs and our implementation but I have some updates. Currently service-workers/service-worker/resource-timing.https.html is failing. https://cs.chromium.org/chromium/src/third_party/WebKit/LayoutTests/external/wpt/service-workers/service-worker/resource-timing.https-expected.txt?l=1&rcl=692b8e57542917a11c5c6c5fb62a9787925e8ec7 I don't think this is failing because we aren't setting workerStart on NW fallback. I think the cause of the failure is that we don't add PerformanceResourceTiming object to the performance.getEntries() when a resource loading failed. In the test, we try to get a PerformanceResourceTiming for 'resources/missing.jpg', which turns out null, because we don't add entreis for resouces which failed to load. Probably we should fix the test to check there is an entry for the given url. (Note: Firefox may be passing the test as they add PerformanceResourceTiming entries for resouces which failed to load. Either behavior should be fine as the spec says that "Resources for which the fetch was initiated, but was later aborted (e.g. due to a network error) MAY be included as PerformanceResourceTiming objects in the Performance Timeline." https://w3c.github.io/resource-timing/#resources-included-in-the-performanceresourcetiming-interface) Regarding not setting workerStart on NW fallback, I think the current behavior is fine. We only fallback to NW when there is no SW. https://cs.chromium.org/chromium/src/content/browser/service_worker/service_worker_controllee_request_handler.cc?l=49&rcl=8eaae0b1d1c61b848ef3e40a052c0ee90287ca08 The spec says that workerStart should be zero when there is no active SW. If no SW exists, there wouldn't be an active SW. Regarding workerStart/fetchStart, I observed workerStart > fetchStart in PerformanceNavigationTiming when I opened a content_shell with SW installed. As described, I think it should always be workerStart <= fetchStart. I'm investigating why this is happening.
,
Feb 22 2018
In regards to the change to resource-timing.https.html, it seems like maybe the intent of the test was changed. The checks being changed were described as "network fallback", not "failed load". In particular I added this check to cover network fallback for cross-origin no-cors requests. This is relevant because the spec blocks access to information on some of these values via the Timing-Allow-Origin header. It should be allowed here. It seems like the change to ignore the check basically loses the cross-origin no-cors network fallback test coverage on chromium. Would it make sense to instead change the test to reference an existing image instead?
,
Feb 22 2018
bkelly: Thanks! Using an existing image is what we ended up decided to do in https://chromium-review.googlesource.com/c/chromium/src/+/930109 (not yet committed).
,
Feb 22 2018
Oh, great! Sorry for my confusion. I got a wpt-sync-bot bug over here based on the upstream PR: https://bugzilla.mozilla.org/show_bug.cgi?id=1440225 I didn't see that it hadn't landed in upstream yet. I'm still trying to get used to this brave new world of WPT sync'ing. Thanks again.
,
Feb 22 2018
Also note, I think wpt.fyi might show firefox failing this test because of spectre-related timer resolution issues. In our tree we have a pref override for the test and we expect to pass: https://searchfox.org/mozilla-central/source/testing/web-platform/meta/service-workers/service-worker/resource-timing.https.html.ini
,
Feb 23 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/7afe9250f043d5a6f98260f28b3a245ccb566a42 commit 7afe9250f043d5a6f98260f28b3a245ccb566a42 Author: Kenichi Ishibashi <bashi@chromium.org> Date: Fri Feb 23 01:09:30 2018 service worker: Update WPT test for resource timing Before this CL, the test assumed that there should be a PerformanceResourceTiming for fetching 'resources/missing.jpg'. As the spec says [1], this assumption is not guaranteed. In fact, Chromium doesn't add PerformanceResourceTiming for resouces which failed to load. This CL updates the test to check there is a corresponding PerformanceResourceTiming entry before doing verifications. [1] https://w3c.github.io/resource-timing/#resources-included-in-the-performanceresourcetiming-interface Bug: 782958 Change-Id: I85e75a8dade9f6620d22a54eaf97468f00360023 Reviewed-on: https://chromium-review.googlesource.com/930109 Reviewed-by: Matt Falkenhagen <falken@chromium.org> Commit-Queue: Kenichi Ishibashi <bashi@chromium.org> Cr-Commit-Position: refs/heads/master@{#538648} [delete] https://crrev.com/af6c8baf39fb6ad83d3ef23424f2f9863c310cc7/third_party/WebKit/LayoutTests/external/wpt/service-workers/service-worker/resource-timing.https-expected.txt [modify] https://crrev.com/7afe9250f043d5a6f98260f28b3a245ccb566a42/third_party/WebKit/LayoutTests/external/wpt/service-workers/service-worker/resource-timing.https.html [modify] https://crrev.com/7afe9250f043d5a6f98260f28b3a245ccb566a42/third_party/WebKit/LayoutTests/external/wpt/service-workers/service-worker/resources/resource-timing-iframe.sub.html
,
Feb 23 2018
Sorry, yes it hasn't committed yet in the Chromium tree. It has to do that first then will be auto-synced upstream to WPT.
,
Feb 23 2018
Ohh.. that was funny timing. It committed in Chromium one minute before I wrote comment c#13.
,
Mar 27 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/9fa2684557b49c27f72c7fc97c5ee0904c9d21d6 commit 9fa2684557b49c27f72c7fc97c5ee0904c9d21d6 Author: Kenichi Ishibashi <bashi@chromium.org> Date: Tue Mar 27 03:10:15 2018 service_worker: Add tests for navigation timing This CL adds some tests for PerformanceNavigationTiming which are involved with service worker. - SW intercepts a navigation - SW falls back to network - Redirect and SW intercepts a navigation These tests check `workerStart <= fetchStart` because starting a worker should happen before fetching a resource when service worker is involved. Bug: 782958 Change-Id: Idd3fa8f76a328e77ee531b81bd91ee3db223f12c Reviewed-on: https://chromium-review.googlesource.com/979873 Commit-Queue: Kenichi Ishibashi <bashi@chromium.org> Reviewed-by: Makoto Shimazu <shimazu@chromium.org> Reviewed-by: Matt Falkenhagen <falken@chromium.org> Cr-Commit-Position: refs/heads/master@{#545935} [add] https://crrev.com/9fa2684557b49c27f72c7fc97c5ee0904c9d21d6/third_party/WebKit/LayoutTests/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt [add] https://crrev.com/9fa2684557b49c27f72c7fc97c5ee0904c9d21d6/third_party/WebKit/LayoutTests/external/wpt/service-workers/service-worker/navigation-timing.https.html [add] https://crrev.com/9fa2684557b49c27f72c7fc97c5ee0904c9d21d6/third_party/WebKit/LayoutTests/external/wpt/service-workers/service-worker/resources/navigation-timing-worker.js [add] https://crrev.com/9fa2684557b49c27f72c7fc97c5ee0904c9d21d6/third_party/WebKit/LayoutTests/flag-specific/enable-features=NetworkService/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt
,
Mar 27 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/4c97ba8c9a34159a5951206ecacfb5db3b24cdf2 commit 4c97ba8c9a34159a5951206ecacfb5db3b24cdf2 Author: Reilly Grant <reillyg@chromium.org> Date: Tue Mar 27 18:16:08 2018 Add additional expectations for navigation-timing.https.html This test has additional failures when run with the NetworkService flag. Bug: 782958 Change-Id: Ia331cb3e2f92df49c1fac7a10bac4ddb859feeed Tbr: bashi@chromium.org No-Try: true Reviewed-on: https://chromium-review.googlesource.com/981402 Reviewed-by: Reilly Grant <reillyg@chromium.org> Commit-Queue: Reilly Grant <reillyg@chromium.org> Cr-Commit-Position: refs/heads/master@{#546171} [add] https://crrev.com/4c97ba8c9a34159a5951206ecacfb5db3b24cdf2/third_party/WebKit/LayoutTests/flag-specific/enable-features=NetworkService/virtual/navigation-mojo-response/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt [add] https://crrev.com/4c97ba8c9a34159a5951206ecacfb5db3b24cdf2/third_party/WebKit/LayoutTests/flag-specific/enable-features=NetworkService/virtual/outofblink-cors/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt
,
Mar 27 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/f7ba040854a29b9864c621ce04af4751692d5700 commit f7ba040854a29b9864c621ce04af4751692d5700 Author: Reilly Grant <reillyg@chromium.org> Date: Tue Mar 27 19:33:39 2018 Fixup additional expectations for navigation-timing.https.html The expectations added in r546171 were missing trailing newlines. This patch adds them. Bug: 782958 Change-Id: I6d93ebf17b06fa30e6ca0638766c2c35f046bf0e Tbr: bashi@chromium.org No-Try: true Reviewed-on: https://chromium-review.googlesource.com/982400 Reviewed-by: Reilly Grant <reillyg@chromium.org> Commit-Queue: Reilly Grant <reillyg@chromium.org> Cr-Commit-Position: refs/heads/master@{#546204} [modify] https://crrev.com/f7ba040854a29b9864c621ce04af4751692d5700/third_party/WebKit/LayoutTests/flag-specific/enable-features=NetworkService/virtual/navigation-mojo-response/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt [modify] https://crrev.com/f7ba040854a29b9864c621ce04af4751692d5700/third_party/WebKit/LayoutTests/flag-specific/enable-features=NetworkService/virtual/outofblink-cors/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt
,
Mar 29 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/2ad71d138d55feab49fe8297bf5105bcbbcaa533 commit 2ad71d138d55feab49fe8297bf5105bcbbcaa533 Author: Kenichi Ishibashi <bashi@chromium.org> Date: Thu Mar 29 09:18:08 2018 S13nSW: Update expectation for navigation-timing.https-expected.txt Rebaseline after r546365. Tbr: falken@chromium.org,kinuko@chromium.org Bug: 782958 Change-Id: I751ba813b526fef8efd758fc3e3b0967d550ffd4 Reviewed-on: https://chromium-review.googlesource.com/985675 Reviewed-by: Kenichi Ishibashi <bashi@chromium.org> Commit-Queue: Kenichi Ishibashi <bashi@chromium.org> Cr-Commit-Position: refs/heads/master@{#546776} [modify] https://crrev.com/2ad71d138d55feab49fe8297bf5105bcbbcaa533/third_party/WebKit/LayoutTests/flag-specific/enable-features=NetworkService/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt
,
Mar 29 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/981b3796e311601d4f44d35f0aab9077195a76dc commit 981b3796e311601d4f44d35f0aab9077195a76dc Author: Reilly Grant <reillyg@chromium.org> Date: Thu Mar 29 18:43:12 2018 Update virtual test expectations for navigation-timing.https.html Rebaseline the NetworkService expectations for the navigation-mojo-response and outofblink-cors virtual tests suites. Bug: 782958 Change-Id: Id000af5d6c8d82255a55a58a42a9436cec99005d Tbr: bashi@chromium.org No-Try: true Reviewed-on: https://chromium-review.googlesource.com/986648 Reviewed-by: Reilly Grant <reillyg@chromium.org> Commit-Queue: Reilly Grant <reillyg@chromium.org> Cr-Commit-Position: refs/heads/master@{#546885} [modify] https://crrev.com/981b3796e311601d4f44d35f0aab9077195a76dc/third_party/WebKit/LayoutTests/flag-specific/enable-features=NetworkService/virtual/navigation-mojo-response/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt [modify] https://crrev.com/981b3796e311601d4f44d35f0aab9077195a76dc/third_party/WebKit/LayoutTests/flag-specific/enable-features=NetworkService/virtual/outofblink-cors/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt
,
May 18 2018
Issue 844274 has been merged into this issue.
,
May 18 2018
Let me leave some comments of current status and the next step: - Currently PerformanceNavigationTiming#workerStart isn't set properly. It doesn't contain SW startup time. We need to fix it. - We are going to fix it as a part of service worker servicification (S13nServiceWorker).
,
Jun 10 2018
,
Jun 18 2018
internal doc about this: https://docs.google.com/document/d/1-kIZrrhypwWLDFMCl06xX36z7yuAplSUaq5Qj2KD3nY/edit
,
Jul 20
,
Sep 7
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/65e2f0f3c514295dad505806748b0007824841ef commit 65e2f0f3c514295dad505806748b0007824841ef Author: Kenichi Ishibashi <bashi@chromium.org> Date: Fri Sep 07 08:04:53 2018 S13nServiceWorker: Fix `requestStart` performance timing for navigation ServiceWorkerNavigationLoader is responsible for setting up LoadTimingInfo which are used to create web-exposed PerformanceResourceTiming. Specifically, the field |send_start| in LoadTimingInfo is populated as `requestStart` in PerformanceResourceTiming. The resource timing spec[1] doesn't state explicitly but according to a spec discussion[2], following ordering would be reasonable: workerStart <= fetchStart <= requestStart Before this CL, ServiceWorkerNavigationLoader recorded `requestStart` before starting a service worker, at the same time `workerStart` is recorded. This doesn't seem a good timing because `requestStart` would be less than `fetchStart`, which is recorded after the service worker is started. This CL moves the timing to record |send_start| (and corresponding |send_end|) to the time the service worker is started. Note that web-exposed `fetchStart` still doesn't follow the above ordering even after this CL, as we have a special case code for `fetchStart` in navigation. A follow-up CL will address `fetchStart` case. The wpt service-workers/service-worker/navigation-timing.https.html should cover this change. [1] https://w3c.github.io/resource-timing/#sec-performanceresourcetiming [2] https://github.com/w3c/resource-timing/issues/119 Bug: 782958 Change-Id: I339d41d8c93a2cbcd053d4348d8e0f51b1134925 Reviewed-on: https://chromium-review.googlesource.com/1212423 Reviewed-by: Kinuko Yasuda <kinuko@chromium.org> Reviewed-by: Makoto Shimazu <shimazu@chromium.org> Commit-Queue: Kenichi Ishibashi <bashi@chromium.org> Cr-Commit-Position: refs/heads/master@{#589458} [modify] https://crrev.com/65e2f0f3c514295dad505806748b0007824841ef/content/browser/service_worker/service_worker_navigation_loader.cc
,
Sep 10
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/e699a315a0b1ac1c051de9b4b8ca64e1b00abd00 commit e699a315a0b1ac1c051de9b4b8ca64e1b00abd00 Author: Kenichi Ishibashi <bashi@chromium.org> Date: Mon Sep 10 01:50:21 2018 S13nServiceWorker: Fix `fetchStart` performance timing for subresources ServiceWorkerSubresourceLoader records loading milestones. These milestones are used to create web-exposed PerformanceResourceTiming. Before this CL, ServiceWorkerSubresourceLoader recorded |service_worker_ready_time| before calling GetControllerServiceWorker(). This doesn't seem a good timing to record it because: - |service_worker_ready_time| is used to create `fetchStart` of PerformanceResourceTiming. - `fetchStart` should be recorded after the controller service worker is ready to handle fetch event. - But the worker may not be running until we call GetControllerServiceWorker(). This CL moves the timing to record |service_worker_raedy_time| and some others after calling GetControllerServiceWorker(), as calling it makes sure that the controller is running and ready to handle a fetch event. The wpt ervice-workers/service-worker/resource-timing.https.html should cover this change. Bug: 782958 Change-Id: Ic6f6abd34ffdc84e002357a905e7a7726e6b5870 Reviewed-on: https://chromium-review.googlesource.com/1212244 Commit-Queue: Kenichi Ishibashi <bashi@chromium.org> Reviewed-by: Kinuko Yasuda <kinuko@chromium.org> Cr-Commit-Position: refs/heads/master@{#589818} [modify] https://crrev.com/e699a315a0b1ac1c051de9b4b8ca64e1b00abd00/content/renderer/service_worker/service_worker_subresource_loader.cc
,
Sep 10
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/137522b46759fe0441f801f6e7bea09ae5fb25a0 commit 137522b46759fe0441f801f6e7bea09ae5fb25a0 Author: Kenichi Ishibashi <bashi@chromium.org> Date: Mon Sep 10 08:18:14 2018 serviece worker: Fix PerformanceNavigationTiming#fetchStart This is a follow-up CL of crrev.com/c/1212423 and fixes timing ordering of PerformanceNavigationTiming attributes. Background: `fetchStart` of PerformanceNavigationTiming comes from |fetch_start| of NavigationTiming, which is set by NavigationRequest. Since NavigationRequest isn't aware of service worker interception `fetchStart` could come earlier than `workerStart` when the navigation is routed to a service worker. However, `fetchStart` is supposed to come after `workerStart`. We can address this mis-ordering by using worker ready time. When worker ready time is greater than |fetch_start| of NavigationTiming, use worker ready time as |fetch_start|. Justifications: - `fetchStart` is should be recorded after redirects end. - `fetchStart` is should be recorded after `workerStart` if a service worker intercepted the navigation. - There seems no particular ordering between `redirectEnd` and `workerStart`. - NavigationRequest already updates |fetch_start| for redirects. Bug: 782958 Change-Id: I90bdeaee73d361c9d35024f13fd0d3f91ba42b02 Reviewed-on: https://chromium-review.googlesource.com/1215426 Reviewed-by: Makoto Shimazu <shimazu@chromium.org> Reviewed-by: Kinuko Yasuda <kinuko@chromium.org> Commit-Queue: Kenichi Ishibashi <bashi@chromium.org> Cr-Commit-Position: refs/heads/master@{#589851} [modify] https://crrev.com/137522b46759fe0441f801f6e7bea09ae5fb25a0/content/browser/frame_host/navigation_request.cc [delete] https://crrev.com/389d563b1a49e8f3f75156871cc95438d280c77e/third_party/WebKit/LayoutTests/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt [delete] https://crrev.com/389d563b1a49e8f3f75156871cc95438d280c77e/third_party/WebKit/LayoutTests/virtual/outofblink-cors-ns/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt [delete] https://crrev.com/389d563b1a49e8f3f75156871cc95438d280c77e/third_party/WebKit/LayoutTests/virtual/outofblink-cors/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt [delete] https://crrev.com/389d563b1a49e8f3f75156871cc95438d280c77e/third_party/WebKit/LayoutTests/virtual/service-worker-servicification/external/wpt/service-workers/service-worker/navigation-timing.https-expected.txt
,
Sep 10
This change breaks the network service bots: https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Mojo%20Linux/18808
,
Sep 11
I forgot to remove some test expectations. Will upload a fix.
,
Sep 11
Update: I think we've fixed all known issues on S13nServiceWorker path. We can close this when we ship S13nServiceWorker or NetworkService. De-prioritizing.
,
Jan 15
What's the status of S13nServiceWorker and NetworkService?
,
Jan 15
maxlg: S13nSW is issue 715640 and could probably be closed soon. It's shipping in Chrome 71. NetworkService is issue 598073. |
|||||||
►
Sign in to add a comment |
|||||||
Comment 1 by falken@chromium.org
, Nov 8 2017