Add TRON logging for bindApplication
Such that we know how much startup latency is the system to blame
and how much of it is the client process to blame.
Test: Open dead app, inspect logs
Change-Id: Ib8d359c2d59ef6f90893928f2b1d4e2ac2590d74
Fixes: 37327717
diff --git a/proto/src/metrics_constants.proto b/proto/src/metrics_constants.proto
index ff99b19..f37bfac 100644
--- a/proto/src/metrics_constants.proto
+++ b/proto/src/metrics_constants.proto
@@ -3957,6 +3957,11 @@
// OS: O
RUNNING_BACKGROUND_APPS_DIALOG = 944;
+ // FIELD - The delay from the start of the transition until we just call bindApplication on the
+ // client.
+ // OS: O
+ APP_TRANSITION_BIND_APPLICATION_DELAY_MS = 945;
+
// ---- End O Constants, all O constants go above this line ----
// Add new aosp constants above this line.
diff --git a/services/core/java/com/android/server/am/ActivityManagerService.java b/services/core/java/com/android/server/am/ActivityManagerService.java
index d46a24b..73cea2a 100644
--- a/services/core/java/com/android/server/am/ActivityManagerService.java
+++ b/services/core/java/com/android/server/am/ActivityManagerService.java
@@ -120,7 +120,6 @@
import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_OOM_ADJ;
import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_PERMISSIONS_REVIEW;
import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_POWER;
-import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_POWER_QUICK;
import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_PROCESSES;
import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_PROCESS_OBSERVERS;
import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_PROVIDER;
@@ -6795,6 +6794,7 @@
}
checkTime(startTime, "attachApplicationLocked: immediately before bindApplication");
+ mStackSupervisor.mActivityMetricsLogger.notifyBindApplication(app);
if (app.instr != null) {
thread.bindApplication(processName, appInfo, providers,
app.instr.mClass,
diff --git a/services/core/java/com/android/server/am/ActivityMetricsLogger.java b/services/core/java/com/android/server/am/ActivityMetricsLogger.java
index d4de521..bf7b663 100644
--- a/services/core/java/com/android/server/am/ActivityMetricsLogger.java
+++ b/services/core/java/com/android/server/am/ActivityMetricsLogger.java
@@ -10,6 +10,7 @@
import static android.app.ActivityManager.StackId.PINNED_STACK_ID;
import static android.app.ActivityManagerInternal.APP_TRANSITION_TIMEOUT;
import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION;
+import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_BIND_APPLICATION_DELAY_MS;
import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CALLING_PACKAGE_NAME;
import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DELAY_MS;
import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS;
@@ -78,7 +79,8 @@
private int startResult;
private boolean currentTransitionProcessRunning;
private int windowsDrawnDelayMs;
- private int startingWindowDelayMs;
+ private int startingWindowDelayMs = -1;
+ private int bindApplicationDelayMs = -1;
private int reason = APP_TRANSITION_TIMEOUT;
private boolean loggedWindowsDrawn;
private boolean loggedStartingWindowDrawn;
@@ -296,6 +298,22 @@
}
}
+ /**
+ * Notifies the tracker that we called immediately before we call bindApplication on the client.
+ *
+ * @param app The client into which we'll call bindApplication.
+ */
+ void notifyBindApplication(ProcessRecord app) {
+ for (int i = mStackTransitionInfo.size() - 1; i >= 0; i--) {
+ final StackTransitionInfo info = mStackTransitionInfo.valueAt(i);
+
+ // App isn't attached to record yet, so match with info.
+ if (info.launchedActivity.appInfo == app.info) {
+ info.bindApplicationDelayMs = calculateCurrentDelay();
+ }
+ }
+ }
+
private boolean allStacksWindowsDrawn() {
for (int index = mStackTransitionInfo.size() - 1; index >= 0; index--) {
if (!mStackTransitionInfo.valueAt(index).loggedWindowsDrawn) {
@@ -356,6 +374,10 @@
builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
info.startingWindowDelayMs);
}
+ if (info.bindApplicationDelayMs != -1) {
+ builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
+ info.bindApplicationDelayMs);
+ }
builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
mMetricsLogger.write(builder);
}