Collecting LatencyInfo in telemetry

tools/perf/metrics/rendering_stats.py

Index: tools/perf/metrics/rendering_stats.py
diff --git a/tools/perf/metrics/rendering_stats.py b/tools/perf/metrics/rendering_stats.py
index ca3440b033448c3d8b5a58b78397bf95e0dbdce3..3885d9f0f21cccc22b64ac90978c353950d0b0e2 100644
--- a/tools/perf/metrics/rendering_stats.py
+++ b/tools/perf/metrics/rendering_stats.py
@@ -6,7 +6,7 @@ from operator import attrgetter
 
 
 class RenderingStats(object):
-  def __init__(self, renderer_process, timeline_ranges):
+  def __init__(self, renderer_process, browser_main_thread, timeline_ranges):
     """
     Utility class for extracting rendering statistics from the timeline (or
     other loggin facilities), and providing them in a common format to classes
@@ -20,6 +20,7 @@ class RenderingStats(object):
     """
     assert(len(timeline_ranges) > 0)
     self.renderer_process = renderer_process
+    self.browser_main_thread = browser_main_thread
 
     self.frame_timestamps = []
     self.frame_times = []
@@ -29,12 +30,67 @@ class RenderingStats(object):
     self.recorded_pixel_count = []
     self.rasterize_time = []
     self.rasterized_pixel_count = []
+    self.mouse_wheel_latency = []
+    self.gesture_scroll_latency = []
+    self.touch_scroll_latency = []
 
     for timeline_range in timeline_ranges:
       if timeline_range.is_empty:
         continue
       self.initMainThreadStatsFromTimeline(timeline_range)
       self.initImplThreadStatsFromTimeline(timeline_range)
+      if self.browser_main_thread:
+        self.initInputLatencyFromTimeline(timeline_range)
+
+  def initInputLatencyFromTimeline(self, timeline_range):
+    event_name = "InputLatency"
+    ui_comp_name = 'INPUT_EVENT_LATENCY_UI_COMPONENT'

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

this code is incredibly dense and hard to read and the variable names are hard
to understand. what is a comp_name? remember, your job is not just to make this
work, but to make it so that other people can read this and understand what is
going on.

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

I refactored this into a few helper functions, hopefully making this easier to
understand.

+    original_comp_name = 'INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT'
+    begin_comp_name = 'INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT'
+    end_comp_name = 'INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT'
+    mouse_wheel_events = []
+    scroll_events = []
+    for event in self.browser_main_thread.IterAllAsyncSlicesOfName(event_name):

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

i dont get the point of event_name as a variable here, its actually quite
misleading

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

this function should really be split into a few functions so that you can unit
test its pieces. there's one piece that takes a browser_main_thread and gets
produces a class with the different events of interest in different arrays. 

then you might use a
@property
def mouse_wheel_latency_times(self):
  if self._mouse_wheel_latency_times:
     return self._mouse_wheel_latency_times
  .. build _mouse_wheel_latency_times

so that the three loops below are 

then, once you have this, you'll realize that you can write  a unit test for
this entire function without having to create a RenderStats object --- all you
need to do is test the object in isolation. You'll still need a basic test that
the renderstats integration with your new objct works but it'll be better
isolated.

+      if event.start >= timeline_range.min and event.end <= timeline_range.max:
+        for ss in event.sub_slices:
+          if 'step' not in ss.args:
+            continue
+          if 'data' not in ss.args:
+            continue
+          if ss.args['step'] == 'MouseWheel':
+            mouse_wheel_events.append(ss)
+          elif ss.args['step'] == 'GestureScrollUpdate':
+            scroll_events.append(ss)
+
+    # mouse_wheel_latency is the time from when mouse wheel event reaches RWH
+    # to buffer swapped.
+    for event in mouse_wheel_events:
+      data = event.args['data']
+      if begin_comp_name in data and end_comp_name in data:
+        latency = data[end_comp_name]['time'] - data[begin_comp_name]['time']
+        self.mouse_wheel_latency.append(latency / 1000.0)
+
+    # gesture_scroll_latency is the time from when gesture scroll event reaches
+    # RWH to buffer swapped. It is available on all platforms.
+    # touch_scroll_latency is the time from when the touch event is created
+    # to when the buffer swapped due to the scroll generated from the original
+    # touch event. On Aura, the starting timestamp is kept in UI_COMPONENT, and
+    # on Android, the starting timestamp is kept in ORIGINAL_COMPONENT.
+    for event in scroll_events:
+      data = event.args['data']
+      if end_comp_name in data:
+        end_time = data[end_comp_name]['time']
+        if begin_comp_name in data:

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

this huge set of branches shold be broken into a set of helper functions. I
can't understand what is going on here. It looks like you've got a
GetGestureScrollLatencyFromEvent() and a GetTouchScrollLatencyFromEvent() maybe?

+          latency = end_time - data[begin_comp_name]['time']
+          self.gesture_scroll_latency.append(latency / 1000.0)
+        if ui_comp_name in data and original_comp_name in data:
+          raise ValueError, 'LatencyInfo has both UI and ORIGINAL component'
+        if ui_comp_name in data:
+          latency = end_time - data[ui_comp_name]['time']
+          self.touch_scroll_latency.append(latency / 1000.0)
+        elif original_comp_name in data:
+          latency = end_time - data[original_comp_name]['time']
+          self.touch_scroll_latency.append(latency / 1000.0)
 
   def initMainThreadStatsFromTimeline(self, timeline_range):
     event_name = 'BenchmarkInstrumentation::MainThreadRenderingStats'