service worker: Add UMA for navigation preload response timing.

service worker: Add UMA for navigation preload response timing.

This should help understand how nav preload is doing in the wild:
whether it or sw startup is finishing first, and the timings for
concurrent startup and preload, and how long we end up waiting for one
after the other has finished.

Added are:
- ServiceWorker.NavigationPreload.ConcurrentTime: the time
when both startup and preload are happening concurrently
- ServiceWorker.NavigationPreload.FinishedBeforeStartWorker: indicates
which one finished first
- ServiceWorker.NavigationPreload.NavPreloadAfterSWStart: the
time spent waiting for nav preload to finish, after sw start finished
- ServiceWorker.NavigationPreload.SWStartAfterNavPreload: the reverse
- ServiceWorker.NavigationPreload.ResponseTime: the time it
took for the nav preload response to arrive

In addition, there are suffixed histograms of the above to break down
the timings in the two winner scenarios, and furthmore to see the
breakdowns in the interesting situation of when a SW needed to be
started up.

BUG=661090
Review-Url: https://codereview.chromium.org/2652603002
Cr-Commit-Position: refs/heads/master@{#445965}
Committed: https://chromium.googlesource.com/chromium/src/+/402d868859229cf42674996b82f3468922afc628

[falken, 2017-01-23 08:47:35]

The CQ bit was checked by falken@chromium.org to run a CQ dry run

[falken, 2017-01-23 08:47:43]

falken@chromium.org changed reviewers:
+ horo@chromium.org

[falken, 2017-01-23 08:47:43]

ptal

[commit-bot: I haz the power, 2017-01-23 08:47:50]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-23 09:41:43]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-23 09:41:44]

Dry run: Try jobs failed on following builders:
  win_chromium_x64_rel_ng on master.tryserver.chromium.win (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_x64_...)

[horo, 2017-01-24 01:48:33]

https://codereview.chromium.org/2652603002/diff/20001/content/browser/service...
File content/browser/service_worker/service_worker_metrics.cc (right):

https://codereview.chromium.org/2652603002/diff/20001/content/browser/service...
content/browser/service_worker/service_worker_metrics.cc:856: const bool
did_worker_startup =
nit:

|did_worker_startup_in_existing_process| may be better.

https://codereview.chromium.org/2652603002/diff/20001/content/browser/service...
File content/browser/service_worker/service_worker_url_request_job.cc (right):

https://codereview.chromium.org/2652603002/diff/20001/content/browser/service...
content/browser/service_worker/service_worker_url_request_job.cc:908: // Don't
expect this to happen, but don't ruin the UMA if it does.
Do we actually need this check??
I think DCHECK() is enough.

[danielmgriffin81, 2017-01-24 04:39:14]

danielmgriffin81@gmail.com changed reviewers:
+ danielmgriffin81@gmail.com

[falken, 2017-01-24 04:41:17]

falken@chromium.org changed reviewers:
- danielmgriffin81@gmail.com

[falken, 2017-01-24 04:41:18]

Thank you.

https://codereview.chromium.org/2652603002/diff/20001/content/browser/service...
File content/browser/service_worker/service_worker_metrics.cc (right):

https://codereview.chromium.org/2652603002/diff/20001/content/browser/service...
content/browser/service_worker/service_worker_metrics.cc:856: const bool
did_worker_startup =
On 2017/01/24 01:48:33, horo wrote:
> nit:
> 
> |did_worker_startup_in_existing_process| may be better.

Revised.

https://codereview.chromium.org/2652603002/diff/20001/content/browser/service...
File content/browser/service_worker/service_worker_url_request_job.cc (right):

https://codereview.chromium.org/2652603002/diff/20001/content/browser/service...
content/browser/service_worker/service_worker_url_request_job.cc:908: // Don't
expect this to happen, but don't ruin the UMA if it does.
On 2017/01/24 01:48:33, horo wrote:
> Do we actually need this check??
> I think DCHECK() is enough.

I wasn't sure if OnReceivedResposne() is gauranteed to be called only once. I
revised it to use OnceCallback so the callback wouldn't be called again if that
happens.

[horo, 2017-01-24 05:42:24]

lgtm

[falken, 2017-01-24 05:53:27]

falken@chromium.org changed reviewers:
+ jwd@chromium.org

[falken, 2017-01-24 05:53:28]

jwd: can you review histograms?

[falken, 2017-01-24 05:53:39]

The CQ bit was checked by falken@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2017-01-24 05:53:53]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-24 08:36:10]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-24 08:36:11]

