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