OLD | NEW |
1 # Copyright 2013 The Chromium Authors. All rights reserved. | 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 | 2 # Use of this source code is governed by a BSD-style license that can be |
3 # found in the LICENSE file. | 3 # found in the LICENSE file. |
4 | 4 |
5 import Queue | 5 import Queue |
6 import datetime | 6 import datetime |
7 import logging | 7 import logging |
8 import re | 8 import re |
9 import threading | 9 import threading |
10 from pylib import android_commands | 10 from pylib import android_commands |
11 from pylib.device import device_utils | 11 from pylib.device import device_utils |
12 | 12 |
13 | 13 |
14 # Log marker containing SurfaceTexture timestamps. | 14 # Log marker containing SurfaceTexture timestamps. |
15 _SURFACE_TEXTURE_TIMESTAMPS_MESSAGE = 'SurfaceTexture update timestamps' | 15 _SURFACE_TEXTURE_TIMESTAMPS_MESSAGE = 'SurfaceTexture update timestamps' |
16 _SURFACE_TEXTURE_TIMESTAMP_RE = r'\d+' | 16 _SURFACE_TEXTURE_TIMESTAMP_RE = r'\d+' |
17 | 17 |
18 _MIN_NORMALIZED_FRAME_LENGTH = 0.5 | |
19 | |
20 | 18 |
21 class SurfaceStatsCollector(object): | 19 class SurfaceStatsCollector(object): |
22 """Collects surface stats for a SurfaceView from the output of SurfaceFlinger. | 20 """Collects surface stats for a SurfaceView from the output of SurfaceFlinger. |
23 | 21 |
24 Args: | 22 Args: |
25 device: A DeviceUtils instance. | 23 device: A DeviceUtils instance. |
26 """ | 24 """ |
27 class Result(object): | |
28 def __init__(self, name, value, unit): | |
29 self.name = name | |
30 self.value = value | |
31 self.unit = unit | |
32 | 25 |
33 def __init__(self, device): | 26 def __init__(self, device): |
34 # TODO(jbudorick) Remove once telemetry gets switched over. | 27 # TODO(jbudorick) Remove once telemetry gets switched over. |
35 if isinstance(device, android_commands.AndroidCommands): | 28 if isinstance(device, android_commands.AndroidCommands): |
36 device = device_utils.DeviceUtils(device) | 29 device = device_utils.DeviceUtils(device) |
37 self._device = device | 30 self._device = device |
38 self._collector_thread = None | 31 self._collector_thread = None |
39 self._use_legacy_method = False | |
40 self._surface_before = None | 32 self._surface_before = None |
41 self._get_data_event = None | 33 self._get_data_event = None |
42 self._data_queue = None | 34 self._data_queue = None |
43 self._stop_event = None | 35 self._stop_event = None |
44 self._results = [] | |
45 self._warn_about_empty_data = True | 36 self._warn_about_empty_data = True |
46 | 37 |
47 def DisableWarningAboutEmptyData(self): | 38 def DisableWarningAboutEmptyData(self): |
48 self._warn_about_empty_data = False | 39 self._warn_about_empty_data = False |
49 | 40 |
50 def Start(self): | 41 def Start(self): |
51 assert not self._collector_thread | 42 assert not self._collector_thread |
52 | 43 |
53 if self._ClearSurfaceFlingerLatencyData(): | 44 if self._ClearSurfaceFlingerLatencyData(): |
54 self._get_data_event = threading.Event() | 45 self._get_data_event = threading.Event() |
55 self._stop_event = threading.Event() | 46 self._stop_event = threading.Event() |
56 self._data_queue = Queue.Queue() | 47 self._data_queue = Queue.Queue() |
57 self._collector_thread = threading.Thread(target=self._CollectorThread) | 48 self._collector_thread = threading.Thread(target=self._CollectorThread) |
58 self._collector_thread.start() | 49 self._collector_thread.start() |
59 else: | 50 else: |
60 self._use_legacy_method = True | 51 raise Exception('SurfaceFlinger not supported on this device.') |
61 self._surface_before = self._GetSurfaceStatsLegacy() | |
62 | 52 |
63 def Stop(self): | 53 def Stop(self): |
64 self._StorePerfResults() | 54 assert self._collector_thread |
| 55 (refresh_period, timestamps) = self._GetDataFromThread() |
65 if self._collector_thread: | 56 if self._collector_thread: |
66 self._stop_event.set() | 57 self._stop_event.set() |
67 self._collector_thread.join() | 58 self._collector_thread.join() |
68 self._collector_thread = None | 59 self._collector_thread = None |
69 | 60 return (refresh_period, timestamps) |
70 def SampleResults(self): | |
71 self._StorePerfResults() | |
72 results = self.GetResults() | |
73 self._results = [] | |
74 return results | |
75 | |
76 def GetResults(self): | |
77 return self._results or self._GetEmptyResults() | |
78 | |
79 @staticmethod | |
80 def _GetEmptyResults(): | |
81 return [ | |
82 SurfaceStatsCollector.Result('refresh_period', None, 'seconds'), | |
83 SurfaceStatsCollector.Result('jank_count', None, 'janks'), | |
84 SurfaceStatsCollector.Result('max_frame_delay', None, 'vsyncs'), | |
85 SurfaceStatsCollector.Result('frame_lengths', None, 'vsyncs'), | |
86 SurfaceStatsCollector.Result('avg_surface_fps', None, 'fps') | |
87 ] | |
88 | |
89 @staticmethod | |
90 def _GetNormalizedDeltas(data, refresh_period, min_normalized_delta=None): | |
91 deltas = [t2 - t1 for t1, t2 in zip(data, data[1:])] | |
92 if min_normalized_delta != None: | |
93 deltas = [d for d in deltas | |
94 if d / refresh_period >= min_normalized_delta] | |
95 return (deltas, [delta / refresh_period for delta in deltas]) | |
96 | |
97 @staticmethod | |
98 def _CalculateResults(refresh_period, timestamps, result_suffix): | |
99 """Returns a list of SurfaceStatsCollector.Result.""" | |
100 frame_count = len(timestamps) | |
101 seconds = timestamps[-1] - timestamps[0] | |
102 | |
103 frame_lengths, normalized_frame_lengths = \ | |
104 SurfaceStatsCollector._GetNormalizedDeltas( | |
105 timestamps, refresh_period, _MIN_NORMALIZED_FRAME_LENGTH) | |
106 if len(frame_lengths) < frame_count - 1: | |
107 logging.warning('Skipping frame lengths that are too short.') | |
108 frame_count = len(frame_lengths) + 1 | |
109 if len(frame_lengths) == 0: | |
110 raise Exception('No valid frames lengths found.') | |
111 _, normalized_changes = \ | |
112 SurfaceStatsCollector._GetNormalizedDeltas( | |
113 frame_lengths, refresh_period) | |
114 jankiness = [max(0, round(change)) for change in normalized_changes] | |
115 pause_threshold = 20 | |
116 jank_count = sum(1 for change in jankiness | |
117 if change > 0 and change < pause_threshold) | |
118 return [ | |
119 SurfaceStatsCollector.Result( | |
120 'avg_surface_fps' + result_suffix, | |
121 int(round((frame_count - 1) / seconds)), 'fps'), | |
122 SurfaceStatsCollector.Result( | |
123 'jank_count' + result_suffix, jank_count, 'janks'), | |
124 SurfaceStatsCollector.Result( | |
125 'max_frame_delay' + result_suffix, | |
126 round(max(normalized_frame_lengths)), | |
127 'vsyncs'), | |
128 SurfaceStatsCollector.Result( | |
129 'frame_lengths' + result_suffix, normalized_frame_lengths, | |
130 'vsyncs'), | |
131 ] | |
132 | |
133 @staticmethod | |
134 def _CalculateBuckets(refresh_period, timestamps): | |
135 results = [] | |
136 for pct in [0.99, 0.5]: | |
137 sliced = timestamps[min(int(-pct * len(timestamps)), -3) : ] | |
138 results += SurfaceStatsCollector._CalculateResults( | |
139 refresh_period, sliced, '_' + str(int(pct * 100))) | |
140 return results | |
141 | |
142 def _StorePerfResults(self): | |
143 if self._use_legacy_method: | |
144 surface_after = self._GetSurfaceStatsLegacy() | |
145 td = surface_after['timestamp'] - self._surface_before['timestamp'] | |
146 seconds = td.seconds + td.microseconds / 1e6 | |
147 frame_count = (surface_after['page_flip_count'] - | |
148 self._surface_before['page_flip_count']) | |
149 self._results.append(SurfaceStatsCollector.Result( | |
150 'avg_surface_fps', int(round(frame_count / seconds)), 'fps')) | |
151 return | |
152 | |
153 # Non-legacy method. | |
154 assert self._collector_thread | |
155 (refresh_period, timestamps) = self._GetDataFromThread() | |
156 if not refresh_period or not len(timestamps) >= 3: | |
157 if self._warn_about_empty_data: | |
158 logging.warning('Surface stat data is empty') | |
159 return | |
160 self._results.append(SurfaceStatsCollector.Result( | |
161 'refresh_period', refresh_period, 'seconds')) | |
162 self._results += self._CalculateResults(refresh_period, timestamps, '') | |
163 self._results += self._CalculateBuckets(refresh_period, timestamps) | |
164 | 61 |
165 def _CollectorThread(self): | 62 def _CollectorThread(self): |
166 last_timestamp = 0 | 63 last_timestamp = 0 |
167 timestamps = [] | 64 timestamps = [] |
168 retries = 0 | 65 retries = 0 |
169 | 66 |
170 while not self._stop_event.is_set(): | 67 while not self._stop_event.is_set(): |
171 self._get_data_event.wait(1) | 68 self._get_data_event.wait(1) |
172 try: | 69 try: |
173 refresh_period, new_timestamps = self._GetSurfaceFlingerFrameData() | 70 refresh_period, new_timestamps = self._GetSurfaceFlingerFrameData() |
(...skipping 38 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
212 Returns: | 109 Returns: |
213 True if SurfaceFlinger latency is supported by the device, otherwise | 110 True if SurfaceFlinger latency is supported by the device, otherwise |
214 False. | 111 False. |
215 """ | 112 """ |
216 # The command returns nothing if it is supported, otherwise returns many | 113 # The command returns nothing if it is supported, otherwise returns many |
217 # lines of result just like 'dumpsys SurfaceFlinger'. | 114 # lines of result just like 'dumpsys SurfaceFlinger'. |
218 results = self._device.RunShellCommand( | 115 results = self._device.RunShellCommand( |
219 'dumpsys SurfaceFlinger --latency-clear SurfaceView') | 116 'dumpsys SurfaceFlinger --latency-clear SurfaceView') |
220 return not len(results) | 117 return not len(results) |
221 | 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 |
222 def _GetSurfaceFlingerFrameData(self): | 126 def _GetSurfaceFlingerFrameData(self): |
223 """Returns collected SurfaceFlinger frame timing data. | 127 """Returns collected SurfaceFlinger frame timing data. |
224 | 128 |
225 Returns: | 129 Returns: |
226 A tuple containing: | 130 A tuple containing: |
227 - The display's nominal refresh period in seconds. | 131 - The display's nominal refresh period in milliseconds. |
228 - A list of timestamps signifying frame presentation times in seconds. | 132 - A list of timestamps signifying frame presentation times in |
| 133 milliseconds. |
229 The return value may be (None, None) if there was no data collected (for | 134 The return value may be (None, None) if there was no data collected (for |
230 example, if the app was closed before the collector thread has finished). | 135 example, if the app was closed before the collector thread has finished). |
231 """ | 136 """ |
232 # adb shell dumpsys SurfaceFlinger --latency <window name> | 137 # adb shell dumpsys SurfaceFlinger --latency <window name> |
233 # prints some information about the last 128 frames displayed in | 138 # prints some information about the last 128 frames displayed in |
234 # that window. | 139 # that window. |
235 # The data returned looks like this: | 140 # The data returned looks like this: |
236 # 16954612 | 141 # 16954612 |
237 # 7657467895508 7657482691352 7657493499756 | 142 # 7657467895508 7657482691352 7657493499756 |
238 # 7657484466553 7657499645964 7657511077881 | 143 # 7657484466553 7657499645964 7657511077881 |
(...skipping 18 matching lines...) Expand all Loading... |
257 # | 162 # |
258 # We use the special "SurfaceView" window name because the statistics for | 163 # We use the special "SurfaceView" window name because the statistics for |
259 # the activity's main window are not updated when the main web content is | 164 # the activity's main window are not updated when the main web content is |
260 # composited into a SurfaceView. | 165 # composited into a SurfaceView. |
261 results = self._device.RunShellCommand( | 166 results = self._device.RunShellCommand( |
262 'dumpsys SurfaceFlinger --latency SurfaceView') | 167 'dumpsys SurfaceFlinger --latency SurfaceView') |
263 if not len(results): | 168 if not len(results): |
264 return (None, None) | 169 return (None, None) |
265 | 170 |
266 timestamps = [] | 171 timestamps = [] |
267 nanoseconds_per_second = 1e9 | 172 nanoseconds_per_millisecond = 1e6 |
268 refresh_period = long(results[0]) / nanoseconds_per_second | 173 refresh_period = long(results[0]) / nanoseconds_per_millisecond |
269 | 174 |
270 # If a fence associated with a frame is still pending when we query the | 175 # If a fence associated with a frame is still pending when we query the |
271 # latency data, SurfaceFlinger gives the frame a timestamp of INT64_MAX. | 176 # latency data, SurfaceFlinger gives the frame a timestamp of INT64_MAX. |
272 # Since we only care about completed frames, we will ignore any timestamps | 177 # Since we only care about completed frames, we will ignore any timestamps |
273 # with this value. | 178 # with this value. |
274 pending_fence_timestamp = (1 << 63) - 1 | 179 pending_fence_timestamp = (1 << 63) - 1 |
275 | 180 |
276 for line in results[1:]: | 181 for line in results[1:]: |
277 fields = line.split() | 182 fields = line.split() |
278 if len(fields) != 3: | 183 if len(fields) != 3: |
279 continue | 184 continue |
280 timestamp = long(fields[1]) | 185 timestamp = long(fields[1]) |
281 if timestamp == pending_fence_timestamp: | 186 if timestamp == pending_fence_timestamp: |
282 continue | 187 continue |
283 timestamp /= nanoseconds_per_second | 188 timestamp /= nanoseconds_per_millisecond |
284 timestamps.append(timestamp) | 189 timestamps.append(timestamp) |
285 | 190 |
286 return (refresh_period, timestamps) | 191 return (refresh_period, timestamps) |
287 | |
288 def _GetSurfaceStatsLegacy(self): | |
289 """Legacy method (before JellyBean), returns the current Surface index | |
290 and timestamp. | |
291 | |
292 Calculate FPS by measuring the difference of Surface index returned by | |
293 SurfaceFlinger in a period of time. | |
294 | |
295 Returns: | |
296 Dict of {page_flip_count (or 0 if there was an error), timestamp}. | |
297 """ | |
298 results = self._device.RunShellCommand('service call SurfaceFlinger 1013') | |
299 assert len(results) == 1 | |
300 match = re.search(r'^Result: Parcel\((\w+)', results[0]) | |
301 cur_surface = 0 | |
302 if match: | |
303 try: | |
304 cur_surface = int(match.group(1), 16) | |
305 except Exception: | |
306 logging.error('Failed to parse current surface from ' + match.group(1)) | |
307 else: | |
308 logging.warning('Failed to call SurfaceFlinger surface ' + results[0]) | |
309 return { | |
310 'page_flip_count': cur_surface, | |
311 'timestamp': datetime.datetime.now(), | |
312 } | |
OLD | NEW |