Collecting LatencyInfo in telemetry

tools/perf/metrics/rendering_stats_unittest.py

 # Copyright 2013 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.
 
 import random
 import unittest
 
 from metrics.rendering_stats import RenderingStats
 import telemetry.core.timeline.bounds as timeline_bounds
 from telemetry.core.timeline import model
+import telemetry.core.timeline.async_slice as tracing_async_slice
 
 
 class MockTimer(object):
   """A mock timer class which can generate random durations.
 
   An instance of this class is used as a global timer to generate random
   durations for stats and consistent timestamps for all mock trace events.
   The unit of time is milliseconds.
   """
   def __init__(self):
@@ skipping 12 matching lines @@
   """ Stores expected data for comparison with actual RenderingStats """
   def __init__(self):
     self.frame_timestamps = []
     self.frame_times = []
     self.paint_time = []
     self.painted_pixel_count = []
     self.record_time = []
     self.recorded_pixel_count = []
     self.rasterize_time = []
     self.rasterized_pixel_count = []
+    self.mouse_wheel_latency = []
+    self.gesture_scroll_latency = []

[nduca, 2014/01/23 18:34:45]

these member variable names should be chosen to clearly explain *what* is in the
array. You have to read the Add...Stats function in a huge amount of time to
figure out what they are.

+    self.touch_scroll_latency = []
 
+def AddBrowserInputLatencyStats(mock_timer, input_type, start_thread,
+                                end_thread, ref_stats = None):
+  """ Adds a random browser process input latency stats event.
+
+  input_type: The input type for which the latency slice is generated.
+  start_thread: The start thread on which the async slice is added.
+  end_thread: The end thread on which the async slice is ended.
+  ref_stats: A ReferenceRenderingStats object to record expected values.
+  """
+  ui_comp_name = 'INPUT_EVENT_LATENCY_UI_COMPONENT'
+  begin_comp_name = 'INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT'
+  end_comp_name = 'INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT'
+
+  mock_timer.Advance()
+  ui_comp_time = mock_timer.Get() * 1000.0
+  mock_timer.Advance()
+  begin_comp_time = mock_timer.Get() * 1000.0
+  mock_timer.Advance(10, 20)
+  end_comp_time = mock_timer.Get() * 1000.0
+
+  data = { ui_comp_name: {'time': ui_comp_time},
+           begin_comp_name: {'time': begin_comp_time},
+           end_comp_name: {'time': end_comp_time} }
+
+  timestamp = mock_timer.Get()
+
+  async_slice = tracing_async_slice.AsyncSlice(
+      'benchmark', 'InputLatency', timestamp)
+
+  async_sub_slice = tracing_async_slice.AsyncSlice(
+      'benchmark', 'InputLatency', timestamp)
+  async_sub_slice.args = {'data': data, 'step': input_type}
+  async_sub_slice.parent_slice = async_slice
+  async_sub_slice.start_thread = start_thread
+  async_sub_slice.end_thread = end_thread
+
+  async_slice.sub_slices.append(async_sub_slice)
+  async_slice.start_thread = start_thread
+  async_slice.end_thread = end_thread
+  start_thread.AddAsyncSlice(async_slice)
+
+  if not ref_stats:
+    return
+
+  if input_type == 'MouseWheel':
+    ref_stats.mouse_wheel_latency.append(
+        (data[end_comp_name]['time'] - data[begin_comp_name]['time']) / 1000.0)
+  elif input_type == 'GestureScrollUpdate':
+    ref_stats.gesture_scroll_latency.append(
+        (data[end_comp_name]['time'] - data[begin_comp_name]['time']) / 1000.0)
+    ref_stats.touch_scroll_latency.append(
+        (data[end_comp_name]['time'] - data[ui_comp_name]['time']) / 1000.0)
 
 def AddMainThreadRenderingStats(mock_timer, thread, first_frame,
                                 ref_stats = None):
   """ Adds a random main thread rendering stats event.
 
   thread: The timeline model thread to which the event will be added.
   first_frame: Is this the first frame within the bounds of an action?
   ref_stats: A ReferenceRenderingStats object to record expected values.
   """
   # Create randonm data and timestap for main thread rendering stats.
@@ skipping 82 matching lines @@
 
     # Create 10 main and impl rendering stats events for Action A.
     timer.Advance()
     renderer_main.BeginSlice('webkit.console', 'ActionA', timer.Get(), '')
     for i in xrange(0, 10):
       first = (i == 0)
       AddMainThreadRenderingStats(timer, renderer_main, first, ref_stats)
       AddImplThreadRenderingStats(timer, renderer_compositor, first, ref_stats)
       AddMainThreadRenderingStats(timer, browser_main, first, None)
       AddImplThreadRenderingStats(timer, browser_compositor, first, None)
