ActivityMetricsLogger.java revision 8347163dbb64fb61012c0393163283106a0a351e 
1package com.android.server.am;
2
3import static android.app.ActivityManager.StackId.ASSISTANT_STACK_ID;
4import static android.app.ActivityManager.StackId.DOCKED_STACK_ID;
5import static android.app.ActivityManager.StackId.FREEFORM_WORKSPACE_STACK_ID;
6import static android.app.ActivityManager.StackId.FULLSCREEN_WORKSPACE_STACK_ID;
7import static android.app.ActivityManager.StackId.PINNED_STACK_ID;
8
9import static com.android.server.am.ActivityManagerDebugConfig.TAG_AM;
10import static com.android.server.am.ActivityManagerDebugConfig.TAG_WITH_CLASS_NAME;
11import static com.android.server.am.ActivityStack.STACK_INVISIBLE;
12
13import android.annotation.Nullable;
14import android.app.ActivityManager.StackId;
15import android.content.Context;
16import android.os.SystemClock;
17import android.util.Slog;
18
19import android.metrics.LogMaker;
20import com.android.internal.logging.MetricsLogger;
21import com.android.internal.logging.nano.MetricsProto.MetricsEvent;
22
23import java.util.ArrayList;
24
25/**
26 * Handles logging into Tron.
27 */
28class ActivityMetricsLogger {
29
30    private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_AM;
31
32    // Window modes we are interested in logging. If we ever introduce a new type, we need to add
33    // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array.
34    private static final int WINDOW_STATE_STANDARD = 0;
35    private static final int WINDOW_STATE_SIDE_BY_SIDE = 1;
36    private static final int WINDOW_STATE_FREEFORM = 2;
37    private static final int WINDOW_STATE_ASSISTANT = 3;
38    private static final int WINDOW_STATE_INVALID = -1;
39
40    private static final long INVALID_START_TIME = -1;
41
42    // Preallocated strings we are sending to tron, so we don't have to allocate a new one every
43    // time we log.
44    private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = {
45            "window_time_0", "window_time_1", "window_time_2", "window_time_3"};
46
47    private int mWindowState = WINDOW_STATE_STANDARD;
48    private long mLastLogTimeSecs;
49    private final ActivityStackSupervisor mSupervisor;
50    private final Context mContext;
51
52    private long mCurrentTransitionStartTime = INVALID_START_TIME;
53    private boolean mLoggedWindowsDrawn;
54    private boolean mLoggedStartingWindowDrawn;
55    private boolean mLoggedTransitionStarting;
56
57    ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context) {
58        mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000;
59        mSupervisor = supervisor;
60        mContext = context;
61    }
62
63    void logWindowState() {
64        final long now = SystemClock.elapsedRealtime() / 1000;
65        if (mWindowState != WINDOW_STATE_INVALID) {
66            // We log even if the window state hasn't changed, because the user might remain in
67            // home/fullscreen move forever and we would like to track this kind of behavior
68            // too.
69            MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState],
70                    (int) (now - mLastLogTimeSecs));
71        }
72        mLastLogTimeSecs = now;
73
74        ActivityStack stack = mSupervisor.getStack(DOCKED_STACK_ID);
75        if (stack != null && stack.getStackVisibilityLocked(null) != STACK_INVISIBLE) {
76            mWindowState = WINDOW_STATE_SIDE_BY_SIDE;
77            return;
78        }
79        mWindowState = WINDOW_STATE_INVALID;
80        stack = mSupervisor.getFocusedStack();
81        if (stack.mStackId == PINNED_STACK_ID) {
82            stack = mSupervisor.findStackBehind(stack);
83        }
84        if (StackId.isHomeOrRecentsStack(stack.mStackId)
85                || stack.mStackId == FULLSCREEN_WORKSPACE_STACK_ID) {
86            mWindowState = WINDOW_STATE_STANDARD;
87        } else if (stack.mStackId == DOCKED_STACK_ID) {
88            Slog.wtf(TAG, "Docked stack shouldn't be the focused stack, because it reported not"
89                    + " being visible.");
90            mWindowState = WINDOW_STATE_INVALID;
91        } else if (stack.mStackId == FREEFORM_WORKSPACE_STACK_ID) {
92            mWindowState = WINDOW_STATE_FREEFORM;
93        } else if (stack.mStackId == ASSISTANT_STACK_ID) {
94            mWindowState = WINDOW_STATE_ASSISTANT;
95        } else if (StackId.isStaticStack(stack.mStackId)) {
96            throw new IllegalStateException("Unknown stack=" + stack);
97        }
98    }
99
100    /**
101     * Notifies the tracker at the earliest possible point when we are starting to launch an
102     * activity.
103     */
104    void notifyActivityLaunching() {
105        mCurrentTransitionStartTime = System.currentTimeMillis();
106    }
107
108    /**
109     * Notifies the tracker that the activity is actually launching.
110     *
111     * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
112     *                   launch
113     * @param launchedActivity the activity that is being launched
114     */
115    void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) {
116        final ProcessRecord processRecord = launchedActivity != null
117                ? mSupervisor.mService.mProcessNames.get(launchedActivity.processName,
118                        launchedActivity.appInfo.uid)
119                : null;
120        final boolean processRunning = processRecord != null;
121        final String componentName = launchedActivity != null
122                ? launchedActivity.shortComponentName
123                : null;
124
125        // We consider this a "process switch" if the process of the activity that gets launched
126        // didn't have an activity that was in started state. In this case, we assume that lot
127        // of caches might be purged so the time until it produces the first frame is very
128        // interesting.
129        final boolean processSwitch = processRecord == null
130                || !hasStartedActivity(processRecord, launchedActivity);
131
132        notifyActivityLaunched(resultCode, componentName, processRunning, processSwitch);
133    }
134
135    private boolean hasStartedActivity(ProcessRecord record, ActivityRecord launchedActivity) {
136        final ArrayList<ActivityRecord> activities = record.activities;
137        for (int i = activities.size() - 1; i >= 0; i--) {
138            final ActivityRecord activity = activities.get(i);
139            if (launchedActivity == activity) {
140                continue;
141            }
142            if (!activity.stopped) {
143                return true;
144            }
145        }
146        return false;
147    }
148
149    /**
150     * Notifies the tracker the the activity is actually launching.
151     *
152     * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
153     *                   launch
154     * @param componentName the component name of the activity being launched
155     * @param processRunning whether the process that will contains the activity is already running
156     * @param processSwitch whether the process that will contain the activity didn't have any
157     *                      activity that was stopped, i.e. the started activity is "switching"
158     *                      processes
159     */
160    private void notifyActivityLaunched(int resultCode, @Nullable String componentName,
161            boolean processRunning, boolean processSwitch) {
162
163        if (resultCode < 0 || componentName == null || !processSwitch) {
164
165            // Failed to launch or it was not a process switch, so we don't care about the timing.
166            reset();
167            return;
168        }
169
170        MetricsLogger.action(mContext, MetricsEvent.APP_TRANSITION_COMPONENT_NAME,
171                componentName);
172        MetricsLogger.action(mContext, MetricsEvent.APP_TRANSITION_PROCESS_RUNNING,
173                processRunning);
174        MetricsLogger.action(mContext, MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS,
175                (int) (SystemClock.uptimeMillis() / 1000));
176
177        LogMaker builder = new LogMaker(MetricsEvent.APP_TRANSITION);
178        builder.addTaggedData(MetricsEvent.APP_TRANSITION_COMPONENT_NAME, componentName);
179        builder.addTaggedData(MetricsEvent.APP_TRANSITION_PROCESS_RUNNING, processRunning ? 1 : 0);
180        builder.addTaggedData(MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS,
181                SystemClock.uptimeMillis() / 1000);
182        MetricsLogger.action(builder);
183    }
184
185    /**
186     * Notifies the tracker that all windows of the app have been drawn.
187     */
188    void notifyWindowsDrawn() {
189        if (!isTransitionActive() || mLoggedWindowsDrawn) {
190            return;
191        }
192        MetricsLogger.action(mContext, MetricsEvent.APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS,
193                calculateCurrentDelay());
194        mLoggedWindowsDrawn = true;
195        if (mLoggedTransitionStarting) {
196            reset();
197        }
198    }
199
200    /**
201     * Notifies the tracker that the starting window was drawn.
202     */
203    void notifyStartingWindowDrawn() {
204        if (!isTransitionActive() || mLoggedStartingWindowDrawn) {
205            return;
206        }
207        mLoggedStartingWindowDrawn = true;
208        MetricsLogger.action(mContext, MetricsEvent.APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
209                calculateCurrentDelay());
210    }
211
212    /**
213     * Notifies the tracker that the app transition is starting.
214     *
215     * @param reason The reason why we started it. Must be on of
216     *               ActivityManagerInternal.APP_TRANSITION_* reasons.
217     */
218    void notifyTransitionStarting(int reason) {
219        if (!isTransitionActive() || mLoggedTransitionStarting) {
220            return;
221        }
222        MetricsLogger.action(mContext, MetricsEvent.APP_TRANSITION_REASON, reason);
223        MetricsLogger.action(mContext, MetricsEvent.APP_TRANSITION_DELAY_MS,
224                calculateCurrentDelay());
225        mLoggedTransitionStarting = true;
226        if (mLoggedWindowsDrawn) {
227            reset();
228        }
229    }
230
231    private boolean isTransitionActive() {
232        return mCurrentTransitionStartTime != INVALID_START_TIME;
233    }
234
235    private void reset() {
236        mCurrentTransitionStartTime = INVALID_START_TIME;
237        mLoggedWindowsDrawn = false;
238        mLoggedTransitionStarting = false;
239        mLoggedStartingWindowDrawn = false;
240    }
241
242    private int calculateCurrentDelay() {
243
244        // Shouldn't take more than 25 days to launch an app, so int is fine here.
245        return (int) (System.currentTimeMillis() - mCurrentTransitionStartTime);
246    }
247}
248