Add sub-metrics for Event.Latency.TouchToFirstScrollUpdateSwapBegin

content/browser/renderer_host/input/render_widget_host_latency_tracker.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/renderer_host/input/render_widget_host_latency_tracker.h"
 
 #include <stddef.h>
 
 #include "base/logging.h"
 #include "base/metrics/histogram_macros.h"
@@ skipping 55 matching lines @@
   } else if (WebInputEvent::isTouchEventType(event.type)) {
     UpdateLatencyCoordinatesImpl(static_cast<const WebTouchEvent&>(event),
                                  latency, device_scale_factor);
   } else if (event.type == WebInputEvent::MouseWheel) {
     UpdateLatencyCoordinatesImpl(static_cast<const WebMouseWheelEvent&>(event),
                                  latency, device_scale_factor);
   }
 }
 
 // Touch to scroll latency that is mostly under 1 second.
-#define UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY(name, start, end)               \
+#define UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY(is_first, name, start, end)     \
   UMA_HISTOGRAM_CUSTOM_COUNTS(                                                \
-      name, (end.event_time - start.event_time).InMicroseconds(), 1, 1000000, \
-      100)
+      base::StringPrintf(name, ""),                                           \

[tdresser, 2016/09/08 15:17:25]

Do we need this StringPrintf? Couldn't we just pass name?

+      (end.event_time - start.event_time).InMicroseconds(), 1, 1000000, 100); \
+  if (is_first) {                                                             \
+    UMA_HISTOGRAM_CUSTOM_COUNTS(                                              \
+        base::StringPrintf(name, "First"),                                    \
+        (end.event_time - start.event_time).InMicroseconds(), 1, 1000000,     \
+        100);                                                                 \
+  }
 
 // Long scroll latency component that is mostly under 200ms.
-#define UMA_HISTOGRAM_SCROLL_LATENCY_LONG(name, start, end)        \
-  UMA_HISTOGRAM_CUSTOM_COUNTS(                                     \
-    name,                                                          \
-    (end.event_time - start.event_time).InMicroseconds(),          \
-    1000, 200000, 50)
+#define UMA_HISTOGRAM_SCROLL_LATENCY_LONG(is_first, name, start, end)          \
+  UMA_HISTOGRAM_CUSTOM_COUNTS(                                                 \
+      base::StringPrintf(name, ""),                                            \
+      (end.event_time - start.event_time).InMicroseconds(), 1000, 200000, 50); \
+  if (is_first) {                                                              \
+    UMA_HISTOGRAM_CUSTOM_COUNTS(                                               \
+        base::StringPrintf(name, "First"),                                     \
+        (end.event_time - start.event_time).InMicroseconds(), 1000, 200000,    \
+        50);                                                                   \
+  }
 
 // Short scroll latency component that is mostly under 50ms.
