Added GPU performance metrics.

Metrics have been added for the GPU using the GPU Tracer. Currently
we record the average, max, and stddev ms for each category
per frame for the following categories:
  render_compositor: Both CPU/GPU side spent on the render compositor.
  browser_compositor: Both CPU/GPU spent on browser compositor.
  total: Both CPU/GPU and total frame time spent in renderer.
  swap: Time between swaps, total FPS.

R=vmiura@chromium.org
BUG=None

Review URL: https://codereview.chromium.org/854833003

Cr-Commit-Position: refs/heads/master@{#313419}

tools/perf/benchmarks/gpu_times.py

+# Copyright 2015 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.
+from metrics import gpu_timeline
+import page_sets
+from telemetry import benchmark
+from telemetry.core.platform import tracing_category_filter
+from telemetry.web_perf import timeline_based_measurement
+
+TOPLEVEL_GL_CATEGORY = 'gpu_toplevel'
+TOPLEVEL_CATEGORIES = ['disabled-by-default-gpu.device',
+                       'disabled-by-default-gpu.service']
+
+
+def _GetGPUTimelineMetric(_):
+      return [gpu_timeline.GPUTimelineMetric()]
+
+
+class _GPUTimes(benchmark.Benchmark):
+  def CreateTimelineBasedMeasurementOptions(self):
+    cat_string = ','.join(TOPLEVEL_CATEGORIES)
+    cat_filter = tracing_category_filter.TracingCategoryFilter(cat_string)
+
+    return timeline_based_measurement.Options(
+        overhead_level=cat_filter,
+        get_metrics_from_flags_callback=_GetGPUTimelineMetric)
+
+
+@benchmark.Enabled('android')
+class GPUTimesKeyMobileSites(_GPUTimes):
+  """Measures GPU timeline metric on key mobile sites."""
+  page_set = page_sets.KeyMobileSitesSmoothPageSet
+
+
+class GPUTimesTop25Sites(_GPUTimes):
+  """Measures GPU timeline metric for the top 25 sites."""
+  page_set = page_sets.Top25SmoothPageSet

tools/perf/metrics/gpu_timeline.py

+# Copyright 2015 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 collections
+import math
+import sys
+
+from telemetry.timeline import model as model_module
+from telemetry.value import scalar
+from telemetry.value import list_of_scalar_values
+from telemetry.web_perf.metrics import timeline_based_metric
+
+TOPLEVEL_GL_CATEGORY = 'gpu_toplevel'
+TOPLEVEL_SERVICE_CATEGORY = 'disabled-by-default-gpu.service'
+TOPLEVEL_DEVICE_CATEGORY = 'disabled-by-default-gpu.device'
+
+SERVICE_FRAME_END_MARKER = (TOPLEVEL_SERVICE_CATEGORY, 'SwapBuffer')
+DEVICE_FRAME_END_MARKER = (TOPLEVEL_DEVICE_CATEGORY, 'SwapBuffer')
+
+TRACKED_GL_CONTEXT_NAME = { 'RenderCompositor': 'render_compositor',
+                            'BrowserCompositor': 'browser_compositor',
+                            'Compositor': 'browser_compositor' }
+
+
+def _CalculateFrameTimes(events_per_frame, event_data_func):
+  """Given a list of events per frame and a function to extract event time data,
+     returns a list of frame times."""
+  times_per_frame = []
+  for event_list in events_per_frame:
+    event_times = [event_data_func(event) for event in event_list]
+    times_per_frame.append(sum(event_times))
+  return times_per_frame
+
+
+def _CPUFrameTimes(events_per_frame):
+  """Given a list of events per frame, returns a list of CPU frame times."""
+  # CPU event frames are calculated using the event thread duration.
+  # Some platforms do not support thread_duration, convert those to 0.
+  return _CalculateFrameTimes(events_per_frame,
+                              lambda event : event.thread_duration or 0)
+
+
+def _GPUFrameTimes(events_per_frame):
+  """Given a list of events per frame, returns a list of GPU frame times."""
+  # GPU event frames are asynchronous slices which use the event duration.
+  return _CalculateFrameTimes(events_per_frame,
+                              lambda event : event.duration)
+
+
+def TimelineName(name, source_type, value_type):
+  """Constructs the standard name given in the timeline.
+
+  Args:
+    name: The name of the timeline, for example "total", or "render_compositor".
+    source_type: One of "cpu", "gpu" or None. None is only used for total times.
+    value_type: the type of value. For example "mean", "stddev"...etc.
+  """
+  if source_type:
+    return '%s_%s_%s_time' % (name, value_type, source_type)
+  else:
+    return '%s_%s_time' % (name, value_type)
+
+
+class GPUTimelineMetric(timeline_based_metric.TimelineBasedMetric):
+  """Computes GPU based metrics."""
+
+  def __init__(self):
+    super(GPUTimelineMetric, self).__init__()
+
+  def AddResults(self, model, _, interaction_records, results):
+    self.VerifyNonOverlappedRecords(interaction_records)
+    service_times = self._CalculateGPUTimelineData(model)
+    for value_item, durations in service_times.iteritems():
+      count = len(durations)
+      avg = 0.0
+      stddev = 0.0
+      maximum = 0.0
+      if count:
+        avg = sum(durations) / count
+        stddev = math.sqrt(sum((d - avg) ** 2 for d in durations) / count)
+        maximum = max(durations)
+
+      name, src = value_item
+
+      if src:
+        frame_times_name = '%s_%s_frame_times' % (name, src)
+      else:
+        frame_times_name = '%s_frame_times' % (name)
+
+      if durations:
+        results.AddValue(list_of_scalar_values.ListOfScalarValues(
+            results.current_page, frame_times_name, 'ms', durations))
+
+      results.AddValue(scalar.ScalarValue(results.current_page,
+                                          TimelineName(name, src, 'max'),
+                                          'ms', maximum))
+      results.AddValue(scalar.ScalarValue(results.current_page,
+                                          TimelineName(name, src, 'mean'),
+                                          'ms', avg))
+      results.AddValue(scalar.ScalarValue(results.current_page,
+                                          TimelineName(name, src, 'stddev'),
+                                          'ms', stddev))
+
+  def _CalculateGPUTimelineData(self, model):
+    """Uses the model and calculates the times for various values for each
+       frame. The return value will be a dictionary of the following format:
+         {
+           (EVENT_NAME1, SRC1_TYPE): [FRAME0_TIME, FRAME1_TIME...etc.],
+           (EVENT_NAME2, SRC2_TYPE): [FRAME0_TIME, FRAME1_TIME...etc.],
+         }
+
+       Events:
+         swap - The time in milliseconds between each swap marker.
+         total - The amount of time spent in the renderer thread.
+         TRACKED_NAMES: Using the TRACKED_GL_CONTEXT_NAME dict, we
+                        include the traces per frame for the
+                        tracked name.
+       Source Types:
+         None - This will only be valid for the "swap" event.
+         cpu - For an event, the "cpu" source type signifies time spent on the
+               gpu thread using the CPU. This uses the "gpu.service" markers.
+         gpu - For an event, the "gpu" source type signifies time spent on the
+               gpu thread using the GPU. This uses the "gpu.device" markers.
+    """
+    all_service_events = []
+    current_service_frame_end = sys.maxint
+    current_service_events = []
+
+    all_device_events = []
+    current_device_frame_end = sys.maxint
+    current_device_events = []
+
+    tracked_events = {}
+    tracked_events.update(
+        dict([((value, 'cpu'), [])
+              for value in TRACKED_GL_CONTEXT_NAME.itervalues()]))
+    tracked_events.update(
+        dict([((value, 'gpu'), [])
+              for value in TRACKED_GL_CONTEXT_NAME.itervalues()]))
+
+    # These will track traces within the current frame.
+    current_tracked_service_events = collections.defaultdict(list)
+    current_tracked_device_events = collections.defaultdict(list)
+
+    event_iter = model.IterAllEvents(
+        event_type_predicate=model_module.IsSliceOrAsyncSlice)
+    for event in event_iter:
+      # Look for frame end markers
+      if (event.category, event.name) == SERVICE_FRAME_END_MARKER:
+        current_service_frame_end = event.end
+      elif (event.category, event.name) == DEVICE_FRAME_END_MARKER:
+        current_device_frame_end = event.end
+
+      # Track all other toplevel gl category markers
+      elif event.args.get('gl_category', None) == TOPLEVEL_GL_CATEGORY:
+        base_name = event.name
+        dash_index = base_name.rfind('-')
+        if dash_index != -1:
+          base_name = base_name[:dash_index]
+        tracked_name = TRACKED_GL_CONTEXT_NAME.get(base_name, None)
+
+        if event.category == TOPLEVEL_SERVICE_CATEGORY:
+          # Check if frame has ended.
+          if event.start >= current_service_frame_end:
+            if current_service_events:
+              all_service_events.append(current_service_events)
+              for value in TRACKED_GL_CONTEXT_NAME.itervalues():
+                tracked_events[(value, 'cpu')].append(
+                    current_tracked_service_events[value])
+            current_service_events = []
+            current_service_frame_end = sys.maxint
+            current_tracked_service_events.clear()
+
+          current_service_events.append(event)
+          if tracked_name:
+            current_tracked_service_events[tracked_name].append(event)
+
+        elif event.category == TOPLEVEL_DEVICE_CATEGORY:
+          # Check if frame has ended.
+          if event.start >= current_device_frame_end:
+            if current_device_events:
+              all_device_events.append(current_device_events)
+              for value in TRACKED_GL_CONTEXT_NAME.itervalues():
+                tracked_events[(value, 'gpu')].append(
+                    current_tracked_device_events[value])
+            current_device_events = []
+            current_device_frame_end = sys.maxint
+            current_tracked_device_events.clear()
+
+          current_device_events.append(event)
+          if tracked_name:
+            current_tracked_device_events[tracked_name].append(event)
+
+    # Append Data for Last Frame.
+    if current_service_events:
+      all_service_events.append(current_service_events)
+      for value in TRACKED_GL_CONTEXT_NAME.itervalues():
+        tracked_events[(value, 'cpu')].append(
+            current_tracked_service_events[value])
+    if current_device_events:
+      all_device_events.append(current_device_events)
+      for value in TRACKED_GL_CONTEXT_NAME.itervalues():
+        tracked_events[(value, 'gpu')].append(
+            current_tracked_device_events[value])
+
+    # Calculate Mean Frame Time for the CPU side.
+    frame_times = []
+    if all_service_events:
+      prev_frame_end = all_service_events[0][0].start
+      for event_list in all_service_events:
+        last_service_event_in_frame = event_list[-1]
+        frame_times.append(last_service_event_in_frame.end - prev_frame_end)
+        prev_frame_end = last_service_event_in_frame.end
+
+    # Create the timeline data dictionary for service side traces.
+    total_frame_value = ('swap', None)
+    cpu_frame_value = ('total', 'cpu')
+    gpu_frame_value = ('total', 'gpu')
+    timeline_data = {}
+    timeline_data[total_frame_value] = frame_times
+    timeline_data[cpu_frame_value] = _CPUFrameTimes(all_service_events)
+    for value in TRACKED_GL_CONTEXT_NAME.itervalues():
+      cpu_value = (value, 'cpu')
+      timeline_data[cpu_value] = _CPUFrameTimes(tracked_events[cpu_value])
+
+    # Add in GPU side traces if it was supported (IE. device traces exist).
+    if all_device_events:
+      timeline_data[gpu_frame_value] = _GPUFrameTimes(all_device_events)
+      for value in TRACKED_GL_CONTEXT_NAME.itervalues():
+        gpu_value = (value, 'gpu')
+        tracked_gpu_event = tracked_events[gpu_value]
+        timeline_data[gpu_value] = _GPUFrameTimes(tracked_gpu_event)
+
+    return timeline_data

tools/telemetry/telemetry/web_perf/timeline_based_measurement.py

@@ -30,19 +30,24 @@ ALL_OVERHEAD_LEVELS = [
   DEBUG_OVERHEAD_LEVEL
 ]
 
+DEFAULT_METRICS = {
+  tir_module.IS_FAST: fast_metric.FastMetric,
+  tir_module.IS_SMOOTH: smoothness.SmoothnessMetric,
+  tir_module.IS_RESPONSIVE: responsiveness_metric.ResponsivenessMetric,
+}
 
 class InvalidInteractions(Exception):
   pass
 
 
-def _GetMetricFromMetricType(metric_type):
-  if metric_type == tir_module.IS_FAST:
-    return fast_metric.FastMetric()
-  if metric_type == tir_module.IS_SMOOTH:
-    return smoothness.SmoothnessMetric()
-  if metric_type == tir_module.IS_RESPONSIVE:
-    return responsiveness_metric.ResponsivenessMetric()
-  raise Exception('Unrecognized metric type: %s' % metric_type)
+def _GetMetricsFromFlags(record_custom_flags):
+  flags_set = set(record_custom_flags)
+  unknown_flags = flags_set.difference(DEFAULT_METRICS)
+  if unknown_flags:
+    raise Exception("Unknown metric flags: %s" % sorted(unknown_flags))
+
+  return [metric() for flag, metric in DEFAULT_METRICS.iteritems()
+          if flag in flags_set]
 
 
 # TODO(nednguyen): Get rid of this results wrapper hack after we add interaction
@@ -63,6 +68,7 @@ class _ResultsWrapper(object):
     value.name = self._GetResultName(value.name)
     self._results.AddValue(value)
 
+
 def _GetRendererThreadsToInteractionRecordsMap(model):
   threads_to_records_map = defaultdict(list)
   interaction_labels_of_previous_threads = set()
@@ -82,14 +88,15 @@ def _GetRendererThreadsToInteractionRecordsMap(model):
 
   return threads_to_records_map
 
+
 class _TimelineBasedMetrics(object):
   def __init__(self, model, renderer_thread, interaction_records,
-               get_metric_from_metric_type_callback):
+               get_metrics_from_flags_callback):
     self._model = model
     self._renderer_thread = renderer_thread
     self._interaction_records = interaction_records
