1 /* 2 * Copyright (C) 2013 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17 package com.android.uiautomator.platform; 18 19 import android.os.Environment; 20 import android.util.Log; 21 22 import java.util.Arrays; 23 import java.util.List; 24 import java.util.ArrayList; 25 import java.io.BufferedReader; 26 import java.io.File; 27 import java.io.FileWriter; 28 import java.io.BufferedWriter; 29 import java.io.InputStreamReader; 30 import java.io.IOException; 31 import java.lang.Math; 32 33 /* 34 * Tools to measure jankiness through SurfaceFlinger 35 */ 36 public class SurfaceFlingerHelper { 37 private static String TAG = "SurfaceFlingerHelper"; 38 private static int BUFFER_SIZE = 128; 39 private static int BUFFER_NUMBER = 3; 40 private static String CLEAR_BUFFER_CMD = "dumpsys SurfaceFlinger --latency-clear"; 41 private static String FRAME_LATENCY_CMD = "dumpsys SurfaceFlinger --latency"; 42 private static final String RAW_DATA_DIR = "UiJankinessRawData"; 43 private static final String LOCAL_TMP_DIR = "/data/local/tmp/"; 44 /* If the latency between two frames is greater than this number, it it treated as a pause 45 * not a jankiness */ 46 private static final int PAUSE_LATENCY = 20; 47 48 /* An array list which includes the raw buffer information from frame latency tool */ 49 private static List<List<String>> mFrameBufferData = new ArrayList<List<String>>(BUFFER_SIZE); 50 51 /* Record the refresh period returned from driver */ 52 private static long mRefreshPeriod = -1; 53 54 /* Record the size of frame latency */ 55 private static int mFrameLatencySampleSize = 0; 56 57 /* An integer array which includes delta vsync */ 58 private static long[] mDeltaVsync = new long[BUFFER_SIZE]; 59 60 /* Integer array for delta of delta vsync */ 61 private static long[] mDelta2Vsync = new long[BUFFER_SIZE]; 62 63 /* the maximum delta vsync number */ 64 private static long mMaxDeltaVsync; 65 66 /* Normalized data */ 67 private static double[] mNormalizedDelta2Vsync = new double[BUFFER_SIZE]; 68 private static int[] mRoundNormalizedDelta2Vsync = new int[BUFFER_SIZE]; 69 // Symbol of unfinished frame time */ 70 public static final String PENDING_FENCE_TIME = new Long(Long.MAX_VALUE).toString(); 71 72 /** 73 * Run clear buffer command and clear the saved frame buffer results 74 * 75 * @param windowName the window name that the buffer will be cleared 76 */ 77 public static void clearBuffer(String windowName) { 78 // clear results 79 if (mFrameBufferData != null) { 80 mFrameBufferData.clear(); 81 } 82 Arrays.fill(mDeltaVsync, -1); 83 Arrays.fill(mDelta2Vsync, -1); 84 Arrays.fill(mNormalizedDelta2Vsync, -1.0); 85 Arrays.fill(mRoundNormalizedDelta2Vsync, -1); 86 mRefreshPeriod = -1; 87 mFrameLatencySampleSize = 0; 88 mMaxDeltaVsync = 0; 89 90 Process p = null; 91 BufferedReader resultReader = null; 92 String command = CLEAR_BUFFER_CMD; 93 if (windowName != null) { 94 command = String.format("%s %s", CLEAR_BUFFER_CMD, windowName); 95 } 96 try { 97 p = Runtime.getRuntime().exec(command); 98 int status = p.waitFor(); 99 if (status != 0) { 100 Log.e(TAG, String.format("Run shell command: %s, status: %s", 101 command, status)); 102 } 103 } catch (IOException e) { 104 Log.e(TAG, "// Exception from command " + command + ":", e); 105 } catch (InterruptedException e) { 106 Log.e(TAG, "// Interrupted while waiting for the command to finish. ", e); 107 } finally { 108 try { 109 if (resultReader != null) { 110 resultReader.close(); 111 } 112 if (p != null) { 113 p.destroy(); 114 } 115 } catch (IOException e) { 116 Log.e(TAG, "exception " + e); 117 } 118 } 119 } 120 121 /** 122 * Run frame latency command without ignoring pending fence time 123 * 124 * @param windowName the window name which SurfaceFlinger will acquire frame time for 125 */ 126 public static boolean dumpFrameLatency(String windowName) { 127 return dumpFrameLatency(windowName, false); 128 } 129 130 /** 131 * Run frame latency command to get frame time 132 * 133 * @param windowName the window name which SurfaceFlinger will get frame time for 134 * @param ignorePendingFenceTime flag to process frames with pending fence time 135 * set true to ignore pending fence time 136 * set false to fail the test if pending fence time is not allowed 137 */ 138 public static boolean dumpFrameLatency(String windowName, boolean ignorePendingFenceTime) { 139 Process p = null; 140 BufferedReader resultReader = null; 141 String command = FRAME_LATENCY_CMD; 142 if (windowName != null) { 143 command = String.format("%s %s", FRAME_LATENCY_CMD, windowName); 144 } 145 log("dump frame latency command: " + command); 146 try { 147 p = Runtime.getRuntime().exec(command); 148 int status = p.waitFor(); 149 if (status != 0) { 150 Log.e(TAG, String.format("Run shell command: %s, status: %s",command, status)); 151 } 152 resultReader = new BufferedReader(new InputStreamReader(p.getInputStream())); 153 String line = resultReader.readLine(); 154 mRefreshPeriod = Long.parseLong(line.trim()); 155 log("reading refresh period: " + mRefreshPeriod); 156 if (mRefreshPeriod < 0) { 157 return false; 158 } 159 boolean dataInvalidFlag = false; 160 while((line = resultReader.readLine()) != null) { 161 // remove lines which are empty 162 if (line.trim().isEmpty()) { 163 break; 164 } 165 String[] bufferValues = line.split("\\s+"); 166 if (bufferValues[0].trim().compareTo("0") == 0) { 167 continue; 168 } else if (bufferValues[1].trim().compareTo(PENDING_FENCE_TIME) == 0 ) { 169 if (ignorePendingFenceTime) { 170 log("ignore pending fence time"); 171 dataInvalidFlag = true; 172 } else { 173 log("the data contains unfinished frame time, please allow the animation" 174 + " to finish in the test before calling dumpFrameLatency."); 175 return false; 176 } 177 } 178 // store raw data which could have both valid and invalid data 179 List<String> delayArray = Arrays.asList(bufferValues); 180 mFrameBufferData.add(delayArray); 181 if (!dataInvalidFlag) { 182 // only count frames which have valid time 183 ++mFrameLatencySampleSize; 184 } 185 } 186 log("frame latency sample size: " + mFrameLatencySampleSize); 187 } catch (InterruptedException e) { 188 Log.e(TAG, "// Exception from command " + command + ":", e); 189 } catch (IOException e) { 190 Log.e(TAG, "Open file error: ", e); 191 return false; 192 } 193 finally { 194 try { 195 if (resultReader != null) { 196 resultReader.close(); 197 } 198 if (p != null) { 199 p.destroy(); 200 } 201 } catch (IOException e) { 202 Log.e(TAG, "io exception: ", e); 203 } 204 } 205 return true; 206 } 207 208 public static int getDataSampleSize() { 209 return mFrameLatencySampleSize; 210 } 211 212 public static long getRefreshPeriod() { 213 if (mRefreshPeriod < 0) { 214 // Haven't dump the frame latency yet 215 log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving the refresh period"); 216 } 217 return mRefreshPeriod; 218 } 219 220 public static String getFrameBufferData() { 221 if (mFrameBufferData.get(0) == null) { 222 log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame buffer data"); 223 return null; 224 } 225 String rawData = String.format("%d\n", mRefreshPeriod); 226 List<String> tempList = new ArrayList<String>(BUFFER_NUMBER); 227 for (int i = 0; i < mFrameBufferData.size(); i++) { 228 tempList = mFrameBufferData.get(i); 229 for (int j = 0; j < BUFFER_NUMBER; j++) { 230 rawData += String.format("%s", tempList.get(j)); 231 if (j < BUFFER_NUMBER - 1) { 232 rawData += "\t"; 233 } else { 234 rawData += "\n"; 235 } 236 } 237 } 238 return rawData; 239 } 240 241 /** 242 * Calculate delta(vsync) 243 * @return 244 */ 245 public static long[] getDeltaVsync() { 246 if (mRefreshPeriod < 0) { 247 log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame latency"); 248 return null; 249 } 250 if (mDeltaVsync[0] < 0 ) { 251 // keep a record of the max DeltaVsync 252 mMaxDeltaVsync = 0; 253 // get the first frame vsync time 254 long preVsyncTime = Long.parseLong(mFrameBufferData.get(0).get(1)); 255 for (int i = 0; i < mFrameLatencySampleSize - 1; i++) { 256 long curVsyncTime = Long.parseLong(mFrameBufferData.get(i + 1).get(1)); 257 mDeltaVsync[i] = curVsyncTime - preVsyncTime; 258 preVsyncTime = curVsyncTime; 259 if (mMaxDeltaVsync < mDeltaVsync[i]) { 260 mMaxDeltaVsync = mDeltaVsync[i]; 261 } 262 } 263 } 264 return mDeltaVsync; 265 } 266 267 /** 268 * Calculate difference between delta vsync 269 * @return 270 */ 271 public static long[] getDelta2Vsync() { 272 if (mRefreshPeriod < 0) { 273 log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame latency"); 274 return null; 275 } 276 if (mDeltaVsync[0] < 0) { 277 getDeltaVsync(); 278 } 279 if (mDelta2Vsync[0] < 0) { 280 int numDeltaVsync = mFrameLatencySampleSize - 1; 281 for (int i = 0; i < numDeltaVsync - 1; i++) { 282 mDelta2Vsync[i] = mDeltaVsync[i + 1] - mDeltaVsync[i]; 283 } 284 } 285 return mDelta2Vsync; 286 } 287 288 /** 289 * normalized delta(delta(vsync)) by refresh period 290 * @return 291 */ 292 public static double[] getNormalizedDelta2Vsync() { 293 if (mRefreshPeriod < 0) { 294 log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame latency"); 295 return null; 296 } 297 if (mDelta2Vsync[0] < 0) { 298 getDelta2Vsync(); 299 } 300 if (mNormalizedDelta2Vsync[0] < 0) { 301 for (int i = 0; i < mFrameLatencySampleSize - 2; i++) { 302 mNormalizedDelta2Vsync[i] = (double)mDelta2Vsync[i] /mRefreshPeriod; 303 } 304 } 305 return mNormalizedDelta2Vsync; 306 } 307 308 public static int[] getRoundNormalizedDelta2Vsync() { 309 if (mRefreshPeriod < 0) { 310 log("Run command \"" + FRAME_LATENCY_CMD + " \" for number of jankiness."); 311 return null; 312 } 313 if (mNormalizedDelta2Vsync[0] < 0) { 314 getNormalizedDelta2Vsync(); 315 } 316 317 for (int i = 0; i < mFrameLatencySampleSize - 2; i++) { 318 int value = (int)Math.round(Math.max(mNormalizedDelta2Vsync[i], 0.0)); 319 mRoundNormalizedDelta2Vsync[i] = value; 320 } 321 return mRoundNormalizedDelta2Vsync; 322 } 323 324 /* 325 * Get number of jankiness using Vsync time difference 326 */ 327 public static int getVsyncJankiness() { 328 if (mRefreshPeriod < 0) { 329 log("Run command \"" + FRAME_LATENCY_CMD + " \" for number of jankiness."); 330 return -1; 331 } 332 if (mRoundNormalizedDelta2Vsync[0] < 0) { 333 getRoundNormalizedDelta2Vsync(); 334 } 335 int numberJankiness = 0; 336 for (int i = 0; i < mFrameLatencySampleSize - 2; i++) { 337 int value = mRoundNormalizedDelta2Vsync[i]; 338 // ignore the latency which is too long 339 if (value > 0 && value < PAUSE_LATENCY) { 340 numberJankiness++; 341 } 342 } 343 return numberJankiness; 344 } 345 346 /* Track the maximum delta which shows the accumulating time 347 * before animation starts */ 348 public static int getMaxDeltaVsync() { 349 return Math.round((float)mMaxDeltaVsync /mRefreshPeriod); 350 } 351 352 /** 353 * Calculate frame rate 354 * @return 355 */ 356 public static double getFrameRate() { 357 if (mRefreshPeriod < 0) { 358 log("Run command \"" + FRAME_LATENCY_CMD + " \" before calcuating average frame rate"); 359 return -1.0; 360 } 361 if (mFrameBufferData.get(0) == null) { 362 log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame buffer data"); 363 return -1.0; 364 } 365 long startTime = Long.parseLong(mFrameBufferData.get(0).get(1)); 366 long endTime = Long.parseLong(mFrameBufferData.get(mFrameLatencySampleSize - 1).get(1)); 367 long totalDuration = endTime - startTime; 368 return (double)((mFrameLatencySampleSize - 1) * Math.pow(10, 9))/totalDuration; 369 } 370 371 /** 372 * Print raw data and processed results into file <testcasename_[iteration]_processed.txt> 373 * @param fileName 374 * @param index 375 */ 376 public static void printData(String fileName, int index) { 377 String rawAndProcDataFileName = String.format("%s/%s_%d_processed.txt", RAW_DATA_DIR, 378 fileName, index); 379 log("write raw data and process data into file: " + rawAndProcDataFileName); 380 BufferedWriter fw = null; 381 try { 382 fw = new BufferedWriter(new FileWriter(new File(rawAndProcDataFileName), false)); 383 // Show the number of jankiness first: 384 fw.write(String.format("Jankiness count: %d\n", getVsyncJankiness())); 385 fw.write(String.format("Max accumulated frames: %d\n", getMaxDeltaVsync())); 386 fw.write(String.format("Frame rate is: %f\n", getFrameRate())); 387 388 // refresh period 389 fw.write(String.valueOf(mRefreshPeriod)); 390 fw.write("\n"); 391 fw.write("app\tvsync\tset\tdelta(vsync)\tdelta^2(vsync)\t" + 392 "delta^2(vsync)/refreshPeriod\t normalized delta^2(vsync)\n"); 393 394 for (int i = 0; i < mFrameLatencySampleSize; i++) { 395 // write raw data 396 List<String> rawData = mFrameBufferData.get(i); 397 String line = String.format("%s\t%s\t%s\t%d\t%d\t%f\t%d\n", 398 rawData.get(0), rawData.get(1), rawData.get(2), 399 mDeltaVsync[i], mDelta2Vsync[i], 400 mNormalizedDelta2Vsync[i], mRoundNormalizedDelta2Vsync[i]); 401 fw.write(line); 402 } 403 } catch (IOException e) { 404 log("Open file error: " + e.toString()); 405 } finally { 406 try { 407 if (fw != null) { 408 fw.flush(); 409 fw.close(); 410 } 411 } 412 catch (IOException e) { 413 Log.e(TAG, "close file exception: ", e); 414 } 415 } 416 } 417 418 private static void log(String msg) { 419 Log.v(TAG, msg); 420 } 421 } 422
