OLD | NEW |
(Empty) | |
| 1 # Copyright (c) 2012 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 |
| 11 from pylib import perf_tests_helper |
| 12 |
| 13 |
| 14 # Log marker containing SurfaceTexture timestamps. |
| 15 _SURFACE_TEXTURE_TIMESTAMPS_MESSAGE = 'SurfaceTexture update timestamps' |
| 16 _SURFACE_TEXTURE_TIMESTAMP_RE = '\d+' |
| 17 |
| 18 |
| 19 class SurfaceStatsCollector(object): |
| 20 """Collects surface stats for a window from the output of SurfaceFlinger. |
| 21 |
| 22 Args: |
| 23 adb: the adb coonection to use. |
| 24 window_package: Package name of the window. |
| 25 window_activity: Activity name of the window. |
| 26 """ |
| 27 def __init__(self, adb, window_package, window_activity, trace_tag): |
| 28 self._adb = adb |
| 29 self._window_package = window_package |
| 30 self._window_activity = window_activity |
| 31 self._trace_tag = trace_tag |
| 32 self._collector_thread = None |
| 33 self._use_legacy_method = False |
| 34 self._surface_before = None |
| 35 self._get_data_event = None |
| 36 self._data_queue = None |
| 37 self._stop_event = None |
| 38 |
| 39 def __enter__(self): |
| 40 assert not self._collector_thread |
| 41 |
| 42 if self._ClearSurfaceFlingerLatencyData(): |
| 43 self._get_data_event = threading.Event() |
| 44 self._stop_event = threading.Event() |
| 45 self._data_queue = Queue.Queue() |
| 46 self._collector_thread = threading.Thread(target=self._CollectorThread) |
| 47 self._collector_thread.start() |
| 48 else: |
| 49 self._use_legacy_method = True |
| 50 self._surface_before = self._GetSurfaceStatsLegacy() |
| 51 |
| 52 def __exit__(self, *args): |
| 53 self._PrintPerfResults() |
| 54 if self._collector_thread: |
| 55 self._stop_event.set() |
| 56 self._collector_thread.join() |
| 57 self._collector_thread = None |
| 58 |
| 59 def _PrintPerfResults(self): |
| 60 if self._use_legacy_method: |
| 61 surface_after = self._GetSurfaceStatsLegacy() |
| 62 td = surface_after['timestamp'] - self._surface_before['timestamp'] |
| 63 seconds = td.seconds + td.microseconds / 1e6 |
| 64 frame_count = (surface_after['page_flip_count'] - |
| 65 self._surface_before['page_flip_count']) |
| 66 else: |
| 67 assert self._collector_thread |
| 68 (seconds, latencies) = self._GetDataFromThread() |
| 69 if not seconds or not len(latencies): |
| 70 logging.warning('Surface stat data is empty') |
| 71 return |
| 72 |
| 73 frame_count = len(latencies) |
| 74 jitter_count = 0 |
| 75 last_latency = latencies[0] |
| 76 for latency in latencies[1:]: |
| 77 if latency > last_latency: |
| 78 jitter_count = jitter_count + 1 |
| 79 last_latency = latency |
| 80 |
| 81 perf_tests_helper.PrintPerfResult( |
| 82 'surface_latencies', 'surface_latencies' + self._trace_tag, |
| 83 latencies, '') |
| 84 perf_tests_helper.PrintPerfResult( |
| 85 'peak_jitter', 'peak_jitter' + self._trace_tag, [max(latencies)], '') |
| 86 perf_tests_helper.PrintPerfResult( |
| 87 'jitter_percent', 'jitter_percent' + self._trace_tag, |
| 88 [jitter_count * 100.0 / frame_count], 'percent') |
| 89 |
| 90 print 'SurfaceMonitorTime: %fsecs' % seconds |
| 91 perf_tests_helper.PrintPerfResult( |
| 92 'avg_surface_fps', 'avg_surface_fps' + self._trace_tag, |
| 93 [int(round(frame_count / seconds))], 'fps') |
| 94 |
| 95 def _CollectorThread(self): |
| 96 last_timestamp = 0 |
| 97 first_timestamp = 0 |
| 98 latencies = [] |
| 99 |
| 100 while not self._stop_event.is_set(): |
| 101 self._get_data_event.wait(1) |
| 102 try: |
| 103 (t, last_timestamp) = self._GetSurfaceFlingerLatencyData(last_timestamp, |
| 104 latencies) |
| 105 if not first_timestamp: |
| 106 first_timestamp = t |
| 107 |
| 108 if self._get_data_event.is_set(): |
| 109 self._get_data_event.clear() |
| 110 self._data_queue.put(((last_timestamp - first_timestamp) / 1e9, |
| 111 latencies)) |
| 112 latencies = [] |
| 113 first_timestamp = 0 |
| 114 except Exception as e: |
| 115 # On any error, before aborting, put the exception into _data_queue to |
| 116 # prevent the main thread from waiting at _data_queue.get() infinitely. |
| 117 self._data_queue.put(e) |
| 118 raise |
| 119 |
| 120 def _GetDataFromThread(self): |
| 121 self._get_data_event.set() |
| 122 ret = self._data_queue.get() |
| 123 if isinstance(ret, Exception): |
| 124 raise ret |
| 125 return ret |
| 126 |
| 127 def _ClearSurfaceFlingerLatencyData(self): |
| 128 """Clears the SurfaceFlinger latency data. |
| 129 |
| 130 Returns: |
| 131 True if SurfaceFlinger latency is supported by the device, otherwise |
| 132 False. |
| 133 """ |
| 134 # The command returns nothing if it is supported, otherwise returns many |
| 135 # lines of result just like 'dumpsys SurfaceFlinger'. |
| 136 results = self._adb.RunShellCommand( |
| 137 'dumpsys SurfaceFlinger --latency-clear %s/%s' % |
| 138 (self._window_package, self._window_activity)) |
| 139 return not len(results) |
| 140 |
| 141 def _GetSurfaceFlingerLatencyData(self, previous_timestamp, latencies): |
| 142 """Returns collected SurfaceFlinger latency data. |
| 143 |
| 144 Args: |
| 145 previous_timestamp: The timestamp returned from the previous call or 0. |
| 146 Only data after this timestamp will be returned. |
| 147 latencies: A list to receive latency data. The latencies are integers |
| 148 each of which is the number of refresh periods of each frame. |
| 149 |
| 150 Returns: |
| 151 A tuple containing: |
| 152 - The timestamp of the beginning of the first frame (ns), |
| 153 - The timestamp of the end of the last frame (ns). |
| 154 |
| 155 Raises: |
| 156 Exception if failed to run the SurfaceFlinger command or SurfaceFlinger |
| 157 returned invalid result. |
| 158 """ |
| 159 # adb shell dumpsys SurfaceFlinger --latency <window name> |
| 160 # prints some information about the last 128 frames displayed in |
| 161 # that window. |
| 162 # The data returned looks like this: |
| 163 # 16954612 |
| 164 # 7657467895508 7657482691352 7657493499756 |
| 165 # 7657484466553 7657499645964 7657511077881 |
| 166 # 7657500793457 7657516600576 7657527404785 |
| 167 # (...) |
| 168 # |
| 169 # The first line is the refresh period (here 16.95 ms), it is followed |
| 170 # by 128 lines w/ 3 timestamps in nanosecond each: |
| 171 # A) when the app started to draw |
| 172 # B) the vsync immediately preceding SF submitting the frame to the h/w |
| 173 # C) timestamp immediately after SF submitted that frame to the h/w |
| 174 # |
| 175 # The difference between the 1st and 3rd timestamp is the frame-latency. |
| 176 # An interesting data is when the frame latency crosses a refresh period |
| 177 # boundary, this can be calculated this way: |
| 178 # |
| 179 # ceil((C - A) / refresh-period) |
| 180 # |
| 181 # (each time the number above changes, we have a "jank"). |
| 182 # If this happens a lot during an animation, the animation appears |
| 183 # janky, even if it runs at 60 fps in average. |
| 184 results = self._adb.RunShellCommand( |
| 185 'dumpsys SurfaceFlinger --latency %s/%s' % |
| 186 (self._window_package, self._window_activity), log_result=True) |
| 187 assert len(results) |
| 188 |
| 189 refresh_period = int(results[0]) |
| 190 last_timestamp = previous_timestamp |
| 191 first_timestamp = 0 |
| 192 for line in results[1:]: |
| 193 fields = line.split() |
| 194 if len(fields) == 3: |
| 195 timestamp = long(fields[0]) |
| 196 last_timestamp = long(fields[2]) |
| 197 if (timestamp > previous_timestamp): |
| 198 if not first_timestamp: |
| 199 first_timestamp = timestamp |
| 200 # This is integral equivalent of ceil((C-A) / refresh-period) |
| 201 latency_ns = int(last_timestamp - timestamp) |
| 202 latencies.append((latency_ns + refresh_period - 1) / refresh_period) |
| 203 return (first_timestamp, last_timestamp) |
| 204 |
| 205 def _GetSurfaceStatsLegacy(self): |
| 206 """Legacy method (before JellyBean), returns the current Surface index |
| 207 and timestamp. |
| 208 |
| 209 Calculate FPS by measuring the difference of Surface index returned by |
| 210 SurfaceFlinger in a period of time. |
| 211 |
| 212 Returns: |
| 213 Dict of {page_flip_count (or 0 if there was an error), timestamp}. |
| 214 """ |
| 215 results = self._adb.RunShellCommand('service call SurfaceFlinger 1013') |
| 216 assert len(results) == 1 |
| 217 match = re.search('^Result: Parcel\((\w+)', results[0]) |
| 218 cur_surface = 0 |
| 219 if match: |
| 220 try: |
| 221 cur_surface = int(match.group(1), 16) |
| 222 except Exception: |
| 223 logging.error('Failed to parse current surface from ' + match.group(1)) |
| 224 else: |
| 225 logging.warning('Failed to call SurfaceFlinger surface ' + results[0]) |
| 226 return { |
| 227 'page_flip_count': cur_surface, |
| 228 'timestamp': datetime.datetime.now(), |
| 229 } |
OLD | NEW |