1# Copyright 2014 The Chromium Authors. All rights reserved.
2# Use of this source code is governed by a BSD-style license that can be
3# found in the LICENSE file.
4import itertools
5
6from operator import attrgetter
7
8from telemetry.web_perf.metrics import rendering_frame
9
10# These are LatencyInfo component names indicating the various components
11# that the input event has travelled through.
12# This is when the input event first reaches chrome.
13UI_COMP_NAME = 'INPUT_EVENT_LATENCY_UI_COMPONENT'
14# This is when the input event was originally created by OS.
15ORIGINAL_COMP_NAME = 'INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT'
16# This is when the input event was sent from browser to renderer.
17BEGIN_COMP_NAME = 'INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT'
18# This is when an input event is turned into a scroll update.
19BEGIN_SCROLL_UPDATE_COMP_NAME = (
20    'LATENCY_BEGIN_SCROLL_LISTENER_UPDATE_MAIN_COMPONENT')
21# This is when a scroll update is forwarded to the main thread.
22FORWARD_SCROLL_UPDATE_COMP_NAME = (
23    'INPUT_EVENT_LATENCY_FORWARD_SCROLL_UPDATE_TO_MAIN_COMPONENT')
24# This is when the input event has reached swap buffer.
25END_COMP_NAME = 'INPUT_EVENT_GPU_SWAP_BUFFER_COMPONENT'
26
27# Name for a main thread scroll update latency event.
28MAIN_THREAD_SCROLL_UPDATE_EVENT_NAME = 'Latency::ScrollUpdate'
29# Name for a gesture scroll update latency event.
30GESTURE_SCROLL_UPDATE_EVENT_NAME = 'InputLatency::GestureScrollUpdate'
31
32# These are keys used in the 'data' field dictionary located in
33# BenchmarkInstrumentation::ImplThreadRenderingStats.
34VISIBLE_CONTENT_DATA = 'visible_content_area'
35APPROXIMATED_VISIBLE_CONTENT_DATA = 'approximated_visible_content_area'
36CHECKERBOARDED_VISIBLE_CONTENT_DATA = 'checkerboarded_visible_content_area'
37# These are keys used in the 'errors' field  dictionary located in
38# RenderingStats in this file.
39APPROXIMATED_PIXEL_ERROR = 'approximated_pixel_percentages'
40CHECKERBOARDED_PIXEL_ERROR = 'checkerboarded_pixel_percentages'
41
42
43def GetLatencyEvents(process, timeline_range):
44  """Get LatencyInfo trace events from the process's trace buffer that are
45     within the timeline_range.
46
47  Input events dump their LatencyInfo into trace buffer as async trace event
48  of name starting with "InputLatency". Non-input events with name starting
49  with "Latency". The trace event has a member 'data' containing its latency
50  history.
51
52  """
53  latency_events = []
54  if not process:
55    return latency_events
56  for event in itertools.chain(
57      process.IterAllAsyncSlicesStartsWithName('InputLatency'),
58      process.IterAllAsyncSlicesStartsWithName('Latency')):
59    if event.start >= timeline_range.min and event.end <= timeline_range.max:
60      for ss in event.sub_slices:
61        if 'data' in ss.args:
62          latency_events.append(ss)
63  return latency_events
64
65
66def ComputeEventLatencies(input_events):
67  """ Compute input event latencies.
68
69  Input event latency is the time from when the input event is created to
70  when its resulted page is swap buffered.
71  Input event on different platforms uses different LatencyInfo component to
72  record its creation timestamp. We go through the following component list
73  to find the creation timestamp:
74  1. INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT -- when event is created in OS
75  2. INPUT_EVENT_LATENCY_UI_COMPONENT -- when event reaches Chrome
76  3. INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT -- when event reaches RenderWidget
77
78  If the latency starts with a
79  LATENCY_BEGIN_SCROLL_UPDATE_MAIN_COMPONENT component, then it is
80  classified as a scroll update instead of a normal input latency measure.
81
82  Returns:
83    A list sorted by increasing start time of latencies which are tuples of
84    (input_event_name, latency_in_ms).
85  """
86  input_event_latencies = []
87  for event in input_events:
88    data = event.args['data']
89    if END_COMP_NAME in data:
90      end_time = data[END_COMP_NAME]['time']
91      if ORIGINAL_COMP_NAME in data:
92        start_time = data[ORIGINAL_COMP_NAME]['time']
93      elif UI_COMP_NAME in data:
94        start_time = data[UI_COMP_NAME]['time']
95      elif BEGIN_COMP_NAME in data:
96        start_time = data[BEGIN_COMP_NAME]['time']
97      elif BEGIN_SCROLL_UPDATE_COMP_NAME in data:
98        start_time = data[BEGIN_SCROLL_UPDATE_COMP_NAME]['time']
99      else:
100        raise ValueError('LatencyInfo has no begin component')
101      latency = (end_time - start_time) / 1000.0
102      input_event_latencies.append((start_time, event.name, latency))
103
104  input_event_latencies.sort()
105  return [(name, latency) for _, name, latency in input_event_latencies]
106
107
108def HasRenderingStats(process):
109  """ Returns True if the process contains at least one
110      BenchmarkInstrumentation::*RenderingStats event with a frame.
111  """
112  if not process:
113    return False
114  for event in process.IterAllSlicesOfName(
115      'BenchmarkInstrumentation::DisplayRenderingStats'):
116    if 'data' in event.args and event.args['data']['frame_count'] == 1:
117      return True
118  for event in process.IterAllSlicesOfName(
119      'BenchmarkInstrumentation::ImplThreadRenderingStats'):
120    if 'data' in event.args and event.args['data']['frame_count'] == 1:
121      return True
122  return False
123
124def GetTimestampEventName(process):
125  """ Returns the name of the events used to count frame timestamps. """
126  if process.name == 'SurfaceFlinger':
127    return 'vsync_before'
128
129  event_name = 'BenchmarkInstrumentation::DisplayRenderingStats'
130  for event in process.IterAllSlicesOfName(event_name):
131    if 'data' in event.args and event.args['data']['frame_count'] == 1:
132      return event_name
133
134  return 'BenchmarkInstrumentation::ImplThreadRenderingStats'
135
136class RenderingStats(object):
137  def __init__(self, renderer_process, browser_process, surface_flinger_process,
138               timeline_ranges):
139    """
140    Utility class for extracting rendering statistics from the timeline (or
141    other loggin facilities), and providing them in a common format to classes
142    that compute benchmark metrics from this data.
143
144    Stats are lists of lists of numbers. The outer list stores one list per
145    timeline range.
146
147    All *_time values are measured in milliseconds.
148    """
149    assert len(timeline_ranges) > 0
150    self.refresh_period = None
151
152    # Find the top level process with rendering stats (browser or renderer).
153    if surface_flinger_process:
154      timestamp_process = surface_flinger_process
155      self._GetRefreshPeriodFromSurfaceFlingerProcess(surface_flinger_process)
156    elif HasRenderingStats(browser_process):
157      timestamp_process = browser_process
158    else:
159      timestamp_process = renderer_process
160
161    timestamp_event_name = GetTimestampEventName(timestamp_process)
162
163    # A lookup from list names below to any errors or exceptions encountered
164    # in attempting to generate that list.
165    self.errors = {}
166
167    self.frame_timestamps = []
168    self.frame_times = []
169    self.approximated_pixel_percentages = []
170    self.checkerboarded_pixel_percentages = []
171    # End-to-end latency for input event - from when input event is
172    # generated to when the its resulted page is swap buffered.
173    self.input_event_latency = []
174    self.frame_queueing_durations = []
175    # Latency from when a scroll update is sent to the main thread until the
176    # resulting frame is swapped.
177    self.main_thread_scroll_latency = []
178    # Latency for a GestureScrollUpdate input event.
179    self.gesture_scroll_update_latency = []
180
181    for timeline_range in timeline_ranges:
182      self.frame_timestamps.append([])
183      self.frame_times.append([])
184      self.approximated_pixel_percentages.append([])
185      self.checkerboarded_pixel_percentages.append([])
186      self.input_event_latency.append([])
187      self.main_thread_scroll_latency.append([])
188      self.gesture_scroll_update_latency.append([])
189
190      if timeline_range.is_empty:
191        continue
192      self._InitFrameTimestampsFromTimeline(
193          timestamp_process, timestamp_event_name, timeline_range)
194      self._InitImplThreadRenderingStatsFromTimeline(
195          renderer_process, timeline_range)
196      self._InitInputLatencyStatsFromTimeline(
197          browser_process, renderer_process, timeline_range)
198      self._InitFrameQueueingDurationsFromTimeline(
199          renderer_process, timeline_range)
200
201  def _GetRefreshPeriodFromSurfaceFlingerProcess(self, surface_flinger_process):
202    for event in surface_flinger_process.IterAllEventsOfName('vsync_before'):
203      self.refresh_period = event.args['data']['refresh_period']
204      return
205
206  def _InitInputLatencyStatsFromTimeline(
207      self, browser_process, renderer_process, timeline_range):
208    latency_events = GetLatencyEvents(browser_process, timeline_range)
209    # Plugin input event's latency slice is generated in renderer process.
210    latency_events.extend(GetLatencyEvents(renderer_process, timeline_range))
211    event_latencies = ComputeEventLatencies(latency_events)
212    # Don't include scroll updates in the overall input latency measurement,
213    # because scroll updates can take much more time to process than other
214    # input events and would therefore add noise to overall latency numbers.
215    self.input_event_latency[-1] = [
216        latency for name, latency in event_latencies
217        if name != MAIN_THREAD_SCROLL_UPDATE_EVENT_NAME]
218    self.main_thread_scroll_latency[-1] = [
219        latency for name, latency in event_latencies
220        if name == MAIN_THREAD_SCROLL_UPDATE_EVENT_NAME]
221    self.gesture_scroll_update_latency[-1] = [
222        latency for name, latency in event_latencies
223        if name == GESTURE_SCROLL_UPDATE_EVENT_NAME]
224
225  def _GatherEvents(self, event_name, process, timeline_range):
226    events = []
227    for event in process.IterAllSlicesOfName(event_name):
228      if event.start >= timeline_range.min and event.end <= timeline_range.max:
229        if 'data' not in event.args:
230          continue
231        events.append(event)
232    events.sort(key=attrgetter('start'))
233    return events
234
235  def _AddFrameTimestamp(self, event):
236    frame_count = event.args['data']['frame_count']
237    if frame_count > 1:
238      raise ValueError('trace contains multi-frame render stats')
239    if frame_count == 1:
240      self.frame_timestamps[-1].append(
241          event.start)
242      if len(self.frame_timestamps[-1]) >= 2:
243        self.frame_times[-1].append(
244            self.frame_timestamps[-1][-1] - self.frame_timestamps[-1][-2])
245
246  def _InitFrameTimestampsFromTimeline(
247      self, process, timestamp_event_name, timeline_range):
248    for event in self._GatherEvents(
249        timestamp_event_name, process, timeline_range):
250      self._AddFrameTimestamp(event)
251
252  def _InitImplThreadRenderingStatsFromTimeline(self, process, timeline_range):
253    event_name = 'BenchmarkInstrumentation::ImplThreadRenderingStats'
254    for event in self._GatherEvents(event_name, process, timeline_range):
255      data = event.args['data']
256      if VISIBLE_CONTENT_DATA not in data:
257        self.errors[APPROXIMATED_PIXEL_ERROR] = (
258          'Calculating approximated_pixel_percentages not possible because '
259          'visible_content_area was missing.')
260        self.errors[CHECKERBOARDED_PIXEL_ERROR] = (
261          'Calculating checkerboarded_pixel_percentages not possible because '
262          'visible_content_area was missing.')
263        return
264      visible_content_area = data[VISIBLE_CONTENT_DATA]
265      if visible_content_area == 0:
266        self.errors[APPROXIMATED_PIXEL_ERROR] = (
267          'Calculating approximated_pixel_percentages would have caused '
268          'a divide-by-zero')
269        self.errors[CHECKERBOARDED_PIXEL_ERROR] = (
270          'Calculating checkerboarded_pixel_percentages would have caused '
271          'a divide-by-zero')
272        return
273      if APPROXIMATED_VISIBLE_CONTENT_DATA in data:
274        self.approximated_pixel_percentages[-1].append(
275          round(float(data[APPROXIMATED_VISIBLE_CONTENT_DATA]) /
276                float(data[VISIBLE_CONTENT_DATA]) * 100.0, 3))
277      else:
278        self.errors[APPROXIMATED_PIXEL_ERROR] = (
279          'approximated_pixel_percentages was not recorded')
280      if CHECKERBOARDED_VISIBLE_CONTENT_DATA in data:
281        self.checkerboarded_pixel_percentages[-1].append(
282          round(float(data[CHECKERBOARDED_VISIBLE_CONTENT_DATA]) /
283                float(data[VISIBLE_CONTENT_DATA]) * 100.0, 3))
284      else:
285        self.errors[CHECKERBOARDED_PIXEL_ERROR] = (
286          'checkerboarded_pixel_percentages was not recorded')
287
288  def _InitFrameQueueingDurationsFromTimeline(self, process, timeline_range):
289    try:
290      events = rendering_frame.GetFrameEventsInsideRange(process,
291                                                         timeline_range)
292      new_frame_queueing_durations = [e.queueing_duration for e in events]
293      self.frame_queueing_durations.append(new_frame_queueing_durations)
294    except rendering_frame.NoBeginFrameIdException:
295      self.errors['frame_queueing_durations'] = (
296          'Current chrome version does not support the queueing delay metric.')
297