Dry run: Try jobs failed on following builders:
  mac_chromium_rel_ng on master.tryserver.chromium.mac (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.mac/builders/mac_chromium_rel_...)

[jwd, 2017-01-24 21:43:37]

lgtm

[falken, 2017-01-24 22:37:32]

The CQ bit was checked by falken@chromium.org

[commit-bot: I haz the power, 2017-01-24 22:38:18]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-24 22:46:38]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-24 22:46:39]

Try jobs failed on following builders:
  chromium_presubmit on master.tryserver.chromium.linux (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.linux/builders/chromium_presub...)

[falken, 2017-01-24 23:25:28]

The CQ bit was checked by falken@chromium.org

[commit-bot: I haz the power, 2017-01-24 23:26:22]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-25 00:47:21]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-25 00:47:22]

Try jobs failed on following builders:
  mac_chromium_rel_ng on master.tryserver.chromium.mac (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.mac/builders/mac_chromium_rel_...)

[falken, 2017-01-25 00:57:33]

The CQ bit was checked by falken@chromium.org

[commit-bot: I haz the power, 2017-01-25 00:58:32]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-25 02:04:37]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-25 02:04:38]

Failed to apply patch for
content/browser/service_worker/service_worker_fetch_dispatcher.cc:
While running git apply --index -p1;
  error: patch failed:
content/browser/service_worker/service_worker_fetch_dispatcher.cc:97
  error: content/browser/service_worker/service_worker_fetch_dispatcher.cc:
patch does not apply

