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

Commit c526bdf8 authored by TreeHugger Robot's avatar TreeHugger Robot Committed by Android (Google) Code Review
Browse files

Merge changes Ie8685a12,I87abde9f

* changes:
  am: Add unit tests for ActivityMetricsLaunchObserver
  am: Add new LaunchObserver to track app launch sequences
parents 70c02611 cb76aac9
Loading
Loading
Loading
Loading
+182 −0
Original line number Diff line number Diff line
/*
 * Copyright (C) 2018 The Android Open Source Project
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package com.android.server.wm;

import android.annotation.IntDef;
import android.annotation.NonNull;
import android.annotation.Nullable;
import android.content.Intent;

import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;

/**
 * Observe activity manager 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).
 *
 * 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.
 *
 * The intent can fail to launch the activity, in which case the sequence's state transitions to
 * {@code INTENT_FAILED} via {@link #onIntentFailed}. This is a terminal state.
 *
 * If an activity is successfully started, the launch sequence's state will transition into
 * {@code STARTED} via {@link #onActivityLaunched}. This is a transient state.
 *
 * It must then transition to either {@code CANCELLED} with {@link #onActivityLaunchCancelled}
 * or into {@code FINISHED} with {@link #onActivityLaunchFinished}. These are terminal states.
 *
 * Note that the {@link ActivityRecord} 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.
 *
 * Upon reaching a terminal state, it is considered that there are no active launch sequences
 * until a subsequent transition into {@code INTENT_STARTED} initiates a new launch sequence.
 *
 * <pre>
 *        ┌⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯┐     ┌⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯┐     ╔══════════════════════════╗
 *    ╴╴▶ ⋮ INTENT_STARTED ⋮ ──▶ ⋮     ACTIVITY_LAUNCHED     ⋮ ──▶ ║ ACTIVITY_LAUNCH_FINISHED ║
 *        └⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯┘     └⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯⋯┘     ╚══════════════════════════╝
 *          :                      :
 *          :                      :
 *          ▼                      ▼
 *        ╔════════════════╗     ╔═══════════════════════════╗
 *        ║ INTENT_FAILED  ║     ║ ACTIVITY_LAUNCH_CANCELLED ║
 *        ╚════════════════╝     ╚═══════════════════════════╝
 * </pre>
 */
public interface ActivityMetricsLaunchObserver {
    /**
     * The 'temperature' at which a launch sequence had started.
     *
     * The lower the temperature the more work has to be done during start-up.
     * A 'cold' temperature means that a new process has been started and likely
     * nothing is cached.
     *
     * A hot temperature means the existing activity is brought to the foreground.
     * It may need to regenerate some objects as a result of {@code onTrimMemory}.
     *
     * A warm temperature is in the middle; an existing process is used, but the activity
     * has to be created from scratch with {@code #onCreate}.
     *
     * @see https://developer.android.com/topic/performance/vitals/launch-time
     */
    @Retention(RetentionPolicy.SOURCE)
    @IntDef({
            TEMPERATURE_COLD,
            TEMPERATURE_WARM,
            TEMPERATURE_HOT
    })
    @interface Temperature {}

    /** Cold launch sequence: a new process has started. */
    public static final int TEMPERATURE_COLD = 1;
    /** Warm launch sequence: process reused, but activity has to be created. */
    public static final int TEMPERATURE_WARM = 2;
    /** Hot launch sequence: process reused, activity brought-to-top. */
    public static final int TEMPERATURE_HOT = 3;

    /**
     * Notifies the observer that a new launch sequence has begun as a result of a new intent.
     *
     * Once a launch sequence begins, the resolved activity will either subsequently start with
     * {@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.
     */
    public void onIntentStarted(@NonNull Intent intent);