-#define UMA_HISTOGRAM_SCROLL_LATENCY_SHORT(name, start, end)       \
-  UMA_HISTOGRAM_CUSTOM_COUNTS(                                     \
-    name,                                                          \
-    (end.event_time - start.event_time).InMicroseconds(),          \
-    1, 50000, 50)
+#define UMA_HISTOGRAM_SCROLL_LATENCY_SHORT(is_first, name, start, end)       \
+  UMA_HISTOGRAM_CUSTOM_COUNTS(                                               \
+      base::StringPrintf(name, ""),                                          \
+      (end.event_time - start.event_time).InMicroseconds(), 1, 50000, 50);   \
+  if (is_first) {                                                            \
+    UMA_HISTOGRAM_CUSTOM_COUNTS(                                             \
+        base::StringPrintf(name, "First"),                                   \
+        (end.event_time - start.event_time).InMicroseconds(), 1, 50000, 50); \
+  }
 
 void ComputeScrollLatencyHistograms(
     const LatencyInfo::LatencyComponent& gpu_swap_begin_component,
     const LatencyInfo::LatencyComponent& gpu_swap_end_component,
     int64_t latency_component_id,
     const LatencyInfo& latency,
     bool is_running_navigation_hint_task) {
   DCHECK(!latency.coalesced());
   if (latency.coalesced())
     return;
 
   DCHECK(!gpu_swap_begin_component.event_time.is_null());
   DCHECK(!gpu_swap_end_component.event_time.is_null());
   LatencyInfo::LatencyComponent original_component;
+  bool is_first_scroll = false;
   if (latency.FindLatency(
           ui::INPUT_EVENT_LATENCY_FIRST_SCROLL_UPDATE_ORIGINAL_COMPONENT,
           latency_component_id, &original_component)) {
-    // This UMA metric tracks the time between the final frame swap for the
-    // first scroll event in a sequence and the original timestamp of that
-    // scroll event's underlying touch event.
-    for (size_t i = 0; i < original_component.event_count; i++) {
-      UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY(
-          "Event.Latency.TouchToFirstScrollUpdateSwapBegin",
-          original_component, gpu_swap_begin_component);
-    }
-    // TODO(horo): IsRunningNavigationHintTask UMAs are only for
-    // SpeculativeLaunchServiceWorker experimentation. So remove this UMA when
-    // the experimentation finished (crbug.com/638827).
-    if (is_running_navigation_hint_task) {
-      for (size_t i = 0; i < original_component.event_count; i++) {
-        UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY(
-            "Event.Latency.TouchToFirstScrollUpdateSwapBegin_"
-            "IsRunningNavigationHintTask",
-            original_component, gpu_swap_begin_component);
-      }
-    }
+    is_first_scroll = true;
   } else if (!latency.FindLatency(
                  ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT,
                  latency_component_id, &original_component)) {
     return;
   }
 
   // This UMA metric tracks the time from when the original touch event is
   // created to when the scroll gesture results in final frame swap.
   for (size_t i = 0; i < original_component.event_count; i++) {
     UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY(
-        "Event.Latency.TouchToScrollUpdateSwapBegin", original_component,
-        gpu_swap_begin_component);
+        is_first_scroll, "Event.Latency.TouchTo%sScrollUpdateSwapBegin",
+        original_component, gpu_swap_begin_component);
   }
   // TODO(horo): IsRunningNavigationHintTask UMAs are only for
   // SpeculativeLaunchServiceWorker experimentation. So remove this UMA when
   // the experimentation finished (crbug.com/638827).
   if (is_running_navigation_hint_task) {
     for (size_t i = 0; i < original_component.event_count; i++) {
       UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY(
-          "Event.Latency.TouchToScrollUpdateSwapBegin_"
+          is_first_scroll,
+          "Event.Latency.TouchTo%sScrollUpdateSwapBegin_"
           "IsRunningNavigationHintTask",
           original_component, gpu_swap_begin_component);
     }
   }
 
-  // TODO(miletus): Add validation for making sure the following components
-  // are present and their event times are legit.
   LatencyInfo::LatencyComponent rendering_scheduled_component;
   bool rendering_scheduled_on_main = latency.FindLatency(
       ui::INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_MAIN_COMPONENT,
       0, &rendering_scheduled_component);
 
   if (!rendering_scheduled_on_main) {
     if (!latency.FindLatency(
-            ui::INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_IMPL_COMPONENT,
-            0, &rendering_scheduled_component))
+            ui::INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_IMPL_COMPONENT, 0,
+            &rendering_scheduled_component)) {
       return;
+    }
   }
 
   if (rendering_scheduled_on_main) {
     UMA_HISTOGRAM_SCROLL_LATENCY_LONG(
-        "Event.Latency.ScrollUpdate.TouchToHandled_Main",
+        is_first_scroll, "Event.Latency.%sScrollUpdate.TouchToHandled_Main",
         original_component, rendering_scheduled_component);
   } else {
     UMA_HISTOGRAM_SCROLL_LATENCY_LONG(
-        "Event.Latency.ScrollUpdate.TouchToHandled_Impl",
+        is_first_scroll, "Event.Latency.%sScrollUpdate.TouchToHandled_Impl",
         original_component, rendering_scheduled_component);
   }
 
   LatencyInfo::LatencyComponent renderer_swap_component;
