From 4a263005499369c660b01af63a616eb5c20e49c5 Mon Sep 17 00:00:00 2001 From: Riddle Hsu Date: Thu, 21 Apr 2022 00:26:47 -0600 Subject: [PATCH] Reduce overhead of activity launch observer The cost of writing ActivityRecordProto is heavy. Especially it executes in window manager's lock. Since the usage of proto was removed. The callback interface is simplified to only send id and name. Though currently there is no use case, it is more accurate to associate different launch sequence because the assumption "only one start at a time" is not true anymore since multi-window/area/display support. Bug: 229822111 Test: atest ActivityMetricsLaunchObserverTests Change-Id: I6a151e72616fd4cf7a2e17d3c7f92aee8605c485 --- .../server/am/ActivityManagerService.java | 23 +-- .../wm/ActivityMetricsLaunchObserver.java | 81 ++++----- .../server/wm/ActivityMetricsLogger.java | 50 ++---- .../server/wm/LaunchObserverRegistryImpl.java | 72 +++----- .../ProfcollectForwardingService.java | 27 +-- .../ActivityMetricsLaunchObserverTests.java | 155 +++++++++--------- 6 files changed, 150 insertions(+), 258 deletions(-) diff --git a/services/core/java/com/android/server/am/ActivityManagerService.java b/services/core/java/com/android/server/am/ActivityManagerService.java index b9a55f990ce59..f1e05da166b3d 100644 --- a/services/core/java/com/android/server/am/ActivityManagerService.java +++ b/services/core/java/com/android/server/am/ActivityManagerService.java @@ -1024,30 +1024,9 @@ public class ActivityManagerService extends IActivityManager.Stub private final ActivityMetricsLaunchObserver mActivityLaunchObserver = new ActivityMetricsLaunchObserver() { @Override - public void onActivityLaunched(byte[] activity, int temperature) { + public void onActivityLaunched(long id, ComponentName name, int temperature) { mAppProfiler.onActivityLaunched(); } - - // The other observer methods are unused - @Override - public void onIntentStarted(Intent intent, long timestampNs) { - } - - @Override - public void onIntentFailed() { - } - - @Override - public void onActivityLaunchCancelled(byte[] abortingActivity) { - } - - @Override - public void onActivityLaunchFinished(byte[] finalActivity, long timestampNs) { - } - - @Override - public void onReportFullyDrawn(byte[] finalActivity, long timestampNs) { - } }; private volatile boolean mBinderTransactionTrackingEnabled = false; diff --git a/services/core/java/com/android/server/wm/ActivityMetricsLaunchObserver.java b/services/core/java/com/android/server/wm/ActivityMetricsLaunchObserver.java index c6b17e24b1dec..81e5fbd564e08 100644 --- a/services/core/java/com/android/server/wm/ActivityMetricsLaunchObserver.java +++ b/services/core/java/com/android/server/wm/ActivityMetricsLaunchObserver.java @@ -18,17 +18,19 @@ package com.android.server.wm; import android.annotation.IntDef; import android.annotation.NonNull; -import android.annotation.Nullable; +import android.content.ComponentName; import android.content.Intent; import java.lang.annotation.Retention; import java.lang.annotation.RetentionPolicy; /** - * Observe activity manager launch sequences. + * Observe activity launch sequences. * - * The activity manager can have at most 1 concurrent launch sequences. Calls to this interface - * are ordered by a happens-before relation for each defined state transition (see below). + * Multiple calls to the callback methods can occur without first terminating the current launch + * sequence because activity can be launched concurrently. So the implementation should associate + * the corresponding event according to the timestamp from {@link #onIntentStarted} which is also + * used as the identifier to indicate which launch sequence it belongs to. * * When a new launch sequence is made, that sequence is in the {@code INTENT_STARTED} state which * is communicated by the {@link #onIntentStarted} callback. This is a transient state. @@ -47,7 +49,7 @@ import java.lang.annotation.RetentionPolicy; * Note this transition may not happen if the reportFullyDrawn event is not receivied, * in which case {@code FINISHED} is terminal. * - * Note that the {@code ActivityRecordProto} provided as a parameter to some state transitions isn't + * Note that the {@code ComponentName} provided as a parameter to some state transitions isn't * necessarily the same within a single launch sequence: it is only the top-most activity at the * time (if any). Trampoline activities coalesce several activity starts into a single launch * sequence. @@ -67,7 +69,7 @@ import java.lang.annotation.RetentionPolicy; * ╚════════════════╝ ╚═══════════════════════════╝ ╚═══════════════════════════╝ * */ -public interface ActivityMetricsLaunchObserver { +public class ActivityMetricsLaunchObserver { /** * The 'temperature' at which a launch sequence had started. * @@ -98,14 +100,6 @@ public interface ActivityMetricsLaunchObserver { /** Hot launch sequence: process reused, activity brought-to-top. */ public static final int TEMPERATURE_HOT = 3; - /** - * Typedef marker that a {@code byte[]} actually contains an - * ActivityRecordProto - * in the protobuf format. - */ - @Retention(RetentionPolicy.SOURCE) - @interface ActivityRecordProto {} - /** * Notifies the observer that a new launch sequence has begun as a result of a new intent. * @@ -113,26 +107,25 @@ public interface ActivityMetricsLaunchObserver { * {@link #onActivityLaunched} or abort early (for example due to a resolution error or due to * a security error) with {@link #onIntentFailed}. * - * Multiple calls to this method cannot occur without first terminating the current - * launch sequence. + * @param timestampNanos The timestamp when receiving the intent. It is also use as an + * identifier for other callback methods to known which launch sequence + * it is associated with. */ - public void onIntentStarted(@NonNull Intent intent, long timestampNanos); + public void onIntentStarted(@NonNull Intent intent, long timestampNanos) { + } /** * Notifies the observer that the current launch sequence has failed to launch an activity. * - * This function call terminates the current launch sequence. The next method call, if any, - * must be {@link #onIntentStarted}. + * This function call terminates the current launch sequence. * * Examples of this happening: * - Failure to resolve to an activity * - Calling package did not have the security permissions to call the requested activity * - Resolved activity was already running and only needed to be brought to the top - * - * Multiple calls to this method cannot occur without first terminating the current - * launch sequence. */ - public void onIntentFailed(); + public void onIntentFailed(long id) { + } /** * Notifies the observer that the current launch sequence had begun starting an activity. @@ -145,62 +138,58 @@ public interface ActivityMetricsLaunchObserver { * necessarily the activity which will be considered as displayed when the activity * finishes launching (e.g. {@code activity} in {@link #onActivityLaunchFinished}). * - * Multiple calls to this method cannot occur without first terminating the current - * launch sequence. + * @param id The timestamp as an identifier from {@link #onIntentStarted}. It may be a new id + * if the launching activity is started from an existing launch sequence (trampoline) + * but cannot coalesce to the existing one, e.g. to a different display. + * @param name The launching activity name. */ - public void onActivityLaunched(@NonNull @ActivityRecordProto byte[] activity, - @Temperature int temperature); + public void onActivityLaunched(long id, ComponentName name, @Temperature int temperature) { + } /** * Notifies the observer that the current launch sequence has been aborted. * - * This function call terminates the current launch sequence. The next method call, if any, - * must be {@link #onIntentStarted}. + * This function call terminates the current launch sequence. * * This can happen for many reasons, for example the user switches away to another app * prior to the launch sequence completing, or the application being killed. * - * Multiple calls to this method cannot occur without first terminating the current - * launch sequence. - * - * @param abortingActivity the last activity that had the top-most window during abort - * (this can be {@code null} in rare situations its unknown). + * @param id The timestamp as an identifier from {@link #onIntentStarted}. * * @apiNote The aborting activity isn't necessarily the same as the starting activity; * in the case of a trampoline, multiple activities could've been started * and only the latest activity is reported here. */ - public void onActivityLaunchCancelled(@Nullable @ActivityRecordProto byte[] abortingActivity); + public void onActivityLaunchCancelled(long id) { + } /** * Notifies the observer that the current launch sequence has been successfully finished. * - * This function call terminates the current launch sequence. The next method call, if any, - * must be {@link #onIntentStarted}. + * This function call terminates the current launch sequence. * * A launch sequence is considered to be successfully finished when a frame is fully * drawn for the first time: the top-most activity at the time is what's reported here. * - * @param finalActivity the top-most activity whose windows were first to fully draw + * @param id The timestamp as an identifier from {@link #onIntentStarted}. + * @param name The name of drawn activity. It can be different from {@link #onActivityLaunched} + * if the transition contains multiple launching activities (e.g. trampoline). * @param timestampNanos the timestamp of ActivityLaunchFinished event in nanoseconds. * To compute the TotalTime duration, deduct the timestamp {@link #onIntentStarted} * from {@code timestampNanos}. * - * Multiple calls to this method cannot occur without first terminating the current - * launch sequence. - * * @apiNote The finishing activity isn't necessarily the same as the starting activity; * in the case of a trampoline, multiple activities could've been started * and only the latest activity that was top-most during first-frame drawn * is reported here. */ - public void onActivityLaunchFinished(@NonNull @ActivityRecordProto byte[] finalActivity, - long timestampNanos); + public void onActivityLaunchFinished(long id, ComponentName name, long timestampNanos) { + } /** * Notifies the observer that the application self-reported itself as being fully drawn. * - * @param activity the activity that triggers the ReportFullyDrawn event. + * @param id The timestamp as an identifier from {@link #onIntentStarted}. * @param timestampNanos the timestamp of ReportFullyDrawn event in nanoseconds. * To compute the duration, deduct the deduct the timestamp {@link #onIntentStarted} * from {@code timestampNanos}. @@ -209,7 +198,7 @@ public interface ActivityMetricsLaunchObserver { * It is used as an accurate estimate of meanfully app startup time. * This event may be missing for many apps. */ - public void onReportFullyDrawn(@NonNull @ActivityRecordProto byte[] activity, - long timestampNanos); + public void onReportFullyDrawn(long id, long timestampNanos) { + } } diff --git a/services/core/java/com/android/server/wm/ActivityMetricsLogger.java b/services/core/java/com/android/server/wm/ActivityMetricsLogger.java index 7f84f61a91ffd..1ea08f5cfea28 100644 --- a/services/core/java/com/android/server/wm/ActivityMetricsLogger.java +++ b/services/core/java/com/android/server/wm/ActivityMetricsLogger.java @@ -97,7 +97,6 @@ import android.util.Log; import android.util.Slog; import android.util.SparseArray; import android.util.TimeUtils; -import android.util.proto.ProtoOutputStream; import com.android.internal.annotations.VisibleForTesting; import com.android.internal.logging.MetricsLogger; @@ -176,7 +175,6 @@ class ActivityMetricsLogger { * in-order on the same thread to fulfill the "happens-before" guarantee in LaunchObserver. */ private final LaunchObserverRegistryImpl mLaunchObserver; - @VisibleForTesting static final int LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE = 512; private final ArrayMap mLastHibernationStates = new ArrayMap<>(); private AppHibernationManagerInternal mAppHibernationManagerInternal; @@ -675,7 +673,7 @@ class ActivityMetricsLogger { launchObserverNotifyActivityLaunched(newInfo); } else { // As abort for no process switch. - launchObserverNotifyIntentFailed(); + launchObserverNotifyIntentFailed(newInfo.mTransitionStartTimeNs); } scheduleCheckActivityToBeDrawnIfSleeping(launchedActivity); @@ -910,7 +908,7 @@ class ActivityMetricsLogger { } if (DEBUG_METRICS) Slog.i(TAG, "abort launch cause=" + cause); state.stopTrace(true /* abort */); - launchObserverNotifyIntentFailed(); + launchObserverNotifyIntentFailed(state.mCurrentTransitionStartTimeNs); } /** Aborts tracking of current launch metrics. */ @@ -1187,7 +1185,7 @@ class ActivityMetricsLogger { Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); // Notify reportFullyDrawn event. - launchObserverNotifyReportFullyDrawn(r, currentTimestampNs); + launchObserverNotifyReportFullyDrawn(info, currentTimestampNs); return infoSnapshot; } @@ -1531,11 +1529,11 @@ class ActivityMetricsLogger { * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or * intent being delivered to the top running activity. */ - private void launchObserverNotifyIntentFailed() { + private void launchObserverNotifyIntentFailed(long id) { Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "MetricsLogger:launchObserverNotifyIntentFailed"); - mLaunchObserver.onIntentFailed(); + mLaunchObserver.onIntentFailed(id); Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); } @@ -1552,8 +1550,8 @@ class ActivityMetricsLogger { convertTransitionTypeToLaunchObserverTemperature(info.mTransitionType); // Beginning a launch is timing sensitive and so should be observed as soon as possible. - mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.mLastLaunchedActivity), - temperature); + mLaunchObserver.onActivityLaunched(info.mTransitionStartTimeNs, + info.mLastLaunchedActivity.mActivityComponent, temperature); Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); } @@ -1561,10 +1559,10 @@ class ActivityMetricsLogger { /** * Notifies the {@link ActivityMetricsLaunchObserver} the reportFullDrawn event. */ - private void launchObserverNotifyReportFullyDrawn(ActivityRecord r, long timestampNs) { + private void launchObserverNotifyReportFullyDrawn(TransitionInfo info, long timestampNs) { Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "MetricsLogger:launchObserverNotifyReportFullyDrawn"); - mLaunchObserver.onReportFullyDrawn(convertActivityRecordToProto(r), timestampNs); + mLaunchObserver.onReportFullyDrawn(info.mTransitionStartTimeNs, timestampNs); Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); } @@ -1576,10 +1574,7 @@ class ActivityMetricsLogger { Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "MetricsLogger:launchObserverNotifyActivityLaunchCancelled"); - final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto = - info != null ? convertActivityRecordToProto(info.mLastLaunchedActivity) : null; - - mLaunchObserver.onActivityLaunchCancelled(activityRecordProto); + mLaunchObserver.onActivityLaunchCancelled(info.mTransitionStartTimeNs); Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); } @@ -1592,33 +1587,12 @@ class ActivityMetricsLogger { Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "MetricsLogger:launchObserverNotifyActivityLaunchFinished"); - mLaunchObserver.onActivityLaunchFinished( - convertActivityRecordToProto(info.mLastLaunchedActivity), timestampNs); + mLaunchObserver.onActivityLaunchFinished(info.mTransitionStartTimeNs, + info.mLastLaunchedActivity.mActivityComponent, timestampNs); Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); } - @VisibleForTesting - static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] - convertActivityRecordToProto(ActivityRecord record) { - // May take non-negligible amount of time to convert ActivityRecord into a proto, - // so track the time. - Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, - "MetricsLogger:convertActivityRecordToProto"); - - // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream, - // so create a new one every time. - final ProtoOutputStream protoOutputStream = - new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE); - // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object). - record.dumpDebug(protoOutputStream, WindowTraceLogLevel.ALL); - final byte[] bytes = protoOutputStream.getBytes(); - - Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); - - return bytes; - } - private static @ActivityMetricsLaunchObserver.Temperature int convertTransitionTypeToLaunchObserverTemperature(int transitionType) { switch (transitionType) { diff --git a/services/core/java/com/android/server/wm/LaunchObserverRegistryImpl.java b/services/core/java/com/android/server/wm/LaunchObserverRegistryImpl.java index 362ed3c380c5a..9cbc1bdcbeebd 100644 --- a/services/core/java/com/android/server/wm/LaunchObserverRegistryImpl.java +++ b/services/core/java/com/android/server/wm/LaunchObserverRegistryImpl.java @@ -16,12 +16,11 @@ package com.android.server.wm; +import android.content.ComponentName; import android.content.Intent; import android.os.Handler; import android.os.Looper; -import android.os.Message; -import com.android.internal.os.BackgroundThread; import com.android.internal.util.function.pooled.PooledLambda; import java.util.ArrayList; @@ -39,8 +38,8 @@ import java.util.ArrayList; * * @see ActivityTaskManagerInternal#getLaunchObserverRegistry() */ -class LaunchObserverRegistryImpl implements - ActivityMetricsLaunchObserverRegistry, ActivityMetricsLaunchObserver { +class LaunchObserverRegistryImpl extends ActivityMetricsLaunchObserver implements + ActivityMetricsLaunchObserverRegistry { private final ArrayList mList = new ArrayList<>(); /** @@ -79,45 +78,36 @@ class LaunchObserverRegistryImpl implements } @Override - public void onIntentFailed() { + public void onIntentFailed(long id) { mHandler.sendMessage(PooledLambda.obtainMessage( - LaunchObserverRegistryImpl::handleOnIntentFailed, this)); + LaunchObserverRegistryImpl::handleOnIntentFailed, this, id)); } @Override - public void onActivityLaunched( - @ActivityRecordProto byte[] activity, - int temperature) { + public void onActivityLaunched(long id, ComponentName name, int temperature) { mHandler.sendMessage(PooledLambda.obtainMessage( LaunchObserverRegistryImpl::handleOnActivityLaunched, - this, activity, temperature)); + this, id, name, temperature)); } @Override - public void onActivityLaunchCancelled( - @ActivityRecordProto byte[] activity) { + public void onActivityLaunchCancelled(long id) { mHandler.sendMessage(PooledLambda.obtainMessage( - LaunchObserverRegistryImpl::handleOnActivityLaunchCancelled, this, activity)); + LaunchObserverRegistryImpl::handleOnActivityLaunchCancelled, this, id)); } @Override - public void onActivityLaunchFinished( - @ActivityRecordProto byte[] activity, - long timestampNs) { + public void onActivityLaunchFinished(long id, ComponentName name, long timestampNs) { mHandler.sendMessage(PooledLambda.obtainMessage( - LaunchObserverRegistryImpl::handleOnActivityLaunchFinished, - this, - activity, - timestampNs)); + LaunchObserverRegistryImpl::handleOnActivityLaunchFinished, + this, id, name, timestampNs)); } @Override - public void onReportFullyDrawn(@ActivityRecordProto byte[] activity, long timestampNs) { + public void onReportFullyDrawn(long id, long timestampNs) { mHandler.sendMessage(PooledLambda.obtainMessage( - LaunchObserverRegistryImpl::handleOnReportFullyDrawn, - this, - activity, - timestampNs)); + LaunchObserverRegistryImpl::handleOnReportFullyDrawn, + this, id, timestampNs)); } // Use PooledLambda.obtainMessage to invoke below methods. Every method reference must be @@ -135,53 +125,43 @@ class LaunchObserverRegistryImpl implements private void handleOnIntentStarted(Intent intent, long timestampNs) { // Traverse start-to-end to meet the registerLaunchObserver multi-cast order guarantee. for (int i = 0; i < mList.size(); i++) { - ActivityMetricsLaunchObserver o = mList.get(i); - o.onIntentStarted(intent, timestampNs); + mList.get(i).onIntentStarted(intent, timestampNs); } } - private void handleOnIntentFailed() { + private void handleOnIntentFailed(long id) { // Traverse start-to-end to meet the registerLaunchObserver multi-cast order guarantee. for (int i = 0; i < mList.size(); i++) { - ActivityMetricsLaunchObserver o = mList.get(i); - o.onIntentFailed(); + mList.get(i).onIntentFailed(id); } } - private void handleOnActivityLaunched( - @ActivityRecordProto byte[] activity, + private void handleOnActivityLaunched(long id, ComponentName name, @Temperature int temperature) { // Traverse start-to-end to meet the registerLaunchObserver multi-cast order guarantee. for (int i = 0; i < mList.size(); i++) { - ActivityMetricsLaunchObserver o = mList.get(i); - o.onActivityLaunched(activity, temperature); + mList.get(i).onActivityLaunched(id, name, temperature); } } - private void handleOnActivityLaunchCancelled( - @ActivityRecordProto byte[] activity) { + private void handleOnActivityLaunchCancelled(long id) { // Traverse start-to-end to meet the registerLaunchObserver multi-cast order guarantee. for (int i = 0; i < mList.size(); i++) { - ActivityMetricsLaunchObserver o = mList.get(i); - o.onActivityLaunchCancelled(activity); + mList.get(i).onActivityLaunchCancelled(id); } } - private void handleOnActivityLaunchFinished( - @ActivityRecordProto byte[] activity, long timestampNs) { + private void handleOnActivityLaunchFinished(long id, ComponentName name, long timestampNs) { // Traverse start-to-end to meet the registerLaunchObserver multi-cast order guarantee. for (int i = 0; i < mList.size(); i++) { - ActivityMetricsLaunchObserver o = mList.get(i); - o.onActivityLaunchFinished(activity, timestampNs); + mList.get(i).onActivityLaunchFinished(id, name, timestampNs); } } - private void handleOnReportFullyDrawn( - @ActivityRecordProto byte[] activity, long timestampNs) { + private void handleOnReportFullyDrawn(long id, long timestampNs) { // Traverse start-to-end to meet the registerLaunchObserver multi-cast order guarantee. for (int i = 0; i < mList.size(); i++) { - ActivityMetricsLaunchObserver o = mList.get(i); - o.onReportFullyDrawn(activity, timestampNs); + mList.get(i).onReportFullyDrawn(id, timestampNs); } } } diff --git a/services/profcollect/src/com/android/server/profcollect/ProfcollectForwardingService.java b/services/profcollect/src/com/android/server/profcollect/ProfcollectForwardingService.java index bbc28d78d6f24..d3222901db1e6 100644 --- a/services/profcollect/src/com/android/server/profcollect/ProfcollectForwardingService.java +++ b/services/profcollect/src/com/android/server/profcollect/ProfcollectForwardingService.java @@ -274,36 +274,11 @@ public final class ProfcollectForwardingService extends SystemService { } } - private class AppLaunchObserver implements ActivityMetricsLaunchObserver { + private class AppLaunchObserver extends ActivityMetricsLaunchObserver { @Override public void onIntentStarted(Intent intent, long timestampNanos) { traceOnAppStart(intent.getPackage()); } - - @Override - public void onIntentFailed() { - // Ignored - } - - @Override - public void onActivityLaunched(byte[] activity, int temperature) { - // Ignored - } - - @Override - public void onActivityLaunchCancelled(byte[] abortingActivity) { - // Ignored - } - - @Override - public void onActivityLaunchFinished(byte[] finalActivity, long timestampNanos) { - // Ignored - } - - @Override - public void onReportFullyDrawn(byte[] activity, long timestampNanos) { - // Ignored - } } private void registerOTAObserver() { diff --git a/services/tests/wmtests/src/com/android/server/wm/ActivityMetricsLaunchObserverTests.java b/services/tests/wmtests/src/com/android/server/wm/ActivityMetricsLaunchObserverTests.java index 7689e08bc3f36..2fea2284ff2af 100644 --- a/services/tests/wmtests/src/com/android/server/wm/ActivityMetricsLaunchObserverTests.java +++ b/services/tests/wmtests/src/com/android/server/wm/ActivityMetricsLaunchObserverTests.java @@ -27,10 +27,8 @@ import static com.android.dx.mockito.inline.extended.ExtendedMockito.verifyNoMor import static com.google.common.truth.Truth.assertWithMessage; -import static org.mockito.ArgumentMatchers.any; import static org.mockito.ArgumentMatchers.anyInt; import static org.mockito.ArgumentMatchers.anyLong; -import static org.mockito.ArgumentMatchers.argThat; import static org.mockito.ArgumentMatchers.eq; import static org.mockito.Mockito.clearInvocations; import static org.mockito.Mockito.never; @@ -40,24 +38,22 @@ import android.app.ActivityOptions; import android.app.ActivityOptions.SourceInfo; import android.app.WaitResult; import android.app.WindowConfiguration; +import android.content.ComponentName; import android.content.Intent; import android.os.IBinder; import android.os.SystemClock; import android.platform.test.annotations.Presubmit; import android.util.ArrayMap; +import android.util.Log; import android.window.WindowContainerToken; import androidx.test.filters.SmallTest; -import com.android.server.wm.ActivityMetricsLaunchObserver.ActivityRecordProto; - -import org.junit.After; import org.junit.Before; import org.junit.Test; import org.junit.runner.RunWith; -import org.mockito.ArgumentMatcher; +import org.mockito.ArgumentCaptor; -import java.util.Arrays; import java.util.concurrent.TimeUnit; import java.util.function.ToIntFunction; @@ -75,13 +71,14 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { private ActivityMetricsLogger mActivityMetricsLogger; private ActivityMetricsLogger.LaunchingState mLaunchingState; private ActivityMetricsLaunchObserver mLaunchObserver; - private ActivityMetricsLaunchObserverRegistry mLaunchObserverRegistry; private ActivityRecord mTrampolineActivity; private ActivityRecord mTopActivity; private ActivityOptions mActivityOptions; private boolean mLaunchTopByTrampoline; private boolean mNewActivityCreated = true; + private long mExpectedStartedId; + private final ArrayMap mLastLaunchedIds = new ArrayMap<>(); @Before public void setUpAMLO() { @@ -89,9 +86,7 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { // ActivityTaskSupervisor always creates its own instance of ActivityMetricsLogger. mActivityMetricsLogger = mSupervisor.getActivityMetricsLogger(); - - mLaunchObserverRegistry = mActivityMetricsLogger.getLaunchObserverRegistry(); - mLaunchObserverRegistry.registerLaunchObserver(mLaunchObserver); + mActivityMetricsLogger.getLaunchObserverRegistry().registerLaunchObserver(mLaunchObserver); // Sometimes we need an ActivityRecord for ActivityMetricsLogger to do anything useful. // This seems to be the easiest way to create an ActivityRecord. @@ -107,33 +102,6 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { mTrampolineActivity.mVisibleRequested = false; } - @After - public void tearDownAMLO() { - if (mLaunchObserverRegistry != null) { // Don't NPE if setUp failed. - mLaunchObserverRegistry.unregisterLaunchObserver(mLaunchObserver); - } - } - - static class ActivityRecordMatcher implements ArgumentMatcher { - private final @ActivityRecordProto byte[] mExpected; - - public ActivityRecordMatcher(ActivityRecord activityRecord) { - mExpected = activityRecordToProto(activityRecord); - } - - public boolean matches(@ActivityRecordProto byte[] actual) { - return Arrays.equals(mExpected, actual); - } - } - - static @ActivityRecordProto byte[] activityRecordToProto(ActivityRecord record) { - return ActivityMetricsLogger.convertActivityRecordToProto(record); - } - - static @ActivityRecordProto byte[] eqProto(ActivityRecord record) { - return argThat(new ActivityRecordMatcher(record)); - } - private T verifyAsync(T mock) { // With WindowTestRunner, all test methods are inside WM lock, so we have to unblock any // messages that are waiting for the lock. @@ -142,30 +110,62 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { return verify(mock, timeout(TIMEOUT_MS)); } - private void verifyOnActivityLaunchFinished(ActivityRecord activity) { - verifyAsync(mLaunchObserver).onActivityLaunchFinished(eqProto(activity), anyLong()); + private void verifyOnActivityLaunched(ActivityRecord activity) { + final ArgumentCaptor idCaptor = ArgumentCaptor.forClass(Long.class); + verifyAsync(mLaunchObserver).onActivityLaunched(idCaptor.capture(), + eq(activity.mActivityComponent), anyInt()); + final long id = idCaptor.getValue(); + setExpectedStartedId(id, activity); + mLastLaunchedIds.put(activity.mActivityComponent, id); } - private void onIntentStarted(Intent intent) { + private void verifyOnActivityLaunchFinished(ActivityRecord activity) { + verifyAsync(mLaunchObserver).onActivityLaunchFinished(eq(mExpectedStartedId), + eq(activity.mActivityComponent), anyLong()); + } + + private void setExpectedStartedId(long id, Object reason) { + mExpectedStartedId = id; + Log.i("AMLTest", "setExpectedStartedId=" + id + " from " + reason); + } + + private void setLastExpectedStartedId(ActivityRecord r) { + setExpectedStartedId(getLastStartedId(r), r); + } + + private long getLastStartedId(ActivityRecord r) { + final Long id = mLastLaunchedIds.get(r.mActivityComponent); + return id != null ? id : -1; + } + + private long eqLastStartedId(ActivityRecord r) { + return eq(getLastStartedId(r)); + } + + private long onIntentStarted(Intent intent) { notifyActivityLaunching(intent); + long timestamp = -1; // If it is launching top activity from trampoline activity, the observer shouldn't receive // onActivityLaunched because the activities should belong to the same transition. if (!mLaunchTopByTrampoline) { - verifyAsync(mLaunchObserver).onIntentStarted(eq(intent), anyLong()); + final ArgumentCaptor captor = ArgumentCaptor.forClass(Long.class); + verifyAsync(mLaunchObserver).onIntentStarted(eq(intent), captor.capture()); + timestamp = captor.getValue(); } verifyNoMoreInteractions(mLaunchObserver); + return timestamp; } @Test public void testOnIntentFailed() { - onIntentStarted(new Intent("testOnIntentFailed")); + final long id = onIntentStarted(new Intent("testOnIntentFailed")); // Bringing an intent that's already running 'to front' is not considered // as an ACTIVITY_LAUNCHED state transition. notifyActivityLaunched(START_TASK_TO_FRONT, null /* launchedActivity */); - verifyAsync(mLaunchObserver).onIntentFailed(); + verifyAsync(mLaunchObserver).onIntentFailed(eq(id)); verifyNoMoreInteractions(mLaunchObserver); } @@ -208,9 +208,8 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { private void onActivityLaunched(ActivityRecord activity) { onIntentStarted(activity.intent); - notifyActivityLaunched(START_SUCCESS, activity); + notifyAndVerifyActivityLaunched(activity); - verifyAsync(mLaunchObserver).onActivityLaunched(eqProto(activity), anyInt()); verifyNoMoreInteractions(mLaunchObserver); } @@ -235,7 +234,7 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { // Cannot time already-visible activities. notifyActivityLaunched(START_TASK_TO_FRONT, mTopActivity); - verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqProto(mTopActivity)); + verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqLastStartedId(mTopActivity)); verifyNoMoreInteractions(mLaunchObserver); } @@ -250,33 +249,33 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { .build(); notifyActivityLaunching(noDrawnActivity.intent); - notifyActivityLaunched(START_SUCCESS, noDrawnActivity); + notifyAndVerifyActivityLaunched(noDrawnActivity); noDrawnActivity.mVisibleRequested = false; mActivityMetricsLogger.notifyVisibilityChanged(noDrawnActivity); - verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqProto(noDrawnActivity)); + verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqLastStartedId(noDrawnActivity)); // If an activity is removed immediately before visibility update, it should cancel too. final ActivityRecord removedImm = new ActivityBuilder(mAtm).setCreateTask(true).build(); clearInvocations(mLaunchObserver); onActivityLaunched(removedImm); removedImm.removeImmediately(); - // Verify any() instead of proto because the field of record may be changed. - verifyAsync(mLaunchObserver).onActivityLaunchCancelled(any()); + verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqLastStartedId(removedImm)); } @Test public void testOnActivityLaunchWhileSleeping() { notifyActivityLaunching(mTrampolineActivity.intent); - notifyActivityLaunched(START_SUCCESS, mTrampolineActivity); + notifyAndVerifyActivityLaunched(mTrampolineActivity); doReturn(true).when(mTrampolineActivity.mDisplayContent).isSleeping(); mTrampolineActivity.setState(ActivityRecord.State.RESUMED, "test"); mTrampolineActivity.setVisibility(false); waitHandlerIdle(mAtm.mH); // Not cancel immediately because in one of real cases, the keyguard may be going away or // occluded later, then the activity can be drawn. - verify(mLaunchObserver, never()).onActivityLaunchCancelled(eqProto(mTrampolineActivity)); + verify(mLaunchObserver, never()).onActivityLaunchCancelled( + eqLastStartedId(mTrampolineActivity)); clearInvocations(mLaunchObserver); mLaunchTopByTrampoline = true; @@ -289,9 +288,8 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { // The posted message will acquire wm lock, so the test needs to release the lock to verify. final Throwable error = awaitInWmLock(() -> { try { - // Though the aborting target should be eqProto(mTopActivity), use any() to avoid - // any changes in proto that may cause failure by different arguments. - verify(mLaunchObserver, timeout(TIMEOUT_MS)).onActivityLaunchCancelled(any()); + verify(mLaunchObserver, timeout(TIMEOUT_MS)).onActivityLaunchCancelled( + mExpectedStartedId); } catch (Throwable e) { // Catch any errors including assertion because this runs in another thread. return e; @@ -314,9 +312,8 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { mActivityOptions = ActivityOptions.makeBasic(); mActivityOptions.setSourceInfo(SourceInfo.TYPE_LAUNCHER, SystemClock.uptimeMillis() - 10); onIntentStarted(mTopActivity.intent); - notifyActivityLaunched(START_SUCCESS, mTopActivity); - verifyAsync(mLaunchObserver).onActivityLaunched(eqProto(mTopActivity), anyInt()); - verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqProto(prev)); + notifyAndVerifyActivityLaunched(mTopActivity); + verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eq(getLastStartedId(prev))); // The activity reports fully drawn before windows drawn, then the fully drawn event will // be pending (see {@link WindowingModeTransitionInfo#pendingFullyDrawn}). @@ -328,7 +325,7 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { .isEqualTo(SourceInfo.TYPE_LAUNCHER); assertWithMessage("Record event time").that(info.sourceEventDelayMs).isAtLeast(10); - verifyAsync(mLaunchObserver).onReportFullyDrawn(eqProto(mTopActivity), anyLong()); + verifyAsync(mLaunchObserver).onReportFullyDrawn(eq(mExpectedStartedId), anyLong()); verifyOnActivityLaunchFinished(mTopActivity); verifyNoMoreInteractions(mLaunchObserver); @@ -339,9 +336,7 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { private void onActivityLaunchedTrampoline() { onIntentStarted(mTrampolineActivity.intent); - notifyActivityLaunched(START_SUCCESS, mTrampolineActivity); - - verifyAsync(mLaunchObserver).onActivityLaunched(eqProto(mTrampolineActivity), anyInt()); + notifyAndVerifyActivityLaunched(mTrampolineActivity); // A second, distinct, activity launch is coalesced into the current app launch sequence. mLaunchTopByTrampoline = true; @@ -370,6 +365,11 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { mNewActivityCreated, activity, mActivityOptions); } + private void notifyAndVerifyActivityLaunched(ActivityRecord activity) { + notifyActivityLaunched(START_SUCCESS, activity); + verifyOnActivityLaunched(activity); + } + private void notifyTransitionStarting(ActivityRecord activity) { final ArrayMap reasons = new ArrayMap<>(); reasons.put(activity, ActivityTaskManagerInternal.APP_TRANSITION_SPLASH_SCREEN); @@ -430,7 +430,7 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { // Cannot time already-visible activities. notifyActivityLaunched(START_TASK_TO_FRONT, mTopActivity); - verifyAsync(mLaunchObserver).onActivityLaunchCancelled(eqProto(mTopActivity)); + verifyAsync(mLaunchObserver).onActivityLaunchCancelled(mExpectedStartedId); verifyNoMoreInteractions(mLaunchObserver); } @@ -447,25 +447,14 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { // be reported successfully. notifyTransitionStarting(mTopActivity); + verifyOnActivityLaunched(mTopActivity); verifyOnActivityLaunchFinished(mTopActivity); } - @Test - public void testActivityRecordProtoIsNotTooBig() { - // The ActivityRecordProto must not be too big, otherwise converting it at runtime - // will become prohibitively expensive. - assertWithMessage("mTopActivity: %s", mTopActivity) - .that(activityRecordToProto(mTopActivity).length) - .isAtMost(ActivityMetricsLogger.LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE); - - assertWithMessage("mTrampolineActivity: %s", mTrampolineActivity) - .that(activityRecordToProto(mTrampolineActivity).length) - .isAtMost(ActivityMetricsLogger.LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE); - } - @Test public void testConcurrentLaunches() { onActivityLaunched(mTopActivity); + clearInvocations(mLaunchObserver); final ActivityMetricsLogger.LaunchingState previousState = mLaunchingState; final ActivityRecord otherActivity = new ActivityBuilder(mAtm) @@ -476,11 +465,13 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { // state should be created here. onActivityLaunched(otherActivity); - assertWithMessage("Different callers should get 2 indepedent launching states") + assertWithMessage("Different callers should get 2 independent launching states") .that(previousState).isNotEqualTo(mLaunchingState); + setLastExpectedStartedId(otherActivity); transitToDrawnAndVerifyOnLaunchFinished(otherActivity); // The first transition should still be valid. + setLastExpectedStartedId(mTopActivity); transitToDrawnAndVerifyOnLaunchFinished(mTopActivity); } @@ -534,10 +525,12 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { // Before TopActivity is drawn, it launches another activity on a different display. mActivityMetricsLogger.notifyActivityLaunching(activityOnNewDisplay.intent, mTopActivity /* caller */, mTopActivity.getUid()); - notifyActivityLaunched(START_SUCCESS, activityOnNewDisplay); + notifyAndVerifyActivityLaunched(activityOnNewDisplay); // There should be 2 events instead of coalescing as one event. + setLastExpectedStartedId(mTopActivity); transitToDrawnAndVerifyOnLaunchFinished(mTopActivity); + setLastExpectedStartedId(activityOnNewDisplay); transitToDrawnAndVerifyOnLaunchFinished(activityOnNewDisplay); } @@ -548,9 +541,11 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase { onActivityLaunched(mTrampolineActivity); mActivityMetricsLogger.notifyActivityLaunching(mTopActivity.intent, mTrampolineActivity /* caller */, mTrampolineActivity.getUid()); - notifyActivityLaunched(START_SUCCESS, mTopActivity); + notifyAndVerifyActivityLaunched(mTopActivity); // Different windowing modes should be independent launch events. + setLastExpectedStartedId(mTrampolineActivity); transitToDrawnAndVerifyOnLaunchFinished(mTrampolineActivity); + setLastExpectedStartedId(mTopActivity); transitToDrawnAndVerifyOnLaunchFinished(mTopActivity); }