src/tools/telemetry/telemetry/web_perf/metrics/rendering_stats.py

   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.
   4 import logging
   5 from operator import attrgetter
   6
   7 from telemetry.page import page_test
   8 from 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.
  13 UI_COMP_NAME = 'INPUT_EVENT_LATENCY_UI_COMPONENT'
  14 # This is when the input event was originally created by OS.
  15 ORIGINAL_COMP_NAME = 'INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT'
  16 # This is when the input event was sent from browser to renderer.
  17 BEGIN_COMP_NAME = 'INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT'
  18 # This is when an input event is turned into a scroll update.
  19 BEGIN_SCROLL_UPDATE_COMP_NAME = (
  20     'INPUT_EVENT_LATENCY_BEGIN_SCROLL_UPDATE_MAIN_COMPONENT')
  21 # This is when a scroll update is forwarded to the main thread.
  22 FORWARD_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.
  25 END_COMP_NAME = 'INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT'
  26
  27 # Name for a main thread scroll update latency event.
  28 SCROLL_UPDATE_EVENT_NAME = 'InputLatency:ScrollUpdate'
  29 # Name for a gesture scroll update latency event.
  30 GESTURE_SCROLL_UPDATE_EVENT_NAME  = 'InputLatency:GestureScrollUpdate'
  31
  32
  33 class NotEnoughFramesError(page_test.MeasurementFailure):
  34   def __init__(self, frame_count):
  35     super(NotEnoughFramesError, self).__init__(
  36       'Only %i frame timestamps were collected ' % frame_count +
  37       '(at least two are required).\n'
  38       'Issues that have caused this in the past:\n' +
  39       '- Browser bugs that prevents the page from redrawing\n' +
  40       '- Bugs in the synthetic gesture code\n' +
  41       '- Page and benchmark out of sync (e.g. clicked element was renamed)\n' +
  42       '- Pages that render extremely slow\n' +
  43       '- Pages that can\'t be scrolled')
  44
  45
  46 def GetInputLatencyEvents(process, timeline_range):
  47   """Get input events' LatencyInfo from the process's trace buffer that are
  48      within the timeline_range.
  49
  50   Input events dump their LatencyInfo into trace buffer as async trace event
  51   with name "InputLatency". The trace event has a memeber 'data' containing
  52   its latency history.
  53
  54   """
  55   input_events = []
  56   if not process:
  57     return input_events
  58   for event in process.IterAllAsyncSlicesOfName('InputLatency'):
  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           input_events.append(ss)
  63   return input_events
  64
  65
  66 def ComputeInputEventLatencies(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 differnt 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   INPUT_EVENT_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
 108 def 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::MainThreadRenderingStats'):
 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
 124
 125 class RenderingStats(object):
 126   def __init__(self, renderer_process, browser_process, timeline_ranges):
 127     """
 128     Utility class for extracting rendering statistics from the timeline (or
 129     other loggin facilities), and providing them in a common format to classes
 130     that compute benchmark metrics from this data.
 131
 132     Stats are lists of lists of numbers. The outer list stores one list per
 133     timeline range.
 134
 135     All *_time values are measured in milliseconds.
 136     """
 137     assert(len(timeline_ranges) > 0)
 138     # Find the top level process with rendering stats (browser or renderer).
 139     if HasRenderingStats(browser_process):
 140       timestamp_process = browser_process
 141     else:
 142       timestamp_process  = renderer_process
 143
 144     self.frame_timestamps = []
 145     self.frame_times = []
 146     self.paint_times = []
 147     self.painted_pixel_counts = []
 148     self.record_times = []
 149     self.recorded_pixel_counts = []
 150     self.rasterize_times = []
 151     self.rasterized_pixel_counts = []
 152     self.approximated_pixel_percentages = []
 153     # End-to-end latency for input event - from when input event is
 154     # generated to when the its resulted page is swap buffered.
 155     self.input_event_latency = []
 156     self.frame_queueing_durations = []
 157     # Latency from when a scroll update is sent to the main thread until the
 158     # resulting frame is swapped.
 159     self.scroll_update_latency = []
 160     # Latency for a GestureScrollUpdate input event.
 161     self.gesture_scroll_update_latency = []
 162
 163     for timeline_range in timeline_ranges:
 164       self.frame_timestamps.append([])
 165       self.frame_times.append([])
 166       self.paint_times.append([])
 167       self.painted_pixel_counts.append([])
 168       self.record_times.append([])
 169       self.recorded_pixel_counts.append([])
 170       self.rasterize_times.append([])
 171       self.rasterized_pixel_counts.append([])
 172       self.approximated_pixel_percentages.append([])
 173       self.input_event_latency.append([])
 174       self.scroll_update_latency.append([])
 175       self.gesture_scroll_update_latency.append([])
 176
 177       if timeline_range.is_empty:
 178         continue
 179       self._InitFrameTimestampsFromTimeline(timestamp_process, timeline_range)
 180       self._InitMainThreadRenderingStatsFromTimeline(
 181           renderer_process, timeline_range)
 182       self._InitImplThreadRenderingStatsFromTimeline(
 183           renderer_process, timeline_range)
 184       self._InitInputLatencyStatsFromTimeline(
 185           browser_process, renderer_process, timeline_range)
 186       self._InitFrameQueueingDurationsFromTimeline(
 187           renderer_process, timeline_range)
 188
 189     # Check if we have collected at least 2 frames in every range. Otherwise we
 190     # can't compute any meaningful metrics.
 191     for segment in self.frame_timestamps:
 192       if len(segment) < 2:
 193         raise NotEnoughFramesError(len(segment))
 194
 195   def _InitInputLatencyStatsFromTimeline(
 196       self, browser_process, renderer_process, timeline_range):
 197     latency_events = GetInputLatencyEvents(browser_process, timeline_range)
 198     # Plugin input event's latency slice is generated in renderer process.
 199     latency_events.extend(GetInputLatencyEvents(renderer_process,
 200                                                 timeline_range))
 201     input_event_latencies = ComputeInputEventLatencies(latency_events)
 202     self.input_event_latency[-1] = [
 203         latency for name, latency in input_event_latencies]
 204     self.scroll_update_latency[-1] = [
 205         latency for name, latency in input_event_latencies
 206         if name == SCROLL_UPDATE_EVENT_NAME]
 207     self.gesture_scroll_update_latency[-1] = [
 208         latency for name, latency in input_event_latencies
 209         if name == GESTURE_SCROLL_UPDATE_EVENT_NAME]
 210
 211   def _GatherEvents(self, event_name, process, timeline_range):
 212     events = []
 213     for event in process.IterAllSlicesOfName(event_name):
 214       if event.start >= timeline_range.min and event.end <= timeline_range.max:
 215         if 'data' not in event.args:
 216           continue
 217         events.append(event)
 218     events.sort(key=attrgetter('start'))
 219     return events
 220
 221   def _AddFrameTimestamp(self, event):
 222     frame_count = event.args['data']['frame_count']
 223     if frame_count > 1:
 224       raise ValueError('trace contains multi-frame render stats')
 225     if frame_count == 1:
 226       self.frame_timestamps[-1].append(
 227           event.start)
 228       if len(self.frame_timestamps[-1]) >= 2:
 229         self.frame_times[-1].append(round(self.frame_timestamps[-1][-1] -
 230                                           self.frame_timestamps[-1][-2], 2))
 231
 232   def _InitFrameTimestampsFromTimeline(self, process, timeline_range):
 233     event_name = 'BenchmarkInstrumentation::MainThreadRenderingStats'
 234     for event in self._GatherEvents(event_name, process, timeline_range):
 235       self._AddFrameTimestamp(event)
 236
 237     event_name = 'BenchmarkInstrumentation::ImplThreadRenderingStats'
 238     for event in self._GatherEvents(event_name, process, timeline_range):
 239       self._AddFrameTimestamp(event)
 240
 241   def _InitMainThreadRenderingStatsFromTimeline(self, process, timeline_range):
 242     event_name = 'BenchmarkInstrumentation::MainThreadRenderingStats'
 243     for event in self._GatherEvents(event_name, process, timeline_range):
 244       data = event.args['data']
 245       self.paint_times[-1].append(1000.0 * data['paint_time'])
 246       self.painted_pixel_counts[-1].append(data['painted_pixel_count'])
 247       self.record_times[-1].append(1000.0 * data['record_time'])
 248       self.recorded_pixel_counts[-1].append(data['recorded_pixel_count'])
 249
 250   def _InitImplThreadRenderingStatsFromTimeline(self, process, timeline_range):
 251     event_name = 'BenchmarkInstrumentation::ImplThreadRenderingStats'
 252     for event in self._GatherEvents(event_name, process, timeline_range):
 253       data = event.args['data']
 254       self.rasterize_times[-1].append(1000.0 * data['rasterize_time'])
 255       self.rasterized_pixel_counts[-1].append(data['rasterized_pixel_count'])
 256       if data.get('visible_content_area', 0):
 257         self.approximated_pixel_percentages[-1].append(
 258             round(float(data['approximated_visible_content_area']) /
 259                   float(data['visible_content_area']) * 100.0, 3))
 260       else:
 261         self.approximated_pixel_percentages[-1].append(0.0)
 262
 263   def _InitFrameQueueingDurationsFromTimeline(self, process, timeline_range):
 264     try:
 265       events = rendering_frame.GetFrameEventsInsideRange(process,
 266                                                          timeline_range)
 267       new_frame_queueing_durations = [e.queueing_duration for e in events]
 268       self.frame_queueing_durations.append(new_frame_queueing_durations)
 269     except rendering_frame.NoBeginFrameIdException:
 270       logging.warning('Current chrome version does not support the queueing '
 271                       'delay metric.')