def _get_surfaceflinger_frame_data(self): """Returns collected SurfaceFlinger frame timing data. return:(16.6,[[t1,t2,t3],[t4,t5,t6]]) Returns: A tuple containing: - The display's nominal refresh period in seconds. - A list of timestamps signifying frame presentation times in seconds. The return value may be (None, None) if there was no data collected (for example, if the app was closed before the collector thread has finished). """ # shell dumpsys SurfaceFlinger --latency <window name> # prints some information about the last 128 frames displayed in # that window. # The data returned looks like this: # 16954612 # 7657467895508 7657482691352 7657493499756 # 7657484466553 7657499645964 7657511077881 # 7657500793457 7657516600576 7657527404785 # (...) # # The first line is the refresh period (here 16.95 ms), it is followed # by 128 lines w/ 3 timestamps in nanosecond each: # A) when the app started to draw # B) the vsync immediately preceding SF submitting the frame to the h/w # C) timestamp immediately after SF submitted that frame to the h/w # # The difference between the 1st and 3rd timestamp is the frame-latency. # An interesting data is when the frame latency crosses a refresh period # boundary, this can be calculated this way: # # ceil((C - A) / refresh-period) # # (each time the number above changes, we have a "jank"). # If this happens a lot during an animation, the animation appears # janky, even if it runs at 60 fps in average. # # Google Pixel 2 android8.0 dumpsys SurfaceFlinger --latency结果 # 16666666 # 0 0 0 # 0 0 0 # 0 0 0 # 0 0 0 # 但华为 荣耀9 android8.0 dumpsys SurfaceFlinger --latency结果是正常的 但数据更新很慢 也不能用来计算fps # 16666666 # 9223372036854775807 3618832932780 9223372036854775807 # 9223372036854775807 3618849592155 9223372036854775807 # 9223372036854775807 3618866251530 9223372036854775807 # Google Pixel 2 Android8.0 dumpsys SurfaceFlinger --latency window 结果 # C:\Users\luke01>adb -s HT7B81A05143 shell dumpsys SurfaceFlinger --latency com.n # etease.apm/com.example.sdkapp.TestListView # 16666666 refresh_period = None timestamps = [] nanoseconds_per_second = 1e9 pending_fence_timestamp = (1 << 63) - 1 if self.device.adb.get_sdk_version() >= 26: results = self.device.adb.run_shell_cmd( 'dumpsys SurfaceFlinger --latency %s' % self.focus_window) results = results.replace("\r\n", "\n").splitlines() refresh_period = int(results[0]) / nanoseconds_per_second results = self.device.adb.run_shell_cmd( 'dumpsys gfxinfo %s framestats' % self.package_name) # logger.debug(results) # 把dumpsys gfxinfo package_name framestats的结果封装成 dumpsys SurfaceFlinger --latency的结果 # 方便后面计算fps jank统一处理 results = results.replace("\r\n", "\n").splitlines() if not len(results): return (None, None) isHaveFoundWindow = False PROFILEDATA_line = 0 for line in results: if not isHaveFoundWindow: if "Window" in line and self.focus_window in line: isHaveFoundWindow = True # logger.debug("Window line:"+line) if not isHaveFoundWindow: continue if "PROFILEDATA" in line: PROFILEDATA_line += 1 fields = [] fields = line.split(",") if fields and '0' == fields[0]: # logger.debug(line) # 获取INTENDED_VSYNC VSYNC FRAME_COMPLETED时间 利用VSYNC计算fps jank timestamp = [ int(fields[1]), int(fields[2]), int(fields[13]) ] if timestamp[1] == pending_fence_timestamp: continue timestamp = [ _timestamp / nanoseconds_per_second for _timestamp in timestamp ] timestamps.append(timestamp) # 如果到了下一个窗口,退出 if 2 == PROFILEDATA_line: break else: results = self.device.adb.run_shell_cmd( 'dumpsys SurfaceFlinger --latency %s' % self.focus_window) results = results.replace("\r\n", "\n").splitlines() logger.debug("dumpsys SurfaceFlinger --latency result:") logger.debug(results) if not len(results): return (None, None) if not results[0].isdigit(): return (None, None) try: refresh_period = int(results[0]) / nanoseconds_per_second except Exception as e: logger.exception(e) return (None, None) # If a fence associated with a frame is still pending when we query the # latency data, SurfaceFlinger gives the frame a timestamp of INT64_MAX. # Since we only care about completed frames, we will ignore any timestamps # with this value. for line in results[1:]: fields = line.split() if len(fields) != 3: continue timestamp = [int(fields[0]), int(fields[1]), int(fields[2])] if timestamp[1] == pending_fence_timestamp: continue timestamp = [ _timestamp / nanoseconds_per_second for _timestamp in timestamp ] timestamps.append(timestamp) return (refresh_period, timestamps)
def _calculator_thread(self, start_time): '''处理surfaceflinger数据 ''' fps_file = os.path.join(RuntimeData.package_save_path, 'fps.csv') if self.use_legacy_method: fps_title = ['datetime', 'fps'] else: fps_title = ['datetime', "activity window", 'fps', 'jank'] try: with open(fps_file, 'a+') as df: csv.writer(df, lineterminator='\n').writerow(fps_title) if self.fps_queue: fps_file_dic = {'fps_file': fps_file} self.fps_queue.put(fps_file_dic) except RuntimeError as e: logger.exception(e) while True: try: data = self.data_queue.get() if isinstance(data, str) and data == 'Stop': break before = time.time() if self.use_legacy_method: td = data['timestamp'] - self.surface_before['timestamp'] seconds = td.seconds + td.microseconds / 1e6 frame_count = (data['page_flip_count'] - self.surface_before['page_flip_count']) fps = int(round(frame_count / seconds)) if fps > 60: fps = 60 self.surface_before = data logger.debug('FPS:%2s' % fps) tmp_list = [TimeUtils.getCurrentTimeUnderline(), fps] try: with open(fps_file, 'a+') as f: # tmp_list[0] = TimeUtils.formatTimeStamp(tmp_list[0]) csv.writer(f, lineterminator='\n').writerow(tmp_list) except RuntimeError as e: logger.exception(e) else: refresh_period = data[0] timestamps = data[1] collect_time = data[2] fps, jank = self._calculate_results( refresh_period, timestamps) logger.debug('FPS:%2s Jank:%s' % (fps, jank)) fps_list = [collect_time, self.focus_window, fps, jank] if self.fps_queue: self.fps_queue.put(fps_list) if not self.fps_queue: #为了让单个脚本运行时保存数据 try: with open(fps_file, 'a+') as f: tmp_list = copy.deepcopy(fps_list) tmp_list[0] = TimeUtils.formatTimeStamp( tmp_list[0]) csv.writer( f, lineterminator='\n').writerow(tmp_list) except RuntimeError as e: logger.exception(e) time_consume = time.time() - before delta_inter = self.frequency - time_consume if delta_inter > 0: time.sleep(delta_inter) except: logger.error( "an exception hanpend in fps _calculator_thread ,reason unkown!" ) s = traceback.format_exc() logger.debug(s) if self.fps_queue: self.fps_queue.task_done()