Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 31d7ee18 authored by Riddle Hsu's avatar Riddle Hsu
Browse files

Reduce ambiguity of trace from intent to launch activity 

Because the launching activities can be floating/translucent/
in different displays/in multiple window mode, there could be
multiple launching traces at the same time.

The trace processor relied on
"MetricsLogger:launchObserverNotifyIntentStarted" and
"MetricsLogger:launchObserverNotifyActivityLaunchFinished",
which didn't provide enough information to know which startup
it belongs to.

With keeping the old trace for migrating, a new async trace is
added: launchingActivity#$seqId. It has the same meaning as
the "Android App startups" by trace processor. And there will
be another trace when the launch is done to indicate the result.
E.g.
 Activity not found:
   launchingActivity#1:failed
 Becomes invisible before reporting drawn:
   launchingActivity#1:canceled:the.pkg.name
 Successful shown:
   launchingActivity#1:completed:the.pkg.name

So the trace processor can search "launchingActivity#$id:completed:"
to get the launched package name and associate "launchingActivity#$id"
to show directly.

Bug: 222576471
Test: Launch an app with
      "external/perfetto/tools/record_android_trace am".

Change-Id: Ifa78e04f79605db27d7fd2a5f582d286ceae2a13
parent b1c7853e

services/core/java/com/android/server/wm/ActivityMetricsLogger.java

