Merge pull request #179 from setrofim/fps

Add FPS derived metrics

devlib/__init__.py

@@ -13,7 +13,7 @@ from devlib.instrument import Instrument, InstrumentChannel, Measurement, Measur
 from devlib.instrument import MEASUREMENT_TYPES, INSTANTANEOUS, CONTINUOUS
 from devlib.instrument.daq import DaqInstrument
 from devlib.instrument.energy_probe import EnergyProbeInstrument
-from devlib.instrument.frames import GfxInfoFramesInstrument
+from devlib.instrument.frames import GfxInfoFramesInstrument, SurfaceFlingerFramesInstrument
 from devlib.instrument.hwmon import HwmonInstrument
 from devlib.instrument.monsoon import MonsoonInstrument
 from devlib.instrument.netstats import NetstatsInstrument
@@ -21,6 +21,7 @@ from devlib.instrument.gem5power import Gem5PowerInstrument
 
 from devlib.derived import DerivedMeasurements, DerivedMetric
 from devlib.derived.energy import DerivedEnergyMeasurements
+from devlib.derived.fps import DerivedGfxInfoStats, DerivedSurfaceFlingerStats
 
 from devlib.trace.ftrace import FtraceCollector
 

devlib/derived/fps.py

@@ -0,0 +1,214 @@
+from __future__ import division
+import csv
+import os
+import re
+
+try:
+    import pandas as pd
+except ImportError:
+    pd = None
+
+from devlib import DerivedMeasurements, DerivedMetric, MeasurementsCsv, InstrumentChannel
+from devlib.exception import HostError
+from devlib.utils.rendering import gfxinfo_get_last_dump, VSYNC_INTERVAL
+from devlib.utils.types import numeric
+
+
+class DerivedFpsStats(DerivedMeasurements):
+
+    def __init__(self, drop_threshold=5, suffix=None, filename=None, outdir=None):
+        self.drop_threshold = drop_threshold
+        self.suffix = suffix
+        self.filename = filename
+        self.outdir = outdir
+        if (filename is None) and (suffix is None):
+            self.suffix = '-fps'
+        elif (filename is not None) and (suffix is not None):
+            raise ValueError('suffix and filename cannot be specified at the same time.')
+        if filename is not None and os.sep in filename:
+            raise ValueError('filename cannot be a path (cannot countain "{}"'.format(os.sep))
+
+    def process(self, measurements_csv):
+        if isinstance(measurements_csv, basestring):
+            measurements_csv = MeasurementsCsv(measurements_csv)
+        if pd is not None:
+            return self._process_with_pandas(measurements_csv)
+        return self._process_without_pandas(measurements_csv)
+
+    def _get_csv_file_name(self, frames_file):
+        outdir = self.outdir or os.path.dirname(frames_file)
+        if self.filename:
+            return os.path.join(outdir, self.filename)
+
+        frames_basename = os.path.basename(frames_file)
+        rest, ext = os.path.splitext(frames_basename)
+        csv_basename = rest + self.suffix + ext
+        return os.path.join(outdir, csv_basename)
+
+
+class DerivedGfxInfoStats(DerivedFpsStats):
+
+    @staticmethod
+    def process_raw(filepath, *args):
+        metrics = []
+        dump = gfxinfo_get_last_dump(filepath)
+        seen_stats = False
+        for line in dump.split('\n'):
+            if seen_stats and not line.strip():
+                break
+            elif line.startswith('Janky frames:'):
+                text = line.split(': ')[-1]
+                val_text, pc_text = text.split('(')
+                metrics.append(DerivedMetric('janks', numeric(val_text.strip()), 'count'))
+                metrics.append(DerivedMetric('janks_pc', numeric(pc_text[:-3]), 'percent'))
+            elif ' percentile: ' in line:
+                ptile, val_text = line.split(' percentile: ')
+                name = 'render_time_{}_ptile'.format(ptile)
+                value = numeric(val_text.strip()[:-2])
+                metrics.append(DerivedMetric(name, value, 'time_ms'))
+            elif line.startswith('Number '):
+                name_text, val_text = line.strip().split(': ')
+                name = name_text[7:].lower().replace(' ', '_')
+                value = numeric(val_text)
+                metrics.append(DerivedMetric(name, value, 'count'))
+            else:
+                continue
+            seen_stats = True
+        return metrics
+
+    def _process_without_pandas(self, measurements_csv):
+        per_frame_fps = []
+        start_vsync, end_vsync = None, None
+        frame_count = 0
+
+        for frame_data in measurements_csv.iter_values():
+            if frame_data.Flags_flags != 0:
+                continue
+            frame_count += 1
+
+            if start_vsync is None:
+                start_vsync = frame_data.Vsync_time_us
+            end_vsync = frame_data.Vsync_time_us
+
+            frame_time = frame_data.FrameCompleted_time_us - frame_data.IntendedVsync_time_us
+            pff = 1e9 / frame_time
+            if pff > self.drop_threshold:
+                per_frame_fps.append([pff])
+
+        if frame_count:
+            duration = end_vsync - start_vsync
+            fps = (1e6 * frame_count) / float(duration)
+        else:
+            duration = 0
+            fps = 0
+
+        csv_file = self._get_csv_file_name(measurements_csv.path)
+        with open(csv_file, 'wb') as wfh:
+            writer = csv.writer(wfh)
+            writer.writerow(['fps'])
+            writer.writerows(per_frame_fps)
+
+        return [DerivedMetric('fps', fps, 'fps'),
+                DerivedMetric('total_frames', frame_count, 'frames'),
+                MeasurementsCsv(csv_file)]
+
+    def _process_with_pandas(self, measurements_csv):
+        data = pd.read_csv(measurements_csv.path)
+        data = data[data.Flags_flags == 0]
+        frame_time = data.FrameCompleted_time_us - data.IntendedVsync_time_us
+        per_frame_fps = (1e6 / frame_time)
+        keep_filter = per_frame_fps > self.drop_threshold
+        per_frame_fps = per_frame_fps[keep_filter]
+        per_frame_fps.name = 'fps'
+
+        frame_count = data.index.size
+        if frame_count > 1:
+            duration = data.Vsync_time_us.iloc[-1] - data.Vsync_time_us.iloc[0]
+            fps = (1e9 * frame_count) / float(duration)
+        else:
+            duration = 0
+            fps = 0
+
+        csv_file = self._get_csv_file_name(measurements_csv.path)
+        per_frame_fps.to_csv(csv_file, index=False, header=True)
+
+        return [DerivedMetric('fps', fps, 'fps'),
+                DerivedMetric('total_frames', frame_count, 'frames'),
+                MeasurementsCsv(csv_file)]
+
+
+class DerivedSurfaceFlingerStats(DerivedFpsStats):
+
+    def _process_with_pandas(self, measurements_csv):
+        data = pd.read_csv(measurements_csv.path)
+
+        # fiter out bogus frames.
+        bogus_frames_filter = data.actual_present_time_us != 0x7fffffffffffffff
+        actual_present_times = data.actual_present_time_us[bogus_frames_filter]
+        actual_present_time_deltas = actual_present_times.diff().dropna()
+
+        vsyncs_to_compose = actual_present_time_deltas.div(VSYNC_INTERVAL)
+        vsyncs_to_compose.apply(lambda x: int(round(x, 0)))
+
+        # drop values lower than drop_threshold FPS as real in-game frame
+        # rate is unlikely to drop below that (except on loading screens
+        # etc, which should not be factored in frame rate calculation).
+        per_frame_fps = (1.0 / (vsyncs_to_compose.multiply(VSYNC_INTERVAL / 1e9)))
+        keep_filter = per_frame_fps > self.drop_threshold
+        filtered_vsyncs_to_compose = vsyncs_to_compose[keep_filter]
+        per_frame_fps.name = 'fps'
+
+        csv_file = self._get_csv_file_name(measurements_csv.path)
+        per_frame_fps.to_csv(csv_file, index=False, header=True)
+
+        if not filtered_vsyncs_to_compose.empty:
+            fps = 0
+            total_vsyncs = filtered_vsyncs_to_compose.sum()
+            frame_count = filtered_vsyncs_to_compose.size
+
+            if total_vsyncs:
+                fps = 1e9 * frame_count / (VSYNC_INTERVAL * total_vsyncs)
+
+            janks = self._calc_janks(filtered_vsyncs_to_compose)
+            not_at_vsync = self._calc_not_at_vsync(vsyncs_to_compose)
+        else:
+            fps = 0
+            frame_count = 0
+            janks = 0
+            not_at_vsync = 0
+
+        return [DerivedMetric('fps', fps, 'fps'),
+                DerivedMetric('total_frames', frame_count, 'frames'),
+                MeasurementsCsv(csv_file),
+                DerivedMetric('janks', janks, 'count'),
+                DerivedMetric('janks_pc', janks * 100 / frame_count, 'percent'),
+                DerivedMetric('missed_vsync', not_at_vsync, 'count')]
+
+    def _process_without_pandas(self, measurements_csv):
+        # Given that SurfaceFlinger has been deprecated in favor of GfxInfo,
+        # it does not seem worth it implementing this.
+        raise HostError('Please install "pandas" Python package to process SurfaceFlinger frames')
+
+    @staticmethod
+    def _calc_janks(filtered_vsyncs_to_compose):
+        """
+        Internal method for calculating jank frames.
+        """
+        pause_latency = 20
+        vtc_deltas = filtered_vsyncs_to_compose.diff().dropna()
+        vtc_deltas = vtc_deltas.abs()
+        janks = vtc_deltas.apply(lambda x: (pause_latency > x > 1.5) and 1 or 0).sum()
+
+        return janks
+
+    @staticmethod
+    def _calc_not_at_vsync(vsyncs_to_compose):
+        """
+        Internal method for calculating the number of frames that did not
+        render in a single vsync cycle.
+        """
+        epsilon = 0.0001
+        func = lambda x: (abs(x - 1.0) > epsilon) and 1 or 0
+        not_at_vsync = vsyncs_to_compose.apply(func).sum()
+
+        return not_at_vsync