-    self._get_metric_from_metric_type_callback = \
-        get_metric_from_metric_type_callback
+    self._get_metrics_from_flags_callback = \
+        get_metrics_from_flags_callback
 
   def AddResults(self, results):
     interactions_by_label = defaultdict(list)
@@ -105,17 +112,18 @@ class _TimelineBasedMetrics(object):
       self.UpdateResultsByMetric(interactions, wrapped_results)
 
   def UpdateResultsByMetric(self, interactions, wrapped_results):
-    for metric_type in tir_module.METRICS:
-      # For each metric type, either all or none of the interactions should
-      # have that metric.
-      interactions_with_metric = [i for i in interactions if
-                                  i.HasMetric(metric_type)]
-      if not interactions_with_metric:
-        continue
-      if len(interactions_with_metric) != len(interactions):
+    if not interactions:
+      return
+
+    # Either all or none of the interactions should have that metric flags.
+    records_custom_flags = set(interactions[0].GetUserDefinedFlags())
+    for interaction in interactions[1:]:
+      if records_custom_flags != set(interaction.GetUserDefinedFlags()):
         raise InvalidInteractions('Interaction records with the same logical '
                                   'name must have the same flags.')
-      metric = self._get_metric_from_metric_type_callback(metric_type)
+
+    metrics_list = self._get_metrics_from_flags_callback(records_custom_flags)
+    for metric in metrics_list:
       metric.AddResults(self._model, self._renderer_thread,
                         interactions, wrapped_results)
 
