Support trigger java method profiling of WmPerfTests

So that it is easier to compare logic changes.

Bug: 161782359
Test: atest WmPerfTests -- \
      --module-arg \
      WmPerfTests:instrumentation-arg:profiling-iterations:=2 \
      --module-arg \
      WmPerfTests:instrumentation-arg:profiling-sampling:=100 \
Change-Id: Icb2f7f379a3ea515c2fca758db36d3489c33092a
This commit is contained in:
Riddle Hsu
2020-08-19 15:54:07 +08:00
parent f0d495611d
commit 14c4b1a32c
10 changed files with 178 additions and 28 deletions

View File

@@ -53,7 +53,8 @@ public final class BenchmarkState {
private static final int NOT_STARTED = 0; // The benchmark has not started yet.
private static final int WARMUP = 1; // The benchmark is warming up.
private static final int RUNNING = 2; // The benchmark is running.
private static final int FINISHED = 3; // The benchmark has stopped.
private static final int RUNNING_CUSTOMIZED = 3; // Running for customized measurement.
private static final int FINISHED = 4; // The benchmark has stopped.
private int mState = NOT_STARTED; // Current benchmark state.
@@ -76,6 +77,14 @@ public final class BenchmarkState {
private int mRepeatCount = 0;
/**
* Additional iteration that used to apply customized measurement. The result during these
* iterations won't be counted into {@link #mStats}.
*/
private int mMaxCustomizedIterations;
private int mCustomizedIterations;
private CustomizedIterationListener mCustomizedIterationListener;
// Statistics. These values will be filled when the benchmark has finished.
// The computation needs double precision, but long int is fine for final reporting.
private Stats mStats;
@@ -110,6 +119,15 @@ public final class BenchmarkState {
mPaused = false;
}
/**
* This is used to run the benchmark with more information by enabling some debug mechanism but
* we don't want to account the special runs (slower) in the stats report.
*/
public void setCustomizedIterations(int iterations, CustomizedIterationListener listener) {
mMaxCustomizedIterations = iterations;
mCustomizedIterationListener = listener;
}
private void beginWarmup() {
mStartTimeNs = System.nanoTime();
mIteration = 0;
@@ -141,6 +159,11 @@ public final class BenchmarkState {
Debug.stopMethodTracing();
}
mStats = new Stats(mResults);
if (mMaxCustomizedIterations > 0 && mCustomizedIterationListener != null) {
mState = RUNNING_CUSTOMIZED;
mCustomizedIterationListener.onStart(mCustomizedIterations);
return true;
}
mState = FINISHED;
return false;
}
@@ -180,6 +203,15 @@ public final class BenchmarkState {
"Resume the benchmark before finishing each step.");
}
return true;
case RUNNING_CUSTOMIZED:
mCustomizedIterationListener.onFinished(mCustomizedIterations);
mCustomizedIterations++;
if (mCustomizedIterations >= mMaxCustomizedIterations) {
mState = FINISHED;
return false;
}
mCustomizedIterationListener.onStart(mCustomizedIterations);
return true;
case FINISHED:
throw new IllegalStateException("The benchmark has finished.");
default:
@@ -240,4 +272,13 @@ public final class BenchmarkState {
status.putLong(key + "_standardDeviation", standardDeviation());
instrumentation.sendStatus(Activity.RESULT_OK, status);
}
/** The interface to receive the events of customized iteration. */
public interface CustomizedIterationListener {
/** The customized iteration starts. */
void onStart(int iteration);
/** The customized iteration finished. */
void onFinished(int iteration);
}
}

View File

@@ -29,5 +29,7 @@
</application>
<instrumentation android:name="androidx.test.runner.AndroidJUnitRunner"
android:targetPackage="com.android.perftests.wm"/>
android:targetPackage="com.android.perftests.wm">
<meta-data android:name="listener" android:value="android.wm.WmPerfRunListener" />
</instrumentation>
</manifest>

View File

