New issue
Advanced search Search tips
Starred by 2 users

Issue metadata

Status: Assigned
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 2
Type: Bug

Blocked on:
issue 878452

Blocking:
issue 874222



Sign in to add a comment
link

Issue 877972: Add more service worker FetchEvent timing histograms

Reported by wanderview@chromium.org, Aug 27 Project Member

Issue description

Currently we have a number of histograms measuring the timing of service worker FetchEvent handling, but its been suggested we could add some more measurements.  I need to investigate what we currently have and what could be added.
 

Comment 1 by wanderview@chromium.org, Aug 27

I investigated a bit what we have today:

ServiceWorker.EventDispatchingDelay_FETCH_MAIN_FRAME
ServiceWorker.EventDispatchingDelay_FETCH_SUB_FRAME
ServiceWorker.EventDispatchingDelay_FETCH_SUB_RESOURCE

These measure the time required to dispatch the FetchEvent.  They do not include any worker start or js execution time.

ServiceWorker.FetchEvent.Fallback.Time
ServiceWorker.FetchEvent.HasResponse.Time
ServiceWorker.FetchEvent.WaitUntil.Time

These measure the time between the dispatch of the FetchEvent and the specified action.

ServiceWorker.StartWorker.Time
ServiceWorker.StartWorker.Time_ExistingReadyProcess_FETCH_MAIN_FRAME
ServiceWorker.StartWorker.Time_ExistingReadyProcess
ServiceWorker.StopWorker.Time

Times to start/stop the worker.

There are also many navpreload histograms.

Comment 2 by wanderview@chromium.org, Aug 27

Cc: falken@chromium.org
Note, I saw some discrepancies in chrome://histograms with how some of these histograms are collected.

AFAICT, StartWorker.Time histograms are only collected when a navigation triggers the start of the worker.  If a subresource request from a controlled document starts the worker, then the Time histogram is not collected.  This is true for both legacy and s13n mode.

The FetchEvent.Fallback, HasResponse, and WaitUntil Time histograms are only getting collected for subresources in legacy mode.  In s13n mode these histograms are not collected for subresource requests.

Are these issues intended or expected?

Comment 3 by falken@chromium.org, Aug 27

Thanks for looking into this.

BTW the "EventDispatchingDelay" ones are fishy:
- They compare timings from different processes without using  IsConsistentAcrossProcesses and IsHighResolution.
- There is (was?) a bug where they use the wrong time when the event aborted (timed out).
- They are using mojo::Time instead of mojo::TimeTicks.

I think it'd be OK to remove them and make new ones that fit the fetch event path better.

I just saw your comment#2 too. Yes StartWorker.Time is only for the time to start a worker. It's independent of each fetch event.

FetchEvent.Fallback, HasResponse, and WaitUntil are probably not plumbed to s13n mode. As above, we can probably redesign everything to have more consistent timings for the fetch event path specifically.

Comment 4 by wanderview@chromium.org, Aug 27

> I just saw your comment#2 too. Yes StartWorker.Time is only for the time to start a worker. It's independent of each fetch event.

I mean, I was doing this:

1. Stop work via devtools button.
2. In web console trigger a subresource load with fetch("/")
3. Verify worker is running in devtools
4. Observe there is no StartWorker.Time histogram recorded in chrome://histograms

Shouldn't it be recorded regardless of how the worker was started?

Comment 5 by falken@chromium.org, Aug 27

I read that too quickly. Yes the expected behavior is to record the histogram, so that's surprising. Just checking, did you reload chrome://histograms after starting the worker?

Comment 6 by wanderview@chromium.org, Aug 27

Yes, I reloaded chrome://histograms.  I can double-check again later.

Btw, I was using this site to run the steps in #c4:

https://fetch-event-echo.glitch.me/

It always hits FetchEvent fallback, in case that matters.

Comment 7 by wanderview@chromium.org, Aug 28

