build/android/pylib/perf/surface_stats_collector.py

   1 # Copyright 2013 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
   5 import Queue
   6 import datetime
   7 import logging
   8 import re
   9 import threading
  10 from pylib import android_commands
  11 from pylib.device import device_utils
  12
  13
  14 # Log marker containing SurfaceTexture timestamps.
  15 _SURFACE_TEXTURE_TIMESTAMPS_MESSAGE = 'SurfaceTexture update timestamps'
  16 _SURFACE_TEXTURE_TIMESTAMP_RE = r'\d+'
  17
  18
  19 class SurfaceStatsCollector(object):
  20   """Collects surface stats for a SurfaceView from the output of SurfaceFlinger.
  21
  22   Args:
  23     device: A DeviceUtils instance.
  24   """
  25
  26   def __init__(self, device):
  27     # TODO(jbudorick) Remove once telemetry gets switched over.
  28     if isinstance(device, android_commands.AndroidCommands):
  29       device = device_utils.DeviceUtils(device)
  30     self._device = device
  31     self._collector_thread = None
  32     self._surface_before = None
  33     self._get_data_event = None
  34     self._data_queue = None
  35     self._stop_event = None
  36     self._warn_about_empty_data = True
  37
  38   def DisableWarningAboutEmptyData(self):
  39     self._warn_about_empty_data = False
  40
  41   def Start(self):
  42     assert not self._collector_thread
  43
  44     if self._ClearSurfaceFlingerLatencyData():
  45       self._get_data_event = threading.Event()
  46       self._stop_event = threading.Event()
  47       self._data_queue = Queue.Queue()
  48       self._collector_thread = threading.Thread(target=self._CollectorThread)
  49       self._collector_thread.start()
  50     else:
  51       raise Exception('SurfaceFlinger not supported on this device.')
  52
  53   def Stop(self):
  54     assert self._collector_thread
  55     (refresh_period, timestamps) = self._GetDataFromThread()
  56     if self._collector_thread:
  57       self._stop_event.set()
  58       self._collector_thread.join()
  59       self._collector_thread = None
  60     return (refresh_period, timestamps)
  61
  62   def _CollectorThread(self):
  63     last_timestamp = 0
  64     timestamps = []
  65     retries = 0
  66
  67     while not self._stop_event.is_set():
  68       self._get_data_event.wait(1)
  69       try:
  70         refresh_period, new_timestamps = self._GetSurfaceFlingerFrameData()
  71         if refresh_period is None or timestamps is None:
  72           retries += 1
  73           if retries < 3:
  74             continue
  75           if last_timestamp:
  76             # Some data has already been collected, but either the app
  77             # was closed or there's no new data. Signal the main thread and
  78             # wait.
  79             self._data_queue.put((None, None))
  80             self._stop_event.wait()
  81             break
  82           raise Exception('Unable to get surface flinger latency data')
  83
  84         timestamps += [timestamp for timestamp in new_timestamps
  85                        if timestamp > last_timestamp]
  86         if len(timestamps):
  87           last_timestamp = timestamps[-1]
  88
  89         if self._get_data_event.is_set():
  90           self._get_data_event.clear()
  91           self._data_queue.put((refresh_period, timestamps))
  92           timestamps = []
  93       except Exception as e:
  94         # On any error, before aborting, put the exception into _data_queue to
  95         # prevent the main thread from waiting at _data_queue.get() infinitely.
  96         self._data_queue.put(e)
  97         raise
  98
  99   def _GetDataFromThread(self):
 100     self._get_data_event.set()
 101     ret = self._data_queue.get()
 102     if isinstance(ret, Exception):
 103       raise ret
 104     return ret
 105
 106   def _ClearSurfaceFlingerLatencyData(self):
 107     """Clears the SurfaceFlinger latency data.
 108
 109     Returns:
 110       True if SurfaceFlinger latency is supported by the device, otherwise
 111       False.
 112     """
 113     # The command returns nothing if it is supported, otherwise returns many
 114     # lines of result just like 'dumpsys SurfaceFlinger'.
 115     results = self._device.RunShellCommand(
 116         'dumpsys SurfaceFlinger --latency-clear SurfaceView')
 117     return not len(results)
 118
 119   def GetSurfaceFlingerPid(self):
 120     results = self._device.RunShellCommand('ps | grep surfaceflinger')
 121     if not results:
 122       raise Exception('Unable to get surface flinger process id')
 123     pid = results[0].split()[1]
 124     return pid
 125
 126   def _GetSurfaceFlingerFrameData(self):
 127     """Returns collected SurfaceFlinger frame timing data.
 128
 129     Returns:
 130       A tuple containing:
 131       - The display's nominal refresh period in milliseconds.
 132       - A list of timestamps signifying frame presentation times in
 133         milliseconds.
 134       The return value may be (None, None) if there was no data collected (for
 135       example, if the app was closed before the collector thread has finished).
 136     """
 137     # adb shell dumpsys SurfaceFlinger --latency <window name>
 138     # prints some information about the last 128 frames displayed in
 139     # that window.
 140     # The data returned looks like this:
 141     # 16954612
 142     # 7657467895508   7657482691352   7657493499756
 143     # 7657484466553   7657499645964   7657511077881
 144     # 7657500793457   7657516600576   7657527404785
 145     # (...)
 146     #
 147     # The first line is the refresh period (here 16.95 ms), it is followed
 148     # by 128 lines w/ 3 timestamps in nanosecond each:
 149     # A) when the app started to draw
 150     # B) the vsync immediately preceding SF submitting the frame to the h/w
 151     # C) timestamp immediately after SF submitted that frame to the h/w
 152     #
 153     # The difference between the 1st and 3rd timestamp is the frame-latency.
 154     # An interesting data is when the frame latency crosses a refresh period
 155     # boundary, this can be calculated this way:
 156     #
 157     # ceil((C - A) / refresh-period)
 158     #
 159     # (each time the number above changes, we have a "jank").
 160     # If this happens a lot during an animation, the animation appears
 161     # janky, even if it runs at 60 fps in average.
 162     #
 163     # We use the special "SurfaceView" window name because the statistics for
 164     # the activity's main window are not updated when the main web content is
 165     # composited into a SurfaceView.
 166     results = self._device.RunShellCommand(
 167         'dumpsys SurfaceFlinger --latency SurfaceView')
 168     if not len(results):
 169       return (None, None)
 170
 171     timestamps = []
 172     nanoseconds_per_millisecond = 1e6
 173     refresh_period = long(results[0]) / nanoseconds_per_millisecond
 174
 175     # If a fence associated with a frame is still pending when we query the
 176     # latency data, SurfaceFlinger gives the frame a timestamp of INT64_MAX.
 177     # Since we only care about completed frames, we will ignore any timestamps
 178     # with this value.
 179     pending_fence_timestamp = (1 << 63) - 1
 180
 181     for line in results[1:]:
 182       fields = line.split()
 183       if len(fields) != 3:
 184         continue
 185       timestamp = long(fields[1])
 186       if timestamp == pending_fence_timestamp:
 187         continue
 188       timestamp /= nanoseconds_per_millisecond
 189       timestamps.append(timestamp)
 190
 191     return (refresh_period, timestamps)