AML: Enable log and trace for non-process-switch launch
It will be more convenient to measure the generic launch
time by system or event log.
MetricsLogger, StatsLog, LaunchObserver still only focus
on process-switch launch.
Bug: 132736359
Bug: 144570280
Test: atest ActivityMetricsLoggerTests# \
testLaunchTimeEventLogNonProcessSwitch
Change-Id: I2ed45677cbf41dc15938e0fad909cb66fb6ac2c3
diff --git a/services/core/java/com/android/server/wm/ActivityMetricsLogger.java b/services/core/java/com/android/server/wm/ActivityMetricsLogger.java
index de51d4b..72665c8 100644
--- a/services/core/java/com/android/server/wm/ActivityMetricsLogger.java
+++ b/services/core/java/com/android/server/wm/ActivityMetricsLogger.java
@@ -190,6 +190,8 @@
final int mTransitionType;
/** Whether the process was already running when the transition started. */
final boolean mProcessRunning;
+ /** whether the process of the launching activity didn't have any active activity. */
+ final boolean mProcessSwitch;
/** The activities that should be drawn. */
final LinkedList<ActivityRecord> mPendingDrawActivities = new LinkedList<>();
/** The latest activity to have been launched. */
@@ -218,7 +220,8 @@
/** @return Non-null if there will be a window drawn event for the launch. */
@Nullable
static TransitionInfo create(@NonNull ActivityRecord r,
- @NonNull LaunchingState launchingState, boolean processRunning, int startResult) {
+ @NonNull LaunchingState launchingState, boolean processRunning,
+ boolean processSwitch, int startResult) {
int transitionType = INVALID_TRANSITION_TYPE;
if (processRunning) {
if (startResult == START_SUCCESS) {
@@ -235,16 +238,18 @@
// That means the startResult is neither START_SUCCESS nor START_TASK_TO_FRONT.
return null;
}
- return new TransitionInfo(r, launchingState, transitionType, processRunning);
+ return new TransitionInfo(r, launchingState, transitionType, processRunning,
+ processSwitch);
}
/** Use {@link TransitionInfo#create} instead to ensure the transition type is valid. */
private TransitionInfo(ActivityRecord r, LaunchingState launchingState, int transitionType,
- boolean processRunning) {
+ boolean processRunning, boolean processSwitch) {
mLaunchingState = launchingState;
mTransitionStartTimeNs = launchingState.mCurrentTransitionStartTimeNs;
mTransitionType = transitionType;
mProcessRunning = processRunning;
+ mProcessSwitch = processSwitch;
mCurrentTransitionDeviceUptime =
(int) TimeUnit.MILLISECONDS.toSeconds(SystemClock.uptimeMillis());
setLatestLaunchedActivity(r);
@@ -282,6 +287,14 @@
return mPendingDrawActivities.isEmpty();
}
+ /**
+ * @return {@code true} if the transition info should be sent to MetricsLogger, StatsLog, or
+ * LaunchObserver.
+ */
+ boolean isInterestingToLoggerAndObserver() {
+ return mProcessSwitch;
+ }
+
int calculateCurrentDelay() {
return calculateDelay(SystemClock.elapsedRealtimeNanos());
}
@@ -540,13 +553,8 @@
return;
}
- if (!processSwitch) {
- abort(info, "not a process switch");
- return;
- }
-
final TransitionInfo newInfo = TransitionInfo.create(launchedActivity, launchingState,
- processRunning, resultCode);
+ processRunning, processSwitch, resultCode);
if (newInfo == null) {
abort(info, "unrecognized launch");
return;
@@ -557,7 +565,12 @@
mTransitionInfoList.add(newInfo);
mLastTransitionInfo.put(launchedActivity, newInfo);
startLaunchTrace(newInfo);
- launchObserverNotifyActivityLaunched(newInfo);
+ if (newInfo.isInterestingToLoggerAndObserver()) {
+ launchObserverNotifyActivityLaunched(newInfo);
+ } else {
+ // As abort for no process switch.
+ launchObserverNotifyIntentFailed();
+ }
}
/**
@@ -733,7 +746,9 @@
launchObserverNotifyActivityLaunchCancelled(info);
} else {
logAppTransitionFinished(info);
- launchObserverNotifyActivityLaunchFinished(info, timestampNs);
+ if (info.isInterestingToLoggerAndObserver()) {
+ launchObserverNotifyActivityLaunchFinished(info, timestampNs);
+ }
}
info.mPendingDrawActivities.clear();
mTransitionInfoList.remove(info);
@@ -768,8 +783,11 @@
// Take a snapshot of the transition info before sending it to the handler for logging.
// This will avoid any races with other operations that modify the ActivityRecord.
final TransitionInfoSnapshot infoSnapshot = new TransitionInfoSnapshot(info);
- BackgroundThread.getHandler().post(() -> logAppTransition(
- info.mCurrentTransitionDeviceUptime, info.mCurrentTransitionDelayMs, infoSnapshot));
+ if (info.isInterestingToLoggerAndObserver()) {
+ BackgroundThread.getHandler().post(() -> logAppTransition(
+ info.mCurrentTransitionDeviceUptime, info.mCurrentTransitionDelayMs,
+ infoSnapshot));
+ }
BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot));
if (info.mPendingFullyDrawn != null) {
info.mPendingFullyDrawn.run();
@@ -905,6 +923,18 @@
return null;
}
+ final long currentTimestampNs = SystemClock.elapsedRealtimeNanos();
+ final long startupTimeMs = info.mPendingFullyDrawn != null
+ ? info.mWindowsDrawnDelayMs
+ : TimeUnit.NANOSECONDS.toMillis(currentTimestampNs - info.mTransitionStartTimeNs);
+ final TransitionInfoSnapshot infoSnapshot =
+ new TransitionInfoSnapshot(info, r, (int) startupTimeMs);
+ BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot));
+
+ if (!info.isInterestingToLoggerAndObserver()) {
+ return infoSnapshot;
+ }
+
// Record the handling of the reportFullyDrawn callback in the trace system. This is not
// actually used to trace this function, but instead the logical task that this function
// fullfils (handling reportFullyDrawn() callbacks).
@@ -914,10 +944,6 @@
final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
builder.setPackageName(r.packageName);
builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
- final long currentTimestampNs = SystemClock.elapsedRealtimeNanos();
- final long startupTimeMs = info.mPendingFullyDrawn != null
- ? info.mWindowsDrawnDelayMs
- : TimeUnit.NANOSECONDS.toMillis(currentTimestampNs - info.mTransitionStartTimeNs);
builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
builder.setType(restoredFromBundle
? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
@@ -940,10 +966,6 @@
// the trace slice to have a noticable duration.
Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
- final TransitionInfoSnapshot infoSnapshot =
- new TransitionInfoSnapshot(info, r, (int) startupTimeMs);
- BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot));
-
// Notify reportFullyDrawn event.
launchObserverNotifyReportFullyDrawn(r, currentTimestampNs);
@@ -1069,7 +1091,8 @@
return;
}
info.mLaunchTraceName = "launching: " + info.mLastLaunchedActivity.packageName;
- Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, info.mLaunchTraceName, 0);
+ Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, info.mLaunchTraceName,
+ (int) info.mTransitionStartTimeNs /* cookie */);
}
/** Stops trace for the launch is completed or cancelled. */
@@ -1078,7 +1101,8 @@
if (info.mLaunchTraceName == null) {
return;
}
- Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, info.mLaunchTraceName, 0);
+ Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, info.mLaunchTraceName,
+ (int) info.mTransitionStartTimeNs /* cookie */);
info.mLaunchTraceName = null;
}