Owner: ----
Status: Available (was: Assigned)
Handing this over to the service worker team to pursue since it sounds like they have some more bandwidth now.  Happy to look at it again if needed.  Thanks.

Comment 8 by wanderview@chromium.org, Aug 28

Status: Assigned (was: Available)
Actually, let me see what I can do in the short term.  I have some ideas I'd like to try, but I don't know if it will meet the SW team's long term design goals.  We can discuss at our next meeting.  Sorry for my confusion.

Comment 9 by wanderview@chromium.org, Aug 28

I spun the WorkerStart.Time issue off into  bug 878409 .

Comment 10 by wanderview@chromium.org, Aug 28

In our meeting Matt mentioned the EventDispatchingDelay metrics are a bit suspect because the code does not verify the timestamps are comparable across processes before recording them.  So older windows devices may be polluting the data.  Something to make sure we avoid here.

Comment 11 by wanderview@chromium.org, Aug 28

It seems to me there are a few different axes we can use to slice service worker loading data:

By destination:

  * document (top/frame)
  * script (<script>/module/worker/importScripts)
  * stylesheet (top/@import)
  * image (<img>/background-image/etc)
  * others (xhr/fetch/beacon/?)

By Response source:

  * Fallback to network stack
    * hitting network
    * hitting http cache
  * respondWith() Response
    * produced by Fetch API
      * hitting the network
      * hitting http cache
    * produced by Cache API
    * produced by new Response()
  * maybe consider if clone() was called on the response?

By resource timeline:

  * worker start
  * FetchEvent dispatch
  * FetchEvent.respondWith() called
  * Response creation starts (beginning of fetch() or cache.match() depending on source)
  * Response creation completes (fetch() or cache.match() settles depending on source)
  * FetchEvent.respondWith() promise settles
  * Start reading Response body
  * Finish reading Response body

If we don't mind creating a ton of histograms, we could simply track every permutation:

  <TIMELINE_PART>
  <DESTINATION_PART>
  <SOURCE_PART>
  <TIMELINE_PART>-<DESTINATION_PART>
  <TIMELINE_PART>-<SOURCE_PART>
  <TIMELINE_PART>-<DESTINATION_PART>-<SOURCE_PART>
  <DESTINATION_PART>-<SOURCE_PART>

With 5 destination, 6 sources, and 8 timeline parts that would be 300+ histograms.  Maybe we could narrow it down a bit.

Comment 12 by wanderview@chromium.org, Aug 28

I'm going to start by adding source info to the Response as it will likely be useful here and  bug 875013 .

Comment 13 by wanderview@chromium.org, Aug 28

Owner: wanderview@chromium.org

Comment 14 by wanderview@chromium.org, Aug 28

Blockedon: 878452

Comment 15 by falken@chromium.org, Aug 31

Thanks for digging into this, these are good ideas. Just to comment about "ton of histograms", my intuition is it might be excessive, especially if it's combinatorial since it explodes quickly. In practice it'd also be hard to analyze. We previously received this kind of feedback from the metrics team:
https://codereview.chromium.org/2218943002#msg72

Maybe a possible approach is to first implement top-level ones, then based on those results start doing targeted combinations as needed?

Comment 16 by wanderview@chromium.org, Aug 31

Yea, I agree with that approach.  Since we have Fallback.Time and HasResponse.Time already, I was pursuing adding some info about the resource source.  So we could maybe add HasResponse-CacheStorage.Time, etc as a next step.

Also, someone suggested that we currently don't have any histograms that measure BlodDataHandle read times.  That might be a straightforward thing to add to get a sense of CacheStorage body reading performance.

Comment 17 by bugdroid1@chromium.org, Sep 18

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/cf76e1c93d6aa7c45699f3e6a835a58b481db40f

commit cf76e1c93d6aa7c45699f3e6a835a58b481db40f
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Tue Sep 18 08:08:36 2018