@@ -127,22 +135,45 @@ class Options(object):
   Benchmark.CreateTimelineBasedMeasurementOptions.
   """
 
-  def __init__(self, overhead_level=NO_OVERHEAD_LEVEL):
-    """Save the overhead level.
-
-    As the amount of instrumentation increases, so does the overhead.
+  def __init__(self, overhead_level=NO_OVERHEAD_LEVEL,
+               get_metrics_from_flags_callback=_GetMetricsFromFlags):
+    """As the amount of instrumentation increases, so does the overhead.
     The user of the measurement chooses the overhead level that is appropriate,
     and the tracing is filtered accordingly.
 
-    overhead_level: one of NO_OVERHEAD_LEVEL, V8_OVERHEAD_LEVEL,
-        MINIMAL_OVERHEAD_LEVEL, or DEBUG_OVERHEAD_LEVEL.
-        The v8 overhead level is a temporary solution that may be removed.
+    overhead_level: Can either be a custom TracingCategoryFilter object or
+        one of NO_OVERHEAD_LEVEL, V8_OVERHEAD_LEVEL, MINIMAL_OVERHEAD_LEVEL,
+        or DEBUG_OVERHEAD_LEVEL. The v8 overhead level is a temporary solution
+        that may be removed.
+    get_metrics_from_flags_callback: Callback function which returns a
+        a list of metrics based on timeline record flags. See the default
+        _GetMetricsFromFlags() as an example.
     """