devlib/instrument/frames.py

@@ -1,3 +1,4 @@
+from __future__ import division
 from devlib.instrument import (Instrument, CONTINUOUS,
                                MeasurementsCsv, MeasurementType)
 from devlib.utils.rendering import (GfxinfoFrameCollector,

devlib/utils/rendering.py

@@ -18,6 +18,8 @@ logger = logging.getLogger('rendering')
 SurfaceFlingerFrame = namedtuple('SurfaceFlingerFrame',
                                  'desired_present_time actual_present_time frame_ready_time')
 
+VSYNC_INTERVAL = 16666667
+
 
 class FrameCollector(threading.Thread):
 
@@ -193,6 +195,7 @@ class GfxinfoFrameCollector(FrameCollector):
     def _process_raw_file(self, fh):
         found = False
         try:
+            last_vsync = 0
             while True:
                 for line in fh:
                     if line.startswith('---PROFILEDATA---'):
@@ -203,7 +206,11 @@ class GfxinfoFrameCollector(FrameCollector):
                 for line in fh:
                     if line.startswith('---PROFILEDATA---'):
                         break
-                    self.frames.append(map(int, line.strip().split(',')[:-1]))  # has a trailing ','
+                    entries = map(int, line.strip().split(',')[:-1])  # has a trailing ','
+                    if entries[1] <= last_vsync:
+                        continue  # repeat frame
+                    last_vsync = entries[1]
+                    self.frames.append(entries)
         except StopIteration:
             pass
         if not found:

doc/derived_measurements.rst

@@ -124,3 +124,98 @@ Energy
    sites of the coresponding channels according to the following patters:
    ``"<site>_total_energy"`` and ``"<site>_average_power"``.
 
+
+FPS / Rendering
+~~~~~~~~~~~~~~~
+
+.. class:: DerivedGfxInfoStats(drop_threshold=5, suffix='-fps', filename=None, outdir=None)
+
+   Produces FPS (frames-per-second) and other dervied statistics from
+   :class:`GfxInfoFramesInstrument` output. This takes several optional
+   parameters in creation:
+
+   :param drop_threshold: FPS in an application, such as a game, which this
+                          processor is primarily targeted at, cannot reasonably
+                          drop to a very low value. This is specified to this
+                          threhold. If an FPS for a frame is computed to be
+                          lower than this treshold, it will be dropped on the
+                          assumption that frame rednering was suspended by the
+                          system (e.g. when idling), or there was some sort of
+                          error, and therefore this should be used in
+                          performance calculations. defaults to ``5``.
+   :param  suffix: The name of the gerated per-frame FPS csv file will be
+                   derived from the input frames csv file by appending this
+                   suffix. This cannot be specified at the same time as
+                   a ``filename``.
+   :param filename: As an alternative to the suffix, a complete file name for
+                    FPS csv can be specified. This cannot be used at the same
+                    time as the ``suffix``.
+   :param outdir: By default, the FPS csv file will be placed in the same
+                  directory as the input frames csv file. This can be changed
+                  by specifying an alternate directory here
+
+   .. warning:: Specifying both ``filename`` and ``oudir`` will mean that exactly
+                the same file will be used for FPS output on each invocation of
+                ``process()`` (even for different inputs) resulting in previous
+                results being overwritten.
+
+.. method:: DerivedGfxInfoStats.process(measurement_csv)
+
+   Process the fames csv generated by :class:`GfxInfoFramesInstrument` and
+   returns a list containing exactly three entries: :class:`DerivedMetric`\ s
+   ``fps`` and ``total_frames``, followed by a :class:`MeasurentCsv` containing
+   per-frame FPSs values.
+
+.. method:: DerivedGfxInfoStats.process_raw(gfxinfo_frame_raw_file)
+
+   As input, this takes a single argument, which should be the path to the raw
+   output file of  :class:`GfxInfoFramesInstrument`. The returns stats
+   accumulated by gfxinfo. At the time of wrinting, the stats (in order) are:
+   ``janks``, ``janks_pc`` (percentage of all frames),
+   ``render_time_50th_ptile`` (50th percentile, or median, for time to render a
+   frame), ``render_time_90th_ptile``, ``render_time_95th_ptile``,
+   ``render_time_99th_ptile``, ``missed_vsync``, ``hight_input_latency``,
+   ``slow_ui_thread``, ``slow_bitmap_uploads``, ``slow_issue_draw_commands``.
+   Please see the `gfxinfo documentation`_ for details.
+
+.. _gfxinfo documentation: https://developer.android.com/training/testing/performance.html
+
+
+.. class:: DerivedSurfaceFlingerStats(drop_threshold=5, suffix='-fps', filename=None, outdir=None)
+
+   Produces FPS (frames-per-second) and other dervied statistics from
+   :class:`SurfaceFlingerFramesInstrument` output. This takes several optional
+   parameters in creation:
+
+   :param drop_threshold: FPS in an application, such as a game, which this
+                          processor is primarily targeted at, cannot reasonably
+                          drop to a very low value. This is specified to this
+                          threhold. If an FPS for a frame is computed to be
+                          lower than this treshold, it will be dropped on the
+                          assumption that frame rednering was suspended by the
+                          system (e.g. when idling), or there was some sort of
+                          error, and therefore this should be used in
+                          performance calculations. defaults to ``5``.
+   :param  suffix: The name of the gerated per-frame FPS csv file will be
+                   derived from the input frames csv file by appending this
+                   suffix. This cannot be specified at the same time as
+                   a ``filename``.
+   :param filename: As an alternative to the suffix, a complete file name for
+                    FPS csv can be specified. This cannot be used at the same
+                    time as the ``suffix``.
+   :param outdir: By default, the FPS csv file will be placed in the same
+                  directory as the input frames csv file. This can be changed
+                  by specifying an alternate directory here
+
+   .. warning:: Specifying both ``filename`` and ``oudir`` will mean that exactly
+                the same file will be used for FPS output on each invocation of
+                ``process()`` (even for different inputs) resulting in previous
+                results being overwritten.
+
+.. method:: DerivedSurfaceFlingerStats.process(measurement_csv)
+
+   Process the fames csv generated by :class:`SurfaceFlingerFramesInstrument` and
+   returns a list containing exactly three entries: :class:`DerivedMetric`\ s
+   ``fps`` and ``total_frames``, followed by a :class:`MeasurentCsv` containing
+   per-frame FPSs values, followed by ``janks`` ``janks_pc``, and
+   ``missed_vsync`` metrics.