blob: 978e344b22ff7ffe790308ab398b515e50c223d6 [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;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020054import com.android.internal.os.SomeArgs;
Calin Juravle759fbda2018-02-20 19:52:30 +000055import com.android.server.LocalServices;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080056
Jorim Jaggi1e630c02016-05-16 12:13:13 -070057import java.util.ArrayList;
58
Filip Gruszczynski77d94482015-12-11 13:59:52 -080059/**
60 * Handles logging into Tron.
61 */
62class ActivityMetricsLogger {
Jorim Jaggif9704102016-05-05 19:14:22 -070063
64 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_AM;
65
Filip Gruszczynski77d94482015-12-11 13:59:52 -080066 // Window modes we are interested in logging. If we ever introduce a new type, we need to add
67 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array.
68 private static final int WINDOW_STATE_STANDARD = 0;
69 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1;
70 private static final int WINDOW_STATE_FREEFORM = 2;
Winson Chung83471632016-12-13 11:02:12 -080071 private static final int WINDOW_STATE_ASSISTANT = 3;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080072 private static final int WINDOW_STATE_INVALID = -1;
73
Jorim Jaggi275561a2016-02-23 10:11:02 -050074 private static final long INVALID_START_TIME = -1;
75
Jorim Jaggi172e99f2017-10-20 14:33:18 +020076 private static final int MSG_CHECK_VISIBILITY = 0;
Calin Juravle759fbda2018-02-20 19:52:30 +000077 private static final int MSG_LOG_APP_TRANSITION = 1;
78 private static final int MSG_LOG_APP_START_MEMORY_STATE_CAPTURE = 2;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020079
Filip Gruszczynski77d94482015-12-11 13:59:52 -080080 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every
81 // time we log.
82 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = {
Winson Chung83471632016-12-13 11:02:12 -080083 "window_time_0", "window_time_1", "window_time_2", "window_time_3"};
Filip Gruszczynski77d94482015-12-11 13:59:52 -080084
85 private int mWindowState = WINDOW_STATE_STANDARD;
86 private long mLastLogTimeSecs;
87 private final ActivityStackSupervisor mSupervisor;
88 private final Context mContext;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080089 private final MetricsLogger mMetricsLogger = new MetricsLogger();
Filip Gruszczynski77d94482015-12-11 13:59:52 -080090
Jorim Jaggi275561a2016-02-23 10:11:02 -050091 private long mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020092 private long mLastTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080093
94 private int mCurrentTransitionDeviceUptime;
95 private int mCurrentTransitionDelayMs;
Jorim Jaggi275561a2016-02-23 10:11:02 -050096 private boolean mLoggedTransitionStarting;
97
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +010098 private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo =
99 new SparseArray<>();
100 private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo =
101 new SparseArray<>();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200102 private final H mHandler;
Calin Juravle759fbda2018-02-20 19:52:30 +0000103
104 private ArtManagerInternal mArtManagerInternal;
105
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200106 private final class H extends Handler {
107
108 public H(Looper looper) {
109 super(looper);
110 }
111
112 @Override
113 public void handleMessage(Message msg) {
114 switch (msg.what) {
115 case MSG_CHECK_VISIBILITY:
116 final SomeArgs args = (SomeArgs) msg.obj;
117 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2);
118 break;
Calin Juravle759fbda2018-02-20 19:52:30 +0000119 case MSG_LOG_APP_TRANSITION:
120 logAppTransition(msg.arg1, msg.arg2,
121 (WindowingModeTransitionInfoSnapshot) msg.obj);
122 break;
Narayan Kamath203a9ab2018-02-20 17:06:21 +0000123 case MSG_LOG_APP_START_MEMORY_STATE_CAPTURE:
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100124 logAppStartMemoryStateCapture((WindowingModeTransitionInfo) msg.obj);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800125 break;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200126 }
127 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000128 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800129
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100130 private final class WindowingModeTransitionInfo {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800131 private ActivityRecord launchedActivity;
132 private int startResult;
133 private boolean currentTransitionProcessRunning;
134 private int windowsDrawnDelayMs;
Jorim Jaggi515dd682017-05-05 15:05:07 +0200135 private int startingWindowDelayMs = -1;
136 private int bindApplicationDelayMs = -1;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800137 private int reason = APP_TRANSITION_TIMEOUT;
138 private boolean loggedWindowsDrawn;
139 private boolean loggedStartingWindowDrawn;
140 }
141
Calin Juravle759fbda2018-02-20 19:52:30 +0000142 private final class WindowingModeTransitionInfoSnapshot {
143 final private ApplicationInfo applicationInfo;
144 final private String packageName;
145 final private String launchedActivityName;
146 final private String launchedActivityLaunchedFromPackage;
147 final private String launchedActivityLaunchToken;
148 final private String launchedActivityAppRecordRequiredAbi;
149 final private int reason;
150 final private int startingWindowDelayMs;
151 final private int bindApplicationDelayMs;
152 final private int windowsDrawnDelayMs;
153 final private int type;
154
155 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info) {
156 applicationInfo = info.launchedActivity.appInfo;
157 packageName = info.launchedActivity.packageName;
158 launchedActivityName = info.launchedActivity.info.name;
159 launchedActivityLaunchedFromPackage = info.launchedActivity.launchedFromPackage;
160 launchedActivityLaunchToken = info.launchedActivity.info.launchToken;
161 launchedActivityAppRecordRequiredAbi = info.launchedActivity.app == null
162 ? null
163 : info.launchedActivity.app.requiredAbi;
164 reason = info.reason;
165 startingWindowDelayMs = info.startingWindowDelayMs;
166 bindApplicationDelayMs = info.bindApplicationDelayMs;
167 windowsDrawnDelayMs = info.windowsDrawnDelayMs;
168 type = getTransitionType(info);
169 }
170 }
171
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200172 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper) {
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800173 mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000;
174 mSupervisor = supervisor;
175 mContext = context;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200176 mHandler = new H(looper);
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800177 }
178
179 void logWindowState() {
180 final long now = SystemClock.elapsedRealtime() / 1000;
181 if (mWindowState != WINDOW_STATE_INVALID) {
182 // We log even if the window state hasn't changed, because the user might remain in
183 // home/fullscreen move forever and we would like to track this kind of behavior
184 // too.
185 MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState],
186 (int) (now - mLastLogTimeSecs));
187 }
188 mLastLogTimeSecs = now;
189
Wale Ogunwale926aade2017-08-29 11:24:37 -0700190 mWindowState = WINDOW_STATE_INVALID;
191 ActivityStack stack = mSupervisor.getFocusedStack();
192 if (stack.isActivityTypeAssistant()) {
193 mWindowState = WINDOW_STATE_ASSISTANT;
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800194 return;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800195 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700196
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700197 int windowingMode = stack.getWindowingMode();
198 if (windowingMode == WINDOWING_MODE_PINNED) {
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800199 stack = mSupervisor.findStackBehind(stack);
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700200 windowingMode = stack.getWindowingMode();
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800201 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700202 switch (windowingMode) {
203 case WINDOWING_MODE_FULLSCREEN:
204 mWindowState = WINDOW_STATE_STANDARD;
205 break;
206 case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY:
207 case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY:
208 mWindowState = WINDOW_STATE_SIDE_BY_SIDE;
209 break;
Bryce Lee6c605092017-10-12 11:14:49 -0700210 case WINDOWING_MODE_FREEFORM:
Wale Ogunwale926aade2017-08-29 11:24:37 -0700211 mWindowState = WINDOW_STATE_FREEFORM;
212 break;
213 default:
214 if (windowingMode != WINDOWING_MODE_UNDEFINED) {
215 throw new IllegalStateException("Unknown windowing mode for stack=" + stack
216 + " windowingMode=" + windowingMode);
217 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800218 }
219 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500220
221 /**
222 * Notifies the tracker at the earliest possible point when we are starting to launch an
223 * activity.
224 */
225 void notifyActivityLaunching() {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800226 if (!isAnyTransitionActive()) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200227 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunching");
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400228 mCurrentTransitionStartTime = SystemClock.uptimeMillis();
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200229 mLastTransitionStartTime = mCurrentTransitionStartTime;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800230 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500231 }
232
233 /**
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700234 * Notifies the tracker that the activity is actually launching.
235 *
236 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
237 * launch
238 * @param launchedActivity the activity that is being launched
239 */
240 void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800241 final ProcessRecord processRecord = findProcessForActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700242 final boolean processRunning = processRecord != null;
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700243
244 // We consider this a "process switch" if the process of the activity that gets launched
245 // didn't have an activity that was in started state. In this case, we assume that lot
246 // of caches might be purged so the time until it produces the first frame is very
247 // interesting.
248 final boolean processSwitch = processRecord == null
249 || !hasStartedActivity(processRecord, launchedActivity);
250
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800251 notifyActivityLaunched(resultCode, launchedActivity, processRunning, processSwitch);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700252 }
253
254 private boolean hasStartedActivity(ProcessRecord record, ActivityRecord launchedActivity) {
255 final ArrayList<ActivityRecord> activities = record.activities;
256 for (int i = activities.size() - 1; i >= 0; i--) {
257 final ActivityRecord activity = activities.get(i);
258 if (launchedActivity == activity) {
259 continue;
260 }
261 if (!activity.stopped) {
262 return true;
263 }
264 }
265 return false;
266 }
267
268 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500269 * Notifies the tracker the the activity is actually launching.
270 *
271 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
272 * launch
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800273 * @param launchedActivity the activity being launched
Jorim Jaggi275561a2016-02-23 10:11:02 -0500274 * @param processRunning whether the process that will contains the activity is already running
Jorim Jaggibe67c902016-04-12 00:53:16 -0700275 * @param processSwitch whether the process that will contain the activity didn't have any
276 * activity that was stopped, i.e. the started activity is "switching"
277 * processes
Jorim Jaggi275561a2016-02-23 10:11:02 -0500278 */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800279 private void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity,
Jorim Jaggibe67c902016-04-12 00:53:16 -0700280 boolean processRunning, boolean processSwitch) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500281
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200282 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched"
283 + " resultCode=" + resultCode
284 + " launchedActivity=" + launchedActivity
285 + " processRunning=" + processRunning
286 + " processSwitch=" + processSwitch);
287
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800288 // If we are already in an existing transition, only update the activity name, but not the
289 // other attributes.
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100290 final int windowingMode = launchedActivity != null
291 ? launchedActivity.getWindowingMode()
292 : WINDOWING_MODE_UNDEFINED;
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200293
294 if (mCurrentTransitionStartTime == INVALID_START_TIME) {
295 return;
296 }
297
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100298 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800299 if (launchedActivity != null && info != null) {
300 info.launchedActivity = launchedActivity;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500301 return;
302 }
303
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100304 final boolean otherWindowModesLaunching =
305 mWindowingModeTransitionInfo.size() > 0 && info == null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800306 if ((resultCode < 0 || launchedActivity == null || !processSwitch
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100307 || windowingMode == WINDOWING_MODE_UNDEFINED) && !otherWindowModesLaunching) {
Alison Cichowlas803054d2016-12-13 14:38:01 -0500308
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800309 // Failed to launch or it was not a process switch, so we don't care about the timing.
310 reset(true /* abort */);
311 return;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100312 } else if (otherWindowModesLaunching) {
313 // Don't log this windowing mode but continue with the other windowing modes.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800314 return;
315 }
316
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200317 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful");
318
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100319 final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo();
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800320 newInfo.launchedActivity = launchedActivity;
321 newInfo.currentTransitionProcessRunning = processRunning;
322 newInfo.startResult = resultCode;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100323 mWindowingModeTransitionInfo.put(windowingMode, newInfo);
324 mLastWindowingModeTransitionInfo.put(windowingMode, newInfo);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800325 mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500326 }
327
328 /**
329 * Notifies the tracker that all windows of the app have been drawn.
330 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100331 void notifyWindowsDrawn(int windowingMode, long timestamp) {
332 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200333
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100334 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800335 if (info == null || info.loggedWindowsDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500336 return;
337 }
Sudheer Shankac766db02017-06-12 10:37:29 -0700338 info.windowsDrawnDelayMs = calculateDelay(timestamp);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800339 info.loggedWindowsDrawn = true;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100340 if (allWindowsDrawn() && mLoggedTransitionStarting) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800341 reset(false /* abort */);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500342 }
343 }
344
345 /**
346 * Notifies the tracker that the starting window was drawn.
347 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100348 void notifyStartingWindowDrawn(int windowingMode, long timestamp) {
349 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800350 if (info == null || info.loggedStartingWindowDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500351 return;
352 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800353 info.loggedStartingWindowDrawn = true;
Sudheer Shankac766db02017-06-12 10:37:29 -0700354 info.startingWindowDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500355 }
356
357 /**
358 * Notifies the tracker that the app transition is starting.
359 *
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100360 * @param windowingModeToReason A map from windowing mode to a reason integer, which must be on
361 * of ActivityManagerInternal.APP_TRANSITION_* reasons.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500362 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100363 void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) {
Jorim Jaggid8a57772017-04-14 16:50:42 -0700364 if (!isAnyTransitionActive() || mLoggedTransitionStarting) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500365 return;
366 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200367 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting");
Sudheer Shankac766db02017-06-12 10:37:29 -0700368 mCurrentTransitionDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500369 mLoggedTransitionStarting = true;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100370 for (int index = windowingModeToReason.size() - 1; index >= 0; index--) {
371 final int windowingMode = windowingModeToReason.keyAt(index);
372 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
373 windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800374 if (info == null) {
375 continue;
376 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100377 info.reason = windowingModeToReason.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800378 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100379 if (allWindowsDrawn()) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800380 reset(false /* abort */);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500381 }
382 }
383
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200384 /**
385 * Notifies the tracker that the visibility of an app is changing.
386 *
387 * @param activityRecord the app that is changing its visibility
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200388 */
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200389 void notifyVisibilityChanged(ActivityRecord activityRecord) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100390 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
391 activityRecord.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200392 if (info == null) {
393 return;
394 }
395 if (info.launchedActivity != activityRecord) {
396 return;
397 }
398 final TaskRecord t = activityRecord.getTask();
399 final SomeArgs args = SomeArgs.obtain();
400 args.arg1 = t;
401 args.arg2 = activityRecord;
402 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget();
403 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200404
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200405 private void checkVisibility(TaskRecord t, ActivityRecord r) {
406 synchronized (mSupervisor.mService) {
407
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100408 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
409 r.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200410
411 // If we have an active transition that's waiting on a certain activity that will be
412 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
413 if (info != null && !t.isVisible()) {
414 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible"
415 + " activity=" + r);
416 logAppTransitionCancel(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100417 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
418 if (mWindowingModeTransitionInfo.size() == 0) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200419 reset(true /* abort */);
420 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200421 }
422 }
423 }
424
Jorim Jaggi515dd682017-05-05 15:05:07 +0200425 /**
426 * Notifies the tracker that we called immediately before we call bindApplication on the client.
427 *
428 * @param app The client into which we'll call bindApplication.
429 */
430 void notifyBindApplication(ProcessRecord app) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100431 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
432 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200433
434 // App isn't attached to record yet, so match with info.
435 if (info.launchedActivity.appInfo == app.info) {
436 info.bindApplicationDelayMs = calculateCurrentDelay();
437 }
438 }
439 }
440
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100441 private boolean allWindowsDrawn() {
442 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
443 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800444 return false;
445 }
446 }
447 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500448 }
449
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800450 private boolean isAnyTransitionActive() {
451 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100452 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800453 }
454
455 private void reset(boolean abort) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200456 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800457 if (!abort && isAnyTransitionActive()) {
458 logAppTransitionMultiEvents();
459 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500460 mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800461 mCurrentTransitionDelayMs = -1;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500462 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100463 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500464 }
465
466 private int calculateCurrentDelay() {
467
468 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400469 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500470 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800471
Sudheer Shankac766db02017-06-12 10:37:29 -0700472 private int calculateDelay(long timestamp) {
473 // Shouldn't take more than 25 days to launch an app, so int is fine here.
474 return (int) (timestamp - mCurrentTransitionStartTime);
475 }
476
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100477 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200478 final int type = getTransitionType(info);
479 if (type == -1) {
480 return;
481 }
482 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
483 builder.setPackageName(info.launchedActivity.packageName);
484 builder.setType(type);
485 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
486 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000487 StatsLog.write(
488 StatsLog.APP_START_CANCEL_CHANGED,
489 info.launchedActivity.appInfo.uid,
490 info.launchedActivity.packageName,
491 convertAppStartTransitionType(type),
492 info.launchedActivity.info.name);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200493 }
494
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800495 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200496 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100497 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
498 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800499 final int type = getTransitionType(info);
500 if (type == -1) {
501 return;
502 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000503
504 // Take a snapshot of the transition info before sending it to the handler for logging.
505 // This will avoid any races with other operations that modify the ActivityRecord.
506 final WindowingModeTransitionInfoSnapshot infoSnapshot =
507 new WindowingModeTransitionInfoSnapshot(info);
508 mHandler.obtainMessage(MSG_LOG_APP_TRANSITION, mCurrentTransitionDeviceUptime,
509 mCurrentTransitionDelayMs, infoSnapshot).sendToTarget();
510
511 info.launchedActivity.info.launchToken = null;
Narayan Kamath203a9ab2018-02-20 17:06:21 +0000512 mHandler.obtainMessage(MSG_LOG_APP_START_MEMORY_STATE_CAPTURE, info).sendToTarget();
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800513 }
514 }
515
Calin Juravle759fbda2018-02-20 19:52:30 +0000516 // This gets called on the handler without holding the activity manager lock.
517 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
518 WindowingModeTransitionInfoSnapshot info) {
519 final LogMaker builder = new LogMaker(APP_TRANSITION);
520 builder.setPackageName(info.packageName);
521 builder.setType(info.type);
522 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
523 final boolean isInstantApp = info.applicationInfo.isInstantApp();
524 if (info.launchedActivityLaunchedFromPackage != null) {
525 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
526 info.launchedActivityLaunchedFromPackage);
527 }
528 String launchToken = info.launchedActivityLaunchToken;
529 if (launchToken != null) {
530 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
531 }
532 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
533 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
534 currentTransitionDeviceUptime);
535 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
536 builder.setSubtype(info.reason);
537 if (info.startingWindowDelayMs != -1) {
538 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
539 info.startingWindowDelayMs);
540 }
541 if (info.bindApplicationDelayMs != -1) {
542 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
543 info.bindApplicationDelayMs);
544 }
545 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
546 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
547 final PackageOptimizationInfo packageOptimizationInfo =
548 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
549 ? PackageOptimizationInfo.createWithNoInfo()
550 : artManagerInternal.getPackageOptimizationInfo(
551 info.applicationInfo,
552 info.launchedActivityAppRecordRequiredAbi);
553 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
554 packageOptimizationInfo.getCompilationReason());
555 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
556 packageOptimizationInfo.getCompilationFilter());
557 mMetricsLogger.write(builder);
558 StatsLog.write(
559 StatsLog.APP_START_CHANGED,
560 info.applicationInfo.uid,
561 info.packageName,
562 convertAppStartTransitionType(info.type),
563 info.launchedActivityName,
564 info.launchedActivityLaunchedFromPackage,
565 isInstantApp,
566 currentTransitionDeviceUptime * 1000,
567 info.reason,
568 currentTransitionDelayMs,
569 info.startingWindowDelayMs,
570 info.bindApplicationDelayMs,
571 info.windowsDrawnDelayMs,
572 launchToken,
573 packageOptimizationInfo.getCompilationReason(),
574 packageOptimizationInfo.getCompilationFilter());
575 }
576
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000577 private int convertAppStartTransitionType(int tronType) {
578 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
579 return StatsLog.APP_START_CHANGED__TYPE__COLD;
580 }
581 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
582 return StatsLog.APP_START_CHANGED__TYPE__WARM;
583 }
584 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
585 return StatsLog.APP_START_CHANGED__TYPE__HOT;
586 }
587 return StatsLog.APP_START_CHANGED__TYPE__APP_START_TRANSITION_TYPE_UNKNOWN;
588 }
589
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200590 void logAppTransitionReportedDrawn(ActivityRecord r, boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100591 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
592 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200593 if (info == null) {
594 return;
595 }
596 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
597 builder.setPackageName(r.packageName);
598 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000599 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
600 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200601 builder.setType(restoredFromBundle
602 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
603 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
604 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
605 info.currentTransitionProcessRunning ? 1 : 0);
606 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000607 StatsLog.write(
608 StatsLog.APP_START_FULLY_DRAWN_CHANGED,
609 info.launchedActivity.appInfo.uid,
610 info.launchedActivity.packageName,
611 restoredFromBundle
612 ? StatsLog.APP_START_FULLY_DRAWN_CHANGED__TYPE__WITH_BUNDLE
613 : StatsLog.APP_START_FULLY_DRAWN_CHANGED__TYPE__WITHOUT_BUNDLE,
614 info.launchedActivity.info.name,
615 info.currentTransitionProcessRunning,
616 startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200617 }
618
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100619 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800620 if (info.currentTransitionProcessRunning) {
621 if (info.startResult == START_SUCCESS) {
622 return TYPE_TRANSITION_WARM_LAUNCH;
623 } else if (info.startResult == START_TASK_TO_FRONT) {
624 return TYPE_TRANSITION_HOT_LAUNCH;
625 }
626 } else if (info.startResult == START_SUCCESS) {
627 return TYPE_TRANSITION_COLD_LAUNCH;
628 }
629 return -1;
630 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800631
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100632 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfo info) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800633 final ProcessRecord processRecord = findProcessForActivity(info.launchedActivity);
634 if (processRecord == null) {
635 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
636 return;
637 }
638
639 final int pid = processRecord.pid;
640 final int uid = info.launchedActivity.appInfo.uid;
641 final MemoryStat memoryStat = readMemoryStatFromMemcg(uid, pid);
642 if (memoryStat == null) {
643 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
644 return;
645 }
646
647 StatsLog.write(
648 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
649 uid,
650 info.launchedActivity.processName,
651 info.launchedActivity.info.name,
652 memoryStat.pgfault,
653 memoryStat.pgmajfault,
654 memoryStat.rssInBytes,
655 memoryStat.cacheInBytes,
656 memoryStat.swapInBytes);
657 }
658
659 private ProcessRecord findProcessForActivity(ActivityRecord launchedActivity) {
660 return launchedActivity != null
661 ? mSupervisor.mService.mProcessNames.get(launchedActivity.processName,
662 launchedActivity.appInfo.uid)
663 : null;
664 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000665
666 private ArtManagerInternal getArtManagerInternal() {
667 if (mArtManagerInternal == null) {
668 // Note that this may be null.
669 // ArtManagerInternal is registered during PackageManagerService
670 // initialization which happens after ActivityManagerService.
671 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
672 }
673 return mArtManagerInternal;
674 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800675}