blob: bc0f74715240a587862338683b7b7634e9c29c49 [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;
Vishnu Nairbb9ab4b2018-12-13 10:29:46 -08006import static android.app.WaitResult.LAUNCH_STATE_COLD;
7import static android.app.WaitResult.LAUNCH_STATE_HOT;
8import static android.app.WaitResult.LAUNCH_STATE_WARM;
Bryce Lee6c605092017-10-12 11:14:49 -07009import static android.app.WindowConfiguration.WINDOWING_MODE_FREEFORM;
Wale Ogunwale3382ab12017-07-27 08:55:03 -070010import static android.app.WindowConfiguration.WINDOWING_MODE_FULLSCREEN;
11import static android.app.WindowConfiguration.WINDOWING_MODE_PINNED;
Vishnu Nair132ee832018-09-28 15:00:05 -070012import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_PRIMARY;
Wale Ogunwale926aade2017-08-29 11:24:37 -070013import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_SECONDARY;
14import static android.app.WindowConfiguration.WINDOWING_MODE_UNDEFINED;
Vishnu Nair132ee832018-09-28 15:00:05 -070015
Michal Karpinski201bc0c2018-07-20 15:32:00 +010016import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.ACTION_ACTIVITY_START;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080017import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION;
Jorim Jaggi515dd682017-05-05 15:05:07 +020018import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_BIND_APPLICATION_DELAY_MS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070019import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CALLING_PACKAGE_NAME;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020020import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CANCELLED;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080021import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DELAY_MS;
22import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070023import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_IS_EPHEMERAL;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020024import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_PROCESS_RUNNING;
25import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN;
26import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN_MS;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080027import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_STARTING_WINDOW_DELAY_MS;
28import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010029import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_PACKAGE_NAME;
30import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID;
31import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW;
32import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_PROC_STATE;
Jorim Jaggicdfc04e2017-04-28 19:06:24 +020033import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010034import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_COMING_FROM_PENDING_INTENT;
Todd Kennedy50d946c12017-03-17 13:55:38 -070035import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INSTANT_APP_LAUNCH_TOKEN;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010036import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INTENT_ACTION;
37import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_CUR_PROC_STATE;
38import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES;
39import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES;
40import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES;
41import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_OVERLAY_UI;
42import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_TOP_UI;
43import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION;
44import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT;
45import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT;
46import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PENDING_UI_CLEAN;
47import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PROCESS_NAME;
48import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010049import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW;
Vishnu Nair132ee832018-09-28 15:00:05 -070050import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_PROC_STATE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010051import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_SHORT_COMPONENT_NAME;
Calin Juravle759fbda2018-02-20 19:52:30 +000052import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_FILTER;
Vishnu Nair132ee832018-09-28 15:00:05 -070053import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_REASON;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080054import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_COLD_LAUNCH;
55import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_HOT_LAUNCH;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020056import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE;
57import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080058import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH;
Vishnu Nair132ee832018-09-28 15:00:05 -070059import static com.android.server.am.EventLogTags.AM_ACTIVITY_LAUNCH_TIME;
Ng Zhi Anbbefdec2018-01-30 17:12:39 -080060import static com.android.server.am.MemoryStatUtil.MemoryStat;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +000061import static com.android.server.am.MemoryStatUtil.readMemoryStatFromFilesystem;
Vishnu Naira62534b2018-11-09 09:13:22 -080062import static com.android.server.wm.ActivityTaskManagerDebugConfig.DEBUG_METRICS;
63import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_ATM;
64import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_WITH_CLASS_NAME;
Vishnu Nair132ee832018-09-28 15:00:05 -070065import static com.android.server.wm.ActivityTaskManagerInternal.APP_TRANSITION_TIMEOUT;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080066
Vishnu Nairbb9ab4b2018-12-13 10:29:46 -080067import android.app.WaitResult;
Igor Murashkin212d06c2018-10-22 16:34:39 -070068import android.app.WindowConfiguration.WindowingMode;
Michal Karpinski319069b2019-03-27 15:46:50 +000069import android.content.ComponentName;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080070import android.content.Context;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010071import android.content.Intent;
Calin Juravle759fbda2018-02-20 19:52:30 +000072import android.content.pm.ApplicationInfo;
73import android.content.pm.dex.ArtManagerInternal;
74import android.content.pm.dex.PackageOptimizationInfo;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080075import android.metrics.LogMaker;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020076import android.os.Handler;
77import android.os.Looper;
78import android.os.Message;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080079import android.os.SystemClock;
Vishnu Nair132ee832018-09-28 15:00:05 -070080import android.os.Trace;
81import android.util.EventLog;
82import android.util.Log;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020083import android.util.Slog;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080084import android.util.SparseArray;
85import android.util.SparseIntArray;
Olivier Gaillardaed7f122017-12-12 14:26:22 +000086import android.util.StatsLog;
Vishnu Nair132ee832018-09-28 15:00:05 -070087import android.util.TimeUtils;
Igor Murashkinc0b47e42018-11-07 15:54:18 -080088import android.util.proto.ProtoOutputStream;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080089
Vishnu Nairbb9ab4b2018-12-13 10:29:46 -080090import com.android.internal.annotations.VisibleForTesting;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080091import com.android.internal.logging.MetricsLogger;
Ng Zhi An83473542018-02-20 09:02:14 -080092import com.android.internal.os.BackgroundThread;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020093import com.android.internal.os.SomeArgs;
Calin Juravle759fbda2018-02-20 19:52:30 +000094import com.android.server.LocalServices;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080095
96/**
Vishnu Nair132ee832018-09-28 15:00:05 -070097 * Listens to activity launches, transitions, visibility changes and window drawn callbacks to
98 * determine app launch times and draw delays. Source of truth for activity metrics and provides
99 * data for Tron, logcat, event logs and {@link android.app.WaitResult}.
100 *
101 * Tests:
Tadashi G. Takaoka28bc3702019-04-23 11:01:48 +0900102 * atest CtsWindowManagerDeviceTestCases:ActivityMetricsLoggerTests
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800103 */
104class ActivityMetricsLogger {
Jorim Jaggif9704102016-05-05 19:14:22 -0700105
Wale Ogunwale98875612018-10-12 07:53:02 -0700106 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_ATM;
Jorim Jaggif9704102016-05-05 19:14:22 -0700107
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800108 // Window modes we are interested in logging. If we ever introduce a new type, we need to add
109 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array.
110 private static final int WINDOW_STATE_STANDARD = 0;
111 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1;
112 private static final int WINDOW_STATE_FREEFORM = 2;
Winson Chung83471632016-12-13 11:02:12 -0800113 private static final int WINDOW_STATE_ASSISTANT = 3;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800114 private static final int WINDOW_STATE_INVALID = -1;
115
Jorim Jaggi275561a2016-02-23 10:11:02 -0500116 private static final long INVALID_START_TIME = -1;
Vishnu Nair132ee832018-09-28 15:00:05 -0700117 private static final int INVALID_DELAY = -1;
118 private static final int INVALID_TRANSITION_TYPE = -1;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500119
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200120 private static final int MSG_CHECK_VISIBILITY = 0;
121
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800122 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every
123 // time we log.
124 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = {
Winson Chung83471632016-12-13 11:02:12 -0800125 "window_time_0", "window_time_1", "window_time_2", "window_time_3"};
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800126
127 private int mWindowState = WINDOW_STATE_STANDARD;
128 private long mLastLogTimeSecs;
129 private final ActivityStackSupervisor mSupervisor;
130 private final Context mContext;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800131 private final MetricsLogger mMetricsLogger = new MetricsLogger();
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800132
Igor Murashkin212d06c2018-10-22 16:34:39 -0700133 // set to INVALID_START_TIME in reset.
134 // set to valid value in notifyActivityLaunching
Jorim Jaggi275561a2016-02-23 10:11:02 -0500135 private long mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200136 private long mLastTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800137
138 private int mCurrentTransitionDeviceUptime;
139 private int mCurrentTransitionDelayMs;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700140
141 /** If the any app transitions have been logged as starting, after the latest reset. */
Jorim Jaggi275561a2016-02-23 10:11:02 -0500142 private boolean mLoggedTransitionStarting;
143
Igor Murashkin212d06c2018-10-22 16:34:39 -0700144 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100145 private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo =
146 new SparseArray<>();
Igor Murashkin212d06c2018-10-22 16:34:39 -0700147 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100148 private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo =
149 new SparseArray<>();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200150 private final H mHandler;
Calin Juravle759fbda2018-02-20 19:52:30 +0000151
152 private ArtManagerInternal mArtManagerInternal;
Vishnu Nair132ee832018-09-28 15:00:05 -0700153 private final StringBuilder mStringBuilder = new StringBuilder();
Calin Juravle759fbda2018-02-20 19:52:30 +0000154
Igor Murashkin212d06c2018-10-22 16:34:39 -0700155 /**
156 * Due to the global single concurrent launch sequence, all calls to this observer must be made
157 * in-order on the same thread to fulfill the "happens-before" guarantee in LaunchObserver.
158 */
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800159 private final LaunchObserverRegistryImpl mLaunchObserver;
160 @VisibleForTesting static final int LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE = 512;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700161
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200162 private final class H extends Handler {
163
164 public H(Looper looper) {
165 super(looper);
166 }
167
168 @Override
169 public void handleMessage(Message msg) {
170 switch (msg.what) {
171 case MSG_CHECK_VISIBILITY:
172 final SomeArgs args = (SomeArgs) msg.obj;
173 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2);
174 break;
175 }
176 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000177 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800178
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100179 private final class WindowingModeTransitionInfo {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700180 /** The latest activity to have been launched. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800181 private ActivityRecord launchedActivity;
182 private int startResult;
183 private boolean currentTransitionProcessRunning;
Vishnu Nair132ee832018-09-28 15:00:05 -0700184 /** Elapsed time from when we launch an activity to when its windows are drawn. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800185 private int windowsDrawnDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700186 private int startingWindowDelayMs = INVALID_DELAY;
187 private int bindApplicationDelayMs = INVALID_DELAY;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800188 private int reason = APP_TRANSITION_TIMEOUT;
189 private boolean loggedWindowsDrawn;
190 private boolean loggedStartingWindowDrawn;
Vishnu Nair132ee832018-09-28 15:00:05 -0700191 private boolean launchTraceActive;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800192 }
193
Vishnu Nair132ee832018-09-28 15:00:05 -0700194 final class WindowingModeTransitionInfoSnapshot {
Calin Juravle759fbda2018-02-20 19:52:30 +0000195 final private ApplicationInfo applicationInfo;
Wale Ogunwalef6733932018-06-27 05:14:34 -0700196 final private WindowProcessController processRecord;
Vishnu Nair132ee832018-09-28 15:00:05 -0700197 final String packageName;
198 final String launchedActivityName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000199 final private String launchedActivityLaunchedFromPackage;
200 final private String launchedActivityLaunchToken;
201 final private String launchedActivityAppRecordRequiredAbi;
Vishnu Nair132ee832018-09-28 15:00:05 -0700202 final String launchedActivityShortComponentName;
Ng Zhi An83473542018-02-20 09:02:14 -0800203 final private String processName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000204 final private int reason;
205 final private int startingWindowDelayMs;
206 final private int bindApplicationDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700207 final int windowsDrawnDelayMs;
208 final int type;
209 final int userId;
210 /**
211 * Elapsed time from when we launch an activity to when the app reported it was
212 * fully drawn. If this is not reported then the value is set to INVALID_DELAY.
213 */
214 final int windowsFullyDrawnDelayMs;
215 final int activityRecordIdHashCode;
Calin Juravle759fbda2018-02-20 19:52:30 +0000216
217 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700218 this(info, info.launchedActivity);
219 }
220
221 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
222 ActivityRecord launchedActivity) {
223 this(info, launchedActivity, INVALID_DELAY);
224 }
225
226 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
227 ActivityRecord launchedActivity, int windowsFullyDrawnDelayMs) {
228 applicationInfo = launchedActivity.appInfo;
229 packageName = launchedActivity.packageName;
230 launchedActivityName = launchedActivity.info.name;
231 launchedActivityLaunchedFromPackage = launchedActivity.launchedFromPackage;
232 launchedActivityLaunchToken = launchedActivity.info.launchToken;
233 launchedActivityAppRecordRequiredAbi = launchedActivity.app == null
Calin Juravle759fbda2018-02-20 19:52:30 +0000234 ? null
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700235 : launchedActivity.app.getRequiredAbi();
Calin Juravle759fbda2018-02-20 19:52:30 +0000236 reason = info.reason;
237 startingWindowDelayMs = info.startingWindowDelayMs;
238 bindApplicationDelayMs = info.bindApplicationDelayMs;
239 windowsDrawnDelayMs = info.windowsDrawnDelayMs;
240 type = getTransitionType(info);
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700241 processRecord = findProcessForActivity(launchedActivity);
242 processName = launchedActivity.processName;
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800243 userId = launchedActivity.mUserId;
Vishnu Nair132ee832018-09-28 15:00:05 -0700244 launchedActivityShortComponentName = launchedActivity.shortComponentName;
245 activityRecordIdHashCode = System.identityHashCode(launchedActivity);
246 this.windowsFullyDrawnDelayMs = windowsFullyDrawnDelayMs;
Calin Juravle759fbda2018-02-20 19:52:30 +0000247 }
Vishnu Nairbb9ab4b2018-12-13 10:29:46 -0800248
249 @WaitResult.LaunchState int getLaunchState() {
250 switch (type) {
251 case TYPE_TRANSITION_WARM_LAUNCH:
252 return LAUNCH_STATE_WARM;
253 case TYPE_TRANSITION_HOT_LAUNCH:
254 return LAUNCH_STATE_HOT;
255 case TYPE_TRANSITION_COLD_LAUNCH:
256 return LAUNCH_STATE_COLD;
257 default:
258 return -1;
259 }
260 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000261 }
262
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200263 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper) {
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800264 mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000;
265 mSupervisor = supervisor;
266 mContext = context;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200267 mHandler = new H(looper);
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800268 mLaunchObserver = new LaunchObserverRegistryImpl(looper);
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800269 }
270
271 void logWindowState() {
272 final long now = SystemClock.elapsedRealtime() / 1000;
273 if (mWindowState != WINDOW_STATE_INVALID) {
274 // We log even if the window state hasn't changed, because the user might remain in
275 // home/fullscreen move forever and we would like to track this kind of behavior
276 // too.
277 MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState],
278 (int) (now - mLastLogTimeSecs));
279 }
280 mLastLogTimeSecs = now;
281
Wale Ogunwale926aade2017-08-29 11:24:37 -0700282 mWindowState = WINDOW_STATE_INVALID;
Wale Ogunwaled32da472018-11-16 07:19:28 -0800283 ActivityStack stack =
284 mSupervisor.mRootActivityContainer.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) {
Wale Ogunwaled32da472018-11-16 07:19:28 -0800296 stack = mSupervisor.mRootActivityContainer.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 Jaggi6cb6ba52019-05-06 14:14:22 +0200329 if (mCurrentTransitionStartTime == INVALID_START_TIME) {
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 }
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800522 final TaskRecord t = activityRecord.getTaskRecord();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200523 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
Vishnu Nairb1de42d2019-01-28 09:49:51 -0800529 private boolean hasVisibleNonFinishingActivity(TaskRecord t) {
530 for (int i = t.mActivities.size() - 1; i >= 0; --i) {
531 final ActivityRecord r = t.mActivities.get(i);
532 if (r.visible && !r.finishing) {
533 return true;
534 }
535 }
536 return false;
537 }
538
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200539 private void checkVisibility(TaskRecord t, ActivityRecord r) {
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700540 synchronized (mSupervisor.mService.mGlobalLock) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200541
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100542 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
543 r.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200544
545 // If we have an active transition that's waiting on a certain activity that will be
546 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
Vishnu Naird15063b2019-06-11 08:08:25 -0700547
548 // We have no active transitions.
549 if (info == null) {
550 return;
551 }
552
553 // The notified activity whose visibility changed is no longer the launched activity.
554 // We can still wait to get onWindowsDrawn.
555 if (info.launchedActivity != r) {
556 return;
557 }
558
559 // Check if there is any activity in the task that is visible and not finishing. If the
560 // launched activity finished before it is drawn and if there is another activity in
561 // the task then that activity will be draw on screen.
562 if (hasVisibleNonFinishingActivity(t)) {
563 return;
564 }
565
566 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible activity=" + r);
567 logAppTransitionCancel(info);
568 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
569 if (mWindowingModeTransitionInfo.size() == 0) {
570 reset(true /* abort */, info, "notifyVisibilityChanged to invisible");
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200571 }
572 }
573 }
574
Jorim Jaggi515dd682017-05-05 15:05:07 +0200575 /**
576 * Notifies the tracker that we called immediately before we call bindApplication on the client.
577 *
Wale Ogunwale31913b52018-10-13 08:29:31 -0700578 * @param appInfo The client into which we'll call bindApplication.
Jorim Jaggi515dd682017-05-05 15:05:07 +0200579 */
Wale Ogunwale31913b52018-10-13 08:29:31 -0700580 void notifyBindApplication(ApplicationInfo appInfo) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100581 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
582 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200583
584 // App isn't attached to record yet, so match with info.
Wale Ogunwale31913b52018-10-13 08:29:31 -0700585 if (info.launchedActivity.appInfo == appInfo) {
Jorim Jaggi515dd682017-05-05 15:05:07 +0200586 info.bindApplicationDelayMs = calculateCurrentDelay();
587 }
588 }
589 }
590
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100591 private boolean allWindowsDrawn() {
592 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
593 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800594 return false;
595 }
596 }
597 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500598 }
599
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800600 private boolean isAnyTransitionActive() {
601 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100602 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800603 }
604
Igor Murashkin212d06c2018-10-22 16:34:39 -0700605 private void reset(boolean abort, WindowingModeTransitionInfo info, String cause) {
606 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort + ",cause=" + cause);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800607 if (!abort && isAnyTransitionActive()) {
608 logAppTransitionMultiEvents();
609 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700610 stopLaunchTrace(info);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700611
612 // Ignore reset-after reset.
613 if (isAnyTransitionActive()) {
614 // LaunchObserver callbacks.
615 if (abort) {
616 launchObserverNotifyActivityLaunchCancelled(info);
617 } else {
618 launchObserverNotifyActivityLaunchFinished(info);
619 }
620 } else {
621 launchObserverNotifyIntentFailed();
622 }
623
Jorim Jaggi275561a2016-02-23 10:11:02 -0500624 mCurrentTransitionStartTime = INVALID_START_TIME;
Vishnu Nair132ee832018-09-28 15:00:05 -0700625 mCurrentTransitionDelayMs = INVALID_DELAY;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500626 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100627 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500628 }
629
630 private int calculateCurrentDelay() {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500631 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400632 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500633 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800634
Sudheer Shankac766db02017-06-12 10:37:29 -0700635 private int calculateDelay(long timestamp) {
636 // Shouldn't take more than 25 days to launch an app, so int is fine here.
637 return (int) (timestamp - mCurrentTransitionStartTime);
638 }
639
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100640 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200641 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700642 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200643 return;
644 }
645 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
646 builder.setPackageName(info.launchedActivity.packageName);
647 builder.setType(type);
648 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
649 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000650 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800651 StatsLog.APP_START_CANCELED,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000652 info.launchedActivity.appInfo.uid,
653 info.launchedActivity.packageName,
654 convertAppStartTransitionType(type),
655 info.launchedActivity.info.name);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700656 if (DEBUG_METRICS) {
657 Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)",
658 info.launchedActivity.appInfo.uid,
659 info.launchedActivity.packageName,
660 convertAppStartTransitionType(type),
661 info.launchedActivity.info.name));
662 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200663 }
664
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800665 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200666 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100667 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
668 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800669 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700670 if (type == INVALID_TRANSITION_TYPE) {
Vishnu Nair194c64f2019-04-12 13:51:40 -0700671 if (DEBUG_METRICS) {
672 Slog.i(TAG, "invalid transition type"
673 + " processRunning=" + info.currentTransitionProcessRunning
674 + " startResult=" + info.startResult);
675 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800676 return;
677 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000678
679 // Take a snapshot of the transition info before sending it to the handler for logging.
680 // This will avoid any races with other operations that modify the ActivityRecord.
681 final WindowingModeTransitionInfoSnapshot infoSnapshot =
682 new WindowingModeTransitionInfoSnapshot(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800683 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime;
684 final int currentTransitionDelayMs = mCurrentTransitionDelayMs;
685 BackgroundThread.getHandler().post(() -> logAppTransition(
686 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot));
Vishnu Nair132ee832018-09-28 15:00:05 -0700687 BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot));
Calin Juravle759fbda2018-02-20 19:52:30 +0000688
689 info.launchedActivity.info.launchToken = null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800690 }
691 }
692
Ng Zhi An83473542018-02-20 09:02:14 -0800693 // This gets called on a background thread without holding the activity manager lock.
Calin Juravle759fbda2018-02-20 19:52:30 +0000694 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
695 WindowingModeTransitionInfoSnapshot info) {
696 final LogMaker builder = new LogMaker(APP_TRANSITION);
697 builder.setPackageName(info.packageName);
698 builder.setType(info.type);
699 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
700 final boolean isInstantApp = info.applicationInfo.isInstantApp();
701 if (info.launchedActivityLaunchedFromPackage != null) {
702 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
703 info.launchedActivityLaunchedFromPackage);
704 }
705 String launchToken = info.launchedActivityLaunchToken;
706 if (launchToken != null) {
707 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
708 }
709 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
710 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
711 currentTransitionDeviceUptime);
712 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
713 builder.setSubtype(info.reason);
Vishnu Nair132ee832018-09-28 15:00:05 -0700714 if (info.startingWindowDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000715 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
716 info.startingWindowDelayMs);
717 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700718 if (info.bindApplicationDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000719 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
720 info.bindApplicationDelayMs);
721 }
722 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
723 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
724 final PackageOptimizationInfo packageOptimizationInfo =
725 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
726 ? PackageOptimizationInfo.createWithNoInfo()
727 : artManagerInternal.getPackageOptimizationInfo(
728 info.applicationInfo,
729 info.launchedActivityAppRecordRequiredAbi);
730 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
731 packageOptimizationInfo.getCompilationReason());
732 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
733 packageOptimizationInfo.getCompilationFilter());
734 mMetricsLogger.write(builder);
735 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800736 StatsLog.APP_START_OCCURRED,
Calin Juravle759fbda2018-02-20 19:52:30 +0000737 info.applicationInfo.uid,
738 info.packageName,
739 convertAppStartTransitionType(info.type),
740 info.launchedActivityName,
741 info.launchedActivityLaunchedFromPackage,
742 isInstantApp,
743 currentTransitionDeviceUptime * 1000,
744 info.reason,
745 currentTransitionDelayMs,
746 info.startingWindowDelayMs,
747 info.bindApplicationDelayMs,
748 info.windowsDrawnDelayMs,
749 launchToken,
750 packageOptimizationInfo.getCompilationReason(),
751 packageOptimizationInfo.getCompilationFilter());
Igor Murashkin212d06c2018-10-22 16:34:39 -0700752
753 if (DEBUG_METRICS) {
754 Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)",
755 info.applicationInfo.uid,
756 info.packageName,
757 convertAppStartTransitionType(info.type),
758 info.launchedActivityName,
759 info.launchedActivityLaunchedFromPackage));
760 }
761
762
Ng Zhi An83473542018-02-20 09:02:14 -0800763 logAppStartMemoryStateCapture(info);
Calin Juravle759fbda2018-02-20 19:52:30 +0000764 }
765
Vishnu Nair132ee832018-09-28 15:00:05 -0700766 private void logAppDisplayed(WindowingModeTransitionInfoSnapshot info) {
767 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
768 return;
769 }
770
771 EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME,
772 info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,
773 info.windowsDrawnDelayMs);
774
775 StringBuilder sb = mStringBuilder;
776 sb.setLength(0);
777 sb.append("Displayed ");
778 sb.append(info.launchedActivityShortComponentName);
779 sb.append(": ");
780 TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb);
781 Log.i(TAG, sb.toString());
782 }
783
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000784 private int convertAppStartTransitionType(int tronType) {
785 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800786 return StatsLog.APP_START_OCCURRED__TYPE__COLD;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000787 }
788 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800789 return StatsLog.APP_START_OCCURRED__TYPE__WARM;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000790 }
791 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800792 return StatsLog.APP_START_OCCURRED__TYPE__HOT;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000793 }
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800794 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000795 }
796
Vishnu Nair132ee832018-09-28 15:00:05 -0700797 WindowingModeTransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r,
798 boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100799 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
800 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200801 if (info == null) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700802 return null;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200803 }
Chris Wailes35c193c2018-10-09 18:12:00 -0700804
805 // Record the handling of the reportFullyDrawn callback in the trace system. This is not
806 // actually used to trace this function, but instead the logical task that this function
807 // fullfils (handling reportFullyDrawn() callbacks).
808 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
809 "ActivityManager:ReportingFullyDrawn " + info.launchedActivity.packageName);
810
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200811 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
812 builder.setPackageName(r.packageName);
813 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000814 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
815 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200816 builder.setType(restoredFromBundle
817 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
818 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
819 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
820 info.currentTransitionProcessRunning ? 1 : 0);
821 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000822 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800823 StatsLog.APP_START_FULLY_DRAWN,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000824 info.launchedActivity.appInfo.uid,
825 info.launchedActivity.packageName,
826 restoredFromBundle
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800827 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE
828 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000829 info.launchedActivity.info.name,
830 info.currentTransitionProcessRunning,
831 startupTimeMs);
Chris Wailes35c193c2018-10-09 18:12:00 -0700832
833 // Ends the trace started at the beginning of this function. This is located here to allow
834 // the trace slice to have a noticable duration.
835 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
836
Vishnu Nair132ee832018-09-28 15:00:05 -0700837 final WindowingModeTransitionInfoSnapshot infoSnapshot =
838 new WindowingModeTransitionInfoSnapshot(info, r, (int) startupTimeMs);
839 BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot));
840 return infoSnapshot;
841 }
842
843 private void logAppFullyDrawn(WindowingModeTransitionInfoSnapshot info) {
844 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
845 return;
846 }
847
848 StringBuilder sb = mStringBuilder;
849 sb.setLength(0);
850 sb.append("Fully drawn ");
851 sb.append(info.launchedActivityShortComponentName);
852 sb.append(": ");
853 TimeUtils.formatDuration(info.windowsFullyDrawnDelayMs, sb);
854 Log.i(TAG, sb.toString());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200855 }
856
Michal Karpinski4fd5b842019-01-28 15:13:32 +0000857 void logAbortedBgActivityStart(Intent intent, WindowProcessController callerApp,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100858 int callingUid, String callingPackage, int callingUidProcState,
859 boolean callingUidHasAnyVisibleWindow,
860 int realCallingUid, int realCallingUidProcState,
861 boolean realCallingUidHasAnyVisibleWindow,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100862 boolean comingFromPendingIntent) {
863
864 final long nowElapsed = SystemClock.elapsedRealtime();
865 final long nowUptime = SystemClock.uptimeMillis();
866 final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START);
867 builder.setTimestamp(System.currentTimeMillis());
868 builder.addTaggedData(FIELD_CALLING_UID, callingUid);
869 builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage);
870 builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE,
871 processStateAmToProto(callingUidProcState));
872 builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
873 callingUidHasAnyVisibleWindow ? 1 : 0);
874 builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid);
875 builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE,
876 processStateAmToProto(realCallingUidProcState));
877 builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
878 realCallingUidHasAnyVisibleWindow ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100879 builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0);
Michal Karpinski8596ded2018-11-14 14:43:48 +0000880 if (intent != null) {
881 builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction());
Michal Karpinski319069b2019-03-27 15:46:50 +0000882 ComponentName component = intent.getComponent();
883 if (component != null) {
884 builder.addTaggedData(FIELD_TARGET_SHORT_COMPONENT_NAME,
885 component.flattenToShortString());
886 }
Michal Karpinski8596ded2018-11-14 14:43:48 +0000887 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100888 if (callerApp != null) {
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700889 builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100890 builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700891 processStateAmToProto(callerApp.getCurrentProcState()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100892 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700893 callerApp.hasClientActivities() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100894 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES,
895 callerApp.hasForegroundServices() ? 1 : 0);
896 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700897 callerApp.hasForegroundActivities() ? 1 : 0);
898 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100899 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700900 callerApp.hasOverlayUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100901 builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700902 callerApp.hasPendingUiClean() ? 1 : 0);
903 if (callerApp.getInteractionEventTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100904 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700905 (nowElapsed - callerApp.getInteractionEventTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100906 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700907 if (callerApp.getFgInteractionTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100908 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700909 (nowElapsed - callerApp.getFgInteractionTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100910 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700911 if (callerApp.getWhenUnimportant() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100912 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700913 (nowUptime - callerApp.getWhenUnimportant()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100914 }
915 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100916 mMetricsLogger.write(builder);
917 }
918
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100919 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800920 if (info.currentTransitionProcessRunning) {
921 if (info.startResult == START_SUCCESS) {
922 return TYPE_TRANSITION_WARM_LAUNCH;
923 } else if (info.startResult == START_TASK_TO_FRONT) {
924 return TYPE_TRANSITION_HOT_LAUNCH;
925 }
Vishnu Nair194c64f2019-04-12 13:51:40 -0700926 } else if (info.startResult == START_SUCCESS
927 || (info.startResult == START_TASK_TO_FRONT)) {
928 // TaskRecord may still exist when cold launching an activity and the start
929 // result will be set to START_TASK_TO_FRONT. Treat this as a COLD launch.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800930 return TYPE_TRANSITION_COLD_LAUNCH;
931 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700932 return INVALID_TRANSITION_TYPE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800933 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800934
Ng Zhi An83473542018-02-20 09:02:14 -0800935 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
936 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800937 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
938 return;
939 }
940
Wale Ogunwalef6733932018-06-27 05:14:34 -0700941 final int pid = info.processRecord.getPid();
Ng Zhi An83473542018-02-20 09:02:14 -0800942 final int uid = info.applicationInfo.uid;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +0000943 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800944 if (memoryStat == null) {
945 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
946 return;
947 }
948
949 StatsLog.write(
950 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
951 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800952 info.processName,
953 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800954 memoryStat.pgfault,
955 memoryStat.pgmajfault,
956 memoryStat.rssInBytes,
957 memoryStat.cacheInBytes,
958 memoryStat.swapInBytes);
959 }
960
Wale Ogunwalef6733932018-06-27 05:14:34 -0700961 private WindowProcessController findProcessForActivity(ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800962 return launchedActivity != null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700963 ? mSupervisor.mService.mProcessNames.get(
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700964 launchedActivity.processName, launchedActivity.appInfo.uid)
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800965 : null;
966 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000967
968 private ArtManagerInternal getArtManagerInternal() {
969 if (mArtManagerInternal == null) {
970 // Note that this may be null.
971 // ArtManagerInternal is registered during PackageManagerService
972 // initialization which happens after ActivityManagerService.
973 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
974 }
975 return mArtManagerInternal;
976 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700977
978 /**
Chris Wailes35c193c2018-10-09 18:12:00 -0700979 * Starts traces for app launch.
Vishnu Nair132ee832018-09-28 15:00:05 -0700980 *
981 * @param info
982 * */
983 private void startTraces(WindowingModeTransitionInfo info) {
Ioannis Ilkos66e1cd82019-05-03 10:47:30 +0100984 if (!Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER) || info == null
985 || info.launchTraceActive) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700986 return;
987 }
Ioannis Ilkos66e1cd82019-05-03 10:47:30 +0100988 Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
989 + info.launchedActivity.packageName, 0);
990 info.launchTraceActive = true;
Vishnu Nair132ee832018-09-28 15:00:05 -0700991 }
992
993 private void stopLaunchTrace(WindowingModeTransitionInfo info) {
994 if (info == null) {
995 return;
996 }
997 if (info.launchTraceActive) {
998 Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
999 + info.launchedActivity.packageName, 0);
1000 info.launchTraceActive = false;
1001 }
1002 }
Igor Murashkin212d06c2018-10-22 16:34:39 -07001003
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001004 public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() {
1005 return mLaunchObserver;
1006 }
1007
Igor Murashkin212d06c2018-10-22 16:34:39 -07001008 /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */
1009 private void launchObserverNotifyIntentStarted(Intent intent) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001010 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1011 "MetricsLogger:launchObserverNotifyIntentStarted");
1012
1013 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1014 mLaunchObserver.onIntentStarted(intent);
1015
1016 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001017 }
1018
1019 /**
1020 * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has
1021 * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or
1022 * intent being delivered to the top running activity.
1023 */
1024 private void launchObserverNotifyIntentFailed() {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001025 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1026 "MetricsLogger:launchObserverNotifyIntentFailed");
1027
1028 mLaunchObserver.onIntentFailed();
1029
1030 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001031 }
1032
1033 /**
1034 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1035 * has started.
1036 */
1037 private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001038 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1039 "MetricsLogger:launchObserverNotifyActivityLaunched");
1040
Igor Murashkin212d06c2018-10-22 16:34:39 -07001041 @ActivityMetricsLaunchObserver.Temperature int temperature =
1042 convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info));
1043
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001044 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1045 mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.launchedActivity),
1046 temperature);
1047
1048 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001049 }
1050
1051 /**
1052 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is
1053 * cancelled.
1054 */
1055 private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001056 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1057 "MetricsLogger:launchObserverNotifyActivityLaunchCancelled");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001058
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001059 final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto =
1060 info != null ? convertActivityRecordToProto(info.launchedActivity) : null;
1061
1062 mLaunchObserver.onActivityLaunchCancelled(activityRecordProto);
1063
1064 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001065 }
1066
1067 /**
1068 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1069 * has fully finished (successfully).
1070 */
1071 private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001072 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1073 "MetricsLogger:launchObserverNotifyActivityLaunchFinished");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001074
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001075 mLaunchObserver.onActivityLaunchFinished(
1076 convertActivityRecordToProto(info.launchedActivity));
1077
1078 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1079 }
1080
1081 @VisibleForTesting
1082 static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[]
1083 convertActivityRecordToProto(ActivityRecord record) {
1084 // May take non-negligible amount of time to convert ActivityRecord into a proto,
1085 // so track the time.
1086 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1087 "MetricsLogger:convertActivityRecordToProto");
1088
1089 // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream,
1090 // so create a new one every time.
1091 final ProtoOutputStream protoOutputStream =
1092 new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE);
1093 // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object).
1094 record.writeToProto(protoOutputStream);
1095 final byte[] bytes = protoOutputStream.getBytes();
1096
1097 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1098
1099 return bytes;
Igor Murashkin212d06c2018-10-22 16:34:39 -07001100 }
1101
1102 private static @ActivityMetricsLaunchObserver.Temperature int
1103 convertTransitionTypeToLaunchObserverTemperature(int transitionType) {
1104 switch (transitionType) {
1105 case TYPE_TRANSITION_WARM_LAUNCH:
1106 return ActivityMetricsLaunchObserver.TEMPERATURE_WARM;
1107 case TYPE_TRANSITION_HOT_LAUNCH:
1108 return ActivityMetricsLaunchObserver.TEMPERATURE_HOT;
1109 case TYPE_TRANSITION_COLD_LAUNCH:
1110 return ActivityMetricsLaunchObserver.TEMPERATURE_COLD;
1111 default:
1112 return -1;
1113 }
1114 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -08001115}