    /**
     * 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}.
     *
     * 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();

    /**
     * Notifies the observer that the current launch sequence had begun starting an activity.
     *
     * This is an intermediate state: once an activity begins starting, the entire launch sequence
     * will later terminate by either finishing or cancelling.
     *
     * The initial activity is the first activity to be started as part of a launch sequence:
     * it is represented by {@param activity} However, it isn't
     * 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.
     */
    public void onActivityLaunched(@NonNull ActivityRecord activity,
                                   @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 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).
     *
     * @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 ActivityRecord abortingActivity);

    /**
     * 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}.
     *
     * 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
     *
     * 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 ActivityRecord finalActivity);
}
+153 −14
Original line number Diff line number Diff line
@@ -80,6 +80,7 @@ import static com.android.server.am.MemoryStatUtil.MemoryStat;
import static com.android.server.am.MemoryStatUtil.readMemoryStatFromFilesystem;
import static com.android.server.wm.ActivityTaskManagerInternal.APP_TRANSITION_TIMEOUT;

import android.app.WindowConfiguration.WindowingMode;
import android.content.Context;
import android.content.Intent;
import android.content.pm.ApplicationInfo;
@@ -141,15 +142,21 @@ class ActivityMetricsLogger {
    private final Context mContext;
    private final MetricsLogger mMetricsLogger = new MetricsLogger();

    // set to INVALID_START_TIME in reset.
    // set to valid value in notifyActivityLaunching
    private long mCurrentTransitionStartTime = INVALID_START_TIME;
    private long mLastTransitionStartTime = INVALID_START_TIME;

    private int mCurrentTransitionDeviceUptime;
    private int mCurrentTransitionDelayMs;

    /** If the any app transitions have been logged as starting, after the latest reset. */
    private boolean mLoggedTransitionStarting;

    /** Map : @WindowingMode int => WindowingModeTransitionInfo */
    private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo =
            new SparseArray<>();
    /** Map : @WindowingMode int => WindowingModeTransitionInfo */
    private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo =
            new SparseArray<>();
    private final H mHandler;
