Introduce ServiceWorker.EventDispatchingDelay UMA

content/browser/service_worker/service_worker_metrics.cc

 // Copyright 2014 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "content/browser/service_worker/service_worker_metrics.h"
 
 #include <limits>
 #include <string>
 
 #include "base/metrics/histogram_macros.h"
@@ skipping 92 matching lines @@
       return "_StartingWorker";
     case EmbeddedWorkerStatus::RUNNING:
       return "_RunningWorker";
     case EmbeddedWorkerStatus::STOPPING:
       return "_StoppingWorker";
   }
   NOTREACHED();
   return "_UNKNOWN";
 }
 
+std::string GetSiteSuffix(ServiceWorkerMetrics::Site site) {
+  switch (site) {
+    case ServiceWorkerMetrics::Site::OTHER:
+    case ServiceWorkerMetrics::Site::WITH_FETCH_HANDLER:
+    case ServiceWorkerMetrics::Site::WITHOUT_FETCH_HANDLER:
+      return "";
+    case ServiceWorkerMetrics::Site::NEW_TAB_PAGE:
+      return ".ntp";
+    case ServiceWorkerMetrics::Site::PLUS:
+      return ".plus";
+    case ServiceWorkerMetrics::Site::INBOX:
+      return ".inbox";
+    case ServiceWorkerMetrics::Site::DOCS:
+      return ".docs";
+    case ServiceWorkerMetrics::Site::NUM_TYPES:
+      NOTREACHED() << static_cast<int>(site);
+  }
+  NOTREACHED();
+  return "";
+}
+
 // Use this for histograms with dynamically generated names, which
 // otherwise can't use the UMA_HISTOGRAM macro without code duplication.
 void RecordSuffixedTimeHistogram(const std::string& name,
                                  const std::string& suffix,
                                  base::TimeDelta sample) {
   const std::string name_with_suffix = name + suffix;
+  // This unrolls UMA_HISTOGRAM_TIMES.
+  base::HistogramBase* histogram_pointer = base::Histogram::FactoryTimeGet(
+      name_with_suffix, base::TimeDelta::FromMilliseconds(1),
+      base::TimeDelta::FromSeconds(10), 50,
+      base::HistogramBase::kUmaTargetedHistogramFlag);
+  histogram_pointer->AddTime(sample);
+}
+
+// Use this for histograms with dynamically generated names, which
+// otherwise can't use the UMA_MEDIUM_HISTOGRAM macro without code duplication.
+void RecordSuffixedMediumTimeHistogram(const std::string& name,
+                                       const std::string& suffix,
+                                       base::TimeDelta sample) {
+  const std::string name_with_suffix = name + suffix;
   // This unrolls UMA_HISTOGRAM_MEDIUM_TIMES.
   base::HistogramBase* histogram_pointer = base::Histogram::FactoryTimeGet(
       name_with_suffix, base::TimeDelta::FromMilliseconds(10),
       base::TimeDelta::FromMinutes(3), 50,
       base::HistogramBase::kUmaTargetedHistogramFlag);
   histogram_pointer->AddTime(sample);
 }
 
 // Use this for histograms with dynamically generated names, which
 // otherwise can't use the UMA_HISTOGRAM macro without code duplication.