service worker: Use TimeTicks to record event dispatch time

We can use base::TimeTicks in Blink now. Use it to record
service worker related event dispatching time so that we can
safely compare them with other timing like worker start time.

Cq-Include-Trybots: luci.chromium.try:linux_mojo
Bug: 877972
Change-Id: I399f9b7856e9ea2fdbbdc5c552149577cca3f09e
Reviewed-on: https://chromium-review.googlesource.com/1226473
Reviewed-by: Kinuko Yasuda <kinuko@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#591969}
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/background_fetch/background_fetch_embedded_worker_test_helper.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/background_sync/background_sync_manager.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/cookie_store/cookie_store_manager_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/payments/payment_app_content_unittest_base.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/payments/payment_app_provider_impl.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/embedded_worker_test_helper.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_browsertest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_context_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_fetch_dispatcher.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_fetch_dispatcher.h
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_job_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_navigation_loader_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_object_host_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_provider_host_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_register_job.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_register_job.h
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_registration_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_url_request_job_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_version.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_version.h
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/browser/service_worker/service_worker_version_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/common/service_worker/controller_service_worker.mojom
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/common/service_worker/service_worker.mojom
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/renderer/service_worker/service_worker_context_client.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/renderer/service_worker/service_worker_context_client.h
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/renderer/service_worker/service_worker_context_client_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/renderer/service_worker/service_worker_provider_context_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/renderer/service_worker/service_worker_subresource_loader.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/renderer/service_worker/service_worker_subresource_loader.h
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/content/renderer/service_worker/service_worker_subresource_loader_unittest.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/third_party/blink/public/mojom/payments/payment_app.mojom
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/third_party/blink/public/mojom/service_worker/service_worker_fetch_response_callback.mojom
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/third_party/blink/public/web/modules/service_worker/web_service_worker_context_client.h
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/third_party/blink/renderer/modules/service_worker/respond_with_observer.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/third_party/blink/renderer/modules/service_worker/respond_with_observer.h
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/third_party/blink/renderer/modules/service_worker/service_worker_global_scope_client.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/third_party/blink/renderer/modules/service_worker/service_worker_global_scope_client.h
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/third_party/blink/renderer/modules/service_worker/wait_until_observer.cc
[modify] https://crrev.com/cf76e1c93d6aa7c45699f3e6a835a58b481db40f/third_party/blink/renderer/modules/service_worker/wait_until_observer.h

Comment 18 by bashi@chromium.org, Sep 28

Cc: wanderview@chromium.org
Owner: bashi@chromium.org
Let me own this as I'm working on adding some UMAs.

Comment 19 by bugdroid1@chromium.org, Oct 1

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/025e80659448a44ba1948c928a167b49dfe5a64b

commit 025e80659448a44ba1948c928a167b49dfe5a64b
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Mon Oct 01 23:05:06 2018

service worker: Record time respondWith() is settled

Motivations behind this change are:
- To track time spent executing fetch event handers
- To track IPC delay for navigation case (renderer -> browser).
- To track thread hopping delay for subresource case
  (renderer SW thread -> renderer background thread).

Cq-Include-Trybots: luci.chromium.try:linux_mojo
Bug: 877972
Change-Id: I1ea2e17e3270c9f79e6b5104885562b96ac497b0
Reviewed-on: https://chromium-review.googlesource.com/1242579
Reviewed-by: Kinuko Yasuda <kinuko@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#595622}
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/content/browser/service_worker/embedded_worker_test_helper.cc
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/content/browser/service_worker/service_worker_fetch_dispatcher.cc
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/content/browser/service_worker/service_worker_navigation_loader_unittest.cc
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/content/browser/service_worker/service_worker_url_request_job_unittest.cc
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/content/renderer/service_worker/service_worker_context_client.cc
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/content/renderer/service_worker/service_worker_context_client.h
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/content/renderer/service_worker/service_worker_subresource_loader.cc
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/content/renderer/service_worker/service_worker_subresource_loader.h
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/content/renderer/service_worker/service_worker_subresource_loader_unittest.cc
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/third_party/blink/public/mojom/service_worker/service_worker_fetch_response_callback.mojom
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/third_party/blink/public/web/modules/service_worker/web_service_worker_context_client.h
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/third_party/blink/renderer/modules/service_worker/fetch_respond_with_observer.cc
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/third_party/blink/renderer/modules/service_worker/service_worker_global_scope_client.cc
[modify] https://crrev.com/025e80659448a44ba1948c928a167b49dfe5a64b/third_party/blink/renderer/modules/service_worker/service_worker_global_scope_client.h