+48 −13
Original line number Original line Diff line number Diff line
@@ -191,6 +191,35 @@ class ActivityMetricsLogger { 
        private long mCurrentTransitionStartTimeNs;

        private long mCurrentTransitionStartTimeNs;

        /** Non-null when a {@link TransitionInfo} is created for this state. */

        /** Non-null when a {@link TransitionInfo} is created for this state. */

        private TransitionInfo mAssociatedTransitionInfo;

        private TransitionInfo mAssociatedTransitionInfo;

        /** The sequence id for trace. It is used to map the traces before resolving intent. */

        private static int sTraceSeqId;

        /** The trace format is "launchingActivity#$seqId:$state(:$packageName)". */

        final String mTraceName;



        LaunchingState() {

            if (!Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {

                mTraceName = null;

                return;

            }

            // Use an id because the launching app is not yet known before resolving intent.

            sTraceSeqId++;

            mTraceName = "launchingActivity#" + sTraceSeqId;

            Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, mTraceName, 0);

        }



        void stopTrace(boolean abort) {

            if (mTraceName == null) return;

            Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, mTraceName, 0);

            final String launchResult;

            if (mAssociatedTransitionInfo == null) {

                launchResult = ":failed";

            } else {

                launchResult = (abort ? ":canceled:" : ":completed:")

                        + mAssociatedTransitionInfo.mLastLaunchedActivity.packageName;

            }

            // Put a supplement trace as the description of the async trace with the same id.

            Trace.instant(Trace.TRACE_TAG_ACTIVITY_MANAGER, mTraceName + launchResult);

        }





        @VisibleForTesting

        @VisibleForTesting

        boolean allDrawn() {

        boolean allDrawn() {
@@ -549,10 +578,10 @@ class ActivityMetricsLogger { 
        }

        }





        if (existingInfo == null) {

        if (existingInfo == null) {

            // Only notify the observer for a new launching event.

            launchObserverNotifyIntentStarted(intent, transitionStartTimeNs);

            final LaunchingState launchingState = new LaunchingState();

            final LaunchingState launchingState = new LaunchingState();

            launchingState.mCurrentTransitionStartTimeNs = transitionStartTimeNs;

            launchingState.mCurrentTransitionStartTimeNs = transitionStartTimeNs;

            // Only notify the observer for a new launching event.

            launchObserverNotifyIntentStarted(intent, transitionStartTimeNs);

            return launchingState;

            return launchingState;

        }

        }

        existingInfo.mLaunchingState.mCurrentTransitionStartTimeNs = transitionStartTimeNs;

        existingInfo.mLaunchingState.mCurrentTransitionStartTimeNs = transitionStartTimeNs;
@@ -574,7 +603,7 @@ class ActivityMetricsLogger { 
            @Nullable ActivityOptions options) {

            @Nullable ActivityOptions options) {

        if (launchedActivity == null) {

        if (launchedActivity == null) {

            // The launch is aborted, e.g. intent not resolved, class not found.

            // The launch is aborted, e.g. intent not resolved, class not found.

            abort(null /* info */, "nothing launched");

            abort(launchingState, "nothing launched");

            return;

            return;

        }

        }
@@ -601,7 +630,7 @@ class ActivityMetricsLogger { 




        if (launchedActivity.isReportedDrawn() && launchedActivity.isVisible()) {

        if (launchedActivity.isReportedDrawn() && launchedActivity.isVisible()) {

            // Launched activity is already visible. We cannot measure windows drawn delay.

            // Launched activity is already visible. We cannot measure windows drawn delay.

            abort(info, "launched activity already visible");

            abort(launchingState, "launched activity already visible");

            return;

            return;

        }

        }
@@ -633,7 +662,7 @@ class ActivityMetricsLogger { 
        final TransitionInfo newInfo = TransitionInfo.create(launchedActivity, launchingState,

        final TransitionInfo newInfo = TransitionInfo.create(launchedActivity, launchingState,

                options, processRunning, processSwitch, newActivityCreated, resultCode);

                options, processRunning, processSwitch, newActivityCreated, resultCode);

        if (newInfo == null) {

        if (newInfo == null) {

            abort(info, "unrecognized launch");

            abort(launchingState, "unrecognized launch");

            return;

            return;

        }

        }
@@ -874,23 +903,29 @@ class ActivityMetricsLogger { 
        }

        }

    }

    }





    private void abort(@NonNull LaunchingState state, String cause) {

        if (state.mAssociatedTransitionInfo != null) {

            abort(state.mAssociatedTransitionInfo, cause);

            return;

        }

        if (DEBUG_METRICS) Slog.i(TAG, "abort launch cause=" + cause);

        state.stopTrace(true /* abort */);

        launchObserverNotifyIntentFailed();

    }



    /** Aborts tracking of current launch metrics. */

    /** Aborts tracking of current launch metrics. */

    private void abort(TransitionInfo info, String cause) {

    private void abort(@NonNull TransitionInfo info, String cause) {

        done(true /* abort */, info, cause, 0L /* timestampNs */);

        done(true /* abort */, info, cause, 0L /* timestampNs */);

    }

    }





    /** Called when the given transition (info) is no longer active. */

    /** Called when the given transition (info) is no longer active. */

    private void done(boolean abort, @Nullable TransitionInfo info, String cause,

    private void done(boolean abort, @NonNull TransitionInfo info, String cause,

            long timestampNs) {

            long timestampNs) {

        if (DEBUG_METRICS) {

        if (DEBUG_METRICS) {

            Slog.i(TAG, "done abort=" + abort + " cause=" + cause + " timestamp=" + timestampNs

            Slog.i(TAG, "done abort=" + abort + " cause=" + cause + " timestamp=" + timestampNs

                    + " info=" + info);

                    + " info=" + info);

        }

        }

        if (info == null) {

        info.mLaunchingState.stopTrace(abort);

            launchObserverNotifyIntentFailed();

            return;

        }



        stopLaunchTrace(info);

        stopLaunchTrace(info);

        final Boolean isHibernating =

        final Boolean isHibernating =

                mLastHibernationStates.remove(info.mLastLaunchedActivity.packageName);

                mLastHibernationStates.remove(info.mLastLaunchedActivity.packageName);
@@ -1457,7 +1492,7 @@ class ActivityMetricsLogger { 
    /** Starts trace for an activity is actually launching. */

    /** Starts trace for an activity is actually launching. */

    private void startLaunchTrace(@NonNull TransitionInfo info) {

    private void startLaunchTrace(@NonNull TransitionInfo info) {

        if (DEBUG_METRICS) Slog.i(TAG, "startLaunchTrace " + info);

        if (DEBUG_METRICS) Slog.i(TAG, "startLaunchTrace " + info);

        if (!Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {

        if (info.mLaunchingState.mTraceName == null) {

            return;

            return;

        }

        }

        info.mLaunchTraceName = "launching: " + info.mLastLaunchedActivity.packageName;

        info.mLaunchTraceName = "launching: " + info.mLastLaunchedActivity.packageName;