@@ skipping 200 matching lines @@
   }
 }
 
 void ServiceWorkerMetrics::RecordStartWorkerTime(base::TimeDelta time,
                                                  bool is_installed,
                                                  StartSituation start_situation,
                                                  EventType purpose) {
   if (is_installed) {
     std::string name = "ServiceWorker.StartWorker.Time";
     UMA_HISTOGRAM_MEDIUM_TIMES(name, time);
-    RecordSuffixedTimeHistogram(name, StartSituationToSuffix(start_situation),
-                                time);
-    RecordSuffixedTimeHistogram(
+    RecordSuffixedMediumTimeHistogram(
+        name, StartSituationToSuffix(start_situation), time);
+    RecordSuffixedMediumTimeHistogram(
         "ServiceWorker.StartWorker.Time",
         StartSituationToSuffix(start_situation) + EventTypeToSuffix(purpose),
         time);
   } else {
     UMA_HISTOGRAM_MEDIUM_TIMES("ServiceWorker.StartNewWorker.Time", time);
   }
 }
 
 void ServiceWorkerMetrics::RecordActivatedWorkerPreparationTimeForMainFrame(
     base::TimeDelta time,
     EmbeddedWorkerStatus initial_worker_status,
     StartSituation start_situation) {
   std::string name =
       "ServiceWorker.ActivatedWorkerPreparationForMainFrame.Time";
   UMA_HISTOGRAM_MEDIUM_TIMES(name, time);
-  RecordSuffixedTimeHistogram(
+  RecordSuffixedMediumTimeHistogram(
       name, GetWorkerPreparationSuffix(initial_worker_status, start_situation),
       time);
 }
 
 void ServiceWorkerMetrics::RecordWorkerStopped(StopStatus status) {
   UMA_HISTOGRAM_ENUMERATION("ServiceWorker.WorkerStopped",
                             static_cast<int>(status),
                             static_cast<int>(StopStatus::NUM_TYPES));
 }
 
@@ skipping 45 matching lines @@
       UMA_HISTOGRAM_ENUMERATION(
           "ServiceWorker.EventHandledRatioType.ForeignFetch", type,
           NUM_EVENT_HANDLED_RATIO_TYPE);
       break;
     default:
       // Do nothing.
       break;
   }
 }
 
