• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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 HasDrmStats(process):
109  """ Return True if the process contains DrmEventFlipComplete event.
110  """
111  if not process:
112    return False
113  for event in process.IterAllSlicesOfName('DrmEventFlipComplete'):
114    if 'data' in event.args and event.args['data']['frame_count'] == 1:
115      return True
116  return False
117
118def HasRenderingStats(process):
119  """ Returns True if the process contains at least one
120      BenchmarkInstrumentation::*RenderingStats event with a frame.
121  """
122  if not process:
123    return False
124  for event in process.IterAllSlicesOfName(
125      'BenchmarkInstrumentation::DisplayRenderingStats'):
126    if 'data' in event.args and event.args['data']['frame_count'] == 1:
127      return True
128  for event in process.IterAllSlicesOfName(
129      'BenchmarkInstrumentation::ImplThreadRenderingStats'):
130    if 'data' in event.args and event.args['data']['frame_count'] == 1:
131      return True
132  return False
133
134def GetTimestampEventName(process):
135  """ Returns the name of the events used to count frame timestamps. """
136  if process.name == 'SurfaceFlinger':
137    return 'vsync_before'
138
139  if process.name == 'GPU Process':
140    return 'DrmEventFlipComplete'
141
142  event_name = 'BenchmarkInstrumentation::DisplayRenderingStats'
143  for event in process.IterAllSlicesOfName(event_name):
144    if 'data' in event.args and event.args['data']['frame_count'] == 1:
145      return event_name
146
147  return 'BenchmarkInstrumentation::ImplThreadRenderingStats'
148
149class RenderingStats(object):
150  def __init__(self, renderer_process, browser_process, surface_flinger_process,
151               gpu_process, timeline_ranges):
152    """
153    Utility class for extracting rendering statistics from the timeline (or
154    other loggin facilities), and providing them in a common format to classes
155    that compute benchmark metrics from this data.
156
157    Stats are lists of lists of numbers. The outer list stores one list per
158    timeline range.
159
160    All *_time values are measured in milliseconds.
161    """
162    assert len(timeline_ranges) > 0
163    self.refresh_period = None
164
165    # Find the top level process with rendering stats (browser or renderer).
166    if surface_flinger_process:
167      timestamp_process = surface_flinger_process
168      self._GetRefreshPeriodFromSurfaceFlingerProcess(surface_flinger_process)
169    elif HasDrmStats(gpu_process):
170      timestamp_process = gpu_process
171    elif HasRenderingStats(browser_process):
172      timestamp_process = browser_process
173    else:
174      timestamp_process = renderer_process
175
176    timestamp_event_name = GetTimestampEventName(timestamp_process)
177
178    # A lookup from list names below to any errors or exceptions encountered
179    # in attempting to generate that list.
180    self.errors = {}
181
182    self.frame_timestamps = []
183    self.frame_times = []
184    self.approximated_pixel_percentages = []
185    self.checkerboarded_pixel_percentages = []
186    # End-to-end latency for input event - from when input event is
187    # generated to when the its resulted page is swap buffered.
188    self.input_event_latency = []
189    self.frame_queueing_durations = []
190    # Latency from when a scroll update is sent to the main thread until the
191    # resulting frame is swapped.
192    self.main_thread_scroll_latency = []
193    # Latency for a GestureScrollUpdate input event.
194    self.gesture_scroll_update_latency = []
195
196    for timeline_range in timeline_ranges:
197      self.frame_timestamps.append([])
198      self.frame_times.append([])
199      self.approximated_pixel_percentages.append([])
200      self.checkerboarded_pixel_percentages.append([])
201      self.input_event_latency.append([])
202      self.main_thread_scroll_latency.append([])
203      self.gesture_scroll_update_latency.append([])
204
205      if timeline_range.is_empty:
206        continue
207      self._InitFrameTimestampsFromTimeline(
208          timestamp_process, timestamp_event_name, timeline_range)
209      self._InitImplThreadRenderingStatsFromTimeline(
210          renderer_process, timeline_range)
211      self._InitInputLatencyStatsFromTimeline(
212          browser_process, renderer_process, timeline_range)
213      self._InitFrameQueueingDurationsFromTimeline(
214          renderer_process, timeline_range)
215
216  def _GetRefreshPeriodFromSurfaceFlingerProcess(self, surface_flinger_process):
217    for event in surface_flinger_process.IterAllEventsOfName('vsync_before'):
218      self.refresh_period = event.args['data']['refresh_period']
219      return
220
221  def _InitInputLatencyStatsFromTimeline(
222      self, browser_process, renderer_process, timeline_range):
223    latency_events = GetLatencyEvents(browser_process, timeline_range)
224    # Plugin input event's latency slice is generated in renderer process.
225    latency_events.extend(GetLatencyEvents(renderer_process, timeline_range))
226    event_latencies = ComputeEventLatencies(latency_events)
227    # Don't include scroll updates in the overall input latency measurement,
228    # because scroll updates can take much more time to process than other
229    # input events and would therefore add noise to overall latency numbers.
230    self.input_event_latency[-1] = [
231        latency for name, latency in event_latencies
232        if name != MAIN_THREAD_SCROLL_UPDATE_EVENT_NAME]
233    self.main_thread_scroll_latency[-1] = [
234        latency for name, latency in event_latencies
235        if name == MAIN_THREAD_SCROLL_UPDATE_EVENT_NAME]
236    self.gesture_scroll_update_latency[-1] = [
237        latency for name, latency in event_latencies
238        if name == GESTURE_SCROLL_UPDATE_EVENT_NAME]
239
240  def _GatherEvents(self, event_name, process, timeline_range):
241    events = []
242    for event in process.IterAllSlicesOfName(event_name):
243      if event.start >= timeline_range.min and event.end <= timeline_range.max:
244        if 'data' not in event.args:
245          continue
246        events.append(event)
247    events.sort(key=attrgetter('start'))
248    return events
249
250  def _AddFrameTimestamp(self, event):
251    frame_count = event.args['data']['frame_count']
252    if frame_count > 1:
253      raise ValueError('trace contains multi-frame render stats')
254    if frame_count == 1:
255      if event.name == 'DrmEventFlipComplete':
256        self.frame_timestamps[-1].append(
257            event.args['data']['vblank.tv_sec'] * 1000.0 +
258            event.args['data']['vblank.tv_usec'] / 1000.0)
259      else:
260        self.frame_timestamps[-1].append(
261            event.start)
262      if len(self.frame_timestamps[-1]) >= 2:
263        self.frame_times[-1].append(
264            self.frame_timestamps[-1][-1] - self.frame_timestamps[-1][-2])
265
266  def _InitFrameTimestampsFromTimeline(
267      self, process, timestamp_event_name, timeline_range):
268    for event in self._GatherEvents(
269        timestamp_event_name, process, timeline_range):
270      self._AddFrameTimestamp(event)
271
272  def _InitImplThreadRenderingStatsFromTimeline(self, process, timeline_range):
273    event_name = 'BenchmarkInstrumentation::ImplThreadRenderingStats'
274    for event in self._GatherEvents(event_name, process, timeline_range):
275      data = event.args['data']
276      if VISIBLE_CONTENT_DATA not in data:
277        self.errors[APPROXIMATED_PIXEL_ERROR] = (
278          'Calculating approximated_pixel_percentages not possible because '
279          'visible_content_area was missing.')
280        self.errors[CHECKERBOARDED_PIXEL_ERROR] = (
281          'Calculating checkerboarded_pixel_percentages not possible because '
282          'visible_content_area was missing.')
283        return
284      visible_content_area = data[VISIBLE_CONTENT_DATA]
285      if visible_content_area == 0:
286        self.errors[APPROXIMATED_PIXEL_ERROR] = (
287          'Calculating approximated_pixel_percentages would have caused '
288          'a divide-by-zero')
289        self.errors[CHECKERBOARDED_PIXEL_ERROR] = (
290          'Calculating checkerboarded_pixel_percentages would have caused '
291          'a divide-by-zero')
292        return
293      if APPROXIMATED_VISIBLE_CONTENT_DATA in data:
294        self.approximated_pixel_percentages[-1].append(
295          round(float(data[APPROXIMATED_VISIBLE_CONTENT_DATA]) /
296                float(data[VISIBLE_CONTENT_DATA]) * 100.0, 3))
297      else:
298        self.errors[APPROXIMATED_PIXEL_ERROR] = (
299          'approximated_pixel_percentages was not recorded')
300      if CHECKERBOARDED_VISIBLE_CONTENT_DATA in data:
301        self.checkerboarded_pixel_percentages[-1].append(
302          round(float(data[CHECKERBOARDED_VISIBLE_CONTENT_DATA]) /
303                float(data[VISIBLE_CONTENT_DATA]) * 100.0, 3))
304      else:
305        self.errors[CHECKERBOARDED_PIXEL_ERROR] = (
306          'checkerboarded_pixel_percentages was not recorded')
307
308  def _InitFrameQueueingDurationsFromTimeline(self, process, timeline_range):
309    try:
310      events = rendering_frame.GetFrameEventsInsideRange(process,
311                                                         timeline_range)
312      new_frame_queueing_durations = [e.queueing_duration for e in events]
313      self.frame_queueing_durations.append(new_frame_queueing_durations)
314    except rendering_frame.NoBeginFrameIdException:
315      self.errors['frame_queueing_durations'] = (
316          'Current chrome version does not support the queueing delay metric.')
317