Patch:       content/browser/service_worker/service_worker_fetch_dispatcher.cc
Index: content/browser/service_worker/service_worker_fetch_dispatcher.cc
diff --git a/content/browser/service_worker/service_worker_fetch_dispatcher.cc
b/content/browser/service_worker/service_worker_fetch_dispatcher.cc
index
85cf9d7db3ad27aae10f29f51f41cb6f0955f03d..5cf2c8e08d1cacfa82a25a0ef689c235dbae8bd2
100644
--- a/content/browser/service_worker/service_worker_fetch_dispatcher.cc
+++ b/content/browser/service_worker/service_worker_fetch_dispatcher.cc
@@ -73,8 +73,11 @@ class DelegatingURLLoader final : public mojom::URLLoader {
 // wrapped client.
 class DelegatingURLLoaderClient final : public mojom::URLLoaderClient {
  public:
-  explicit DelegatingURLLoaderClient(mojom::URLLoaderClientPtr client)
-      : binding_(this), client_(std::move(client)) {}
+  explicit DelegatingURLLoaderClient(mojom::URLLoaderClientPtr client,
+                                     base::OnceClosure on_response)
+      : binding_(this),
+        client_(std::move(client)),
+        on_response_(std::move(on_response)) {}
   ~DelegatingURLLoaderClient() override {
     if (!completed_) {
       // Let the service worker know that the request has been canceled.
@@ -97,6 +100,8 @@ class DelegatingURLLoaderClient final : public
mojom::URLLoaderClient {
       const ResourceResponseHead& head,
       mojom::DownloadedTempFilePtr downloaded_file) override {
     client_->OnReceiveResponse(head, std::move(downloaded_file));
+    DCHECK(on_response_);
+    std::move(on_response_).Run();
   }
   void OnReceiveRedirect(const net::RedirectInfo& redirect_info,
                          const ResourceResponseHead& head) override {
@@ -120,6 +125,7 @@ class DelegatingURLLoaderClient final : public
mojom::URLLoaderClient {
  private:
   mojo::AssociatedBinding<mojom::URLLoaderClient> binding_;
   mojom::URLLoaderClientPtr client_;
+  base::OnceClosure on_response_;
   bool completed_ = false;
 
   DISALLOW_COPY_AND_ASSIGN(DelegatingURLLoaderClient);
@@ -402,7 +408,8 @@ void ServiceWorkerFetchDispatcher::Complete(
 }
 
 bool ServiceWorkerFetchDispatcher::MaybeStartNavigationPreload(
-    net::URLRequest* original_request) {
+    net::URLRequest* original_request,
+    base::OnceClosure on_response) {
   if (resource_type_ != RESOURCE_TYPE_MAIN_FRAME &&
       resource_type_ != RESOURCE_TYPE_SUB_FRAME) {
     return false;
@@ -476,7 +483,7 @@ bool
ServiceWorkerFetchDispatcher::MaybeStartNavigationPreload(
   preload_handle_->url_loader_client_request =
       mojo::MakeRequest(&url_loader_client_ptr);
   auto url_loader_client = base::MakeUnique<DelegatingURLLoaderClient>(
-      std::move(url_loader_client_ptr));
+      std::move(url_loader_client_ptr), std::move(on_response));
   mojom::URLLoaderClientAssociatedPtrInfo
url_loader_client_associated_ptr_info;
   url_loader_client->Bind(&url_loader_client_associated_ptr_info,
                           url_loader_factory.associated_group());

[falken, 2017-01-25 03:03:28]

The CQ bit was checked by falken@chromium.org

[falken, 2017-01-25 03:03:28]

The patchset sent to the CQ was uploaded after l-g-t-m from jwd@chromium.org,
horo@chromium.org
Link to the patchset: https://codereview.chromium.org/2652603002/#ps80001
(title: "patch for landing?")

[commit-bot: I haz the power, 2017-01-25 03:04:06]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-25 04:42:04]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-25 04:42:06]

Try jobs failed on following builders:
  linux_android_rel_ng on master.tryserver.chromium.android (JOB_FAILED,
https://build.chromium.org/p/tryserver.chromium.android/builders/linux_androi...)

[falken, 2017-01-25 04:46:27]

On 2017/01/25 04:42:06, commit-bot: I haz the power wrote:
> Try jobs failed on following builders:
>   linux_android_rel_ng on master.tryserver.chromium.android (JOB_FAILED,
>
https://build.chromium.org/p/tryserver.chromium.android/builders/linux_androi...)

Fifth's time's a charm?

[falken, 2017-01-25 04:46:34]

The CQ bit was checked by falken@chromium.org

[commit-bot: I haz the power, 2017-01-25 04:47:02]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-25 06:11:21]

CQ is committing da patch.

Bot data: {"patchset_id": 80001, "attempt_start_ts": 1485319594635820,
"parent_rev": "c767da1904a215d821f211fc01cd5a1da0096858", "commit_rev":
"402d868859229cf42674996b82f3468922afc628"}

[commit-bot: I haz the power, 2017-01-25 06:12:32]

Description was changed from

==========
service worker: Add UMA for navigation preload response timing.

This should help understand how nav preload is doing in the wild:
whether it or sw startup is finishing first, and the timings for
concurrent startup and preload, and how long we end up waiting for one
after the other has finished.

Added are:
- ServiceWorker.NavigationPreload.ConcurrentTime: the time
when both startup and preload are happening concurrently
- ServiceWorker.NavigationPreload.FinishedBeforeStartWorker: indicates
which one finished first
- ServiceWorker.NavigationPreload.NavPreloadAfterSWStart: the
time spent waiting for nav preload to finish, after sw start finished
- ServiceWorker.NavigationPreload.SWStartAfterNavPreload: the reverse
- ServiceWorker.NavigationPreload.ResponseTime: the time it
took for the nav preload response to arrive

In addition, there are suffixed histograms of the above to break down
the timings in the two winner scenarios, and furthmore to see the
breakdowns in the interesting situation of when a SW needed to be
started up.

BUG=661090
==========

to

==========
service worker: Add UMA for navigation preload response timing.

This should help understand how nav preload is doing in the wild:
whether it or sw startup is finishing first, and the timings for
concurrent startup and preload, and how long we end up waiting for one
after the other has finished.

Added are:
- ServiceWorker.NavigationPreload.ConcurrentTime: the time
when both startup and preload are happening concurrently
- ServiceWorker.NavigationPreload.FinishedBeforeStartWorker: indicates
which one finished first
- ServiceWorker.NavigationPreload.NavPreloadAfterSWStart: the
time spent waiting for nav preload to finish, after sw start finished
- ServiceWorker.NavigationPreload.SWStartAfterNavPreload: the reverse
- ServiceWorker.NavigationPreload.ResponseTime: the time it
took for the nav preload response to arrive

In addition, there are suffixed histograms of the above to break down
the timings in the two winner scenarios, and furthmore to see the
breakdowns in the interesting situation of when a SW needed to be
started up.

BUG=661090

Review-Url: https://codereview.chromium.org/2652603002
Cr-Commit-Position: refs/heads/master@{#445965}
Committed:
https://chromium.googlesource.com/chromium/src/+/402d868859229cf42674996b82f3...
==========

[commit-bot: I haz the power, 2017-01-25 06:12:33]

Committed patchset #5 (id:80001) as
https://chromium.googlesource.com/chromium/src/+/402d868859229cf42674996b82f3...