Comment 20 by bugdroid1@chromium.org, Oct 4

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/77ae3479cef09e88672cf57f51f76cab2f71eea2

commit 77ae3479cef09e88672cf57f51f76cab2f71eea2
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Thu Oct 04 22:59:46 2018

service worker: Record fetch event milestones for main resource loading

This CL adds several UMAs to track time spend each stage of service
worker involved main resource loading. The purpose of these UMAs is
to make it easier to investigate performance bottleneck.

Design doc:
https://docs.google.com/document/d/16K2X5k6hUq7lZSee-KXR9FUeSTEEypDXCjYbu_CvkT0/edit?usp=sharing

Cq-Include-Trybots: luci.chromium.try:linux_mojo
Bug: 877972
Change-Id: Ibb2433cafb090e66b450236ef2f5f1f4baa918bf
Reviewed-on: https://chromium-review.googlesource.com/c/1256384
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Reviewed-by: Steven Holte <holte@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#596903}
[modify] https://crrev.com/77ae3479cef09e88672cf57f51f76cab2f71eea2/content/browser/service_worker/service_worker_browsertest.cc
[modify] https://crrev.com/77ae3479cef09e88672cf57f51f76cab2f71eea2/content/browser/service_worker/service_worker_fetch_dispatcher.cc
[modify] https://crrev.com/77ae3479cef09e88672cf57f51f76cab2f71eea2/content/browser/service_worker/service_worker_fetch_dispatcher.h
[modify] https://crrev.com/77ae3479cef09e88672cf57f51f76cab2f71eea2/content/browser/service_worker/service_worker_navigation_loader.cc
[modify] https://crrev.com/77ae3479cef09e88672cf57f51f76cab2f71eea2/content/browser/service_worker/service_worker_navigation_loader.h
[modify] https://crrev.com/77ae3479cef09e88672cf57f51f76cab2f71eea2/content/browser/service_worker/service_worker_url_request_job.cc
[modify] https://crrev.com/77ae3479cef09e88672cf57f51f76cab2f71eea2/content/browser/service_worker/service_worker_url_request_job.h
[modify] https://crrev.com/77ae3479cef09e88672cf57f51f76cab2f71eea2/tools/metrics/histograms/histograms.xml

Comment 21 by bugdroid1@chromium.org, Oct 9

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/482920a470b96188de2207f680db1d3343cbc00e

commit 482920a470b96188de2207f680db1d3343cbc00e
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Tue Oct 09 05:15:09 2018

Add UMA recording checks in ServiceWorkerNavigationLoaderTest

This is a follow-up CL of https://crrev.com/c/1256384. Add
UMA recording checks in unittests to have better testing coverage.

Cq-Include-Trybots: luci.chromium.try:linux_mojo
Bug: 877972
Change-Id: I29b44303755ee7add680f1393f3a2a77bdddede1
Reviewed-on: https://chromium-review.googlesource.com/c/1264137
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#597804}
[modify] https://crrev.com/482920a470b96188de2207f680db1d3343cbc00e/content/browser/service_worker/service_worker_navigation_loader_unittest.cc

Comment 22 by bugdroid1@chromium.org, Oct 9

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/df64c92360495ab98876e131fb0be3b800039a44

