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    return not len(results)
110
111  def GetSurfaceFlingerPid(self):
112    results = self._device.RunShellCommand('ps | grep surfaceflinger')
113    if not results:
114      raise Exception('Unable to get surface flinger process id')
115    pid = results[0].split()[1]
116    return pid
117
118  def _GetSurfaceFlingerFrameData(self):
119    """Returns collected SurfaceFlinger frame timing data.
120
121    Returns:
122      A tuple containing:
123      - The display's nominal refresh period in milliseconds.
124      - A list of timestamps signifying frame presentation times in
125        milliseconds.
126      The return value may be (None, None) if there was no data collected (for
127      example, if the app was closed before the collector thread has finished).
128    """
129    # adb shell dumpsys SurfaceFlinger --latency <window name>
130    # prints some information about the last 128 frames displayed in
131    # that window.
132    # The data returned looks like this:
133    # 16954612
134    # 7657467895508   7657482691352   7657493499756
135    # 7657484466553   7657499645964   7657511077881
136    # 7657500793457   7657516600576   7657527404785
137    # (...)
138    #
139    # The first line is the refresh period (here 16.95 ms), it is followed
140    # by 128 lines w/ 3 timestamps in nanosecond each:
141    # A) when the app started to draw
142    # B) the vsync immediately preceding SF submitting the frame to the h/w
143    # C) timestamp immediately after SF submitted that frame to the h/w
144    #
145    # The difference between the 1st and 3rd timestamp is the frame-latency.
146    # An interesting data is when the frame latency crosses a refresh period
147    # boundary, this can be calculated this way:
148    #
149    # ceil((C - A) / refresh-period)
150    #
151    # (each time the number above changes, we have a "jank").
152    # If this happens a lot during an animation, the animation appears
153    # janky, even if it runs at 60 fps in average.
154    #
155    # We use the special "SurfaceView" window name because the statistics for
156    # the activity's main window are not updated when the main web content is
157    # composited into a SurfaceView.
158    results = self._device.RunShellCommand(
159        'dumpsys SurfaceFlinger --latency SurfaceView')
160    if not len(results):
161      return (None, None)
162
163    timestamps = []
164    nanoseconds_per_millisecond = 1e6
165    refresh_period = long(results[0]) / nanoseconds_per_millisecond
166
167    # If a fence associated with a frame is still pending when we query the
168    # latency data, SurfaceFlinger gives the frame a timestamp of INT64_MAX.
169    # Since we only care about completed frames, we will ignore any timestamps
170    # with this value.
171    pending_fence_timestamp = (1 << 63) - 1
172
173    for line in results[1:]:
174      fields = line.split()
175      if len(fields) != 3:
176        continue
177      timestamp = long(fields[1])
178      if timestamp == pending_fence_timestamp:
179        continue
180      timestamp /= nanoseconds_per_millisecond
181      timestamps.append(timestamp)
182
183    return (refresh_period, timestamps)
184