+    if (not isinstance(overhead_level,
+                       tracing_category_filter.TracingCategoryFilter) and
+        overhead_level not in ALL_OVERHEAD_LEVELS):
+      raise Exception("Overhead level must be a TracingCategoryFilter object"
+                      " or valid overhead level string."
+                      " Given overhead level: %s" % overhead_level)
+
     self._overhead_level = overhead_level
-    self._category_filters = []
+    self._extra_category_filters = []
+    self._get_metrics_from_flags_callback = get_metrics_from_flags_callback
 
   def ExtendTraceCategoryFilters(self, filters):
-    self._category_filters.extend(filters)
+    self._extra_category_filters.extend(filters)
+
+  @property
+  def extra_category_filters(self):
+    return self._extra_category_filters
+
+  @property
+  def overhead_level(self):
+    return self._overhead_level
+
+  @property
+  def get_metrics_from_flags_callback(self):
+    return self._get_metrics_from_flags_callback
 
 
 class TimelineBasedMeasurement(object):
@@ -168,8 +199,7 @@ class TimelineBasedMeasurement(object):
   perf.metrics.timeline_interaction_record module.
   """
   def __init__(self, options):
-    self._overhead_level = options._overhead_level
-    self._category_filters = options._category_filters
+    self._tbm_options = options
 
   def WillRunUserStory(self, tracing_controller,
                        synthetic_delay_categories=None):
@@ -184,20 +214,27 @@ class TimelineBasedMeasurement(object):
     """
     if not tracing_controller.IsChromeTracingSupported():
       raise Exception('Not supported')