+void ServiceWorkerMetrics::RecordFetchEventDispatchingDelay(

[shimazu, 2016/08/18 04:58:53]

I think this could be open to other events. 
If doing so, |start_dispatching_time| can be an additional argument of
SWVersion::OnSimpleEventResponse and it can be recorded in 
ServiceWorkerMetrics::RecordEventDuration.

How do you think?

[horo, 2016/08/22 14:57:35]

Done.

+    base::TimeDelta time,
+    Site site_for_metrics) {
+  const std::string name = "ServiceWorker.FetchEvent.DispatchingDelay";
+  UMA_HISTOGRAM_TIMES(name, time);
+  const std::string site_suffix = GetSiteSuffix(site_for_metrics);
+  if (!site_suffix.empty())
+    RecordSuffixedTimeHistogram(name, site_suffix, time);
+}
+
 void ServiceWorkerMetrics::RecordNavigationHintPrecision(
     EventType start_worker_purpose,
     bool frame_fetch_event_fired) {
   DCHECK(IsNavigationHintEvent(start_worker_purpose));
   UMA_HISTOGRAM_BOOLEAN("ServiceWorker.NavigationHintPrecision",
                         frame_fetch_event_fired);
   switch (start_worker_purpose) {
     case EventType::NAVIGATION_HINT_LINK_MOUSE_DOWN:
       UMA_HISTOGRAM_BOOLEAN(
           "ServiceWorker.NavigationHintPrecision.LINK_MOUSE_DOWN",
@@ skipping 141 matching lines @@
 void ServiceWorkerMetrics::RecordProcessCreated(bool is_new_process) {
   UMA_HISTOGRAM_BOOLEAN("EmbeddedWorkerInstance.ProcessCreated",
                         is_new_process);
 }
 
 void ServiceWorkerMetrics::RecordTimeToSendStartWorker(
     base::TimeDelta duration,
     StartSituation situation) {
   std::string name = "EmbeddedWorkerInstance.Start.TimeToSendStartWorker";
   UMA_HISTOGRAM_MEDIUM_TIMES(name, duration);
-  RecordSuffixedTimeHistogram(name, StartSituationToSuffix(situation),
-                              duration);
+  RecordSuffixedMediumTimeHistogram(name, StartSituationToSuffix(situation),
+                                    duration);
 }
 
 void ServiceWorkerMetrics::RecordTimeToURLJob(base::TimeDelta duration,
                                               StartSituation situation) {
   std::string name = "EmbeddedWorkerInstance.Start.TimeToURLJob";
   UMA_HISTOGRAM_MEDIUM_TIMES(name, duration);
-  RecordSuffixedTimeHistogram(name, StartSituationToSuffix(situation),
-                              duration);
+  RecordSuffixedMediumTimeHistogram(name, StartSituationToSuffix(situation),
+                                    duration);
 }
 
 void ServiceWorkerMetrics::RecordTimeToLoad(base::TimeDelta duration,
                                             LoadSource source,
                                             StartSituation situation) {
   std::string name;
   switch (source) {
     case LoadSource::NETWORK:
       name = "EmbeddedWorkerInstance.Start.TimeToLoad.Network";
       UMA_HISTOGRAM_MEDIUM_TIMES(name, duration);
-      RecordSuffixedTimeHistogram(name, StartSituationToSuffix(situation),
-                                  duration);
+      RecordSuffixedMediumTimeHistogram(name, StartSituationToSuffix(situation),
+                                        duration);
       break;
     case LoadSource::HTTP_CACHE:
       name = "EmbeddedWorkerInstance.Start.TimeToLoad.HttpCache";
       UMA_HISTOGRAM_MEDIUM_TIMES(name, duration);
-      RecordSuffixedTimeHistogram(name, StartSituationToSuffix(situation),
-                                  duration);
+      RecordSuffixedMediumTimeHistogram(name, StartSituationToSuffix(situation),
+                                        duration);
       break;
     case LoadSource::SERVICE_WORKER_STORAGE:
       name = "EmbeddedWorkerInstance.Start.TimeToLoad.InstalledScript";
       UMA_HISTOGRAM_MEDIUM_TIMES(name, duration);
-      RecordSuffixedTimeHistogram(name, StartSituationToSuffix(situation),
-                                  duration);
+      RecordSuffixedMediumTimeHistogram(name, StartSituationToSuffix(situation),
+                                        duration);
       break;
     default:
       NOTREACHED() << static_cast<int>(source);
   }
 }
 
 void ServiceWorkerMetrics::RecordTimeToStartThread(base::TimeDelta duration,
                                                    StartSituation situation) {
   std::string name = "EmbeddedWorkerInstance.Start.TimeToStartThread";
   UMA_HISTOGRAM_MEDIUM_TIMES(name, duration);
-  RecordSuffixedTimeHistogram(name, StartSituationToSuffix(situation),
-                              duration);
+  RecordSuffixedMediumTimeHistogram(name, StartSituationToSuffix(situation),
+                                    duration);
 }
 
 void ServiceWorkerMetrics::RecordTimeToEvaluateScript(
     base::TimeDelta duration,
     StartSituation situation) {
   std::string name = "EmbeddedWorkerInstance.Start.TimeToEvaluateScript";
   UMA_HISTOGRAM_MEDIUM_TIMES(name, duration);
-  RecordSuffixedTimeHistogram(name, StartSituationToSuffix(situation),
-                              duration);
+  RecordSuffixedMediumTimeHistogram(name, StartSituationToSuffix(situation),
+                                    duration);
 }
 
 const char* ServiceWorkerMetrics::LoadSourceToString(LoadSource source) {
   switch (source) {
     case LoadSource::NETWORK:
       return "Network";
     case LoadSource::HTTP_CACHE:
       return "HTTP cache";
     case LoadSource::SERVICE_WORKER_STORAGE:
       return "Service worker storage";
@@ skipping 31 matching lines @@
   } else if (failure_count == 2) {
     UMA_HISTOGRAM_ENUMERATION("ServiceWorker.StartWorker.AfterFailureStreak_2",
                               status, SERVICE_WORKER_ERROR_MAX_VALUE);
   } else if (failure_count == 3) {
     UMA_HISTOGRAM_ENUMERATION("ServiceWorker.StartWorker.AfterFailureStreak_3",
                               status, SERVICE_WORKER_ERROR_MAX_VALUE);
   }
 }
 
 }  // namespace content