blob: a7bf96bbccf501c9871d304affdef1461a1b56b8 [file] [log] [blame]
Wale Ogunwale59507092018-10-29 09:00:30 -07001package com.android.server.wm;
Filip Gruszczynski77d94482015-12-11 13:59:52 -08002
Jorim Jaggi3878ca32017-02-02 17:13:05 -08003import static android.app.ActivityManager.START_SUCCESS;
4import static android.app.ActivityManager.START_TASK_TO_FRONT;
Michal Karpinski201bc0c2018-07-20 15:32:00 +01005import static android.app.ActivityManager.processStateAmToProto;
Bryce Lee6c605092017-10-12 11:14:49 -07006import static android.app.WindowConfiguration.WINDOWING_MODE_FREEFORM;
Wale Ogunwale3382ab12017-07-27 08:55:03 -07007import static android.app.WindowConfiguration.WINDOWING_MODE_FULLSCREEN;
8import static android.app.WindowConfiguration.WINDOWING_MODE_PINNED;
Vishnu Nair132ee832018-09-28 15:00:05 -07009import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_PRIMARY;
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;
Vishnu Nair132ee832018-09-28 15:00:05 -070012
Michal Karpinski201bc0c2018-07-20 15:32:00 +010013import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.ACTION_ACTIVITY_START;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080014import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION;
Jorim Jaggi515dd682017-05-05 15:05:07 +020015import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_BIND_APPLICATION_DELAY_MS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070016import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CALLING_PACKAGE_NAME;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020017import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CANCELLED;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080018import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DELAY_MS;
19import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070020import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_IS_EPHEMERAL;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020021import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_PROCESS_RUNNING;
22import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN;
23import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN_MS;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080024import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_STARTING_WINDOW_DELAY_MS;
25import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010026import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_FLAGS;
27import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_FULLSCREEN;
28import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_NO_DISPLAY;
29import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_VISIBLE;
30import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_VISIBLE_IGNORING_KEYGUARD;
Vishnu Nair132ee832018-09-28 15:00:05 -070031import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_LAUNCH_MODE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010032import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_LAUNCH;
33import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_VISIBLE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010034import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_PROCESS_NAME;
35import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_REAL_ACTIVITY;
36import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_RESULT_TO_PKG_NAME;
37import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_RESULT_TO_SHORT_COMPONENT_NAME;
38import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_SHORT_COMPONENT_NAME;
39import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_TARGET_ACTIVITY;
40import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_PACKAGE_NAME;
41import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID;
42import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW;
43import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_PROC_STATE;
Jorim Jaggicdfc04e2017-04-28 19:06:24 +020044import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010045import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_COMING_FROM_PENDING_INTENT;
Todd Kennedy50d946c12017-03-17 13:55:38 -070046import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INSTANT_APP_LAUNCH_TOKEN;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010047import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INTENT_ACTION;
48import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_CUR_PROC_STATE;
49import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES;
50import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES;
51import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES;
52import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_OVERLAY_UI;
53import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_TOP_UI;
54import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION;
55import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT;
56import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT;
57import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PENDING_UI_CLEAN;
58import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PROCESS_NAME;
59import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010060import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW;
Vishnu Nair132ee832018-09-28 15:00:05 -070061import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_PROC_STATE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010062import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_PACKAGE_NAME;
63import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_SHORT_COMPONENT_NAME;
64import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_UID;
65import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_UID_HAS_ANY_VISIBLE_WINDOW;
66import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_UID_PROC_STATE;
67import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_WHITELIST_TAG;
Calin Juravle759fbda2018-02-20 19:52:30 +000068import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_FILTER;
Vishnu Nair132ee832018-09-28 15:00:05 -070069import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_REASON;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080070import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_COLD_LAUNCH;
71import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_HOT_LAUNCH;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020072import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE;
73import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080074import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH;
Vishnu Nair132ee832018-09-28 15:00:05 -070075import static com.android.server.am.EventLogTags.AM_ACTIVITY_LAUNCH_TIME;
Ng Zhi Anbbefdec2018-01-30 17:12:39 -080076import static com.android.server.am.MemoryStatUtil.MemoryStat;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +000077import static com.android.server.am.MemoryStatUtil.readMemoryStatFromFilesystem;
Vishnu Naira62534b2018-11-09 09:13:22 -080078import static com.android.server.wm.ActivityTaskManagerDebugConfig.DEBUG_METRICS;
79import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_ATM;
80import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_WITH_CLASS_NAME;
Vishnu Nair132ee832018-09-28 15:00:05 -070081import static com.android.server.wm.ActivityTaskManagerInternal.APP_TRANSITION_TIMEOUT;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080082
Igor Murashkin212d06c2018-10-22 16:34:39 -070083import android.app.WindowConfiguration.WindowingMode;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080084import android.content.Context;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010085import android.content.Intent;
Calin Juravle759fbda2018-02-20 19:52:30 +000086import android.content.pm.ApplicationInfo;
87import android.content.pm.dex.ArtManagerInternal;
88import android.content.pm.dex.PackageOptimizationInfo;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080089import android.metrics.LogMaker;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020090import android.os.Handler;
91import android.os.Looper;
92import android.os.Message;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080093import android.os.SystemClock;
Vishnu Nair132ee832018-09-28 15:00:05 -070094import android.os.Trace;
95import android.util.EventLog;
96import android.util.Log;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020097import android.util.Slog;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080098import android.util.SparseArray;
99import android.util.SparseIntArray;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000100import android.util.StatsLog;
Vishnu Nair132ee832018-09-28 15:00:05 -0700101import android.util.TimeUtils;
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800102import android.util.proto.ProtoOutputStream;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800103
104import com.android.internal.logging.MetricsLogger;
Ng Zhi An83473542018-02-20 09:02:14 -0800105import com.android.internal.os.BackgroundThread;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200106import com.android.internal.os.SomeArgs;
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800107import com.android.internal.annotations.VisibleForTesting;
Calin Juravle759fbda2018-02-20 19:52:30 +0000108import com.android.server.LocalServices;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800109
110/**
Vishnu Nair132ee832018-09-28 15:00:05 -0700111 * Listens to activity launches, transitions, visibility changes and window drawn callbacks to
112 * determine app launch times and draw delays. Source of truth for activity metrics and provides
113 * data for Tron, logcat, event logs and {@link android.app.WaitResult}.
114 *
115 * Tests:
Vishnu Nairf8accc52018-10-11 10:19:54 -0700116 * atest CtsActivityManagerDeviceTestCases:ActivityMetricsLoggerTests
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800117 */
118class ActivityMetricsLogger {
Jorim Jaggif9704102016-05-05 19:14:22 -0700119
Wale Ogunwale98875612018-10-12 07:53:02 -0700120 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_ATM;
Jorim Jaggif9704102016-05-05 19:14:22 -0700121
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800122 // Window modes we are interested in logging. If we ever introduce a new type, we need to add
123 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array.
124 private static final int WINDOW_STATE_STANDARD = 0;
125 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1;
126 private static final int WINDOW_STATE_FREEFORM = 2;
Winson Chung83471632016-12-13 11:02:12 -0800127 private static final int WINDOW_STATE_ASSISTANT = 3;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800128 private static final int WINDOW_STATE_INVALID = -1;
129
Jorim Jaggi275561a2016-02-23 10:11:02 -0500130 private static final long INVALID_START_TIME = -1;
Vishnu Nair132ee832018-09-28 15:00:05 -0700131 private static final int INVALID_DELAY = -1;
132 private static final int INVALID_TRANSITION_TYPE = -1;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500133
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200134 private static final int MSG_CHECK_VISIBILITY = 0;
135
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800136 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every
137 // time we log.
138 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = {
Winson Chung83471632016-12-13 11:02:12 -0800139 "window_time_0", "window_time_1", "window_time_2", "window_time_3"};
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800140
141 private int mWindowState = WINDOW_STATE_STANDARD;
142 private long mLastLogTimeSecs;
143 private final ActivityStackSupervisor mSupervisor;
144 private final Context mContext;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800145 private final MetricsLogger mMetricsLogger = new MetricsLogger();
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800146
Igor Murashkin212d06c2018-10-22 16:34:39 -0700147 // set to INVALID_START_TIME in reset.
148 // set to valid value in notifyActivityLaunching
Jorim Jaggi275561a2016-02-23 10:11:02 -0500149 private long mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200150 private long mLastTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800151
152 private int mCurrentTransitionDeviceUptime;
153 private int mCurrentTransitionDelayMs;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700154
155 /** If the any app transitions have been logged as starting, after the latest reset. */
Jorim Jaggi275561a2016-02-23 10:11:02 -0500156 private boolean mLoggedTransitionStarting;
157
Igor Murashkin212d06c2018-10-22 16:34:39 -0700158 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100159 private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo =
160 new SparseArray<>();
Igor Murashkin212d06c2018-10-22 16:34:39 -0700161 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100162 private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo =
163 new SparseArray<>();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200164 private final H mHandler;
Calin Juravle759fbda2018-02-20 19:52:30 +0000165
166 private ArtManagerInternal mArtManagerInternal;
Vishnu Nair132ee832018-09-28 15:00:05 -0700167 private final StringBuilder mStringBuilder = new StringBuilder();
Calin Juravle759fbda2018-02-20 19:52:30 +0000168
Igor Murashkin212d06c2018-10-22 16:34:39 -0700169 /**
170 * Due to the global single concurrent launch sequence, all calls to this observer must be made
171 * in-order on the same thread to fulfill the "happens-before" guarantee in LaunchObserver.
172 */
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800173 private final LaunchObserverRegistryImpl mLaunchObserver;
174 @VisibleForTesting static final int LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE = 512;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700175
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200176 private final class H extends Handler {
177
178 public H(Looper looper) {
179 super(looper);
180 }
181
182 @Override
183 public void handleMessage(Message msg) {
184 switch (msg.what) {
185 case MSG_CHECK_VISIBILITY:
186 final SomeArgs args = (SomeArgs) msg.obj;
187 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2);
188 break;
189 }
190 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000191 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800192
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100193 private final class WindowingModeTransitionInfo {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700194 /** The latest activity to have been launched. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800195 private ActivityRecord launchedActivity;
196 private int startResult;
197 private boolean currentTransitionProcessRunning;
Vishnu Nair132ee832018-09-28 15:00:05 -0700198 /** Elapsed time from when we launch an activity to when its windows are drawn. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800199 private int windowsDrawnDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700200 private int startingWindowDelayMs = INVALID_DELAY;
201 private int bindApplicationDelayMs = INVALID_DELAY;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800202 private int reason = APP_TRANSITION_TIMEOUT;
203 private boolean loggedWindowsDrawn;
204 private boolean loggedStartingWindowDrawn;
Vishnu Nair132ee832018-09-28 15:00:05 -0700205 private boolean launchTraceActive;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800206 }
207
Vishnu Nair132ee832018-09-28 15:00:05 -0700208 final class WindowingModeTransitionInfoSnapshot {
Calin Juravle759fbda2018-02-20 19:52:30 +0000209 final private ApplicationInfo applicationInfo;
Wale Ogunwalef6733932018-06-27 05:14:34 -0700210 final private WindowProcessController processRecord;
Vishnu Nair132ee832018-09-28 15:00:05 -0700211 final String packageName;
212 final String launchedActivityName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000213 final private String launchedActivityLaunchedFromPackage;
214 final private String launchedActivityLaunchToken;
215 final private String launchedActivityAppRecordRequiredAbi;
Vishnu Nair132ee832018-09-28 15:00:05 -0700216 final String launchedActivityShortComponentName;
Ng Zhi An83473542018-02-20 09:02:14 -0800217 final private String processName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000218 final private int reason;
219 final private int startingWindowDelayMs;
220 final private int bindApplicationDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700221 final int windowsDrawnDelayMs;
222 final int type;
223 final int userId;
224 /**
225 * Elapsed time from when we launch an activity to when the app reported it was
226 * fully drawn. If this is not reported then the value is set to INVALID_DELAY.
227 */
228 final int windowsFullyDrawnDelayMs;
229 final int activityRecordIdHashCode;
Calin Juravle759fbda2018-02-20 19:52:30 +0000230
231 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700232 this(info, info.launchedActivity);
233 }
234
235 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
236 ActivityRecord launchedActivity) {
237 this(info, launchedActivity, INVALID_DELAY);
238 }
239
240 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
241 ActivityRecord launchedActivity, int windowsFullyDrawnDelayMs) {
242 applicationInfo = launchedActivity.appInfo;
243 packageName = launchedActivity.packageName;
244 launchedActivityName = launchedActivity.info.name;
245 launchedActivityLaunchedFromPackage = launchedActivity.launchedFromPackage;
246 launchedActivityLaunchToken = launchedActivity.info.launchToken;
247 launchedActivityAppRecordRequiredAbi = launchedActivity.app == null
Calin Juravle759fbda2018-02-20 19:52:30 +0000248 ? null
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700249 : launchedActivity.app.getRequiredAbi();
Calin Juravle759fbda2018-02-20 19:52:30 +0000250 reason = info.reason;
251 startingWindowDelayMs = info.startingWindowDelayMs;
252 bindApplicationDelayMs = info.bindApplicationDelayMs;
253 windowsDrawnDelayMs = info.windowsDrawnDelayMs;
254 type = getTransitionType(info);
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700255 processRecord = findProcessForActivity(launchedActivity);
256 processName = launchedActivity.processName;
Vishnu Nair132ee832018-09-28 15:00:05 -0700257 userId = launchedActivity.userId;
258 launchedActivityShortComponentName = launchedActivity.shortComponentName;
259 activityRecordIdHashCode = System.identityHashCode(launchedActivity);
260 this.windowsFullyDrawnDelayMs = windowsFullyDrawnDelayMs;
Calin Juravle759fbda2018-02-20 19:52:30 +0000261 }
262 }
263
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200264 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper) {
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800265 mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000;
266 mSupervisor = supervisor;
267 mContext = context;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200268 mHandler = new H(looper);
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800269 mLaunchObserver = new LaunchObserverRegistryImpl(looper);
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800270 }
271
272 void logWindowState() {
273 final long now = SystemClock.elapsedRealtime() / 1000;
274 if (mWindowState != WINDOW_STATE_INVALID) {
275 // We log even if the window state hasn't changed, because the user might remain in
276 // home/fullscreen move forever and we would like to track this kind of behavior
277 // too.
278 MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState],
279 (int) (now - mLastLogTimeSecs));
280 }
281 mLastLogTimeSecs = now;
282
Wale Ogunwale926aade2017-08-29 11:24:37 -0700283 mWindowState = WINDOW_STATE_INVALID;
Andrii Kulian5f750bc2018-07-17 08:57:23 -0700284 ActivityStack stack = mSupervisor.getTopDisplayFocusedStack();
lumarkf6c4a982018-06-15 15:43:12 +0800285 if (stack == null) {
286 return;
287 }
288
Wale Ogunwale926aade2017-08-29 11:24:37 -0700289 if (stack.isActivityTypeAssistant()) {
290 mWindowState = WINDOW_STATE_ASSISTANT;
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800291 return;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800292 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700293
Igor Murashkin212d06c2018-10-22 16:34:39 -0700294 @WindowingMode int windowingMode = stack.getWindowingMode();
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700295 if (windowingMode == WINDOWING_MODE_PINNED) {
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800296 stack = mSupervisor.findStackBehind(stack);
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700297 windowingMode = stack.getWindowingMode();
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800298 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700299 switch (windowingMode) {
300 case WINDOWING_MODE_FULLSCREEN:
301 mWindowState = WINDOW_STATE_STANDARD;
302 break;
303 case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY:
304 case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY:
305 mWindowState = WINDOW_STATE_SIDE_BY_SIDE;
306 break;
Bryce Lee6c605092017-10-12 11:14:49 -0700307 case WINDOWING_MODE_FREEFORM:
Wale Ogunwale926aade2017-08-29 11:24:37 -0700308 mWindowState = WINDOW_STATE_FREEFORM;
309 break;
310 default:
311 if (windowingMode != WINDOWING_MODE_UNDEFINED) {
312 throw new IllegalStateException("Unknown windowing mode for stack=" + stack
313 + " windowingMode=" + windowingMode);
314 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800315 }
316 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500317
318 /**
319 * Notifies the tracker at the earliest possible point when we are starting to launch an
320 * activity.
321 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700322 void notifyActivityLaunching(Intent intent) {
323 if (DEBUG_METRICS) {
324 Slog.i(TAG, String.format("notifyActivityLaunching: active:%b, intent:%s",
325 isAnyTransitionActive(),
326 intent));
327 }
328
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800329 if (!isAnyTransitionActive()) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700330
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400331 mCurrentTransitionStartTime = SystemClock.uptimeMillis();
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200332 mLastTransitionStartTime = mCurrentTransitionStartTime;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700333
334 launchObserverNotifyIntentStarted(intent);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800335 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500336 }
337
338 /**
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700339 * Notifies the tracker that the activity is actually launching.
340 *
341 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
342 * launch
343 * @param launchedActivity the activity that is being launched
344 */
345 void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) {
Wale Ogunwalef6733932018-06-27 05:14:34 -0700346 final WindowProcessController processRecord = findProcessForActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700347 final boolean processRunning = processRecord != null;
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700348
349 // We consider this a "process switch" if the process of the activity that gets launched
350 // didn't have an activity that was in started state. In this case, we assume that lot
351 // of caches might be purged so the time until it produces the first frame is very
352 // interesting.
353 final boolean processSwitch = processRecord == null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700354 || !processRecord.hasStartedActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700355
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800356 notifyActivityLaunched(resultCode, launchedActivity, processRunning, processSwitch);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700357 }
358
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700359 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500360 * Notifies the tracker the the activity is actually launching.
361 *
362 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
363 * launch
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800364 * @param launchedActivity the activity being launched
Jorim Jaggi275561a2016-02-23 10:11:02 -0500365 * @param processRunning whether the process that will contains the activity is already running
Jorim Jaggibe67c902016-04-12 00:53:16 -0700366 * @param processSwitch whether the process that will contain the activity didn't have any
367 * activity that was stopped, i.e. the started activity is "switching"
368 * processes
Jorim Jaggi275561a2016-02-23 10:11:02 -0500369 */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800370 private void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity,
Jorim Jaggibe67c902016-04-12 00:53:16 -0700371 boolean processRunning, boolean processSwitch) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500372
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200373 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched"
374 + " resultCode=" + resultCode
375 + " launchedActivity=" + launchedActivity
376 + " processRunning=" + processRunning
377 + " processSwitch=" + processSwitch);
378
Igor Murashkin212d06c2018-10-22 16:34:39 -0700379 // If we are already in an existing transition, only update the activity name, but not the
380 // other attributes.
381 final @WindowingMode int windowingMode = launchedActivity != null
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100382 ? launchedActivity.getWindowingMode()
383 : WINDOWING_MODE_UNDEFINED;
Vishnu Nairf8accc52018-10-11 10:19:54 -0700384 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200385 if (mCurrentTransitionStartTime == INVALID_START_TIME) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700386 // No transition is active ignore this launch.
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200387 return;
388 }
389
Vishnu Nair9ba31652018-11-13 14:34:05 -0800390 if (launchedActivity != null && launchedActivity.mDrawn) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700391 // Launched activity is already visible. We cannot measure windows drawn delay.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700392 reset(true /* abort */, info, "launched activity already visible");
Vishnu Nairf8accc52018-10-11 10:19:54 -0700393 return;
394 }
395
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800396 if (launchedActivity != null && info != null) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700397 // If we are already in an existing transition, only update the activity name, but not
398 // the other attributes.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700399
400 // Coalesce multiple (trampoline) activities from a single sequence together.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800401 info.launchedActivity = launchedActivity;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500402 return;
403 }
404
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100405 final boolean otherWindowModesLaunching =
406 mWindowingModeTransitionInfo.size() > 0 && info == null;
Jorim Jaggi54cff642018-03-15 15:51:32 +0100407 if ((!isLoggableResultCode(resultCode) || launchedActivity == null || !processSwitch
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100408 || windowingMode == WINDOWING_MODE_UNDEFINED) && !otherWindowModesLaunching) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800409 // Failed to launch or it was not a process switch, so we don't care about the timing.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700410 reset(true /* abort */, info, "failed to launch or not a process switch");
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800411 return;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100412 } else if (otherWindowModesLaunching) {
413 // Don't log this windowing mode but continue with the other windowing modes.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800414 return;
415 }
416
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200417 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful");
418
Igor Murashkin212d06c2018-10-22 16:34:39 -0700419 // A new launch sequence [with the windowingMode] has begun.
420 // Start tracking it.
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100421 final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo();
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800422 newInfo.launchedActivity = launchedActivity;
423 newInfo.currentTransitionProcessRunning = processRunning;
424 newInfo.startResult = resultCode;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100425 mWindowingModeTransitionInfo.put(windowingMode, newInfo);
426 mLastWindowingModeTransitionInfo.put(windowingMode, newInfo);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800427 mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000);
Vishnu Nair132ee832018-09-28 15:00:05 -0700428 startTraces(newInfo);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700429 launchObserverNotifyActivityLaunched(newInfo);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500430 }
431
432 /**
Jorim Jaggi54cff642018-03-15 15:51:32 +0100433 * @return True if we should start logging an event for an activity start that returned
434 * {@code resultCode} and that we'll indeed get a windows drawn event.
435 */
436 private boolean isLoggableResultCode(int resultCode) {
437 return resultCode == START_SUCCESS || resultCode == START_TASK_TO_FRONT;
438 }
439
440 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500441 * Notifies the tracker that all windows of the app have been drawn.
442 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700443 WindowingModeTransitionInfoSnapshot notifyWindowsDrawn(@WindowingMode int windowingMode,
444 long timestamp) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100445 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200446
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100447 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800448 if (info == null || info.loggedWindowsDrawn) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700449 return null;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500450 }
Sudheer Shankac766db02017-06-12 10:37:29 -0700451 info.windowsDrawnDelayMs = calculateDelay(timestamp);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800452 info.loggedWindowsDrawn = true;
Vishnu Nair132ee832018-09-28 15:00:05 -0700453 final WindowingModeTransitionInfoSnapshot infoSnapshot =
454 new WindowingModeTransitionInfoSnapshot(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100455 if (allWindowsDrawn() && mLoggedTransitionStarting) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700456 reset(false /* abort */, info, "notifyWindowsDrawn - all windows drawn");
Jorim Jaggi275561a2016-02-23 10:11:02 -0500457 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700458 return infoSnapshot;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500459 }
460
461 /**
462 * Notifies the tracker that the starting window was drawn.
463 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700464 void notifyStartingWindowDrawn(@WindowingMode int windowingMode, long timestamp) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100465 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800466 if (info == null || info.loggedStartingWindowDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500467 return;
468 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800469 info.loggedStartingWindowDrawn = true;
Sudheer Shankac766db02017-06-12 10:37:29 -0700470 info.startingWindowDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500471 }
472
473 /**
474 * Notifies the tracker that the app transition is starting.
475 *
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100476 * @param windowingModeToReason A map from windowing mode to a reason integer, which must be on
Vishnu Nair132ee832018-09-28 15:00:05 -0700477 * of ActivityTaskManagerInternal.APP_TRANSITION_* reasons.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500478 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100479 void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) {
Jorim Jaggid8a57772017-04-14 16:50:42 -0700480 if (!isAnyTransitionActive() || mLoggedTransitionStarting) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700481 // Ignore calls to this made after a reset and prior to notifyActivityLaunching.
482
483 // Ignore any subsequent notifyTransitionStarting until the next reset.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500484 return;
485 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200486 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting");
Sudheer Shankac766db02017-06-12 10:37:29 -0700487 mCurrentTransitionDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500488 mLoggedTransitionStarting = true;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700489
490 WindowingModeTransitionInfo foundInfo = null;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100491 for (int index = windowingModeToReason.size() - 1; index >= 0; index--) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700492 final @WindowingMode int windowingMode = windowingModeToReason.keyAt(index);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100493 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
494 windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800495 if (info == null) {
496 continue;
497 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100498 info.reason = windowingModeToReason.valueAt(index);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700499 foundInfo = info;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800500 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100501 if (allWindowsDrawn()) {
Vishnu Naira62534b2018-11-09 09:13:22 -0800502 // abort metrics collection if we cannot find a matching transition.
503 final boolean abortMetrics = foundInfo == null;
504 reset(abortMetrics, foundInfo, "notifyTransitionStarting - all windows drawn");
Jorim Jaggi275561a2016-02-23 10:11:02 -0500505 }
506 }
507
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200508 /**
509 * Notifies the tracker that the visibility of an app is changing.
510 *
511 * @param activityRecord the app that is changing its visibility
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200512 */
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200513 void notifyVisibilityChanged(ActivityRecord activityRecord) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100514 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
515 activityRecord.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200516 if (info == null) {
517 return;
518 }
519 if (info.launchedActivity != activityRecord) {
520 return;
521 }
522 final TaskRecord t = activityRecord.getTask();
523 final SomeArgs args = SomeArgs.obtain();
524 args.arg1 = t;
525 args.arg2 = activityRecord;
526 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget();
527 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200528
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200529 private void checkVisibility(TaskRecord t, ActivityRecord r) {
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700530 synchronized (mSupervisor.mService.mGlobalLock) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200531
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100532 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
533 r.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200534
535 // If we have an active transition that's waiting on a certain activity that will be
536 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
537 if (info != null && !t.isVisible()) {
538 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible"
539 + " activity=" + r);
540 logAppTransitionCancel(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100541 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
542 if (mWindowingModeTransitionInfo.size() == 0) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700543 reset(true /* abort */, info, "notifyVisibilityChanged to invisible");
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200544 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200545 }
546 }
547 }
548
Jorim Jaggi515dd682017-05-05 15:05:07 +0200549 /**
550 * Notifies the tracker that we called immediately before we call bindApplication on the client.
551 *
Wale Ogunwale31913b52018-10-13 08:29:31 -0700552 * @param appInfo The client into which we'll call bindApplication.
Jorim Jaggi515dd682017-05-05 15:05:07 +0200553 */
Wale Ogunwale31913b52018-10-13 08:29:31 -0700554 void notifyBindApplication(ApplicationInfo appInfo) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100555 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
556 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200557
558 // App isn't attached to record yet, so match with info.
Wale Ogunwale31913b52018-10-13 08:29:31 -0700559 if (info.launchedActivity.appInfo == appInfo) {
Jorim Jaggi515dd682017-05-05 15:05:07 +0200560 info.bindApplicationDelayMs = calculateCurrentDelay();
561 }
562 }
563 }
564
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100565 private boolean allWindowsDrawn() {
566 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
567 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800568 return false;
569 }
570 }
571 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500572 }
573
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800574 private boolean isAnyTransitionActive() {
575 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100576 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800577 }
578
Igor Murashkin212d06c2018-10-22 16:34:39 -0700579 private void reset(boolean abort, WindowingModeTransitionInfo info, String cause) {
580 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort + ",cause=" + cause);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800581 if (!abort && isAnyTransitionActive()) {
582 logAppTransitionMultiEvents();
583 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700584 stopLaunchTrace(info);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700585
586 // Ignore reset-after reset.
587 if (isAnyTransitionActive()) {
588 // LaunchObserver callbacks.
589 if (abort) {
590 launchObserverNotifyActivityLaunchCancelled(info);
591 } else {
592 launchObserverNotifyActivityLaunchFinished(info);
593 }
594 } else {
595 launchObserverNotifyIntentFailed();
596 }
597
Jorim Jaggi275561a2016-02-23 10:11:02 -0500598 mCurrentTransitionStartTime = INVALID_START_TIME;
Vishnu Nair132ee832018-09-28 15:00:05 -0700599 mCurrentTransitionDelayMs = INVALID_DELAY;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500600 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100601 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500602 }
603
604 private int calculateCurrentDelay() {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500605 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400606 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500607 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800608
Sudheer Shankac766db02017-06-12 10:37:29 -0700609 private int calculateDelay(long timestamp) {
610 // Shouldn't take more than 25 days to launch an app, so int is fine here.
611 return (int) (timestamp - mCurrentTransitionStartTime);
612 }
613
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100614 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200615 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700616 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200617 return;
618 }
619 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
620 builder.setPackageName(info.launchedActivity.packageName);
621 builder.setType(type);
622 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
623 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000624 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800625 StatsLog.APP_START_CANCELED,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000626 info.launchedActivity.appInfo.uid,
627 info.launchedActivity.packageName,
628 convertAppStartTransitionType(type),
629 info.launchedActivity.info.name);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700630 if (DEBUG_METRICS) {
631 Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)",
632 info.launchedActivity.appInfo.uid,
633 info.launchedActivity.packageName,
634 convertAppStartTransitionType(type),
635 info.launchedActivity.info.name));
636 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200637 }
638
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800639 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200640 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100641 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
642 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800643 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700644 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800645 return;
646 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000647
648 // Take a snapshot of the transition info before sending it to the handler for logging.
649 // This will avoid any races with other operations that modify the ActivityRecord.
650 final WindowingModeTransitionInfoSnapshot infoSnapshot =
651 new WindowingModeTransitionInfoSnapshot(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800652 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime;
653 final int currentTransitionDelayMs = mCurrentTransitionDelayMs;
654 BackgroundThread.getHandler().post(() -> logAppTransition(
655 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot));
Vishnu Nair132ee832018-09-28 15:00:05 -0700656 BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot));
Calin Juravle759fbda2018-02-20 19:52:30 +0000657
658 info.launchedActivity.info.launchToken = null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800659 }
660 }
661
Ng Zhi An83473542018-02-20 09:02:14 -0800662 // This gets called on a background thread without holding the activity manager lock.
Calin Juravle759fbda2018-02-20 19:52:30 +0000663 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
664 WindowingModeTransitionInfoSnapshot info) {
665 final LogMaker builder = new LogMaker(APP_TRANSITION);
666 builder.setPackageName(info.packageName);
667 builder.setType(info.type);
668 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
669 final boolean isInstantApp = info.applicationInfo.isInstantApp();
670 if (info.launchedActivityLaunchedFromPackage != null) {
671 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
672 info.launchedActivityLaunchedFromPackage);
673 }
674 String launchToken = info.launchedActivityLaunchToken;
675 if (launchToken != null) {
676 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
677 }
678 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
679 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
680 currentTransitionDeviceUptime);
681 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
682 builder.setSubtype(info.reason);
Vishnu Nair132ee832018-09-28 15:00:05 -0700683 if (info.startingWindowDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000684 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
685 info.startingWindowDelayMs);
686 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700687 if (info.bindApplicationDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000688 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
689 info.bindApplicationDelayMs);
690 }
691 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
692 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
693 final PackageOptimizationInfo packageOptimizationInfo =
694 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
695 ? PackageOptimizationInfo.createWithNoInfo()
696 : artManagerInternal.getPackageOptimizationInfo(
697 info.applicationInfo,
698 info.launchedActivityAppRecordRequiredAbi);
699 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
700 packageOptimizationInfo.getCompilationReason());
701 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
702 packageOptimizationInfo.getCompilationFilter());
703 mMetricsLogger.write(builder);
704 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800705 StatsLog.APP_START_OCCURRED,
Calin Juravle759fbda2018-02-20 19:52:30 +0000706 info.applicationInfo.uid,
707 info.packageName,
708 convertAppStartTransitionType(info.type),
709 info.launchedActivityName,
710 info.launchedActivityLaunchedFromPackage,
711 isInstantApp,
712 currentTransitionDeviceUptime * 1000,
713 info.reason,
714 currentTransitionDelayMs,
715 info.startingWindowDelayMs,
716 info.bindApplicationDelayMs,
717 info.windowsDrawnDelayMs,
718 launchToken,
719 packageOptimizationInfo.getCompilationReason(),
720 packageOptimizationInfo.getCompilationFilter());
Igor Murashkin212d06c2018-10-22 16:34:39 -0700721
722 if (DEBUG_METRICS) {
723 Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)",
724 info.applicationInfo.uid,
725 info.packageName,
726 convertAppStartTransitionType(info.type),
727 info.launchedActivityName,
728 info.launchedActivityLaunchedFromPackage));
729 }
730
731
Ng Zhi An83473542018-02-20 09:02:14 -0800732 logAppStartMemoryStateCapture(info);
Calin Juravle759fbda2018-02-20 19:52:30 +0000733 }
734
Vishnu Nair132ee832018-09-28 15:00:05 -0700735 private void logAppDisplayed(WindowingModeTransitionInfoSnapshot info) {
736 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
737 return;
738 }
739
740 EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME,
741 info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,
742 info.windowsDrawnDelayMs);
743
744 StringBuilder sb = mStringBuilder;
745 sb.setLength(0);
746 sb.append("Displayed ");
747 sb.append(info.launchedActivityShortComponentName);
748 sb.append(": ");
749 TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb);
750 Log.i(TAG, sb.toString());
751 }
752
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000753 private int convertAppStartTransitionType(int tronType) {
754 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800755 return StatsLog.APP_START_OCCURRED__TYPE__COLD;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000756 }
757 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800758 return StatsLog.APP_START_OCCURRED__TYPE__WARM;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000759 }
760 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800761 return StatsLog.APP_START_OCCURRED__TYPE__HOT;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000762 }
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800763 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000764 }
765
Vishnu Nair132ee832018-09-28 15:00:05 -0700766 WindowingModeTransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r,
767 boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100768 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
769 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200770 if (info == null) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700771 return null;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200772 }
Chris Wailes35c193c2018-10-09 18:12:00 -0700773
774 // Record the handling of the reportFullyDrawn callback in the trace system. This is not
775 // actually used to trace this function, but instead the logical task that this function
776 // fullfils (handling reportFullyDrawn() callbacks).
777 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
778 "ActivityManager:ReportingFullyDrawn " + info.launchedActivity.packageName);
779
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200780 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
781 builder.setPackageName(r.packageName);
782 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000783 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
784 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200785 builder.setType(restoredFromBundle
786 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
787 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
788 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
789 info.currentTransitionProcessRunning ? 1 : 0);
790 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000791 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800792 StatsLog.APP_START_FULLY_DRAWN,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000793 info.launchedActivity.appInfo.uid,
794 info.launchedActivity.packageName,
795 restoredFromBundle
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800796 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE
797 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000798 info.launchedActivity.info.name,
799 info.currentTransitionProcessRunning,
800 startupTimeMs);
Chris Wailes35c193c2018-10-09 18:12:00 -0700801
802 // Ends the trace started at the beginning of this function. This is located here to allow
803 // the trace slice to have a noticable duration.
804 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
805
Vishnu Nair132ee832018-09-28 15:00:05 -0700806 final WindowingModeTransitionInfoSnapshot infoSnapshot =
807 new WindowingModeTransitionInfoSnapshot(info, r, (int) startupTimeMs);
808 BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot));
809 return infoSnapshot;
810 }
811
812 private void logAppFullyDrawn(WindowingModeTransitionInfoSnapshot info) {
813 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
814 return;
815 }
816
817 StringBuilder sb = mStringBuilder;
818 sb.setLength(0);
819 sb.append("Fully drawn ");
820 sb.append(info.launchedActivityShortComponentName);
821 sb.append(": ");
822 TimeUtils.formatDuration(info.windowsFullyDrawnDelayMs, sb);
823 Log.i(TAG, sb.toString());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200824 }
825
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700826 void logActivityStart(Intent intent, WindowProcessController callerApp, ActivityRecord r,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100827 int callingUid, String callingPackage, int callingUidProcState,
828 boolean callingUidHasAnyVisibleWindow,
829 int realCallingUid, int realCallingUidProcState,
830 boolean realCallingUidHasAnyVisibleWindow,
831 int targetUid, String targetPackage, int targetUidProcState,
832 boolean targetUidHasAnyVisibleWindow, String targetWhitelistTag,
833 boolean comingFromPendingIntent) {
834
835 final long nowElapsed = SystemClock.elapsedRealtime();
836 final long nowUptime = SystemClock.uptimeMillis();
837 final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START);
838 builder.setTimestamp(System.currentTimeMillis());
839 builder.addTaggedData(FIELD_CALLING_UID, callingUid);
840 builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage);
841 builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE,
842 processStateAmToProto(callingUidProcState));
843 builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
844 callingUidHasAnyVisibleWindow ? 1 : 0);
845 builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid);
846 builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE,
847 processStateAmToProto(realCallingUidProcState));
848 builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
849 realCallingUidHasAnyVisibleWindow ? 1 : 0);
850 builder.addTaggedData(FIELD_TARGET_UID, targetUid);
851 builder.addTaggedData(FIELD_TARGET_PACKAGE_NAME, targetPackage);
852 builder.addTaggedData(FIELD_TARGET_UID_PROC_STATE,
853 processStateAmToProto(targetUidProcState));
854 builder.addTaggedData(FIELD_TARGET_UID_HAS_ANY_VISIBLE_WINDOW,
855 targetUidHasAnyVisibleWindow ? 1 : 0);
856 builder.addTaggedData(FIELD_TARGET_WHITELIST_TAG, targetWhitelistTag);
857 builder.addTaggedData(FIELD_TARGET_SHORT_COMPONENT_NAME, r.shortComponentName);
858 builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0);
859 builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction());
860 if (callerApp != null) {
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700861 builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100862 builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700863 processStateAmToProto(callerApp.getCurrentProcState()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100864 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700865 callerApp.hasClientActivities() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100866 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES,
867 callerApp.hasForegroundServices() ? 1 : 0);
868 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700869 callerApp.hasForegroundActivities() ? 1 : 0);
870 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100871 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700872 callerApp.hasOverlayUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100873 builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700874 callerApp.hasPendingUiClean() ? 1 : 0);
875 if (callerApp.getInteractionEventTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100876 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700877 (nowElapsed - callerApp.getInteractionEventTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100878 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700879 if (callerApp.getFgInteractionTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100880 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700881 (nowElapsed - callerApp.getFgInteractionTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100882 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700883 if (callerApp.getWhenUnimportant() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100884 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700885 (nowUptime - callerApp.getWhenUnimportant()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100886 }
887 }
888 builder.addTaggedData(FIELD_ACTIVITY_RECORD_LAUNCH_MODE, r.info.launchMode);
889 builder.addTaggedData(FIELD_ACTIVITY_RECORD_TARGET_ACTIVITY, r.info.targetActivity);
890 builder.addTaggedData(FIELD_ACTIVITY_RECORD_FLAGS, r.info.flags);
891 builder.addTaggedData(FIELD_ACTIVITY_RECORD_REAL_ACTIVITY, r.realActivity.toShortString());
892 builder.addTaggedData(FIELD_ACTIVITY_RECORD_SHORT_COMPONENT_NAME, r.shortComponentName);
893 builder.addTaggedData(FIELD_ACTIVITY_RECORD_PROCESS_NAME, r.processName);
894 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_FULLSCREEN, r.fullscreen ? 1 : 0);
895 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_NO_DISPLAY, r.noDisplay ? 1 : 0);
896 if (r.lastVisibleTime != 0) {
897 builder.addTaggedData(FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_VISIBLE,
898 (nowUptime - r.lastVisibleTime));
899 }
900 if (r.resultTo != null) {
901 builder.addTaggedData(FIELD_ACTIVITY_RECORD_RESULT_TO_PKG_NAME, r.resultTo.packageName);
902 builder.addTaggedData(FIELD_ACTIVITY_RECORD_RESULT_TO_SHORT_COMPONENT_NAME,
903 r.resultTo.shortComponentName);
904 }
905 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_VISIBLE, r.visible ? 1 : 0);
906 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_VISIBLE_IGNORING_KEYGUARD,
907 r.visibleIgnoringKeyguard ? 1 : 0);
908 if (r.lastLaunchTime != 0) {
909 builder.addTaggedData(FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_LAUNCH,
910 (nowUptime - r.lastLaunchTime));
911 }
912 mMetricsLogger.write(builder);
913 }
914
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100915 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800916 if (info.currentTransitionProcessRunning) {
917 if (info.startResult == START_SUCCESS) {
918 return TYPE_TRANSITION_WARM_LAUNCH;
919 } else if (info.startResult == START_TASK_TO_FRONT) {
920 return TYPE_TRANSITION_HOT_LAUNCH;
921 }
922 } else if (info.startResult == START_SUCCESS) {
923 return TYPE_TRANSITION_COLD_LAUNCH;
924 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700925 return INVALID_TRANSITION_TYPE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800926 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800927
Ng Zhi An83473542018-02-20 09:02:14 -0800928 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
929 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800930 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
931 return;
932 }
933
Wale Ogunwalef6733932018-06-27 05:14:34 -0700934 final int pid = info.processRecord.getPid();
Ng Zhi An83473542018-02-20 09:02:14 -0800935 final int uid = info.applicationInfo.uid;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +0000936 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800937 if (memoryStat == null) {
938 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
939 return;
940 }
941
942 StatsLog.write(
943 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
944 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800945 info.processName,
946 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800947 memoryStat.pgfault,
948 memoryStat.pgmajfault,
949 memoryStat.rssInBytes,
950 memoryStat.cacheInBytes,
951 memoryStat.swapInBytes);
952 }
953
Wale Ogunwalef6733932018-06-27 05:14:34 -0700954 private WindowProcessController findProcessForActivity(ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800955 return launchedActivity != null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700956 ? mSupervisor.mService.mProcessNames.get(
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700957 launchedActivity.processName, launchedActivity.appInfo.uid)
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800958 : null;
959 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000960
961 private ArtManagerInternal getArtManagerInternal() {
962 if (mArtManagerInternal == null) {
963 // Note that this may be null.
964 // ArtManagerInternal is registered during PackageManagerService
965 // initialization which happens after ActivityManagerService.
966 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
967 }
968 return mArtManagerInternal;
969 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700970
971 /**
Chris Wailes35c193c2018-10-09 18:12:00 -0700972 * Starts traces for app launch.
Vishnu Nair132ee832018-09-28 15:00:05 -0700973 *
974 * @param info
975 * */
976 private void startTraces(WindowingModeTransitionInfo info) {
977 if (info == null) {
978 return;
979 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700980 int transitionType = getTransitionType(info);
981 if (!info.launchTraceActive && transitionType == TYPE_TRANSITION_WARM_LAUNCH
982 || transitionType == TYPE_TRANSITION_COLD_LAUNCH) {
983 Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
984 + info.launchedActivity.packageName, 0);
Vishnu Nair132ee832018-09-28 15:00:05 -0700985 info.launchTraceActive = true;
986 }
987 }
988
989 private void stopLaunchTrace(WindowingModeTransitionInfo info) {
990 if (info == null) {
991 return;
992 }
993 if (info.launchTraceActive) {
994 Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
995 + info.launchedActivity.packageName, 0);
996 info.launchTraceActive = false;
997 }
998 }
Igor Murashkin212d06c2018-10-22 16:34:39 -0700999
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001000 public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() {
1001 return mLaunchObserver;
1002 }
1003
Igor Murashkin212d06c2018-10-22 16:34:39 -07001004 /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */
1005 private void launchObserverNotifyIntentStarted(Intent intent) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001006 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1007 "MetricsLogger:launchObserverNotifyIntentStarted");
1008
1009 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1010 mLaunchObserver.onIntentStarted(intent);
1011
1012 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001013 }
1014
1015 /**
1016 * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has
1017 * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or
1018 * intent being delivered to the top running activity.
1019 */
1020 private void launchObserverNotifyIntentFailed() {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001021 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1022 "MetricsLogger:launchObserverNotifyIntentFailed");
1023
1024 mLaunchObserver.onIntentFailed();
1025
1026 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001027 }
1028
1029 /**
1030 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1031 * has started.
1032 */
1033 private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001034 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1035 "MetricsLogger:launchObserverNotifyActivityLaunched");
1036
Igor Murashkin212d06c2018-10-22 16:34:39 -07001037 @ActivityMetricsLaunchObserver.Temperature int temperature =
1038 convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info));
1039
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001040 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1041 mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.launchedActivity),
1042 temperature);
1043
1044 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001045 }
1046
1047 /**
1048 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is
1049 * cancelled.
1050 */
1051 private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001052 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1053 "MetricsLogger:launchObserverNotifyActivityLaunchCancelled");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001054
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001055 final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto =
1056 info != null ? convertActivityRecordToProto(info.launchedActivity) : null;
1057
1058 mLaunchObserver.onActivityLaunchCancelled(activityRecordProto);
1059
1060 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001061 }
1062
1063 /**
1064 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1065 * has fully finished (successfully).
1066 */
1067 private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001068 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1069 "MetricsLogger:launchObserverNotifyActivityLaunchFinished");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001070
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001071 mLaunchObserver.onActivityLaunchFinished(
1072 convertActivityRecordToProto(info.launchedActivity));
1073
1074 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1075 }
1076
1077 @VisibleForTesting
1078 static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[]
1079 convertActivityRecordToProto(ActivityRecord record) {
1080 // May take non-negligible amount of time to convert ActivityRecord into a proto,
1081 // so track the time.
1082 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1083 "MetricsLogger:convertActivityRecordToProto");
1084
1085 // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream,
1086 // so create a new one every time.
1087 final ProtoOutputStream protoOutputStream =
1088 new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE);
1089 // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object).
1090 record.writeToProto(protoOutputStream);
1091 final byte[] bytes = protoOutputStream.getBytes();
1092
1093 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1094
1095 return bytes;
Igor Murashkin212d06c2018-10-22 16:34:39 -07001096 }
1097
1098 private static @ActivityMetricsLaunchObserver.Temperature int
1099 convertTransitionTypeToLaunchObserverTemperature(int transitionType) {
1100 switch (transitionType) {
1101 case TYPE_TRANSITION_WARM_LAUNCH:
1102 return ActivityMetricsLaunchObserver.TEMPERATURE_WARM;
1103 case TYPE_TRANSITION_HOT_LAUNCH:
1104 return ActivityMetricsLaunchObserver.TEMPERATURE_HOT;
1105 case TYPE_TRANSITION_COLD_LAUNCH:
1106 return ActivityMetricsLaunchObserver.TEMPERATURE_COLD;
1107 default:
1108 return -1;
1109 }
1110 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -08001111}