@@ -42,7 +42,7 @@
<option name="hidden-api-checks" value="false"/>
<!-- Listener related args for collecting the traces and waiting for the device to stabilize. -->
<option name="device-listeners" value="android.wm.WmPerfRunListener,android.device.collectors.ProcLoadListener,android.device.collectors.PerfettoListener" />
<option name="device-listeners" value="android.device.collectors.ProcLoadListener,android.device.collectors.PerfettoListener" />
<!-- Guarantee that user defined RunListeners will be running before any of the default listeners defined in this runner. -->
<option name="instrumentation-arg" key="newRunListenerMode" value="true" />
@@ -57,8 +57,6 @@
<!-- PerfettoListener related arguments -->
<option name="instrumentation-arg" key="perfetto_config_text_proto" value="true" />
<option name="instrumentation-arg" key="perfetto_config_file" value="trace_config.textproto" />
<option name="instrumentation-arg" key="newRunListenerMode" value="true" />
</test>
<metrics_collector class="com.android.tradefed.device.metric.FilePullerLogCollector">

View File

@@ -25,3 +25,11 @@ adb shell am instrument -w -r -e class android.wm.RelayoutPerfTest \
com.android.perftests.wm/androidx.test.runner.AndroidJUnitRunner
```
* `kill-bg` is optional.
Test arguments
- kill-bg
* boolean: Kill background process before running test.
- profiling-iterations
* int: Run the extra iterations with enabling method profiling.
- profiling-sampling
* int: The interval (0=trace each method, default is 10) of sample profiling in microseconds.

View File

@@ -41,7 +41,8 @@ import java.util.concurrent.TimeUnit;
/** Measure the performance of internal methods in window manager service by trace tag. */
@LargeTest
public class InternalWindowOperationPerfTest extends WindowManagerPerfTestBase {
public class InternalWindowOperationPerfTest extends WindowManagerPerfTestBase
implements ManualBenchmarkState.CustomizedIterationListener {
private static final String TAG = InternalWindowOperationPerfTest.class.getSimpleName();
@Rule
@@ -68,6 +69,9 @@ public class InternalWindowOperationPerfTest extends WindowManagerPerfTestBase {
"finishActivity",
"startActivityInner");
private boolean mIsProfiling;
private boolean mIsTraceStarted;
@Test
@ManualBenchmarkTest(
targetTestDurationNs = 20 * TIME_1_S_IN_NS,
@@ -76,13 +80,13 @@ public class InternalWindowOperationPerfTest extends WindowManagerPerfTestBase {
| StatsReport.FLAG_MAX | StatsReport.FLAG_COEFFICIENT_VAR))
public void testLaunchAndFinishActivity() throws Throwable {
final ManualBenchmarkState state = mPerfStatusReporter.getBenchmarkState();
state.setCustomizedIterations(getProfilingIterations(), this);
long measuredTimeNs = 0;
boolean isTraceStarted = false;
while (state.keepRunning(measuredTimeNs)) {
if (!isTraceStarted && !state.isWarmingUp()) {
if (!mIsTraceStarted && !mIsProfiling && !state.isWarmingUp()) {
startAsyncAtrace();
isTraceStarted = true;
mIsTraceStarted = true;
}
final long startTime = SystemClock.elapsedRealtimeNanos();
mActivityRule.launchActivity();
@@ -91,7 +95,9 @@ public class InternalWindowOperationPerfTest extends WindowManagerPerfTestBase {
measuredTimeNs = SystemClock.elapsedRealtimeNanos() - startTime;
}
stopAsyncAtrace();
if (mIsTraceStarted) {
stopAsyncAtrace();
}
mTraceMarkParser.forAllSlices((key, slices) -> {
for (TraceMarkSlice slice : slices) {
@@ -108,7 +114,7 @@ public class InternalWindowOperationPerfTest extends WindowManagerPerfTestBase {
SystemClock.sleep(TimeUnit.NANOSECONDS.toMillis(TIME_1_S_IN_NS));
}
private void stopAsyncAtrace() throws IOException {
private void stopAsyncAtrace() {
final ParcelFileDescriptor pfd = sUiAutomation.executeShellCommand("atrace --async_stop");
final InputStream inputStream = new ParcelFileDescriptor.AutoCloseInputStream(pfd);
try (BufferedReader reader = new BufferedReader(new InputStreamReader(inputStream))) {
@@ -116,6 +122,28 @@ public class InternalWindowOperationPerfTest extends WindowManagerPerfTestBase {
while ((line = reader.readLine()) != null) {
mTraceMarkParser.visit(line);
}
} catch (IOException e) {
Log.w(TAG, "Failed to read the result of stopped atrace", e);
}
}
@Override
public void onStart(int iteration) {
if (mIsTraceStarted) {
// Do not capture trace when profiling because the result will be much slower.
stopAsyncAtrace();
mIsTraceStarted = false;
}
mIsProfiling = true;
startProfiling(InternalWindowOperationPerfTest.class.getSimpleName()
+ "_MethodTracing_" + iteration + ".trace");
}
@Override
public void onFinished(int iteration) {
stopProfiling();
if (iteration >= getProfilingIterations() - 1) {
mIsProfiling = false;
}
}
}

View File

@@ -62,7 +62,8 @@ import java.util.concurrent.TimeUnit;
@RunWith(Parameterized.class)
@LargeTest
public class RecentsAnimationPerfTest extends WindowManagerPerfTestBase {
public class RecentsAnimationPerfTest extends WindowManagerPerfTestBase
implements ManualBenchmarkState.CustomizedIterationListener {
private static Intent sRecentsIntent;
@Rule
@@ -162,6 +163,7 @@ public class RecentsAnimationPerfTest extends WindowManagerPerfTestBase {
| StatsReport.FLAG_COEFFICIENT_VAR))
public void testRecentsAnimation() throws Throwable {
final ManualBenchmarkState state = mPerfStatusReporter.getBenchmarkState();
state.setCustomizedIterations(getProfilingIterations(), this);
final IActivityTaskManager atm = ActivityTaskManager.getService();
final ArrayList<Pair<String, Boolean>> finishCases = new ArrayList<>();
@@ -230,7 +232,21 @@ public class RecentsAnimationPerfTest extends WindowManagerPerfTestBase {
state.addExtraResult("start", elapsedTimeNsOfStart);
// Ensure the animation callback is done.
Assume.assumeTrue(recentsSemaphore.tryAcquire(TIME_5_S_IN_NS, TimeUnit.NANOSECONDS));
Assume.assumeTrue(recentsSemaphore.tryAcquire(
sIsProfilingMethod ? 10 * TIME_5_S_IN_NS : TIME_5_S_IN_NS,
TimeUnit.NANOSECONDS));
}
}
@Override
public void onStart(int iteration) {
startProfiling(RecentsAnimationPerfTest.class.getSimpleName()
+ "_interval_" + intervalBetweenOperations
+ "_MethodTracing_" + iteration + ".trace");
}
@Override
public void onFinished(int iteration) {
stopProfiling();
}
}

View File

@@ -54,7 +54,8 @@ import java.util.function.IntSupplier;
@RunWith(Parameterized.class)
@LargeTest
@Presubmit
public class RelayoutPerfTest extends WindowManagerPerfTestBase {
public class RelayoutPerfTest extends WindowManagerPerfTestBase
implements BenchmarkState.CustomizedIterationListener {
private int mIteration;
@Rule
@@ -93,9 +94,22 @@ public class RelayoutPerfTest extends WindowManagerPerfTestBase {
mActivityRule.runOnUiThread(() -> activity.setContentView(contentView));
getInstrumentation().waitForIdleSync();
final BenchmarkState state = mPerfStatusReporter.getBenchmarkState();
state.setCustomizedIterations(getProfilingIterations(), this);
final RelayoutRunner relayoutRunner = new RelayoutRunner(activity, contentView.getWindow(),
() -> visibilities[mIteration++ % visibilities.length]);
relayoutRunner.runBenchmark(mPerfStatusReporter.getBenchmarkState());
relayoutRunner.runBenchmark(state);
}
@Override
public void onStart(int iteration) {
startProfiling(RelayoutPerfTest.class.getSimpleName() + "_" + testName
+ "_MethodTracing_" + iteration + ".trace");
}
@Override
public void onFinished(int iteration) {
stopProfiling();
}
/** A dummy view to get IWindow. */

View File

@@ -48,8 +48,6 @@ import org.junit.Test;
public class WindowAddRemovePerfTest extends WindowManagerPerfTestBase
implements ManualBenchmarkState.CustomizedIterationListener {
private static final int PROFILED_ITERATIONS = 2;
@Rule
public final PerfManualStatusReporter mPerfStatusReporter = new PerfManualStatusReporter();
@@ -64,7 +62,7 @@ public class WindowAddRemovePerfTest extends WindowManagerPerfTestBase
sUiAutomation.dropShellPermissionIdentity();
}
/** The last {@link #PROFILED_ITERATIONS} will provide the information of method profiling. */
/** The last customized iterations will provide the information of method profiling. */
@Override
public void onStart(int iteration) {
startProfiling(WindowAddRemovePerfTest.class.getSimpleName()
@@ -80,7 +78,7 @@ public class WindowAddRemovePerfTest extends WindowManagerPerfTestBase
@ManualBenchmarkTest(warmupDurationNs = TIME_1_S_IN_NS, targetTestDurationNs = TIME_5_S_IN_NS)
public void testAddRemoveWindow() throws Throwable {
final ManualBenchmarkState state = mPerfStatusReporter.getBenchmarkState();
state.setCustomizedIterations(PROFILED_ITERATIONS, this);
state.setCustomizedIterations(getProfilingIterations(), this);
new TestWindow().runBenchmark(state);
}

View File

@@ -32,6 +32,7 @@ import androidx.test.runner.lifecycle.ActivityLifecycleCallback;
import androidx.test.runner.lifecycle.ActivityLifecycleMonitorRegistry;
import androidx.test.runner.lifecycle.Stage;
import org.junit.After;
import org.junit.BeforeClass;
import org.junit.runner.Description;
import org.junit.runners.model.Statement;
@@ -52,18 +53,17 @@ public class WindowManagerPerfTestBase {
/**
* The out directory matching the directory-keys of collector in AndroidTest.xml. The directory
* is in /data because while enabling method profling of system server, it cannot write the
* is in /data because while enabling method profiling of system server, it cannot write the
* trace to external storage.
*/
static final File BASE_OUT_PATH = new File("/data/local/tmp/WmPerfTests");
static boolean sIsProfilingMethod;
@BeforeClass
public static void setUpOnce() {
final Context context = getInstrumentation().getContext();
if (!BASE_OUT_PATH.exists()) {
executeShellCommand("mkdir -p " + BASE_OUT_PATH);
}
if (!context.getSystemService(PowerManager.class).isInteractive()
|| context.getSystemService(KeyguardManager.class).isKeyguardLocked()) {
executeShellCommand("input keyevent KEYCODE_WAKEUP");
@@ -73,6 +73,14 @@ public class WindowManagerPerfTestBase {
.addCategory(Intent.CATEGORY_HOME).setFlags(Intent.FLAG_ACTIVITY_NEW_TASK));
}
@After
public void tearDown() {
// Make sure that profiling is stopped if test fails.
if (sIsProfilingMethod) {
stopProfiling();
}
}
/**
* Executes shell command with reading the output. It may also used to block until the current
* command is completed.
@@ -93,12 +101,26 @@ public class WindowManagerPerfTestBase {
}
/** Starts method tracing on system server. */
void startProfiling(String subPath) {
executeShellCommand("am profile start system " + new File(BASE_OUT_PATH, subPath));
static void startProfiling(String subPath) {
if (!BASE_OUT_PATH.exists()) {
executeShellCommand("mkdir -p " + BASE_OUT_PATH);
}
final String samplingArg = WmPerfRunListener.sSamplingIntervalUs > 0
? ("--sampling " + WmPerfRunListener.sSamplingIntervalUs)
: "";
executeShellCommand("am profile start " + samplingArg + " system "
+ new File(BASE_OUT_PATH, subPath));
sIsProfilingMethod = true;
}
void stopProfiling() {
static void stopProfiling() {
executeShellCommand("am profile stop system");
sIsProfilingMethod = false;
}
/** Returns how many iterations should run with method tracing. */
static int getProfilingIterations() {
return WmPerfRunListener.sProfilingIterations;
}
static void runWithShellPermissionIdentity(Runnable runnable) {

View File

@@ -31,6 +31,7 @@ import android.os.BatteryManager;
import android.os.Bundle;
import android.os.SystemClock;
import android.provider.Settings;
import android.util.Log;
import android.view.WindowManagerPolicyConstants;
import android.wm.WindowManagerPerfTestBase.SettingsSession;
@@ -46,10 +47,22 @@ import java.util.List;
/** Prepare the preconditions before running performance test. */
public class WmPerfRunListener extends RunListener {
private static final String TAG = WmPerfRunListener.class.getSimpleName();
private static final String OPTION_KILL_BACKGROUND = "kill-bg";
private static final String ARGUMENT_LOG_ONLY = "log";
private static final String ARGUMENT_KILL_BACKGROUND = "kill-bg";
private static final String ARGUMENT_PROFILING_ITERATIONS = "profiling-iterations";
private static final String ARGUMENT_PROFILING_SAMPLING = "profiling-sampling";
private static final String DEFAULT_PROFILING_ITERATIONS = "0";
private static final String DEFAULT_PROFILING_SAMPLING_US = "10";
private static final long KILL_BACKGROUND_WAIT_MS = 3000;
/** The requested iterations to run with method profiling. */
static int sProfilingIterations;
/** The interval of sample profiling in microseconds. */
static int sSamplingIntervalUs;
private final Context mContext = InstrumentationRegistry.getInstrumentation().getContext();
private long mWaitPreconditionDoneMs = 500;
@@ -83,6 +96,16 @@ public class WmPerfRunListener extends RunListener {
@Override
public void testRunStarted(Description description) {
final Bundle arguments = InstrumentationRegistry.getArguments();
// If true, it only logs the method names without running.
final boolean skip = Boolean.parseBoolean(arguments.getString(ARGUMENT_LOG_ONLY, "false"));
Log.i(TAG, "arguments=" + arguments);
if (skip) {
return;
}
sProfilingIterations = Integer.parseInt(
arguments.getString(ARGUMENT_PROFILING_ITERATIONS, DEFAULT_PROFILING_ITERATIONS));
sSamplingIntervalUs = Integer.parseInt(
arguments.getString(ARGUMENT_PROFILING_SAMPLING, DEFAULT_PROFILING_SAMPLING_US));
// Use gesture navigation for consistency.
mNavigationModeSetting.set(WindowManagerPolicyConstants.NAV_BAR_MODE_GESTURAL);
@@ -97,7 +120,7 @@ public class WmPerfRunListener extends RunListener {
});
PhoneWindow.sendCloseSystemWindows(mContext, "WmPerfTests");
if (Boolean.parseBoolean(arguments.getString(OPTION_KILL_BACKGROUND))) {
if (Boolean.parseBoolean(arguments.getString(ARGUMENT_KILL_BACKGROUND))) {
runWithShellPermissionIdentity(this::killBackgroundProcesses);
mWaitPreconditionDoneMs = KILL_BACKGROUND_WAIT_MS;
}