blob: 748b43339dd75e4f07f8b3a8fa8cf2e298b865cd [file] [log] [blame]
/*
* Copyright (C) 2013 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.android.uiautomator.platform;
import android.os.Environment;
import android.util.Log;
import java.util.Arrays;
import java.util.List;
import java.util.ArrayList;
import java.io.BufferedReader;
import java.io.File;
import java.io.FileWriter;
import java.io.BufferedWriter;
import java.io.InputStreamReader;
import java.io.IOException;
import java.lang.Math;
/*
* Tools to measure jankiness through SurfaceFlinger
*/
public class SurfaceFlingerHelper {
private static String TAG = "SurfaceFlingerHelper";
private static int BUFFER_SIZE = 128;
private static int BUFFER_NUMBER = 3;
private static String CLEAR_BUFFER_CMD = "dumpsys SurfaceFlinger --latency-clear";
private static String FRAME_LATENCY_CMD = "dumpsys SurfaceFlinger --latency";
private static final String RAW_DATA_DIR = "UiJankinessRawData";
private static final String LOCAL_TMP_DIR = "/data/local/tmp/";
/* If the latency between two frames is greater than this number, it it treated as a pause
* not a jankiness */
private static final int PAUSE_LATENCY = 20;
/* An array list which includes the raw buffer information from frame latency tool */
private static List<List<String>> mFrameBufferData = new ArrayList<List<String>>(BUFFER_SIZE);
/* Record the refresh period returned from driver */
private static long mRefreshPeriod = -1;
/* Record the size of frame latency */
private static int mFrameLatencySampleSize = 0;
/* An integer array which includes delta vsync */
private static long[] mDeltaVsync = new long[BUFFER_SIZE];
/* Integer array for delta of delta vsync */
private static long[] mDelta2Vsync = new long[BUFFER_SIZE];
/* the maximum delta vsync number */
private static long mMaxDeltaVsync;
/* Normalized data */
private static double[] mNormalizedDelta2Vsync = new double[BUFFER_SIZE];
private static int[] mRoundNormalizedDelta2Vsync = new int[BUFFER_SIZE];
// Symbol of unfinished frame time */
public static final String PENDING_FENCE_TIME = new Long(Long.MAX_VALUE).toString();
/**
* Run clear buffer command and clear the saved frame buffer results
*
* @param windowName the window name that the buffer will be cleared
*/
public static void clearBuffer(String windowName) {
// clear results
if (mFrameBufferData != null) {
mFrameBufferData.clear();
}
Arrays.fill(mDeltaVsync, -1);
Arrays.fill(mDelta2Vsync, -1);
Arrays.fill(mNormalizedDelta2Vsync, -1.0);
Arrays.fill(mRoundNormalizedDelta2Vsync, -1);
mRefreshPeriod = -1;
mFrameLatencySampleSize = 0;
mMaxDeltaVsync = 0;
Process p = null;
BufferedReader resultReader = null;
String command = CLEAR_BUFFER_CMD;
if (windowName != null) {
command = String.format("%s %s", CLEAR_BUFFER_CMD, windowName);
}
try {
p = Runtime.getRuntime().exec(command);
int status = p.waitFor();
if (status != 0) {
Log.e(TAG, String.format("Run shell command: %s, status: %s",
command, status));
}
} catch (IOException e) {
Log.e(TAG, "// Exception from command " + command + ":", e);
} catch (InterruptedException e) {
Log.e(TAG, "// Interrupted while waiting for the command to finish. ", e);
} finally {
try {
if (resultReader != null) {
resultReader.close();
}
if (p != null) {
p.destroy();
}
} catch (IOException e) {
Log.e(TAG, "exception " + e);
}
}
}
/**
* Run frame latency command without ignoring pending fence time
*
* @param windowName the window name which SurfaceFlinger will acquire frame time for
*/
public static boolean dumpFrameLatency(String windowName) {
return dumpFrameLatency(windowName, false);
}
/**
* Run frame latency command to get frame time
*
* @param windowName the window name which SurfaceFlinger will get frame time for
* @param ignorePendingFenceTime flag to process frames with pending fence time
* set true to ignore pending fence time
* set false to fail the test if pending fence time is not allowed
*/
public static boolean dumpFrameLatency(String windowName, boolean ignorePendingFenceTime) {
Process p = null;
BufferedReader resultReader = null;
String command = FRAME_LATENCY_CMD;
if (windowName != null) {
command = String.format("%s %s", FRAME_LATENCY_CMD, windowName);
}
log("dump frame latency command: " + command);
try {
p = Runtime.getRuntime().exec(command);
int status = p.waitFor();
if (status != 0) {
Log.e(TAG, String.format("Run shell command: %s, status: %s",command, status));
}
resultReader = new BufferedReader(new InputStreamReader(p.getInputStream()));
String line = resultReader.readLine();
mRefreshPeriod = Long.parseLong(line.trim());
log("reading refresh period: " + mRefreshPeriod);
if (mRefreshPeriod < 0) {
return false;
}
boolean dataInvalidFlag = false;
while((line = resultReader.readLine()) != null) {
// remove lines which are empty
if (line.trim().isEmpty()) {
break;
}
String[] bufferValues = line.split("\\s+");
if (bufferValues[0].trim().compareTo("0") == 0) {
continue;
} else if (bufferValues[1].trim().compareTo(PENDING_FENCE_TIME) == 0 ) {
if (ignorePendingFenceTime) {
log("ignore pending fence time");
dataInvalidFlag = true;
} else {
log("the data contains unfinished frame time, please allow the animation"
+ " to finish in the test before calling dumpFrameLatency.");
return false;
}
}
// store raw data which could have both valid and invalid data
List<String> delayArray = Arrays.asList(bufferValues);
mFrameBufferData.add(delayArray);
if (!dataInvalidFlag) {
// only count frames which have valid time
++mFrameLatencySampleSize;
}
}
log("frame latency sample size: " + mFrameLatencySampleSize);
} catch (InterruptedException e) {
Log.e(TAG, "// Exception from command " + command + ":", e);
} catch (IOException e) {
Log.e(TAG, "Open file error: ", e);
return false;
}
finally {
try {
if (resultReader != null) {
resultReader.close();
}
if (p != null) {
p.destroy();
}
} catch (IOException e) {
Log.e(TAG, "io exception: ", e);
}
}
return true;
}
public static int getDataSampleSize() {
return mFrameLatencySampleSize;
}
public static long getRefreshPeriod() {
if (mRefreshPeriod < 0) {
// Haven't dump the frame latency yet
log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving the refresh period");
}
return mRefreshPeriod;
}
public static String getFrameBufferData() {
if (mFrameBufferData.get(0) == null) {
log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame buffer data");
return null;
}
String rawData = String.format("%d\n", mRefreshPeriod);
List<String> tempList = new ArrayList<String>(BUFFER_NUMBER);
for (int i = 0; i < mFrameBufferData.size(); i++) {
tempList = mFrameBufferData.get(i);
for (int j = 0; j < BUFFER_NUMBER; j++) {
rawData += String.format("%s", tempList.get(j));
if (j < BUFFER_NUMBER - 1) {
rawData += "\t";
} else {
rawData += "\n";
}
}
}
return rawData;
}
/**
* Calculate delta(vsync)
* @return
*/
public static long[] getDeltaVsync() {
if (mRefreshPeriod < 0) {
log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame latency");
return null;
}
if (mDeltaVsync[0] < 0 ) {
// keep a record of the max DeltaVsync
mMaxDeltaVsync = 0;
// get the first frame vsync time
long preVsyncTime = Long.parseLong(mFrameBufferData.get(0).get(1));
for (int i = 0; i < mFrameLatencySampleSize - 1; i++) {
long curVsyncTime = Long.parseLong(mFrameBufferData.get(i + 1).get(1));
mDeltaVsync[i] = curVsyncTime - preVsyncTime;
preVsyncTime = curVsyncTime;
if (mMaxDeltaVsync < mDeltaVsync[i]) {
mMaxDeltaVsync = mDeltaVsync[i];
}
}
}
return mDeltaVsync;
}
/**
* Calculate difference between delta vsync
* @return
*/
public static long[] getDelta2Vsync() {
if (mRefreshPeriod < 0) {
log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame latency");
return null;
}
if (mDeltaVsync[0] < 0) {
getDeltaVsync();
}
if (mDelta2Vsync[0] < 0) {
int numDeltaVsync = mFrameLatencySampleSize - 1;
for (int i = 0; i < numDeltaVsync - 1; i++) {
mDelta2Vsync[i] = mDeltaVsync[i + 1] - mDeltaVsync[i];
}
}
return mDelta2Vsync;
}
/**
* normalized delta(delta(vsync)) by refresh period
* @return
*/
public static double[] getNormalizedDelta2Vsync() {
if (mRefreshPeriod < 0) {
log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame latency");
return null;
}
if (mDelta2Vsync[0] < 0) {
getDelta2Vsync();
}
if (mNormalizedDelta2Vsync[0] < 0) {
for (int i = 0; i < mFrameLatencySampleSize - 2; i++) {
mNormalizedDelta2Vsync[i] = (double)mDelta2Vsync[i] /mRefreshPeriod;
}
}
return mNormalizedDelta2Vsync;
}
public static int[] getRoundNormalizedDelta2Vsync() {
if (mRefreshPeriod < 0) {
log("Run command \"" + FRAME_LATENCY_CMD + " \" for number of jankiness.");
return null;
}
if (mNormalizedDelta2Vsync[0] < 0) {
getNormalizedDelta2Vsync();
}
for (int i = 0; i < mFrameLatencySampleSize - 2; i++) {
int value = (int)Math.round(Math.max(mNormalizedDelta2Vsync[i], 0.0));
mRoundNormalizedDelta2Vsync[i] = value;
}
return mRoundNormalizedDelta2Vsync;
}
/*
* Get number of jankiness using Vsync time difference
*/
public static int getVsyncJankiness() {
if (mRefreshPeriod < 0) {
log("Run command \"" + FRAME_LATENCY_CMD + " \" for number of jankiness.");
return -1;
}
if (mRoundNormalizedDelta2Vsync[0] < 0) {
getRoundNormalizedDelta2Vsync();
}
int numberJankiness = 0;
for (int i = 0; i < mFrameLatencySampleSize - 2; i++) {
int value = mRoundNormalizedDelta2Vsync[i];
// ignore the latency which is too long
if (value > 0 && value < PAUSE_LATENCY) {
numberJankiness++;
}
}
return numberJankiness;
}
/* Track the maximum delta which shows the accumulating time
* before animation starts */
public static int getMaxDeltaVsync() {
return Math.round((float)mMaxDeltaVsync /mRefreshPeriod);
}
/**
* Calculate frame rate
* @return
*/
public static double getFrameRate() {
if (mRefreshPeriod < 0) {
log("Run command \"" + FRAME_LATENCY_CMD + " \" before calcuating average frame rate");
return -1.0;
}
if (mFrameBufferData.get(0) == null) {
log("Run command \"" + FRAME_LATENCY_CMD + " \" before retrieving frame buffer data");
return -1.0;
}
long startTime = Long.parseLong(mFrameBufferData.get(0).get(1));
long endTime = Long.parseLong(mFrameBufferData.get(mFrameLatencySampleSize - 1).get(1));
long totalDuration = endTime - startTime;
return (double)((mFrameLatencySampleSize - 1) * Math.pow(10, 9))/totalDuration;
}
/**
* Print raw data and processed results into file <testcasename_[iteration]_processed.txt>
* @param fileName
* @param index
*/
public static void printData(String fileName, int index) {
String rawAndProcDataFileName = String.format("%s/%s_%d_processed.txt", RAW_DATA_DIR,
fileName, index);
log("write raw data and process data into file: " + rawAndProcDataFileName);
BufferedWriter fw = null;
try {
fw = new BufferedWriter(new FileWriter(new File(rawAndProcDataFileName), false));
// Show the number of jankiness first:
fw.write(String.format("Jankiness count: %d\n", getVsyncJankiness()));
fw.write(String.format("Max accumulated frames: %d\n", getMaxDeltaVsync()));
fw.write(String.format("Frame rate is: %f\n", getFrameRate()));
// refresh period
fw.write(String.valueOf(mRefreshPeriod));
fw.write("\n");
fw.write("app\tvsync\tset\tdelta(vsync)\tdelta^2(vsync)\t" +
"delta^2(vsync)/refreshPeriod\t normalized delta^2(vsync)\n");
for (int i = 0; i < mFrameLatencySampleSize; i++) {
// write raw data
List<String> rawData = mFrameBufferData.get(i);
String line = String.format("%s\t%s\t%s\t%d\t%d\t%f\t%d\n",
rawData.get(0), rawData.get(1), rawData.get(2),
mDeltaVsync[i], mDelta2Vsync[i],
mNormalizedDelta2Vsync[i], mRoundNormalizedDelta2Vsync[i]);
fw.write(line);
}
} catch (IOException e) {
log("Open file error: " + e.toString());
} finally {
try {
if (fw != null) {
fw.flush();
fw.close();
}
}
catch (IOException e) {
Log.e(TAG, "close file exception: ", e);
}
}
}
private static void log(String msg) {
Log.v(TAG, msg);
}
}