-    assert self._overhead_level in ALL_OVERHEAD_LEVELS
-    if self._overhead_level == NO_OVERHEAD_LEVEL:
-      category_filter = tracing_category_filter.CreateNoOverheadFilter()
-    # TODO(ernstm): Remove this overhead level when benchmark relevant v8 events
-    # become available in the 'benchmark' category.
-    elif self._overhead_level == V8_OVERHEAD_LEVEL:
-      category_filter = tracing_category_filter.CreateNoOverheadFilter()
-      category_filter.AddIncludedCategory('v8')
-    elif self._overhead_level == MINIMAL_OVERHEAD_LEVEL:
-      category_filter = tracing_category_filter.CreateMinimalOverheadFilter()
-    else:
-      category_filter = tracing_category_filter.CreateDebugOverheadFilter()
 
-    for new_category_filter in self._category_filters:
+    if isinstance(self._tbm_options.overhead_level,
+                  tracing_category_filter.TracingCategoryFilter):
+      category_filter = self._tbm_options.overhead_level
+    else:
+      assert self._tbm_options.overhead_level in ALL_OVERHEAD_LEVELS, (
+          "Invalid TBM Overhead Level: %s" % self._tbm_options.overhead_level)
+
+      if self._tbm_options.overhead_level == NO_OVERHEAD_LEVEL:
+        category_filter = tracing_category_filter.CreateNoOverheadFilter()
+      # TODO(ernstm): Remove this overhead level when benchmark relevant v8
+      # events become available in the 'benchmark' category.
+      elif self._tbm_options.overhead_level == V8_OVERHEAD_LEVEL:
+        category_filter = tracing_category_filter.CreateNoOverheadFilter()
+        category_filter.AddIncludedCategory('v8')
+      elif self._tbm_options.overhead_level == MINIMAL_OVERHEAD_LEVEL:
+        category_filter = tracing_category_filter.CreateMinimalOverheadFilter()
+      else:
+        category_filter = tracing_category_filter.CreateDebugOverheadFilter()
+
+    for new_category_filter in self._tbm_options.extra_category_filters:
       category_filter.AddIncludedCategory(new_category_filter)
 
     # TODO(slamm): Move synthetic_delay_categories to the TBM options.