commit df64c92360495ab98876e131fb0be3b800039a44
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Tue Oct 09 05:15:13 2018

service worker: Don't record fetch timing UMAs when DevTools is attached

When DevTools is attached, some instrumentation code is executed and
these could cause noise.

Cq-Include-Trybots: luci.chromium.try:linux_mojo
Bug: 877972
Change-Id: I7c45739ef7467952b3501413044323873181eb65
Reviewed-on: https://chromium-review.googlesource.com/c/1263535
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#597805}
[modify] https://crrev.com/df64c92360495ab98876e131fb0be3b800039a44/content/browser/service_worker/service_worker_navigation_loader.cc
[modify] https://crrev.com/df64c92360495ab98876e131fb0be3b800039a44/content/browser/service_worker/service_worker_navigation_loader.h

Comment 23 by bugdroid1@chromium.org, Oct 15

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/336ee21faa50626cdb760da8fccea0cd522f77f2

commit 336ee21faa50626cdb760da8fccea0cd522f77f2
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Mon Oct 15 08:11:50 2018

S13nServiceWorker: Set more accurate worker ready time for subresource loading

Before this CL we recorded worker ready time just after getting a
mojo pointer to the controller service worker, but getting the
mojo pointer doesn't guarantee that the controller service worker
is actually running. This means that the recorded timing didn't
capture worker startup delay. To have more accurate timing,
use |dispatch_event_time| of ServiceWorkerFetchEventTiming as
worker ready time. |dispatch_event_time| is recorded just before
dispatching a fetch event so this is reasonable.