-  if (!latency.FindLatency(ui::INPUT_EVENT_LATENCY_RENDERER_SWAP_COMPONENT,
-                           0, &renderer_swap_component))
+  if (!latency.FindLatency(ui::INPUT_EVENT_LATENCY_RENDERER_SWAP_COMPONENT, 0,
+                           &renderer_swap_component)) {
     return;
+  }
 
   if (rendering_scheduled_on_main) {
     UMA_HISTOGRAM_SCROLL_LATENCY_LONG(
-        "Event.Latency.ScrollUpdate.HandledToRendererSwap_Main",
+        is_first_scroll,
+        "Event.Latency.%sScrollUpdate.HandledToRendererSwap_Main",

[tdresser, 2016/09/08 15:17:25]

Passing these format strings around is a bit scary. Add a comment to the
histogram macros that they take a printf style format string. Perhaps rename the
"name" parameter of those macros as well, something like "name_format_string".

         rendering_scheduled_component, renderer_swap_component);
   } else {
     UMA_HISTOGRAM_SCROLL_LATENCY_LONG(
-        "Event.Latency.ScrollUpdate.HandledToRendererSwap_Impl",
+        is_first_scroll,
+        "Event.Latency.%sScrollUpdate.HandledToRendererSwap_Impl",
         rendering_scheduled_component, renderer_swap_component);
   }
 
   LatencyInfo::LatencyComponent browser_received_swap_component;
   if (!latency.FindLatency(
-          ui::INPUT_EVENT_BROWSER_RECEIVED_RENDERER_SWAP_COMPONENT,
-          0, &browser_received_swap_component))
+          ui::INPUT_EVENT_BROWSER_RECEIVED_RENDERER_SWAP_COMPONENT, 0,
+          &browser_received_swap_component)) {
     return;
+  }
 
   UMA_HISTOGRAM_SCROLL_LATENCY_SHORT(
-      "Event.Latency.ScrollUpdate.RendererSwapToBrowserNotified",
+      is_first_scroll,
+      "Event.Latency.%sScrollUpdate.RendererSwapToBrowserNotified",
       renderer_swap_component, browser_received_swap_component);
 
   UMA_HISTOGRAM_SCROLL_LATENCY_LONG(
-      "Event.Latency.ScrollUpdate.BrowserNotifiedToBeforeGpuSwap",
+      is_first_scroll,
+      "Event.Latency.%sScrollUpdate.BrowserNotifiedToBeforeGpuSwap",
       browser_received_swap_component, gpu_swap_begin_component);
 
-  UMA_HISTOGRAM_SCROLL_LATENCY_SHORT("Event.Latency.ScrollUpdate.GpuSwap",
-                                     gpu_swap_begin_component,
-                                     gpu_swap_end_component);
+  UMA_HISTOGRAM_SCROLL_LATENCY_SHORT(
+      is_first_scroll, "Event.Latency.%sScrollUpdate.GpuSwap",
+      gpu_swap_begin_component, gpu_swap_end_component);
 }
 
 // LatencyComponents generated in the renderer must have component IDs
 // provided to them by the browser process. This function adds the correct
 // component ID where necessary.
 void AddLatencyInfoComponentIds(LatencyInfo* latency,
                                 int64_t latency_component_id) {
   std::vector<std::pair<ui::LatencyComponentType, int64_t>> new_components_key;
   std::vector<LatencyInfo::LatencyComponent> new_components_value;
   for (const auto& lc : latency->latency_components()) {
@@ skipping 371 matching lines @@
                            latency_component_id_, nullptr)) {
     return;
   }
 
   ComputeScrollLatencyHistograms(gpu_swap_begin_component,
                                  gpu_swap_end_component, latency_component_id_,
                                  latency, is_running_navigation_hint_task);
 }
 
 }  // namespace content