blob: e2ceb31ceef88f7b0170146e4630ccba1393ff8b [file] [log] [blame]
Filip Gruszczynski77d94482015-12-11 13:59:52 -08001package com.android.server.am;
2
Jorim Jaggi3878ca32017-02-02 17:13:05 -08003import static android.app.ActivityManager.START_SUCCESS;
4import static android.app.ActivityManager.START_TASK_TO_FRONT;
Jorim Jaggi3878ca32017-02-02 17:13:05 -08005import static android.app.ActivityManager.StackId.INVALID_STACK_ID;
Jorim Jaggi3878ca32017-02-02 17:13:05 -08006import static android.app.ActivityManagerInternal.APP_TRANSITION_TIMEOUT;
Wale Ogunwale926aade2017-08-29 11:24:37 -07007import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_PRIMARY;
Bryce Lee6c605092017-10-12 11:14:49 -07008import static android.app.WindowConfiguration.WINDOWING_MODE_FREEFORM;
Wale Ogunwale3382ab12017-07-27 08:55:03 -07009import static android.app.WindowConfiguration.WINDOWING_MODE_FULLSCREEN;
10import static android.app.WindowConfiguration.WINDOWING_MODE_PINNED;
Wale Ogunwale926aade2017-08-29 11:24:37 -070011import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_SECONDARY;
12import static android.app.WindowConfiguration.WINDOWING_MODE_UNDEFINED;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080013import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION;
Jorim Jaggi515dd682017-05-05 15:05:07 +020014import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_BIND_APPLICATION_DELAY_MS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070015import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CALLING_PACKAGE_NAME;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020016import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CANCELLED;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080017import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DELAY_MS;
18import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070019import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_IS_EPHEMERAL;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020020import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_PROCESS_RUNNING;
21import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN;
22import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN_MS;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080023import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_STARTING_WINDOW_DELAY_MS;
24import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS;
Jorim Jaggicdfc04e2017-04-28 19:06:24 +020025import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME;
Todd Kennedy50d946c12017-03-17 13:55:38 -070026import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INSTANT_APP_LAUNCH_TOKEN;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080027import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_COLD_LAUNCH;
28import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_HOT_LAUNCH;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020029import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE;
30import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080031import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020032import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_METRICS;
Jorim Jaggif9704102016-05-05 19:14:22 -070033import static com.android.server.am.ActivityManagerDebugConfig.TAG_AM;
34import static com.android.server.am.ActivityManagerDebugConfig.TAG_WITH_CLASS_NAME;
Ng Zhi Anbbefdec2018-01-30 17:12:39 -080035import static com.android.server.am.MemoryStatUtil.MemoryStat;
36import static com.android.server.am.MemoryStatUtil.readMemoryStatFromMemcg;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080037
Filip Gruszczynski77d94482015-12-11 13:59:52 -080038import android.content.Context;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080039import android.metrics.LogMaker;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020040import android.os.Handler;
41import android.os.Looper;
42import android.os.Message;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080043import android.os.SystemClock;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020044import android.util.Slog;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080045import android.util.SparseArray;
46import android.util.SparseIntArray;
Olivier Gaillardaed7f122017-12-12 14:26:22 +000047import android.util.StatsLog;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080048
49import com.android.internal.logging.MetricsLogger;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020050import com.android.internal.os.SomeArgs;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080051
Jorim Jaggi1e630c02016-05-16 12:13:13 -070052import java.util.ArrayList;
53
Filip Gruszczynski77d94482015-12-11 13:59:52 -080054/**
55 * Handles logging into Tron.
56 */
57class ActivityMetricsLogger {
Jorim Jaggif9704102016-05-05 19:14:22 -070058
59 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_AM;
60
Filip Gruszczynski77d94482015-12-11 13:59:52 -080061 // Window modes we are interested in logging. If we ever introduce a new type, we need to add
62 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array.
63 private static final int WINDOW_STATE_STANDARD = 0;
64 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1;
65 private static final int WINDOW_STATE_FREEFORM = 2;
Winson Chung83471632016-12-13 11:02:12 -080066 private static final int WINDOW_STATE_ASSISTANT = 3;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080067 private static final int WINDOW_STATE_INVALID = -1;
68
Jorim Jaggi275561a2016-02-23 10:11:02 -050069 private static final long INVALID_START_TIME = -1;
70
Jorim Jaggi172e99f2017-10-20 14:33:18 +020071 private static final int MSG_CHECK_VISIBILITY = 0;
Ng Zhi Anbbefdec2018-01-30 17:12:39 -080072 private static final int MSG_LOG_APP_START_MEMORY_STATE_CAPTURE = 1;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020073
Filip Gruszczynski77d94482015-12-11 13:59:52 -080074 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every
75 // time we log.
76 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = {
Winson Chung83471632016-12-13 11:02:12 -080077 "window_time_0", "window_time_1", "window_time_2", "window_time_3"};
Filip Gruszczynski77d94482015-12-11 13:59:52 -080078
79 private int mWindowState = WINDOW_STATE_STANDARD;
80 private long mLastLogTimeSecs;
81 private final ActivityStackSupervisor mSupervisor;
82 private final Context mContext;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080083 private final MetricsLogger mMetricsLogger = new MetricsLogger();
Filip Gruszczynski77d94482015-12-11 13:59:52 -080084
Jorim Jaggi275561a2016-02-23 10:11:02 -050085 private long mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020086 private long mLastTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080087
88 private int mCurrentTransitionDeviceUptime;
89 private int mCurrentTransitionDelayMs;
Jorim Jaggi275561a2016-02-23 10:11:02 -050090 private boolean mLoggedTransitionStarting;
91
Jorim Jaggi3878ca32017-02-02 17:13:05 -080092 private final SparseArray<StackTransitionInfo> mStackTransitionInfo = new SparseArray<>();
Jorim Jaggi4d27b842017-08-17 17:22:26 +020093 private final SparseArray<StackTransitionInfo> mLastStackTransitionInfo = new SparseArray<>();
Jorim Jaggi172e99f2017-10-20 14:33:18 +020094 private final H mHandler;
95 private final class H extends Handler {
96
97 public H(Looper looper) {
98 super(looper);
99 }
100
101 @Override
102 public void handleMessage(Message msg) {
103 switch (msg.what) {
104 case MSG_CHECK_VISIBILITY:
105 final SomeArgs args = (SomeArgs) msg.obj;
106 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2);
107 break;
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800108 case MSG_LOG_APP_START_MEMORY_STATE_CAPTURE:
109 logAppStartMemoryStateCapture((StackTransitionInfo) msg.obj);
110 break;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200111 }
112 }
113 };
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800114
115 private final class StackTransitionInfo {
116 private ActivityRecord launchedActivity;
117 private int startResult;
118 private boolean currentTransitionProcessRunning;
119 private int windowsDrawnDelayMs;
Jorim Jaggi515dd682017-05-05 15:05:07 +0200120 private int startingWindowDelayMs = -1;
121 private int bindApplicationDelayMs = -1;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800122 private int reason = APP_TRANSITION_TIMEOUT;
123 private boolean loggedWindowsDrawn;
124 private boolean loggedStartingWindowDrawn;
125 }
126
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200127 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper) {
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800128 mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000;
129 mSupervisor = supervisor;
130 mContext = context;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200131 mHandler = new H(looper);
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800132 }
133
134 void logWindowState() {
135 final long now = SystemClock.elapsedRealtime() / 1000;
136 if (mWindowState != WINDOW_STATE_INVALID) {
137 // We log even if the window state hasn't changed, because the user might remain in
138 // home/fullscreen move forever and we would like to track this kind of behavior
139 // too.
140 MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState],
141 (int) (now - mLastLogTimeSecs));
142 }
143 mLastLogTimeSecs = now;
144
Wale Ogunwale926aade2017-08-29 11:24:37 -0700145 mWindowState = WINDOW_STATE_INVALID;
146 ActivityStack stack = mSupervisor.getFocusedStack();
147 if (stack.isActivityTypeAssistant()) {
148 mWindowState = WINDOW_STATE_ASSISTANT;
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800149 return;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800150 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700151
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700152 int windowingMode = stack.getWindowingMode();
153 if (windowingMode == WINDOWING_MODE_PINNED) {
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800154 stack = mSupervisor.findStackBehind(stack);
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700155 windowingMode = stack.getWindowingMode();
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800156 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700157 switch (windowingMode) {
158 case WINDOWING_MODE_FULLSCREEN:
159 mWindowState = WINDOW_STATE_STANDARD;
160 break;
161 case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY:
162 case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY:
163 mWindowState = WINDOW_STATE_SIDE_BY_SIDE;
164 break;
Bryce Lee6c605092017-10-12 11:14:49 -0700165 case WINDOWING_MODE_FREEFORM:
Wale Ogunwale926aade2017-08-29 11:24:37 -0700166 mWindowState = WINDOW_STATE_FREEFORM;
167 break;
168 default:
169 if (windowingMode != WINDOWING_MODE_UNDEFINED) {
170 throw new IllegalStateException("Unknown windowing mode for stack=" + stack
171 + " windowingMode=" + windowingMode);
172 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800173 }
174 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500175
176 /**
177 * Notifies the tracker at the earliest possible point when we are starting to launch an
178 * activity.
179 */
180 void notifyActivityLaunching() {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800181 if (!isAnyTransitionActive()) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200182 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunching");
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400183 mCurrentTransitionStartTime = SystemClock.uptimeMillis();
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200184 mLastTransitionStartTime = mCurrentTransitionStartTime;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800185 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500186 }
187
188 /**
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700189 * Notifies the tracker that the activity is actually launching.
190 *
191 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
192 * launch
193 * @param launchedActivity the activity that is being launched
194 */
195 void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800196 final ProcessRecord processRecord = findProcessForActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700197 final boolean processRunning = processRecord != null;
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700198
199 // We consider this a "process switch" if the process of the activity that gets launched
200 // didn't have an activity that was in started state. In this case, we assume that lot
201 // of caches might be purged so the time until it produces the first frame is very
202 // interesting.
203 final boolean processSwitch = processRecord == null
204 || !hasStartedActivity(processRecord, launchedActivity);
205
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800206 notifyActivityLaunched(resultCode, launchedActivity, processRunning, processSwitch);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700207 }
208
209 private boolean hasStartedActivity(ProcessRecord record, ActivityRecord launchedActivity) {
210 final ArrayList<ActivityRecord> activities = record.activities;
211 for (int i = activities.size() - 1; i >= 0; i--) {
212 final ActivityRecord activity = activities.get(i);
213 if (launchedActivity == activity) {
214 continue;
215 }
216 if (!activity.stopped) {
217 return true;
218 }
219 }
220 return false;
221 }
222
223 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500224 * Notifies the tracker the the activity is actually launching.
225 *
226 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
227 * launch
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800228 * @param launchedActivity the activity being launched
Jorim Jaggi275561a2016-02-23 10:11:02 -0500229 * @param processRunning whether the process that will contains the activity is already running
Jorim Jaggibe67c902016-04-12 00:53:16 -0700230 * @param processSwitch whether the process that will contain the activity didn't have any
231 * activity that was stopped, i.e. the started activity is "switching"
232 * processes
Jorim Jaggi275561a2016-02-23 10:11:02 -0500233 */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800234 private void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity,
Jorim Jaggibe67c902016-04-12 00:53:16 -0700235 boolean processRunning, boolean processSwitch) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500236
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200237 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched"
238 + " resultCode=" + resultCode
239 + " launchedActivity=" + launchedActivity
240 + " processRunning=" + processRunning
241 + " processSwitch=" + processSwitch);
242
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800243 // If we are already in an existing transition, only update the activity name, but not the
244 // other attributes.
245 final int stackId = launchedActivity != null && launchedActivity.getStack() != null
246 ? launchedActivity.getStack().mStackId
247 : INVALID_STACK_ID;
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200248
249 if (mCurrentTransitionStartTime == INVALID_START_TIME) {
250 return;
251 }
252
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800253 final StackTransitionInfo info = mStackTransitionInfo.get(stackId);
254 if (launchedActivity != null && info != null) {
255 info.launchedActivity = launchedActivity;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500256 return;
257 }
258
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800259 final boolean otherStacksLaunching = mStackTransitionInfo.size() > 0 && info == null;
260 if ((resultCode < 0 || launchedActivity == null || !processSwitch
261 || stackId == INVALID_STACK_ID) && !otherStacksLaunching) {
Alison Cichowlas803054d2016-12-13 14:38:01 -0500262
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800263 // Failed to launch or it was not a process switch, so we don't care about the timing.
264 reset(true /* abort */);
265 return;
266 } else if (otherStacksLaunching) {
267 // Don't log this stack but continue with the other stacks.
268 return;
269 }
270
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200271 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful");
272
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800273 final StackTransitionInfo newInfo = new StackTransitionInfo();
274 newInfo.launchedActivity = launchedActivity;
275 newInfo.currentTransitionProcessRunning = processRunning;
276 newInfo.startResult = resultCode;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200277 mStackTransitionInfo.put(stackId, newInfo);
278 mLastStackTransitionInfo.put(stackId, newInfo);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800279 mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500280 }
281
282 /**
283 * Notifies the tracker that all windows of the app have been drawn.
284 */
Sudheer Shankac766db02017-06-12 10:37:29 -0700285 void notifyWindowsDrawn(int stackId, long timestamp) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200286 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn stackId=" + stackId);
287
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800288 final StackTransitionInfo info = mStackTransitionInfo.get(stackId);
289 if (info == null || info.loggedWindowsDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500290 return;
291 }
Sudheer Shankac766db02017-06-12 10:37:29 -0700292 info.windowsDrawnDelayMs = calculateDelay(timestamp);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800293 info.loggedWindowsDrawn = true;
294 if (allStacksWindowsDrawn() && mLoggedTransitionStarting) {
295 reset(false /* abort */);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500296 }
297 }
298
299 /**
300 * Notifies the tracker that the starting window was drawn.
301 */
Sudheer Shankac766db02017-06-12 10:37:29 -0700302 void notifyStartingWindowDrawn(int stackId, long timestamp) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800303 final StackTransitionInfo info = mStackTransitionInfo.get(stackId);
304 if (info == null || info.loggedStartingWindowDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500305 return;
306 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800307 info.loggedStartingWindowDrawn = true;
Sudheer Shankac766db02017-06-12 10:37:29 -0700308 info.startingWindowDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500309 }
310
311 /**
312 * Notifies the tracker that the app transition is starting.
313 *
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800314 * @param stackIdReasons A map from stack id to a reason integer, which must be on of
315 * ActivityManagerInternal.APP_TRANSITION_* reasons.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500316 */
Sudheer Shankac766db02017-06-12 10:37:29 -0700317 void notifyTransitionStarting(SparseIntArray stackIdReasons, long timestamp) {
Jorim Jaggid8a57772017-04-14 16:50:42 -0700318 if (!isAnyTransitionActive() || mLoggedTransitionStarting) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500319 return;
320 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200321 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting");
Sudheer Shankac766db02017-06-12 10:37:29 -0700322 mCurrentTransitionDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500323 mLoggedTransitionStarting = true;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800324 for (int index = stackIdReasons.size() - 1; index >= 0; index--) {
325 final int stackId = stackIdReasons.keyAt(index);
326 final StackTransitionInfo info = mStackTransitionInfo.get(stackId);
327 if (info == null) {
328 continue;
329 }
330 info.reason = stackIdReasons.valueAt(index);
331 }
332 if (allStacksWindowsDrawn()) {
333 reset(false /* abort */);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500334 }
335 }
336
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200337 /**
338 * Notifies the tracker that the visibility of an app is changing.
339 *
340 * @param activityRecord the app that is changing its visibility
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200341 */
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200342 void notifyVisibilityChanged(ActivityRecord activityRecord) {
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200343 final StackTransitionInfo info = mStackTransitionInfo.get(activityRecord.getStackId());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200344 if (info == null) {
345 return;
346 }
347 if (info.launchedActivity != activityRecord) {
348 return;
349 }
350 final TaskRecord t = activityRecord.getTask();
351 final SomeArgs args = SomeArgs.obtain();
352 args.arg1 = t;
353 args.arg2 = activityRecord;
354 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget();
355 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200356
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200357 private void checkVisibility(TaskRecord t, ActivityRecord r) {
358 synchronized (mSupervisor.mService) {
359
360 final StackTransitionInfo info = mStackTransitionInfo.get(r.getStackId());
361
362 // If we have an active transition that's waiting on a certain activity that will be
363 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
364 if (info != null && !t.isVisible()) {
365 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible"
366 + " activity=" + r);
367 logAppTransitionCancel(info);
368 mStackTransitionInfo.remove(r.getStackId());
369 if (mStackTransitionInfo.size() == 0) {
370 reset(true /* abort */);
371 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200372 }
373 }
374 }
375
Jorim Jaggi515dd682017-05-05 15:05:07 +0200376 /**
377 * Notifies the tracker that we called immediately before we call bindApplication on the client.
378 *
379 * @param app The client into which we'll call bindApplication.
380 */
381 void notifyBindApplication(ProcessRecord app) {
382 for (int i = mStackTransitionInfo.size() - 1; i >= 0; i--) {
383 final StackTransitionInfo info = mStackTransitionInfo.valueAt(i);
384
385 // App isn't attached to record yet, so match with info.
386 if (info.launchedActivity.appInfo == app.info) {
387 info.bindApplicationDelayMs = calculateCurrentDelay();
388 }
389 }
390 }
391
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800392 private boolean allStacksWindowsDrawn() {
393 for (int index = mStackTransitionInfo.size() - 1; index >= 0; index--) {
394 if (!mStackTransitionInfo.valueAt(index).loggedWindowsDrawn) {
395 return false;
396 }
397 }
398 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500399 }
400
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800401 private boolean isAnyTransitionActive() {
402 return mCurrentTransitionStartTime != INVALID_START_TIME
403 && mStackTransitionInfo.size() > 0;
404 }
405
406 private void reset(boolean abort) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200407 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800408 if (!abort && isAnyTransitionActive()) {
409 logAppTransitionMultiEvents();
410 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500411 mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800412 mCurrentTransitionDelayMs = -1;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500413 mLoggedTransitionStarting = false;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800414 mStackTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500415 }
416
417 private int calculateCurrentDelay() {
418
419 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400420 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500421 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800422
Sudheer Shankac766db02017-06-12 10:37:29 -0700423 private int calculateDelay(long timestamp) {
424 // Shouldn't take more than 25 days to launch an app, so int is fine here.
425 return (int) (timestamp - mCurrentTransitionStartTime);
426 }
427
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200428 private void logAppTransitionCancel(StackTransitionInfo info) {
429 final int type = getTransitionType(info);
430 if (type == -1) {
431 return;
432 }
433 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
434 builder.setPackageName(info.launchedActivity.packageName);
435 builder.setType(type);
436 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
437 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000438 StatsLog.write(
439 StatsLog.APP_START_CANCEL_CHANGED,
440 info.launchedActivity.appInfo.uid,
441 info.launchedActivity.packageName,
442 convertAppStartTransitionType(type),
443 info.launchedActivity.info.name);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200444 }
445
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800446 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200447 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800448 for (int index = mStackTransitionInfo.size() - 1; index >= 0; index--) {
449 final StackTransitionInfo info = mStackTransitionInfo.valueAt(index);
450 final int type = getTransitionType(info);
451 if (type == -1) {
452 return;
453 }
454 final LogMaker builder = new LogMaker(APP_TRANSITION);
455 builder.setPackageName(info.launchedActivity.packageName);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800456 builder.setType(type);
Jason Monk8c09ac72017-03-16 11:53:40 -0400457 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
Todd Kennedy56279cb2017-04-17 14:53:49 -0700458 final boolean isInstantApp = info.launchedActivity.info.applicationInfo.isInstantApp();
Todd Kennedy7655b292017-08-18 15:05:01 -0700459 if (info.launchedActivity.launchedFromPackage != null) {
Todd Kennedy50d946c12017-03-17 13:55:38 -0700460 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
461 info.launchedActivity.launchedFromPackage);
462 }
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000463 String launchToken = info.launchedActivity.info.launchToken;
464 if (launchToken != null) {
465 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
Todd Kennedyb3b431302017-03-20 16:05:48 -0700466 info.launchedActivity.info.launchToken = null;
Todd Kennedy50d946c12017-03-17 13:55:38 -0700467 }
Todd Kennedy56279cb2017-04-17 14:53:49 -0700468 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800469 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
470 mCurrentTransitionDeviceUptime);
471 builder.addTaggedData(APP_TRANSITION_DELAY_MS, mCurrentTransitionDelayMs);
472 builder.setSubtype(info.reason);
473 if (info.startingWindowDelayMs != -1) {
474 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
475 info.startingWindowDelayMs);
476 }
Jorim Jaggi515dd682017-05-05 15:05:07 +0200477 if (info.bindApplicationDelayMs != -1) {
478 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
479 info.bindApplicationDelayMs);
480 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800481 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
482 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000483 StatsLog.write(
484 StatsLog.APP_START_CHANGED,
485 info.launchedActivity.appInfo.uid,
486 info.launchedActivity.packageName,
487 convertAppStartTransitionType(type),
488 info.launchedActivity.info.name,
489 info.launchedActivity.launchedFromPackage,
490 isInstantApp,
491 mCurrentTransitionDeviceUptime * 1000,
492 info.reason,
493 mCurrentTransitionDelayMs,
494 info.startingWindowDelayMs,
495 info.bindApplicationDelayMs,
496 info.windowsDrawnDelayMs,
497 launchToken);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800498 mHandler.obtainMessage(MSG_LOG_APP_START_MEMORY_STATE_CAPTURE, info).sendToTarget();
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800499 }
500 }
501
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000502 private int convertAppStartTransitionType(int tronType) {
503 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
504 return StatsLog.APP_START_CHANGED__TYPE__COLD;
505 }
506 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
507 return StatsLog.APP_START_CHANGED__TYPE__WARM;
508 }
509 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
510 return StatsLog.APP_START_CHANGED__TYPE__HOT;
511 }
512 return StatsLog.APP_START_CHANGED__TYPE__APP_START_TRANSITION_TYPE_UNKNOWN;
513 }
514
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200515 void logAppTransitionReportedDrawn(ActivityRecord r, boolean restoredFromBundle) {
516 final StackTransitionInfo info = mLastStackTransitionInfo.get(r.getStackId());
517 if (info == null) {
518 return;
519 }
520 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
521 builder.setPackageName(r.packageName);
522 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000523 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
524 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200525 builder.setType(restoredFromBundle
526 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
527 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
528 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
529 info.currentTransitionProcessRunning ? 1 : 0);
530 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000531 StatsLog.write(
532 StatsLog.APP_START_FULLY_DRAWN_CHANGED,
533 info.launchedActivity.appInfo.uid,
534 info.launchedActivity.packageName,
535 restoredFromBundle
536 ? StatsLog.APP_START_FULLY_DRAWN_CHANGED__TYPE__WITH_BUNDLE
537 : StatsLog.APP_START_FULLY_DRAWN_CHANGED__TYPE__WITHOUT_BUNDLE,
538 info.launchedActivity.info.name,
539 info.currentTransitionProcessRunning,
540 startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200541 }
542
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800543 private int getTransitionType(StackTransitionInfo info) {
544 if (info.currentTransitionProcessRunning) {
545 if (info.startResult == START_SUCCESS) {
546 return TYPE_TRANSITION_WARM_LAUNCH;
547 } else if (info.startResult == START_TASK_TO_FRONT) {
548 return TYPE_TRANSITION_HOT_LAUNCH;
549 }
550 } else if (info.startResult == START_SUCCESS) {
551 return TYPE_TRANSITION_COLD_LAUNCH;
552 }
553 return -1;
554 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800555
556 private void logAppStartMemoryStateCapture(StackTransitionInfo info) {
557 final ProcessRecord processRecord = findProcessForActivity(info.launchedActivity);
558 if (processRecord == null) {
559 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
560 return;
561 }
562
563 final int pid = processRecord.pid;
564 final int uid = info.launchedActivity.appInfo.uid;
565 final MemoryStat memoryStat = readMemoryStatFromMemcg(uid, pid);
566 if (memoryStat == null) {
567 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
568 return;
569 }
570
571 StatsLog.write(
572 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
573 uid,
574 info.launchedActivity.processName,
575 info.launchedActivity.info.name,
576 memoryStat.pgfault,
577 memoryStat.pgmajfault,
578 memoryStat.rssInBytes,
579 memoryStat.cacheInBytes,
580 memoryStat.swapInBytes);
581 }
582
583 private ProcessRecord findProcessForActivity(ActivityRecord launchedActivity) {
584 return launchedActivity != null
585 ? mSupervisor.mService.mProcessNames.get(launchedActivity.processName,
586 launchedActivity.appInfo.uid)
587 : null;
588 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800589}