Telemetry Test for WebRTC Rendering.

tools/perf/measurements/webrtc_rendering.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 numpy
+import logging
+
+from telemetry.timeline import tracing_category_filter
+from telemetry.timeline import tracing_options
+from telemetry.timeline import model
+from telemetry.page import page_test
+from telemetry.value import scalar
+from telemetry.value import list_of_scalar_values
+from telemetry.value import list_of_string_values
+from metrics import power
+
+
+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])

[qiangchen, 2015/08/28 21:26:01]

Possibly name this variable as num_frames.

[cpaulin (no longer in chrome), 2015/09/16 22:57:04]

Done.

+        population= sum([ticks * bucket[ticks] for ticks in bucket])

[qiangchen, 2015/08/28 21:26:01]

Possibly name this variable as num_vsyncs. 

[cpaulin (no longer in chrome), 2015/09/16 22:57:04]

Done.

+        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 ,

[qiangchen, 2015/08/28 21:26:01]

Question: why we take ticks-1 here?

[cpaulin (no longer in chrome), 2015/09/16 22:57:05]

Because if you have 1 source frame and it displayed 4 times, I think the number
of frozen frames is 3. Does it make sense?

+                         '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])

[qiangchen, 2015/08/28 21:26:01]

How about defining a variable say vsync_duration = 1e6 / DISPLAY_HERTZ instead
of do this computation here and there.

+        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])

[qiangchen, 2015/08/28 21:26:01]

ditto

+        # 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)
+
+        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 WebRTCRendering(page_test.PageTest):

[nednguyen, 2015/09/02 16:26:46]

Please don't add another page_test & use TimelineBasedMeasurement's structure
instead. It's less code to write for you & more existing features that you can
reuse (for example: TBM upload the trace to cloud storage at the end of test run
so you can view the trace on the dashboard)


For example of how to add a timeline_based_metric, see:
https://codereview.chromium.org/1104053006/

[phoglund_chromium, 2015/09/04 09:16:24]

Right, and so most of this code should be a Metric which gets imported by the
Measurement?

+    """Gathers WebRTC video rendering-related metrics on a page set."""
+
+    def __init__(self):
+        super(WebRTCRendering, self).__init__()
+        self._power_metric = None
+        self._webrtc_rendering_metric = None
+
+    def WillStartBrowser(self, platform):
+        self._power_metric = power.PowerMetric(platform)
+
+    def WillNavigateToPage(self, page, tab):
+        self._power_metric.Start(page, tab)
+
+        options = tracing_options.TracingOptions()
+        options.enable_chrome_trace = True
+        # FIXME: Remove the timeline category when impl-side painting is on
+        # everywhere.
+        category_filter = tracing_category_filter.TracingCategoryFilter('cc')
+        tab.browser.platform.tracing_controller.Start(options, category_filter)
+
+    def CustomizeBrowserOptions(self, options):
+        #options.AppendExtraBrowserArgs('--use-fake-device-for-media-stream')
+        options.AppendExtraBrowserArgs('--use-fake-ui-for-media-stream')
+        power.PowerMetric.CustomizeBrowserOptions(options)
+
+    def StopBrowserAfterPage(self, browser, page):
+        # Restart the browser after the last page in the pageset.
+        return True
+
+    def ValidateAndMeasurePage(self, page, tab, results):
+        timeline_data = tab.browser.platform.tracing_controller.Stop()
+        timeline_model = model.TimelineModel(timeline_data)
+        self._power_metric.Stop(page, tab)
+        self._power_metric.AddResults(tab, results)
+        rendering_events = timeline_model.GetAllEventsOfName(
+                'WebMediaPlayerMS::UpdateCurrentFrame')
+        if not rendering_events:
+            rendering_events = [{'args':{'Unkown':'Unknown'}}]
+            # TBD what to do next when no events exist?
+        event_parser = WebMediaPlayerMsRenderingStats(rendering_events)
+        rendering_stats = event_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'))
+
+    def CleanUpAfterPage(self, page, tab):
+        tracing_controller = tab.browser.platform.tracing_controller
+        if tracing_controller.is_tracing_running:
+            tracing_controller.Stop()