blob: 5d5ed550a00c5efa78520588910875bd77d76c82 [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.ActivityManagerInternal.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;
37import static com.android.server.am.MemoryStatUtil.readMemoryStatFromMemcg;
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 Jaggi3878ca32017-02-02 17:13:05 -0800302 if ((resultCode < 0 || 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 /**
325 * Notifies the tracker that all windows of the app have been drawn.
326 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100327 void notifyWindowsDrawn(int windowingMode, long timestamp) {
328 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200329
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100330 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800331 if (info == null || info.loggedWindowsDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500332 return;
333 }
Sudheer Shankac766db02017-06-12 10:37:29 -0700334 info.windowsDrawnDelayMs = calculateDelay(timestamp);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800335 info.loggedWindowsDrawn = true;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100336 if (allWindowsDrawn() && mLoggedTransitionStarting) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800337 reset(false /* abort */);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500338 }
339 }
340
341 /**
342 * Notifies the tracker that the starting window was drawn.
343 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100344 void notifyStartingWindowDrawn(int windowingMode, long timestamp) {
345 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800346 if (info == null || info.loggedStartingWindowDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500347 return;
348 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800349 info.loggedStartingWindowDrawn = true;
Sudheer Shankac766db02017-06-12 10:37:29 -0700350 info.startingWindowDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500351 }
352
353 /**
354 * Notifies the tracker that the app transition is starting.
355 *
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100356 * @param windowingModeToReason A map from windowing mode to a reason integer, which must be on
357 * of ActivityManagerInternal.APP_TRANSITION_* reasons.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500358 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100359 void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) {
Jorim Jaggid8a57772017-04-14 16:50:42 -0700360 if (!isAnyTransitionActive() || mLoggedTransitionStarting) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500361 return;
362 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200363 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting");
Sudheer Shankac766db02017-06-12 10:37:29 -0700364 mCurrentTransitionDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500365 mLoggedTransitionStarting = true;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100366 for (int index = windowingModeToReason.size() - 1; index >= 0; index--) {
367 final int windowingMode = windowingModeToReason.keyAt(index);
368 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
369 windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800370 if (info == null) {
371 continue;
372 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100373 info.reason = windowingModeToReason.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800374 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100375 if (allWindowsDrawn()) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800376 reset(false /* abort */);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500377 }
378 }
379
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200380 /**
381 * Notifies the tracker that the visibility of an app is changing.
382 *
383 * @param activityRecord the app that is changing its visibility
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200384 */
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200385 void notifyVisibilityChanged(ActivityRecord activityRecord) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100386 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
387 activityRecord.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200388 if (info == null) {
389 return;
390 }
391 if (info.launchedActivity != activityRecord) {
392 return;
393 }
394 final TaskRecord t = activityRecord.getTask();
395 final SomeArgs args = SomeArgs.obtain();
396 args.arg1 = t;
397 args.arg2 = activityRecord;
398 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget();
399 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200400
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200401 private void checkVisibility(TaskRecord t, ActivityRecord r) {
402 synchronized (mSupervisor.mService) {
403
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100404 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
405 r.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200406
407 // If we have an active transition that's waiting on a certain activity that will be
408 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
409 if (info != null && !t.isVisible()) {
410 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible"
411 + " activity=" + r);
412 logAppTransitionCancel(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100413 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
414 if (mWindowingModeTransitionInfo.size() == 0) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200415 reset(true /* abort */);
416 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200417 }
418 }
419 }
420
Jorim Jaggi515dd682017-05-05 15:05:07 +0200421 /**
422 * Notifies the tracker that we called immediately before we call bindApplication on the client.
423 *
424 * @param app The client into which we'll call bindApplication.
425 */
426 void notifyBindApplication(ProcessRecord app) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100427 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
428 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200429
430 // App isn't attached to record yet, so match with info.
431 if (info.launchedActivity.appInfo == app.info) {
432 info.bindApplicationDelayMs = calculateCurrentDelay();
433 }
434 }
435 }
436
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100437 private boolean allWindowsDrawn() {
438 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
439 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800440 return false;
441 }
442 }
443 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500444 }
445
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800446 private boolean isAnyTransitionActive() {
447 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100448 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800449 }
450
451 private void reset(boolean abort) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200452 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800453 if (!abort && isAnyTransitionActive()) {
454 logAppTransitionMultiEvents();
455 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500456 mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800457 mCurrentTransitionDelayMs = -1;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500458 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100459 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500460 }
461
462 private int calculateCurrentDelay() {
463
464 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400465 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500466 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800467
Sudheer Shankac766db02017-06-12 10:37:29 -0700468 private int calculateDelay(long timestamp) {
469 // Shouldn't take more than 25 days to launch an app, so int is fine here.
470 return (int) (timestamp - mCurrentTransitionStartTime);
471 }
472
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100473 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200474 final int type = getTransitionType(info);
475 if (type == -1) {
476 return;
477 }
478 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
479 builder.setPackageName(info.launchedActivity.packageName);
480 builder.setType(type);
481 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
482 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000483 StatsLog.write(
484 StatsLog.APP_START_CANCEL_CHANGED,
485 info.launchedActivity.appInfo.uid,
486 info.launchedActivity.packageName,
487 convertAppStartTransitionType(type),
488 info.launchedActivity.info.name);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200489 }
490
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800491 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200492 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100493 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
494 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800495 final int type = getTransitionType(info);
496 if (type == -1) {
497 return;
498 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000499
500 // Take a snapshot of the transition info before sending it to the handler for logging.
501 // This will avoid any races with other operations that modify the ActivityRecord.
502 final WindowingModeTransitionInfoSnapshot infoSnapshot =
503 new WindowingModeTransitionInfoSnapshot(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800504 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime;
505 final int currentTransitionDelayMs = mCurrentTransitionDelayMs;
506 BackgroundThread.getHandler().post(() -> logAppTransition(
507 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot));
Calin Juravle759fbda2018-02-20 19:52:30 +0000508
509 info.launchedActivity.info.launchToken = null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800510 }
511 }
512
Ng Zhi An83473542018-02-20 09:02:14 -0800513 // This gets called on a background thread without holding the activity manager lock.
Calin Juravle759fbda2018-02-20 19:52:30 +0000514 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
515 WindowingModeTransitionInfoSnapshot info) {
516 final LogMaker builder = new LogMaker(APP_TRANSITION);
517 builder.setPackageName(info.packageName);
518 builder.setType(info.type);
519 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
520 final boolean isInstantApp = info.applicationInfo.isInstantApp();
521 if (info.launchedActivityLaunchedFromPackage != null) {
522 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
523 info.launchedActivityLaunchedFromPackage);
524 }
525 String launchToken = info.launchedActivityLaunchToken;
526 if (launchToken != null) {
527 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
528 }
529 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
530 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
531 currentTransitionDeviceUptime);
532 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
533 builder.setSubtype(info.reason);
534 if (info.startingWindowDelayMs != -1) {
535 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
536 info.startingWindowDelayMs);
537 }
538 if (info.bindApplicationDelayMs != -1) {
539 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
540 info.bindApplicationDelayMs);
541 }
542 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
543 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
544 final PackageOptimizationInfo packageOptimizationInfo =
545 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
546 ? PackageOptimizationInfo.createWithNoInfo()
547 : artManagerInternal.getPackageOptimizationInfo(
548 info.applicationInfo,
549 info.launchedActivityAppRecordRequiredAbi);
550 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
551 packageOptimizationInfo.getCompilationReason());
552 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
553 packageOptimizationInfo.getCompilationFilter());
554 mMetricsLogger.write(builder);
555 StatsLog.write(
556 StatsLog.APP_START_CHANGED,
557 info.applicationInfo.uid,
558 info.packageName,
559 convertAppStartTransitionType(info.type),
560 info.launchedActivityName,
561 info.launchedActivityLaunchedFromPackage,
562 isInstantApp,
563 currentTransitionDeviceUptime * 1000,
564 info.reason,
565 currentTransitionDelayMs,
566 info.startingWindowDelayMs,
567 info.bindApplicationDelayMs,
568 info.windowsDrawnDelayMs,
569 launchToken,
570 packageOptimizationInfo.getCompilationReason(),
571 packageOptimizationInfo.getCompilationFilter());
Ng Zhi An83473542018-02-20 09:02:14 -0800572 logAppStartMemoryStateCapture(info);
Calin Juravle759fbda2018-02-20 19:52:30 +0000573 }
574
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000575 private int convertAppStartTransitionType(int tronType) {
576 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
577 return StatsLog.APP_START_CHANGED__TYPE__COLD;
578 }
579 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
580 return StatsLog.APP_START_CHANGED__TYPE__WARM;
581 }
582 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
583 return StatsLog.APP_START_CHANGED__TYPE__HOT;
584 }
585 return StatsLog.APP_START_CHANGED__TYPE__APP_START_TRANSITION_TYPE_UNKNOWN;
586 }
587
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200588 void logAppTransitionReportedDrawn(ActivityRecord r, boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100589 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
590 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200591 if (info == null) {
592 return;
593 }
594 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
595 builder.setPackageName(r.packageName);
596 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000597 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
598 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200599 builder.setType(restoredFromBundle
600 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
601 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
602 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
603 info.currentTransitionProcessRunning ? 1 : 0);
604 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000605 StatsLog.write(
606 StatsLog.APP_START_FULLY_DRAWN_CHANGED,
607 info.launchedActivity.appInfo.uid,
608 info.launchedActivity.packageName,
609 restoredFromBundle
610 ? StatsLog.APP_START_FULLY_DRAWN_CHANGED__TYPE__WITH_BUNDLE
611 : StatsLog.APP_START_FULLY_DRAWN_CHANGED__TYPE__WITHOUT_BUNDLE,
612 info.launchedActivity.info.name,
613 info.currentTransitionProcessRunning,
614 startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200615 }
616
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100617 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800618 if (info.currentTransitionProcessRunning) {
619 if (info.startResult == START_SUCCESS) {
620 return TYPE_TRANSITION_WARM_LAUNCH;
621 } else if (info.startResult == START_TASK_TO_FRONT) {
622 return TYPE_TRANSITION_HOT_LAUNCH;
623 }
624 } else if (info.startResult == START_SUCCESS) {
625 return TYPE_TRANSITION_COLD_LAUNCH;
626 }
627 return -1;
628 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800629
Ng Zhi An83473542018-02-20 09:02:14 -0800630 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
631 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800632 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
633 return;
634 }
635
Ng Zhi An83473542018-02-20 09:02:14 -0800636 final int pid = info.processRecord.pid;
637 final int uid = info.applicationInfo.uid;
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800638 final MemoryStat memoryStat = readMemoryStatFromMemcg(uid, pid);
639 if (memoryStat == null) {
640 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
641 return;
642 }
643
644 StatsLog.write(
645 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
646 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800647 info.processName,
648 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800649 memoryStat.pgfault,
650 memoryStat.pgmajfault,
651 memoryStat.rssInBytes,
652 memoryStat.cacheInBytes,
653 memoryStat.swapInBytes);
654 }
655
656 private ProcessRecord findProcessForActivity(ActivityRecord launchedActivity) {
657 return launchedActivity != null
658 ? mSupervisor.mService.mProcessNames.get(launchedActivity.processName,
659 launchedActivity.appInfo.uid)
660 : null;
661 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000662
663 private ArtManagerInternal getArtManagerInternal() {
664 if (mArtManagerInternal == null) {
665 // Note that this may be null.
666 // ArtManagerInternal is registered during PackageManagerService
667 // initialization which happens after ActivityManagerService.
668 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
669 }
670 return mArtManagerInternal;
671 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800672}