@@ -157,6 +164,12 @@ class ActivityMetricsLogger {
    private ArtManagerInternal mArtManagerInternal;
    private final StringBuilder mStringBuilder = new StringBuilder();

    /**
     * Due to the global single concurrent launch sequence, all calls to this observer must be made
     * in-order on the same thread to fulfill the "happens-before" guarantee in LaunchObserver.
     */
    private final ActivityMetricsLaunchObserver mLaunchObserver = null;

    private final class H extends Handler {

        public H(Looper looper) {
@@ -175,6 +188,7 @@ class ActivityMetricsLogger {
    }

    private final class WindowingModeTransitionInfo {
        /** The latest activity to have been launched. */
        private ActivityRecord launchedActivity;
        private int startResult;
        private boolean currentTransitionProcessRunning;
@@ -273,7 +287,7 @@ class ActivityMetricsLogger {
            return;
        }

        int windowingMode = stack.getWindowingMode();
        @WindowingMode int windowingMode = stack.getWindowingMode();
        if (windowingMode == WINDOWING_MODE_PINNED) {
            stack = mSupervisor.findStackBehind(stack);
            windowingMode = stack.getWindowingMode();
@@ -301,11 +315,19 @@ class ActivityMetricsLogger {
     * Notifies the tracker at the earliest possible point when we are starting to launch an
     * activity.
     */
    void notifyActivityLaunching() {
    void notifyActivityLaunching(Intent intent) {
        if (DEBUG_METRICS) {
            Slog.i(TAG, String.format("notifyActivityLaunching: active:%b, intent:%s",
                                      isAnyTransitionActive(),
                                      intent));
        }

        if (!isAnyTransitionActive()) {
            if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunching");

            mCurrentTransitionStartTime = SystemClock.uptimeMillis();
            mLastTransitionStartTime = mCurrentTransitionStartTime;

            launchObserverNotifyIntentStarted(intent);
        }
    }

@@ -350,7 +372,9 @@ class ActivityMetricsLogger {
                + " processRunning=" + processRunning
                + " processSwitch=" + processSwitch);

        final int windowingMode = launchedActivity != null
        // If we are already in an existing transition, only update the activity name, but not the
        // other attributes.
        final @WindowingMode int windowingMode = launchedActivity != null
                ? launchedActivity.getWindowingMode()
                : WINDOWING_MODE_UNDEFINED;
        final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
@@ -361,13 +385,15 @@ class ActivityMetricsLogger {

        if (launchedActivity != null && launchedActivity.nowVisible) {
            // Launched activity is already visible. We cannot measure windows drawn delay.
            reset(true /* abort */, info);
            reset(true /* abort */, info, "launched activity already visible");
            return;
        }

        if (launchedActivity != null && info != null) {
            // If we are already in an existing transition, only update the activity name, but not
            // the other attributes.

            // Coalesce multiple (trampoline) activities from a single sequence together.
            info.launchedActivity = launchedActivity;
            return;
        }
@@ -377,7 +403,7 @@ class ActivityMetricsLogger {
        if ((!isLoggableResultCode(resultCode) || launchedActivity == null || !processSwitch
                || windowingMode == WINDOWING_MODE_UNDEFINED) && !otherWindowModesLaunching) {
            // Failed to launch or it was not a process switch, so we don't care about the timing.
            reset(true /* abort */, info);
            reset(true /* abort */, info, "failed to launch or not a process switch");
            return;
        } else if (otherWindowModesLaunching) {
            // Don't log this windowing mode but continue with the other windowing modes.
@@ -386,6 +412,8 @@ class ActivityMetricsLogger {

        if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful");

        // A new launch sequence [with the windowingMode] has begun.
        // Start tracking it.
        final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo();
        newInfo.launchedActivity = launchedActivity;
        newInfo.currentTransitionProcessRunning = processRunning;
@@ -394,6 +422,7 @@ class ActivityMetricsLogger {
        mLastWindowingModeTransitionInfo.put(windowingMode, newInfo);
        mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000);
        startTraces(newInfo);
        launchObserverNotifyActivityLaunched(newInfo);
    }

    /**
@@ -407,7 +436,8 @@ class ActivityMetricsLogger {
    /**
     * Notifies the tracker that all windows of the app have been drawn.
     */
    WindowingModeTransitionInfoSnapshot notifyWindowsDrawn(int windowingMode, long timestamp) {
    WindowingModeTransitionInfoSnapshot notifyWindowsDrawn(@WindowingMode int windowingMode,
                                                           long timestamp) {
        if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode);

        final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
@@ -419,7 +449,7 @@ class ActivityMetricsLogger {
        final WindowingModeTransitionInfoSnapshot infoSnapshot =
                new WindowingModeTransitionInfoSnapshot(info);
        if (allWindowsDrawn() && mLoggedTransitionStarting) {
            reset(false /* abort */, info);
            reset(false /* abort */, info, "notifyWindowsDrawn - all windows drawn");
        }
        return infoSnapshot;
    }
@@ -427,7 +457,7 @@ class ActivityMetricsLogger {
    /**
     * Notifies the tracker that the starting window was drawn.
     */
    void notifyStartingWindowDrawn(int windowingMode, long timestamp) {
    void notifyStartingWindowDrawn(@WindowingMode int windowingMode, long timestamp) {
        final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
        if (info == null || info.loggedStartingWindowDrawn) {
            return;
@@ -444,22 +474,28 @@ class ActivityMetricsLogger {
     */
    void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) {
        if (!isAnyTransitionActive() || mLoggedTransitionStarting) {
            // Ignore calls to this made after a reset and prior to notifyActivityLaunching.

            // Ignore any subsequent notifyTransitionStarting until the next reset.
            return;
        }
        if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting");
        mCurrentTransitionDelayMs = calculateDelay(timestamp);
        mLoggedTransitionStarting = true;

        WindowingModeTransitionInfo foundInfo = null;
        for (int index = windowingModeToReason.size() - 1; index >= 0; index--) {
            final int windowingMode = windowingModeToReason.keyAt(index);
            final @WindowingMode int windowingMode = windowingModeToReason.keyAt(index);
            final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
                    windowingMode);
            if (info == null) {
                continue;
            }
            info.reason = windowingModeToReason.valueAt(index);
            foundInfo = info;
        }
        if (allWindowsDrawn()) {
            reset(false /* abort */, null /* WindowingModeTransitionInfo */);
            reset(false /* abort */, foundInfo, "notifyTransitionStarting - all windows drawn");
        }
    }

@@ -498,7 +534,7 @@ class ActivityMetricsLogger {
                logAppTransitionCancel(info);
                mWindowingModeTransitionInfo.remove(r.getWindowingMode());
                if (mWindowingModeTransitionInfo.size() == 0) {
                    reset(true /* abort */, info);
                    reset(true /* abort */, info, "notifyVisibilityChanged to invisible");
                }
            }
        }
@@ -534,12 +570,25 @@ class ActivityMetricsLogger {
                && mWindowingModeTransitionInfo.size() > 0;
    }

    private void reset(boolean abort, WindowingModeTransitionInfo info) {
        if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort);
    private void reset(boolean abort, WindowingModeTransitionInfo info, String cause) {
        if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort + ",cause=" + cause);
        if (!abort && isAnyTransitionActive()) {
            logAppTransitionMultiEvents();
        }
        stopLaunchTrace(info);

        // Ignore reset-after reset.
        if (isAnyTransitionActive()) {
            // LaunchObserver callbacks.
            if (abort) {
                launchObserverNotifyActivityLaunchCancelled(info);
            } else {
                launchObserverNotifyActivityLaunchFinished(info);
            }
        } else {
            launchObserverNotifyIntentFailed();
        }

        mCurrentTransitionStartTime = INVALID_START_TIME;
        mCurrentTransitionDelayMs = INVALID_DELAY;
        mLoggedTransitionStarting = false;
@@ -572,6 +621,13 @@ class ActivityMetricsLogger {
                info.launchedActivity.packageName,
                convertAppStartTransitionType(type),
                info.launchedActivity.info.name);
        if (DEBUG_METRICS) {
            Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)",
                    info.launchedActivity.appInfo.uid,
                    info.launchedActivity.packageName,
                    convertAppStartTransitionType(type),
                    info.launchedActivity.info.name));
        }
    }

    private void logAppTransitionMultiEvents() {
@@ -656,6 +712,17 @@ class ActivityMetricsLogger {
                launchToken,
                packageOptimizationInfo.getCompilationReason(),
                packageOptimizationInfo.getCompilationFilter());

        if (DEBUG_METRICS) {
            Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)",
                    info.applicationInfo.uid,
                    info.packageName,
                    convertAppStartTransitionType(info.type),
                    info.launchedActivityName,
                    info.launchedActivityLaunchedFromPackage));
        }


        logAppStartMemoryStateCapture(info);
    }

@@ -923,4 +990,76 @@ class ActivityMetricsLogger {
            info.launchTraceActive = false;
        }
    }

    /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */
    private void launchObserverNotifyIntentStarted(Intent intent) {
        if (mLaunchObserver != null) {
            // Beginning a launch is timing sensitive and so should be observed as soon as possible.
            mLaunchObserver.onIntentStarted(intent);
        }
    }

    /**
     * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has
     * 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() {
        if (mLaunchObserver != null) {
            mLaunchObserver.onIntentFailed();
        }
    }

    /**
     * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
     * has started.
     */
    private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) {
        @ActivityMetricsLaunchObserver.Temperature int temperature =
                convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info));

        if (mLaunchObserver != null) {
            // Beginning a launch is timing sensitive and so should be observed as soon as possible.
            mLaunchObserver.onActivityLaunched(info.launchedActivity,
                                               temperature);
        }
    }

    /**
     * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is
     * cancelled.
     */
    private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) {
        final ActivityRecord launchedActivity = info != null ? info.launchedActivity : null;

        if (mLaunchObserver != null) {
            mLaunchObserver.onActivityLaunchCancelled(launchedActivity);
        }
    }

    /**
     * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
     * has fully finished (successfully).
     */
    private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) {
        final ActivityRecord launchedActivity = info.launchedActivity;

        if (mLaunchObserver != null) {
            mLaunchObserver.onActivityLaunchFinished(launchedActivity);
        }
    }

    private static @ActivityMetricsLaunchObserver.Temperature int
            convertTransitionTypeToLaunchObserverTemperature(int transitionType) {
        switch (transitionType) {
            case TYPE_TRANSITION_WARM_LAUNCH:
                return ActivityMetricsLaunchObserver.TEMPERATURE_WARM;
            case TYPE_TRANSITION_HOT_LAUNCH:
                return ActivityMetricsLaunchObserver.TEMPERATURE_HOT;
            case TYPE_TRANSITION_COLD_LAUNCH:
                return ActivityMetricsLaunchObserver.TEMPERATURE_COLD;
            default:
                return -1;
        }
    }
}
+1 −1
Original line number Diff line number Diff line
@@ -4745,7 +4745,7 @@ public class ActivityStackSupervisor extends ConfigurationContainer implements D
                final ActivityRecord targetActivity = task.getTopActivity();

                sendPowerHintForLaunchStartIfNeeded(true /* forceSend */, targetActivity);
                mActivityMetricsLogger.notifyActivityLaunching();
                mActivityMetricsLogger.notifyActivityLaunching(task.intent);
                try {
                    mService.moveTaskToFrontLocked(task.taskId, 0, options,
                            true /* fromRecents */);
+1 −1
Original line number Diff line number Diff line
@@ -996,7 +996,7 @@ class ActivityStarter {
        if (intent != null && intent.hasFileDescriptors()) {
            throw new IllegalArgumentException("File descriptors passed in Intent");
        }
        mSupervisor.getActivityMetricsLogger().notifyActivityLaunching();
        mSupervisor.getActivityMetricsLogger().notifyActivityLaunching(intent);
        boolean componentSpecified = intent.getComponent() != null;

        final int realCallingPid = Binder.getCallingPid();
+1 −1
Original line number Diff line number Diff line
@@ -122,7 +122,7 @@ class RecentsAnimation implements RecentsAnimationCallbacks,
                    targetActivity);
        }

        mStackSupervisor.getActivityMetricsLogger().notifyActivityLaunching();
        mStackSupervisor.getActivityMetricsLogger().notifyActivityLaunching(intent);

        mService.mAmInternal.setRunningRemoteAnimation(mCallingPid, true);

Loading