@@ -217,7 +254,8 @@ class TimelineBasedMeasurement(object):
     for renderer_thread, interaction_records in (
         threads_to_records_map.iteritems()):
       meta_metrics = _TimelineBasedMetrics(
-          model, renderer_thread, interaction_records, _GetMetricFromMetricType)
+          model, renderer_thread, interaction_records,
+          self._tbm_options.get_metrics_from_flags_callback)
       meta_metrics.AddResults(results)
 
   def DidRunUserStory(self, tracing_controller):

tools/telemetry/telemetry/web_perf/timeline_based_measurement_unittest.py

@@ -52,14 +52,21 @@ class FakeLoadingMetric(timeline_based_metric.TimelineBasedMetric):
         len(interaction_records)))
 
 
-def GetMetricFromMetricType(metric_type):
-  if metric_type == tir_module.IS_FAST:
-    return FakeFastMetric()
-  if metric_type == tir_module.IS_SMOOTH:
-    return FakeSmoothMetric()
-  if metric_type == tir_module.IS_RESPONSIVE:
-    return FakeLoadingMetric()
-  raise Exception('Unrecognized metric type: %s' % metric_type)
+FAKE_METRICS_METRICS = {
+  tir_module.IS_FAST: FakeFastMetric,
+  tir_module.IS_SMOOTH: FakeSmoothMetric,
+  tir_module.IS_RESPONSIVE: FakeLoadingMetric,
+}
+
+
+def GetMetricFromFlags(record_custom_flags):
+  flags_set = set(record_custom_flags)
+  unknown_flags = flags_set.difference(FAKE_METRICS_METRICS)
+  if unknown_flags:
+    raise Exception("Unknown metric flags: %s" % sorted(unknown_flags))
+
+  return [metric() for flag, metric in FAKE_METRICS_METRICS.iteritems()
+          if flag in flags_set]
 
 
 class TimelineBasedMetricTestData(object):
@@ -115,7 +122,7 @@ class TimelineBasedMetricTestData(object):
   def AddResults(self):
     for thread, records in self._threads_to_records_map.iteritems():
       metric = tbm_module._TimelineBasedMetrics(  # pylint: disable=W0212
-        self._model, thread, records, GetMetricFromMetricType)
+        self._model, thread, records, GetMetricFromFlags)
       metric.AddResults(self._results)
     self._results.DidRunPage(self._ps.pages[0])
 

tools/telemetry/telemetry/web_perf/timeline_interaction_record.py

@@ -176,6 +176,10 @@ class TimelineInteractionRecord(object):
                            'interaction record: %s' % metric_type)
     return metric_type in self._flags
 
+  def GetUserDefinedFlags(self):
+    return [metric_type for metric_type in METRICS
+            if metric_type in self._flags]
+
   def GetOverlappedThreadTimeForSlice(self, timeline_slice):
     """Get the thread duration of timeline_slice that overlaps with this record.