blob: 9e9f6388c63a8e8988fd139c92f1c075a0b196f9 [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;
Wale Ogunwale6767eae2018-05-03 15:52:51 -07005import static android.app.ActivityTaskManagerInternal.APP_TRANSITION_TIMEOUT;
Wale Ogunwale926aade2017-08-29 11:24:37 -07006import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_PRIMARY;
Bryce Lee6c605092017-10-12 11:14:49 -07007import static android.app.WindowConfiguration.WINDOWING_MODE_FREEFORM;
Wale Ogunwale3382ab12017-07-27 08:55:03 -07008import static android.app.WindowConfiguration.WINDOWING_MODE_FULLSCREEN;
9import static android.app.WindowConfiguration.WINDOWING_MODE_PINNED;
Wale Ogunwale926aade2017-08-29 11:24:37 -070010import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_SECONDARY;
11import static android.app.WindowConfiguration.WINDOWING_MODE_UNDEFINED;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080012import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION;
Jorim Jaggi515dd682017-05-05 15:05:07 +020013import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_BIND_APPLICATION_DELAY_MS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070014import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CALLING_PACKAGE_NAME;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020015import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CANCELLED;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080016import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DELAY_MS;
17import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070018import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_IS_EPHEMERAL;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020019import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_PROCESS_RUNNING;
20import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN;
21import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN_MS;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080022import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_STARTING_WINDOW_DELAY_MS;
23import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS;
Jorim Jaggicdfc04e2017-04-28 19:06:24 +020024import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME;
Todd Kennedy50d946c12017-03-17 13:55:38 -070025import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INSTANT_APP_LAUNCH_TOKEN;
Calin Juravle759fbda2018-02-20 19:52:30 +000026import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_REASON;
27import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_FILTER;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080028import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_COLD_LAUNCH;
29import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_HOT_LAUNCH;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020030import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE;
31import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080032import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020033import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_METRICS;
Jorim Jaggif9704102016-05-05 19:14:22 -070034import static com.android.server.am.ActivityManagerDebugConfig.TAG_AM;
35import static com.android.server.am.ActivityManagerDebugConfig.TAG_WITH_CLASS_NAME;
Ng Zhi Anbbefdec2018-01-30 17:12:39 -080036import static com.android.server.am.MemoryStatUtil.MemoryStat;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +000037import static com.android.server.am.MemoryStatUtil.readMemoryStatFromFilesystem;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080038
Filip Gruszczynski77d94482015-12-11 13:59:52 -080039import android.content.Context;
Calin Juravle759fbda2018-02-20 19:52:30 +000040import android.content.pm.ApplicationInfo;
41import android.content.pm.dex.ArtManagerInternal;
42import android.content.pm.dex.PackageOptimizationInfo;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080043import android.metrics.LogMaker;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020044import android.os.Handler;
45import android.os.Looper;
46import android.os.Message;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080047import android.os.SystemClock;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020048import android.util.Slog;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080049import android.util.SparseArray;
50import android.util.SparseIntArray;
Olivier Gaillardaed7f122017-12-12 14:26:22 +000051import android.util.StatsLog;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080052
53import com.android.internal.logging.MetricsLogger;
Ng Zhi An83473542018-02-20 09:02:14 -080054import com.android.internal.os.BackgroundThread;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020055import com.android.internal.os.SomeArgs;
Calin Juravle759fbda2018-02-20 19:52:30 +000056import com.android.server.LocalServices;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080057
Jorim Jaggi1e630c02016-05-16 12:13:13 -070058import java.util.ArrayList;
59
Filip Gruszczynski77d94482015-12-11 13:59:52 -080060/**
61 * Handles logging into Tron.
62 */
63class ActivityMetricsLogger {
Jorim Jaggif9704102016-05-05 19:14:22 -070064
65 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_AM;
66
Filip Gruszczynski77d94482015-12-11 13:59:52 -080067 // Window modes we are interested in logging. If we ever introduce a new type, we need to add
68 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array.
69 private static final int WINDOW_STATE_STANDARD = 0;
70 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1;
71 private static final int WINDOW_STATE_FREEFORM = 2;
Winson Chung83471632016-12-13 11:02:12 -080072 private static final int WINDOW_STATE_ASSISTANT = 3;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080073 private static final int WINDOW_STATE_INVALID = -1;
74
Jorim Jaggi275561a2016-02-23 10:11:02 -050075 private static final long INVALID_START_TIME = -1;
76
Jorim Jaggi172e99f2017-10-20 14:33:18 +020077 private static final int MSG_CHECK_VISIBILITY = 0;
78
Filip Gruszczynski77d94482015-12-11 13:59:52 -080079 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every
80 // time we log.
81 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = {
Winson Chung83471632016-12-13 11:02:12 -080082 "window_time_0", "window_time_1", "window_time_2", "window_time_3"};
Filip Gruszczynski77d94482015-12-11 13:59:52 -080083
84 private int mWindowState = WINDOW_STATE_STANDARD;
85 private long mLastLogTimeSecs;
86 private final ActivityStackSupervisor mSupervisor;
87 private final Context mContext;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080088 private final MetricsLogger mMetricsLogger = new MetricsLogger();
Filip Gruszczynski77d94482015-12-11 13:59:52 -080089
Jorim Jaggi275561a2016-02-23 10:11:02 -050090 private long mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020091 private long mLastTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080092
93 private int mCurrentTransitionDeviceUptime;
94 private int mCurrentTransitionDelayMs;
Jorim Jaggi275561a2016-02-23 10:11:02 -050095 private boolean mLoggedTransitionStarting;
96
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +010097 private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo =
98 new SparseArray<>();
99 private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo =
100 new SparseArray<>();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200101 private final H mHandler;
Calin Juravle759fbda2018-02-20 19:52:30 +0000102
103 private ArtManagerInternal mArtManagerInternal;
104
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200105 private final class H extends Handler {
106
107 public H(Looper looper) {
108 super(looper);
109 }
110
111 @Override
112 public void handleMessage(Message msg) {
113 switch (msg.what) {
114 case MSG_CHECK_VISIBILITY:
115 final SomeArgs args = (SomeArgs) msg.obj;
116 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2);
117 break;
118 }
119 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000120 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800121
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100122 private final class WindowingModeTransitionInfo {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800123 private ActivityRecord launchedActivity;
124 private int startResult;
125 private boolean currentTransitionProcessRunning;
126 private int windowsDrawnDelayMs;
Jorim Jaggi515dd682017-05-05 15:05:07 +0200127 private int startingWindowDelayMs = -1;
128 private int bindApplicationDelayMs = -1;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800129 private int reason = APP_TRANSITION_TIMEOUT;
130 private boolean loggedWindowsDrawn;
131 private boolean loggedStartingWindowDrawn;
132 }
133
Calin Juravle759fbda2018-02-20 19:52:30 +0000134 private final class WindowingModeTransitionInfoSnapshot {
135 final private ApplicationInfo applicationInfo;
Ng Zhi An83473542018-02-20 09:02:14 -0800136 final private ProcessRecord processRecord;
Calin Juravle759fbda2018-02-20 19:52:30 +0000137 final private String packageName;
138 final private String launchedActivityName;
139 final private String launchedActivityLaunchedFromPackage;
140 final private String launchedActivityLaunchToken;
141 final private String launchedActivityAppRecordRequiredAbi;
Ng Zhi An83473542018-02-20 09:02:14 -0800142 final private String processName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000143 final private int reason;
144 final private int startingWindowDelayMs;
145 final private int bindApplicationDelayMs;
146 final private int windowsDrawnDelayMs;
147 final private int type;
148
149 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info) {
150 applicationInfo = info.launchedActivity.appInfo;
151 packageName = info.launchedActivity.packageName;
152 launchedActivityName = info.launchedActivity.info.name;
153 launchedActivityLaunchedFromPackage = info.launchedActivity.launchedFromPackage;
154 launchedActivityLaunchToken = info.launchedActivity.info.launchToken;
155 launchedActivityAppRecordRequiredAbi = info.launchedActivity.app == null
156 ? null
157 : info.launchedActivity.app.requiredAbi;
158 reason = info.reason;
159 startingWindowDelayMs = info.startingWindowDelayMs;
160 bindApplicationDelayMs = info.bindApplicationDelayMs;
161 windowsDrawnDelayMs = info.windowsDrawnDelayMs;
162 type = getTransitionType(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800163 processRecord = findProcessForActivity(info.launchedActivity);
164 processName = info.launchedActivity.processName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000165 }
166 }
167
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200168 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper) {
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800169 mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000;
170 mSupervisor = supervisor;
171 mContext = context;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200172 mHandler = new H(looper);
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800173 }
174
175 void logWindowState() {
176 final long now = SystemClock.elapsedRealtime() / 1000;
177 if (mWindowState != WINDOW_STATE_INVALID) {
178 // We log even if the window state hasn't changed, because the user might remain in
179 // home/fullscreen move forever and we would like to track this kind of behavior
180 // too.
181 MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState],
182 (int) (now - mLastLogTimeSecs));
183 }
184 mLastLogTimeSecs = now;
185
Wale Ogunwale926aade2017-08-29 11:24:37 -0700186 mWindowState = WINDOW_STATE_INVALID;
187 ActivityStack stack = mSupervisor.getFocusedStack();
188 if (stack.isActivityTypeAssistant()) {
189 mWindowState = WINDOW_STATE_ASSISTANT;
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800190 return;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800191 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700192
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700193 int windowingMode = stack.getWindowingMode();
194 if (windowingMode == WINDOWING_MODE_PINNED) {
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800195 stack = mSupervisor.findStackBehind(stack);
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700196 windowingMode = stack.getWindowingMode();
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800197 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700198 switch (windowingMode) {
199 case WINDOWING_MODE_FULLSCREEN:
200 mWindowState = WINDOW_STATE_STANDARD;
201 break;
202 case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY:
203 case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY:
204 mWindowState = WINDOW_STATE_SIDE_BY_SIDE;
205 break;
Bryce Lee6c605092017-10-12 11:14:49 -0700206 case WINDOWING_MODE_FREEFORM:
Wale Ogunwale926aade2017-08-29 11:24:37 -0700207 mWindowState = WINDOW_STATE_FREEFORM;
208 break;
209 default:
210 if (windowingMode != WINDOWING_MODE_UNDEFINED) {
211 throw new IllegalStateException("Unknown windowing mode for stack=" + stack
212 + " windowingMode=" + windowingMode);
213 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800214 }
215 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500216
217 /**
218 * Notifies the tracker at the earliest possible point when we are starting to launch an
219 * activity.
220 */
221 void notifyActivityLaunching() {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800222 if (!isAnyTransitionActive()) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200223 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunching");
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400224 mCurrentTransitionStartTime = SystemClock.uptimeMillis();
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200225 mLastTransitionStartTime = mCurrentTransitionStartTime;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800226 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500227 }
228
229 /**
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700230 * Notifies the tracker that the activity is actually launching.
231 *
232 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
233 * launch
234 * @param launchedActivity the activity that is being launched
235 */
236 void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800237 final ProcessRecord processRecord = findProcessForActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700238 final boolean processRunning = processRecord != null;
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700239
240 // We consider this a "process switch" if the process of the activity that gets launched
241 // didn't have an activity that was in started state. In this case, we assume that lot
242 // of caches might be purged so the time until it produces the first frame is very
243 // interesting.
244 final boolean processSwitch = processRecord == null
245 || !hasStartedActivity(processRecord, launchedActivity);
246
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800247 notifyActivityLaunched(resultCode, launchedActivity, processRunning, processSwitch);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700248 }
249
250 private boolean hasStartedActivity(ProcessRecord record, ActivityRecord launchedActivity) {
251 final ArrayList<ActivityRecord> activities = record.activities;
252 for (int i = activities.size() - 1; i >= 0; i--) {
253 final ActivityRecord activity = activities.get(i);
254 if (launchedActivity == activity) {
255 continue;
256 }
257 if (!activity.stopped) {
258 return true;
259 }
260 }
261 return false;
262 }
263
264 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500265 * Notifies the tracker the the activity is actually launching.
266 *
267 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
268 * launch
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800269 * @param launchedActivity the activity being launched
Jorim Jaggi275561a2016-02-23 10:11:02 -0500270 * @param processRunning whether the process that will contains the activity is already running
Jorim Jaggibe67c902016-04-12 00:53:16 -0700271 * @param processSwitch whether the process that will contain the activity didn't have any
272 * activity that was stopped, i.e. the started activity is "switching"
273 * processes
Jorim Jaggi275561a2016-02-23 10:11:02 -0500274 */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800275 private void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity,
Jorim Jaggibe67c902016-04-12 00:53:16 -0700276 boolean processRunning, boolean processSwitch) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500277
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200278 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched"
279 + " resultCode=" + resultCode
280 + " launchedActivity=" + launchedActivity
281 + " processRunning=" + processRunning
282 + " processSwitch=" + processSwitch);
283
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800284 // If we are already in an existing transition, only update the activity name, but not the
285 // other attributes.
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100286 final int windowingMode = launchedActivity != null
287 ? launchedActivity.getWindowingMode()
288 : WINDOWING_MODE_UNDEFINED;
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200289
290 if (mCurrentTransitionStartTime == INVALID_START_TIME) {
291 return;
292 }
293
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100294 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800295 if (launchedActivity != null && info != null) {
296 info.launchedActivity = launchedActivity;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500297 return;
298 }
299
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100300 final boolean otherWindowModesLaunching =
301 mWindowingModeTransitionInfo.size() > 0 && info == null;
Jorim Jaggi54cff642018-03-15 15:51:32 +0100302 if ((!isLoggableResultCode(resultCode) || launchedActivity == null || !processSwitch
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100303 || windowingMode == WINDOWING_MODE_UNDEFINED) && !otherWindowModesLaunching) {
Alison Cichowlas803054d2016-12-13 14:38:01 -0500304
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800305 // Failed to launch or it was not a process switch, so we don't care about the timing.
306 reset(true /* abort */);
307 return;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100308 } else if (otherWindowModesLaunching) {
309 // Don't log this windowing mode but continue with the other windowing modes.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800310 return;
311 }
312
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200313 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful");
314
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100315 final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo();
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800316 newInfo.launchedActivity = launchedActivity;
317 newInfo.currentTransitionProcessRunning = processRunning;
318 newInfo.startResult = resultCode;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100319 mWindowingModeTransitionInfo.put(windowingMode, newInfo);
320 mLastWindowingModeTransitionInfo.put(windowingMode, newInfo);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800321 mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500322 }
323
324 /**
Jorim Jaggi54cff642018-03-15 15:51:32 +0100325 * @return True if we should start logging an event for an activity start that returned
326 * {@code resultCode} and that we'll indeed get a windows drawn event.
327 */
328 private boolean isLoggableResultCode(int resultCode) {
329 return resultCode == START_SUCCESS || resultCode == START_TASK_TO_FRONT;
330 }
331
332 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500333 * Notifies the tracker that all windows of the app have been drawn.
334 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100335 void notifyWindowsDrawn(int windowingMode, long timestamp) {
336 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200337
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100338 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800339 if (info == null || info.loggedWindowsDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500340 return;
341 }
Sudheer Shankac766db02017-06-12 10:37:29 -0700342 info.windowsDrawnDelayMs = calculateDelay(timestamp);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800343 info.loggedWindowsDrawn = true;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100344 if (allWindowsDrawn() && mLoggedTransitionStarting) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800345 reset(false /* abort */);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500346 }
347 }
348
349 /**
350 * Notifies the tracker that the starting window was drawn.
351 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100352 void notifyStartingWindowDrawn(int windowingMode, long timestamp) {
353 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800354 if (info == null || info.loggedStartingWindowDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500355 return;
356 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800357 info.loggedStartingWindowDrawn = true;
Sudheer Shankac766db02017-06-12 10:37:29 -0700358 info.startingWindowDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500359 }
360
361 /**
362 * Notifies the tracker that the app transition is starting.
363 *
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100364 * @param windowingModeToReason A map from windowing mode to a reason integer, which must be on
365 * of ActivityManagerInternal.APP_TRANSITION_* reasons.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500366 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100367 void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) {
Jorim Jaggid8a57772017-04-14 16:50:42 -0700368 if (!isAnyTransitionActive() || mLoggedTransitionStarting) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500369 return;
370 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200371 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting");
Sudheer Shankac766db02017-06-12 10:37:29 -0700372 mCurrentTransitionDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500373 mLoggedTransitionStarting = true;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100374 for (int index = windowingModeToReason.size() - 1; index >= 0; index--) {
375 final int windowingMode = windowingModeToReason.keyAt(index);
376 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
377 windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800378 if (info == null) {
379 continue;
380 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100381 info.reason = windowingModeToReason.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800382 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100383 if (allWindowsDrawn()) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800384 reset(false /* abort */);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500385 }
386 }
387
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200388 /**
389 * Notifies the tracker that the visibility of an app is changing.
390 *
391 * @param activityRecord the app that is changing its visibility
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200392 */
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200393 void notifyVisibilityChanged(ActivityRecord activityRecord) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100394 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
395 activityRecord.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200396 if (info == null) {
397 return;
398 }
399 if (info.launchedActivity != activityRecord) {
400 return;
401 }
402 final TaskRecord t = activityRecord.getTask();
403 final SomeArgs args = SomeArgs.obtain();
404 args.arg1 = t;
405 args.arg2 = activityRecord;
406 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget();
407 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200408
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200409 private void checkVisibility(TaskRecord t, ActivityRecord r) {
410 synchronized (mSupervisor.mService) {
411
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100412 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
413 r.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200414
415 // If we have an active transition that's waiting on a certain activity that will be
416 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
417 if (info != null && !t.isVisible()) {
418 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible"
419 + " activity=" + r);
420 logAppTransitionCancel(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100421 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
422 if (mWindowingModeTransitionInfo.size() == 0) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200423 reset(true /* abort */);
424 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200425 }
426 }
427 }
428
Jorim Jaggi515dd682017-05-05 15:05:07 +0200429 /**
430 * Notifies the tracker that we called immediately before we call bindApplication on the client.
431 *
432 * @param app The client into which we'll call bindApplication.
433 */
434 void notifyBindApplication(ProcessRecord app) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100435 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
436 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200437
438 // App isn't attached to record yet, so match with info.
439 if (info.launchedActivity.appInfo == app.info) {
440 info.bindApplicationDelayMs = calculateCurrentDelay();
441 }
442 }
443 }
444
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100445 private boolean allWindowsDrawn() {
446 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
447 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800448 return false;
449 }
450 }
451 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500452 }
453
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800454 private boolean isAnyTransitionActive() {
455 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100456 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800457 }
458
459 private void reset(boolean abort) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200460 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800461 if (!abort && isAnyTransitionActive()) {
462 logAppTransitionMultiEvents();
463 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500464 mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800465 mCurrentTransitionDelayMs = -1;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500466 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100467 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500468 }
469
470 private int calculateCurrentDelay() {
471
472 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400473 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500474 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800475
Sudheer Shankac766db02017-06-12 10:37:29 -0700476 private int calculateDelay(long timestamp) {
477 // Shouldn't take more than 25 days to launch an app, so int is fine here.
478 return (int) (timestamp - mCurrentTransitionStartTime);
479 }
480
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100481 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200482 final int type = getTransitionType(info);
483 if (type == -1) {
484 return;
485 }
486 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
487 builder.setPackageName(info.launchedActivity.packageName);
488 builder.setType(type);
489 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
490 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000491 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800492 StatsLog.APP_START_CANCELED,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000493 info.launchedActivity.appInfo.uid,
494 info.launchedActivity.packageName,
495 convertAppStartTransitionType(type),
496 info.launchedActivity.info.name);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200497 }
498
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800499 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200500 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100501 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
502 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800503 final int type = getTransitionType(info);
504 if (type == -1) {
505 return;
506 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000507
508 // Take a snapshot of the transition info before sending it to the handler for logging.
509 // This will avoid any races with other operations that modify the ActivityRecord.
510 final WindowingModeTransitionInfoSnapshot infoSnapshot =
511 new WindowingModeTransitionInfoSnapshot(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800512 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime;
513 final int currentTransitionDelayMs = mCurrentTransitionDelayMs;
514 BackgroundThread.getHandler().post(() -> logAppTransition(
515 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot));
Calin Juravle759fbda2018-02-20 19:52:30 +0000516
517 info.launchedActivity.info.launchToken = null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800518 }
519 }
520
Ng Zhi An83473542018-02-20 09:02:14 -0800521 // This gets called on a background thread without holding the activity manager lock.
Calin Juravle759fbda2018-02-20 19:52:30 +0000522 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
523 WindowingModeTransitionInfoSnapshot info) {
524 final LogMaker builder = new LogMaker(APP_TRANSITION);
525 builder.setPackageName(info.packageName);
526 builder.setType(info.type);
527 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
528 final boolean isInstantApp = info.applicationInfo.isInstantApp();
529 if (info.launchedActivityLaunchedFromPackage != null) {
530 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
531 info.launchedActivityLaunchedFromPackage);
532 }
533 String launchToken = info.launchedActivityLaunchToken;
534 if (launchToken != null) {
535 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
536 }
537 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
538 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
539 currentTransitionDeviceUptime);
540 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
541 builder.setSubtype(info.reason);
542 if (info.startingWindowDelayMs != -1) {
543 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
544 info.startingWindowDelayMs);
545 }
546 if (info.bindApplicationDelayMs != -1) {
547 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
548 info.bindApplicationDelayMs);
549 }
550 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
551 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
552 final PackageOptimizationInfo packageOptimizationInfo =
553 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
554 ? PackageOptimizationInfo.createWithNoInfo()
555 : artManagerInternal.getPackageOptimizationInfo(
556 info.applicationInfo,
557 info.launchedActivityAppRecordRequiredAbi);
558 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
559 packageOptimizationInfo.getCompilationReason());
560 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
561 packageOptimizationInfo.getCompilationFilter());
562 mMetricsLogger.write(builder);
563 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800564 StatsLog.APP_START_OCCURRED,
Calin Juravle759fbda2018-02-20 19:52:30 +0000565 info.applicationInfo.uid,
566 info.packageName,
567 convertAppStartTransitionType(info.type),
568 info.launchedActivityName,
569 info.launchedActivityLaunchedFromPackage,
570 isInstantApp,
571 currentTransitionDeviceUptime * 1000,
572 info.reason,
573 currentTransitionDelayMs,
574 info.startingWindowDelayMs,
575 info.bindApplicationDelayMs,
576 info.windowsDrawnDelayMs,
577 launchToken,
578 packageOptimizationInfo.getCompilationReason(),
579 packageOptimizationInfo.getCompilationFilter());
Ng Zhi An83473542018-02-20 09:02:14 -0800580 logAppStartMemoryStateCapture(info);
Calin Juravle759fbda2018-02-20 19:52:30 +0000581 }
582
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000583 private int convertAppStartTransitionType(int tronType) {
584 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800585 return StatsLog.APP_START_OCCURRED__TYPE__COLD;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000586 }
587 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800588 return StatsLog.APP_START_OCCURRED__TYPE__WARM;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000589 }
590 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800591 return StatsLog.APP_START_OCCURRED__TYPE__HOT;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000592 }
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800593 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000594 }
595
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200596 void logAppTransitionReportedDrawn(ActivityRecord r, boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100597 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
598 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200599 if (info == null) {
600 return;
601 }
602 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
603 builder.setPackageName(r.packageName);
604 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000605 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
606 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200607 builder.setType(restoredFromBundle
608 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
609 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
610 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
611 info.currentTransitionProcessRunning ? 1 : 0);
612 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000613 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800614 StatsLog.APP_START_FULLY_DRAWN,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000615 info.launchedActivity.appInfo.uid,
616 info.launchedActivity.packageName,
617 restoredFromBundle
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800618 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE
619 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000620 info.launchedActivity.info.name,
621 info.currentTransitionProcessRunning,
622 startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200623 }
624
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100625 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800626 if (info.currentTransitionProcessRunning) {
627 if (info.startResult == START_SUCCESS) {
628 return TYPE_TRANSITION_WARM_LAUNCH;
629 } else if (info.startResult == START_TASK_TO_FRONT) {
630 return TYPE_TRANSITION_HOT_LAUNCH;
631 }
632 } else if (info.startResult == START_SUCCESS) {
633 return TYPE_TRANSITION_COLD_LAUNCH;
634 }
635 return -1;
636 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800637
Ng Zhi An83473542018-02-20 09:02:14 -0800638 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
639 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800640 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
641 return;
642 }
643
Ng Zhi An83473542018-02-20 09:02:14 -0800644 final int pid = info.processRecord.pid;
645 final int uid = info.applicationInfo.uid;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +0000646 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800647 if (memoryStat == null) {
648 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
649 return;
650 }
651
652 StatsLog.write(
653 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
654 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800655 info.processName,
656 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800657 memoryStat.pgfault,
658 memoryStat.pgmajfault,
659 memoryStat.rssInBytes,
660 memoryStat.cacheInBytes,
661 memoryStat.swapInBytes);
662 }
663
664 private ProcessRecord findProcessForActivity(ActivityRecord launchedActivity) {
665 return launchedActivity != null
666 ? mSupervisor.mService.mProcessNames.get(launchedActivity.processName,
667 launchedActivity.appInfo.uid)
668 : null;
669 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000670
671 private ArtManagerInternal getArtManagerInternal() {
672 if (mArtManagerInternal == null) {
673 // Note that this may be null.
674 // ArtManagerInternal is registered during PackageManagerService
675 // initialization which happens after ActivityManagerService.
676 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
677 }
678 return mArtManagerInternal;
679 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800680}