Cq-Include-Trybots: luci.chromium.try:linux_mojo
Bug: 877972
Change-Id: Ifb8e905095794770dd8a4973e1e0d569ccfde00e
Reviewed-on: https://chromium-review.googlesource.com/c/1278459
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Cr-Commit-Position: refs/heads/master@{#599587}
[modify] https://crrev.com/336ee21faa50626cdb760da8fccea0cd522f77f2/content/renderer/service_worker/service_worker_subresource_loader.cc
[modify] https://crrev.com/336ee21faa50626cdb760da8fccea0cd522f77f2/content/renderer/service_worker/service_worker_subresource_loader.h
[modify] https://crrev.com/336ee21faa50626cdb760da8fccea0cd522f77f2/content/renderer/service_worker/service_worker_subresource_loader_unittest.cc

Comment 24 by bugdroid1@chromium.org, Oct 18

Project Member

Comment 25 by bugdroid1@chromium.org, Nov 28

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/3e4375680f3a22e3942f6be02b62d5e2d9ac4559

commit 3e4375680f3a22e3942f6be02b62d5e2d9ac4559
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Wed Nov 28 00:54:40 2018

service worker: Record some fetch event timings up to 3 minutes

Before this CL, all histograms under ServiceWorker.LoadTiming category
were recorded by UMA_HISTOGRAM_TIMES macro. The macro can record up to
10 seconds but we've realized that 10 seconds limit isn't enough for
some milestones. Use UMA_HISTOGRAM_MEDIUM_TIMES for these histograms
so that they can be recorded up to 3 minutes.

Bug: 877972
Change-Id: Icca1ddd583c87c4dd9a6ebd924b81edd2648b2f0
Reviewed-on: https://chromium-review.googlesource.com/c/1350433
Commit-Queue: Matt Falkenhagen <falken@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Reviewed-by: Brian White <bcwhite@chromium.org>
Cr-Commit-Position: refs/heads/master@{#611474}
[modify] https://crrev.com/3e4375680f3a22e3942f6be02b62d5e2d9ac4559/content/browser/service_worker/service_worker_navigation_loader.cc
[modify] https://crrev.com/3e4375680f3a22e3942f6be02b62d5e2d9ac4559/content/renderer/service_worker/service_worker_subresource_loader.cc
[modify] https://crrev.com/3e4375680f3a22e3942f6be02b62d5e2d9ac4559/content/renderer/service_worker/service_worker_subresource_loader_unittest.cc
[modify] https://crrev.com/3e4375680f3a22e3942f6be02b62d5e2d9ac4559/tools/metrics/histograms/histograms.xml

Comment 26 by bugdroid1@chromium.org, Dec 4

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/b74246e6c5b0be281038718eb93a0ed70e7ff6ed

commit b74246e6c5b0be281038718eb93a0ed70e7ff6ed
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Tue Dec 04 11:42:18 2018

Add response source field in FetchAPIResponse

We've done an early analysis of new histograms for service worker load timing
and realized that we need further breakdown. Specifically we'd like to have
breakdown of loading time by response source (e.g. from network, HttpCache,
CacheStorage). This CL adds the source of a response so that we can record
response load time separately based on their sources. Currently the source is
set in following cases (otherwise the source is unspecified):
- response from fetch(). In this case the source could be either kNetwork or
  kHttpCache.
- response from Cache#match() or Cache#matchAll(). In this case the source is
  kCacheStorage.

This CL doesn't add histograms but follow-up CLs will add them.

This CL based on wanderview@'s CL [1]. For those who are curious about why we
need to touch a number of files, see [2] for how we populate information from
blink to content. You may also wonder why we can't use existing fields in
ResourceResponseInfo like |was_fetched_via_cache|. The answer is that service
worker URLLoaders (SWNavigationLoader and SWSubresourceLoader) create
ResourceResponseInfo from FetchResponseAPI, as [2] implies.

[1] https://crrev.com/c/1194765
[2] https://drive.google.com/file/d/16ITKnTM63_5Y2GTEBzmCJh_7cqm_MQtL/view?usp=sharing

Change-Id: I2f8d1ab80257fb4511424bc9bcb0f24d37a8b46e
Bug: 877972
Reviewed-on: https://chromium-review.googlesource.com/c/1358100
Reviewed-by: Kinuko Yasuda <kinuko@chromium.org>
Reviewed-by: Yutaka Hirano <yhirano@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Reviewed-by: Makoto Shimazu <shimazu@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#613512}
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/content/browser/cache_storage/cache_storage_cache.cc
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/content/browser/cache_storage/cache_storage_cache_unittest.cc
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/content/browser/cache_storage/cache_storage_manager_unittest.cc
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/content/browser/service_worker/service_worker_browsertest.cc
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/content/common/background_fetch/background_fetch_types.cc
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/content/renderer/service_worker/service_worker_type_util.cc
[add] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/content/test/data/service_worker/http_cache.html
[add] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/content/test/data/service_worker/http_cache.html.mock-http-headers
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/services/network/public/mojom/fetch_api.mojom
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/third_party/blink/public/mojom/fetch/fetch_api_response.mojom
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/third_party/blink/public/platform/modules/service_worker/web_service_worker_response.h
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/third_party/blink/renderer/core/fetch/fetch_manager.cc
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/third_party/blink/renderer/core/fetch/fetch_response_data.cc
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/third_party/blink/renderer/core/fetch/fetch_response_data.h
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/third_party/blink/renderer/core/fetch/response.cc
[modify] https://crrev.com/b74246e6c5b0be281038718eb93a0ed70e7ff6ed/third_party/blink/renderer/platform/exported/web_service_worker_response.cc

Comment 27 by bugdroid1@chromium.org, Dec 7

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/076901524c18ebf5b9736c86a8dd6bdf5c976222

commit 076901524c18ebf5b9736c86a8dd6bdf5c976222
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Fri Dec 07 01:31:15 2018

service worker: Fix inconsistencies in fetch timing histograms

In https://crrev.com/c/1350433 I updated some histograms for fetch
resource timing. The intention was to change the upper limit of these
histogram from 10 secs to 3 mins but I wrongly updated histograms.xml.
Specifically I should have updated histograms.xml like:
- MainResource.ForwardServiceWorkerToWorkerReady
  -> MainResource.ForwardServiceWorkerToWorkerReady2
- Subresource.ResponseReceivedToCompleted
  -> Subresource.ResponseReceivedToCompleted2

But what I did was:
- MainResource.ResponseReceivedToCompleted
  -> MainResource.ResponseReceivedToCompleted2
- Subresource.ForwardServiceWorkerToWorkerReady
  -> Subresource.ForwardServiceWorkerToWorkerReady2

This CL fixes the inconsistencies. As for ResponseReceivedToCompleted,
it would be better to use 3 mins upper limit so I added it for main
resource.

Bug: 877972
Change-Id: Ic28b5c523de7f4c150ca9cd79bf183ff37e2667d
Reviewed-on: https://chromium-review.googlesource.com/c/1364931
Reviewed-by: Brian White <bcwhite@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#614565}
[modify] https://crrev.com/076901524c18ebf5b9736c86a8dd6bdf5c976222/content/browser/service_worker/service_worker_navigation_loader.cc
[modify] https://crrev.com/076901524c18ebf5b9736c86a8dd6bdf5c976222/content/browser/service_worker/service_worker_navigation_loader_unittest.cc
[modify] https://crrev.com/076901524c18ebf5b9736c86a8dd6bdf5c976222/tools/metrics/histograms/histograms.xml

Comment 28 by bugdroid1@chromium.org, Dec 10

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/e42a9dc939cf083d7e5a040eefeb94f0157cd626

commit e42a9dc939cf083d7e5a040eefeb94f0157cd626
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Mon Dec 10 23:51:43 2018

service worker: Add UMAs for subresource response body read time

This is a follow-up CL of https://crrev.com/c/1358100. Adds
breakdown histograms for time taken reading subresource response body
by its source.

This CL also updates
ServiceWorker.LoadTiming.Subresource.ResponseReceivedToCompleted.
This was obsoleted and ResponseReceivedToCompleted2 was added
in https://crrev.com/c/1350433 but I forgot to update histograms.xml.

Change-Id: Ic9feb36ca1c10a341edb8bb73ca76afc968dbbcd
Bug: 877972
Reviewed-on: https://chromium-review.googlesource.com/c/1363732
Reviewed-by: Ilya Sherman <isherman@chromium.org>
Reviewed-by: Makoto Shimazu <shimazu@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#615330}
[modify] https://crrev.com/e42a9dc939cf083d7e5a040eefeb94f0157cd626/content/renderer/service_worker/service_worker_subresource_loader.cc
[modify] https://crrev.com/e42a9dc939cf083d7e5a040eefeb94f0157cd626/content/renderer/service_worker/service_worker_subresource_loader.h
[modify] https://crrev.com/e42a9dc939cf083d7e5a040eefeb94f0157cd626/content/renderer/service_worker/service_worker_subresource_loader_unittest.cc
[modify] https://crrev.com/e42a9dc939cf083d7e5a040eefeb94f0157cd626/tools/metrics/histograms/histograms.xml

Comment 29 by bugdroid1@chromium.org, Jan 7

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/8965dbacb189a98b51abd6298fd432bb9dfa0342

commit 8965dbacb189a98b51abd6298fd432bb9dfa0342
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Mon Jan 07 22:41:16 2019

service worker: Add breakdown UMAs for response reading time of navigation

This is similar to https://crrev.com/c/1363732 but for main frame
navigation.

Bug: 877972
Change-Id: I8d2875b205aae13e36e5d2323b2b873213c80875
Reviewed-on: https://chromium-review.googlesource.com/c/1396010
Reviewed-by: Jesse Doherty <jwd@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#620509}
[modify] https://crrev.com/8965dbacb189a98b51abd6298fd432bb9dfa0342/content/browser/service_worker/service_worker_navigation_loader.cc
[modify] https://crrev.com/8965dbacb189a98b51abd6298fd432bb9dfa0342/content/browser/service_worker/service_worker_navigation_loader.h
[modify] https://crrev.com/8965dbacb189a98b51abd6298fd432bb9dfa0342/content/common/service_worker/service_worker_utils.cc
[modify] https://crrev.com/8965dbacb189a98b51abd6298fd432bb9dfa0342/content/common/service_worker/service_worker_utils.h
[modify] https://crrev.com/8965dbacb189a98b51abd6298fd432bb9dfa0342/content/renderer/service_worker/service_worker_subresource_loader.cc
[modify] https://crrev.com/8965dbacb189a98b51abd6298fd432bb9dfa0342/tools/metrics/histograms/histograms.xml

Comment 30 by bugdroid1@chromium.org, Jan 8

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/f634ccd9c814489b06fe58263e59ecbf55527cb2

commit f634ccd9c814489b06fe58263e59ecbf55527cb2
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Tue Jan 08 05:22:55 2019

service worker: Fix fetch timing UMA recording for subresource loading

Before this CL there was a path in ServiceWorkerSubresourceLoader
where we called RecordTimingMetrics(true) even when the request
fell back to network. Specifically:

OnFallback()
-> CommitEmptyResponseAndComplete()
-> CommitCompleted()
-> RecordTimingMetrics(true)

This generated bogus numbers for
ServiceWorker.LoadTiming.Subresource.ResponseReceivedToCompleted2.
This CL fixes it by updating CommitCompleted() to check a flag
that indicates that network fallback was requested.

Bug: 877972
Change-Id: Ia944903938b8a7daed1665475f4b2a871f2b21ab
Reviewed-on: https://chromium-review.googlesource.com/c/1397504
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Cr-Commit-Position: refs/heads/master@{#620631}
[modify] https://crrev.com/f634ccd9c814489b06fe58263e59ecbf55527cb2/content/renderer/service_worker/service_worker_subresource_loader.cc
[modify] https://crrev.com/f634ccd9c814489b06fe58263e59ecbf55527cb2/content/renderer/service_worker/service_worker_subresource_loader_unittest.cc

Comment 31 by bugdroid1@chromium.org, Jan 10

Project Member
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/e8c36a75a0448d1882cdc3537839389ea1008ae7

commit e8c36a75a0448d1882cdc3537839389ea1008ae7
Author: Kenichi Ishibashi <bashi@chromium.org>
Date: Thu Jan 10 02:01:38 2019

Remove is_in_cache_storage from FetchAPIResponse

We now have |response_source| in FetchAPIResponse and we can use
the response source to see whether the response comes from CacheStorage.

Bug: 877972
Change-Id: Ia3d749790b8a49da6764fa90d4e77125160e96ac
Reviewed-on: https://chromium-review.googlesource.com/c/1395864
Reviewed-by: Kinuko Yasuda <kinuko@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Commit-Queue: Kenichi Ishibashi <bashi@chromium.org>
Cr-Commit-Position: refs/heads/master@{#621418}
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/content/browser/cache_storage/cache_storage_cache.cc
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/content/browser/cache_storage/cache_storage_cache_unittest.cc
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/content/browser/cache_storage/cache_storage_manager_unittest.cc
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/content/browser/service_worker/service_worker_browsertest.cc
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/content/browser/service_worker/service_worker_url_request_job.cc
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/content/common/background_fetch/background_fetch_types.cc
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/content/common/service_worker/service_worker_loader_helpers.cc
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/content/renderer/service_worker/service_worker_subresource_loader_unittest.cc
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/content/renderer/service_worker/service_worker_type_util.cc
[modify] https://crrev.com/e8c36a75a0448d1882cdc3537839389ea1008ae7/third_party/blink/public/mojom/fetch/fetch_api_response.mojom

Sign in to add a comment