+      AddBrowserInputLatencyStats(timer, 'MouseWheel', browser_main,
+                                  renderer_main, ref_stats)
+      AddBrowserInputLatencyStats(timer, 'GestureScrollUpdate', browser_main,
+                                  renderer_main, ref_stats)
     renderer_main.EndSlice(timer.Get())
 
     # Create 5 main and impl rendering stats events not within any action.
     for i in xrange(0, 5):
       first = (i == 0)
       AddMainThreadRenderingStats(timer, renderer_main, first, None)
       AddImplThreadRenderingStats(timer, renderer_compositor, first, None)
       AddMainThreadRenderingStats(timer, browser_main, first, None)
       AddImplThreadRenderingStats(timer, browser_compositor, first, None)
+      AddBrowserInputLatencyStats(timer, 'MouseWheel', browser_main,
+                                  renderer_main, None)
+      AddBrowserInputLatencyStats(timer, 'GestureScrollUpdate', browser_main,
+                                  renderer_main, None)
 
     # Create 10 main and impl rendering stats events for Action B.
     timer.Advance()
     renderer_main.BeginSlice('webkit.console', 'ActionB', timer.Get(), '')
     for i in xrange(0, 10):
       first = (i == 0)
       AddMainThreadRenderingStats(timer, renderer_main, first, ref_stats)
       AddImplThreadRenderingStats(timer, renderer_compositor, first, ref_stats)
       AddMainThreadRenderingStats(timer, browser_main, first, None)
       AddImplThreadRenderingStats(timer, browser_compositor, first, None)
+      AddBrowserInputLatencyStats(timer, 'MouseWheel', browser_main,
+                                  renderer_main, ref_stats)
+      AddBrowserInputLatencyStats(timer, 'GestureScrollUpdate', browser_main,
+                                  renderer_main, ref_stats)
     renderer_main.EndSlice(timer.Get())
 
     # Create 10 main and impl rendering stats events for Action A.
     timer.Advance()
     renderer_main.BeginSlice('webkit.console', 'ActionA', timer.Get(), '')
     for i in xrange(0, 10):
       first = (i == 0)
       AddMainThreadRenderingStats(timer, renderer_main, first, ref_stats)
       AddImplThreadRenderingStats(timer, renderer_compositor, first, ref_stats)
       AddMainThreadRenderingStats(timer, browser_main, first, None)
       AddImplThreadRenderingStats(timer, browser_compositor, first, None)
+      AddBrowserInputLatencyStats(timer, 'MouseWheel', browser_main,

[nduca, 2014/01/23 18:34:45]

it worries me that this is one huge unit test. Can you refactor this unit test
to have test of the new latency fields separate from the test of the existing
stuff?

[Yufeng Shen (Slow to review), 2014/01/30 01:16:05]

Done.

+                                  renderer_main, ref_stats)
+      AddBrowserInputLatencyStats(timer, 'GestureScrollUpdate', browser_main,
+                                  renderer_main, ref_stats)
     renderer_main.EndSlice(timer.Get())
 
     renderer_main.FinalizeImport()
     renderer_compositor.FinalizeImport()
 
     timeline_markers = timeline.FindTimelineMarkers(
         ['ActionA', 'ActionB', 'ActionA'])
     timeline_ranges = [ timeline_bounds.Bounds.CreateFromEvent(marker)
                         for marker in timeline_markers ]
-    stats = RenderingStats(renderer, timeline_ranges)
+    stats = RenderingStats(renderer, browser_main, timeline_ranges)
 
     # Compare rendering stats to reference.
     self.assertEquals(stats.frame_timestamps, ref_stats.frame_timestamps)
     self.assertEquals(stats.frame_times, ref_stats.frame_times)
     self.assertEquals(stats.rasterize_time, ref_stats.rasterize_time)
     self.assertEquals(stats.rasterized_pixel_count,
                       ref_stats.rasterized_pixel_count)
     self.assertEquals(stats.paint_time, ref_stats.paint_time)
     self.assertEquals(stats.painted_pixel_count, ref_stats.painted_pixel_count)
     self.assertEquals(stats.record_time, ref_stats.record_time)
-    self.assertEquals(stats.recorded_pixel_count,
-                      ref_stats.recorded_pixel_count)
+    self.assertEquals(stats.mouse_wheel_latency,
+                      ref_stats.mouse_wheel_latency)
+    self.assertEquals(stats.gesture_scroll_latency,
+                      ref_stats.gesture_scroll_latency)
+    self.assertEquals(stats.touch_scroll_latency,
+                      ref_stats.touch_scroll_latency)