Telemetry Test for WebRTC Rendering.

tools/telemetry/telemetry/web_perf/metrics/webrtc_rendering_timeline.py

Index: tools/telemetry/telemetry/web_perf/metrics/webrtc_rendering_timeline.py
diff --git a/tools/telemetry/telemetry/web_perf/metrics/webrtc_rendering_timeline.py b/tools/telemetry/telemetry/web_perf/metrics/webrtc_rendering_timeline.py
new file mode 100644
index 0000000000000000000000000000000000000000..a14808a92f7271c0ce942c2630345adc1ad59d89
--- /dev/null
+++ b/tools/telemetry/telemetry/web_perf/metrics/webrtc_rendering_timeline.py
@@ -0,0 +1,307 @@
+# 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 logging
+
+import numpy
+
+from telemetry.value import list_of_scalar_values
+from telemetry.web_perf.metrics import timeline_based_metric
+from telemetry.value import scalar
+from telemetry.value import list_of_string_values
+
+WEB_MEDIA_PLAYER_MS_EVENT = 'WebMediaPlayerMS::UpdateCurrentFrame'
+
+DISPLAY_HERTZ = 60.0
+# When to consider a frame frozen (in VSYNC units):
+# meaning 1 initial frame + 5 repeats of that frame.
+FROZEN_THRESHOLD = 6
+# Severity factor.
+SEVERITY = 3
+
+
+class WebMediaPlayerMsRenderingStats(object):
+  """Analyzes events of WebMediaPlayerMs type."""
+
+  def __init__(self, events):
+    """Save relevant events."""
+    self.relevant_events = events
+
+  def InferCadence(self):
+    """Calculate the apparent cadence of the rendering."""
+    # Term 'cadence' loosely used here for lack of a better word.
+    cadence = []
+    frame_persistence = 0
+    old_ideal_render = 0
+    for event in self.relevant_events:
+      if (event.args and 'Ideal Render Instant' in event.args
+          and event.args['Ideal Render Instant'] == old_ideal_render):
+        frame_persistence += 1
+      elif event.args and 'Ideal Render Instant' in event.args:
+        cadence.append(frame_persistence)
+        frame_persistence = 1
+        old_ideal_render = event.args['Ideal Render Instant']
+    cadence.append(frame_persistence)
+    cadence.pop(0)
+    return cadence
+
+  def Bucketize(self, cadence):
+    """Create distribution for the cadence frame display values."""
+    # If the overall display distribution is A1:A2:..:An,
+    # this will tell us how many times a frame
+    # stays displayed during Ak vsync duration (i.e. Ak/DISPLAY_HERTZ)
+    # also known as 'source to output' distribution.
+    bucket = {}
+    for ticks in cadence:
+      if ticks in bucket:
+        bucket[ticks] += 1
+      else:
+        bucket[ticks] = 1
+    return bucket
+
+  def InferFpsFromCadence(self, bucket):
+    """Calculate the apparent FPS from cadence pattern."""
+    # The mean ratio is the barycenter
+    weight = sum([bucket[ticks] for ticks in bucket])
+    population = sum([ticks * bucket[ticks] for ticks in bucket])
+    mean_ratio = float(population) / weight
+    fps = DISPLAY_HERTZ / mean_ratio
+    return fps
+
+  def InferFrozenFramesEvents(self, bucket):
+    """Find evidence of frozen frames in distribution."""
+    # For simplicity we count as freezing the frames
+    # that appear at least five times in a row
+    # counted from 'Ideal Render Instant' perspective.
+    frozen_frames = []
+    for ticks in bucket:
+      if ticks >= FROZEN_THRESHOLD:
+        logging.error('%s frames not updated after %s vsyncs',
+            bucket[ticks], ticks)
+        frozen_frames.append(
+            {'frozen_frames': ticks -1,
+             'occurences': bucket[ticks]})
+    return frozen_frames
+
+  def FrozenPenaltyWeight(self, number_frozen_frames):
+    """Returns the weighted penalty for a number of frozen frames."""
+    # As mentioned earlier, we count for frozen anything above 6 vsync
+    # display duration for the same 'Initial Render Instant'.
+    penalty = {
+      0: 0,
+      1: 0,
+      2: 0,
+      3: 0,
+      4: 0,
+      5: 1,
+      6: 5,
+      7: 15,
+      8: 25
+    }
+    weight = penalty.get(number_frozen_frames,
+        8 * (number_frozen_frames - 4))
+    return weight
+
+  def InferTimeStats(self):
+    """Calculate time stamp stats for all events."""
+
+    cadence = self.InferCadence()
+    bucket = self.Bucketize(cadence)
+    fps = self.InferFpsFromCadence(bucket)
+    frozen_frames = self.InferFrozenFramesEvents(bucket)
+    # Drift time between Ideal Render Instant and Actual Render Begin.
+    drift_time = []
+    old_ideal_render = 0
+    discrepancy = []
+    index = 0
+    for event in self.relevant_events:
+      current_ideal_render = event.args['Ideal Render Instant']
+      if current_ideal_render == old_ideal_render:
+        continue
+      drift_time.append(
+              event.args['Actual Render Begin'] - current_ideal_render)
+      discrepancy.append(abs(current_ideal_render - old_ideal_render
+              - 1e6 / DISPLAY_HERTZ * cadence[index]))
+      old_ideal_render = current_ideal_render
+      index += 1
+    discrepancy.pop(0)
+    last_ideal_render = self.relevant_events[-1].args['Ideal Render Instant']
+    first_ideal_render = self.relevant_events[0].args['Ideal Render Instant']
+    rendering_length_error = 100.0 * (sum([x for x in discrepancy]) /
+        (last_ideal_render - first_ideal_render))
+    # Some stats on drift time.
+    mean_drift_time = numpy.mean(drift_time)
+    std_dev_drift_time = numpy.std(drift_time)
+    norm_drift_time = [abs(x - mean_drift_time) for x in drift_time]
+    # How many times is a frame later/earlier than T=2/DISPLAY_HERTZ.
+    # Time is in microseconds.
+    frames_severely_out_of_sync = len(
+        [x for x in norm_drift_time if abs(x) > 2e6 / DISPLAY_HERTZ])
+    percent_badly_oos = (
+        100.0 * frames_severely_out_of_sync / len(norm_drift_time))
+    # How many times is a frame later/earlier than 1/DISPLAY_HERTZ.
+    frames_out_of_sync = len(
+        [x for x in norm_drift_time if abs(x) > 1e6 / (DISPLAY_HERTZ)])
+    percent_out_of_sync = (
+        100.0 * frames_out_of_sync / len(norm_drift_time))
+
+    frames_oos_only_once = frames_out_of_sync - frames_severely_out_of_sync
+    # For safety I don't use population = len(self.relevant_events) just
+    # in case other events are added later.
+    population = sum([n * bucket[n] for n in bucket])
+    # Calculate smoothness metric.
+    # From the formula, we can see that smoothness score can be negative.
+    smoothness_score = 100.0 - 100.0*(frames_oos_only_once +
+        SEVERITY * frames_severely_out_of_sync) / len(norm_drift_time)
+    # Calculate freezing metric.
+    # Freezing metric can be negative if things are really bad.
+    freezing_score = 100.0
+    for frozen_report in frozen_frames:
+      weight = self.FrozenPenaltyWeight(frozen_report['frozen_frames'])
+      freezing_score -= (
+          100.0 * frozen_report['occurences'] / population * weight)
+    # negative score are meaningless, so zero them
+    if freezing_score < 0:
+      freezing_score = 0
+    if smoothness_score < 0:
+      smoothness_score = 0
+
+    stats = {
+        'drift_time': drift_time,
+        'mean_drift_time': mean_drift_time,
+        'std_dev_drift_time': std_dev_drift_time,
+        'percent_badly_out_of_sync': percent_badly_oos,
+        'percent_out_of_sync': percent_out_of_sync,
+        'smoothness_score': smoothness_score,
+        'freezing_score': freezing_score,
+        'rendering_length_error': rendering_length_error,
+        'fps': fps,
+        'bucket': bucket}
+    return stats
+
+
+class WebrtcRenderingTimelineMetric(timeline_based_metric.TimelineBasedMetric):
+  """WebrtcRenderingTimelineMetric calculates metric for WebMediaPlayerMS.
+
+  The following metrics are added to the results:
+    WebRtcRendering_drift_time usec
+    WebRTCRendering_std_dev_drift_time usec
+    WebRTCRendering_percent_badly_out_of_sync %
+    WebRTCRendering_percent_out_of_sync %
+    WebRTCRendering_fps FPS
+    WebRTCRendering_smoothness_score %
+    WebRTCRendering_freezing_score %
+    WebRTCRendering_rendering_length_error %
+  """
+
+  def __init__(self):
+    super(WebrtcRenderingTimelineMetric, self).__init__()
+    print '### DEBUG processing rendering timeline ###'
+
+  @staticmethod
+  def IsMediaPlayerMSEvent(event):
+    """Verify that the event is a webmediaplayerMS event."""
+    return event.name == WEB_MEDIA_PLAYER_MS_EVENT
+
+  @staticmethod
+  def IsEventInInteraction(event, interaction):
+    """Verify that the event belong to the gbiven interaction."""
+    return interaction.start <= event.start <= interaction.end
+
+  def AddResults(self, model, renderer_thread, interactions, results):
+    """Adding metrics to the results."""
+    assert interactions
+    print "## DEBUG in AddResults ###"
+    found_events = []
+    for event in renderer_thread.parent.IterAllEvents(
+        event_predicate=self.IsMediaPlayerMSEvent):
+      if self.IsEventInInteraction(event, interactions):
+        found_events.append(event)
+    stats_parser = WebMediaPlayerMsRenderingStats(found_events)
+    rendering_stats = stats_parser.InferTimeStats()
+    logging.info('rendering stats : %s', rendering_stats)
+    results.AddValue(list_of_scalar_values.ListOfScalarValues(
+        results.current_page,
+        'WebRtcRendering_drift_time',
+        'usec',
+        rendering_stats['drift_time'],
+        important=True,
+        description='Drift time for a rendered frame'))
+
+    results.AddValue(scalar.ScalarValue(
+        results.current_page,
+        'WebRTCRendering_mean_drift_time',
+        'usec',
+        rendering_stats['mean_drift_time'],
+        important=True,
+        description='Mean drift time for frames'))
+
+    results.AddValue(scalar.ScalarValue(
+        results.current_page,
+        'WebRTCRendering_std_dev_drift_time',
+        'usec',
+        rendering_stats['std_dev_drift_time'],
+        important=True,
+        description='Standard deviation of drift time for frames'))
+
+    results.AddValue(scalar.ScalarValue(
+        results.current_page,
+        'WebRTCRendering_percent_badly_out_of_sync',
+        '%',
+        rendering_stats['percent_badly_out_of_sync'],
+        important=True,
+        description='Percentage of frame which drifted more than 2 VSYNC'))
+
+    results.AddValue(scalar.ScalarValue(
+        results.current_page,
+        'WebRTCRendering_percent_out_of_sync',
+        '%',
+        rendering_stats['percent_out_of_sync'],
+        important=True,
+        description='Percentage of frame which drifted more than 1 VSYNC'))
+
+    # make the output distribution a list since
+    # no facilities for dict values exist (yet)
+    bucket_list = []
+    for key, value in rendering_stats['bucket'].iteritems():
+      temp = '%s:%s' % (key, value)
+      bucket_list.append(temp)
+    results.AddValue(list_of_string_values.ListOfStringValues(
+      results.current_page,
+      'WebRtcRendering_bucket',
+      'frames:occurences',
+      bucket_list,
+      important=True,
+      description='Output distribution of frames'))
+
+    results.AddValue(scalar.ScalarValue(
+      results.current_page,
+      'WebRTCRendering_fps',
+      'FPS',
+      rendering_stats['fps'],
+      important=True,
+      description='Calculated Frame Rate of video rendering'))
+
+    results.AddValue(scalar.ScalarValue(
+      results.current_page,
+      'WebRTCRendering_smoothness_score',
+      '%',
+      rendering_stats['smoothness_score'],
+      important=True,
+      description='Smoothness score of rendering'))
+
+    results.AddValue(scalar.ScalarValue(
+      results.current_page,
+      'WebRTCRendering_freezing_score',
+      '%',
+      rendering_stats['freezing_score'],
+      important=True,
+      description='Freezing score of rendering'))
+
+    results.AddValue(scalar.ScalarValue(
+      results.current_page,
+      'WebRTCRendering_rendering_length_error',
+      '%',
+      rendering_stats['rendering_length_error'],
+      important=True,
+      description='Rendering length error rate'))