blob: b6c62619c1c1dd420d329eb0d25fc43866fea1cd [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;
Yan Wang9eac5ec2019-09-30 15:42:18 -070095import java.util.concurrent.TimeUnit;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080096
97/**
Vishnu Nair132ee832018-09-28 15:00:05 -070098 * Listens to activity launches, transitions, visibility changes and window drawn callbacks to
99 * determine app launch times and draw delays. Source of truth for activity metrics and provides
100 * data for Tron, logcat, event logs and {@link android.app.WaitResult}.
101 *
102 * Tests:
Tadashi G. Takaoka28bc3702019-04-23 11:01:48 +0900103 * atest CtsWindowManagerDeviceTestCases:ActivityMetricsLoggerTests
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800104 */
105class ActivityMetricsLogger {
Jorim Jaggif9704102016-05-05 19:14:22 -0700106
Wale Ogunwale98875612018-10-12 07:53:02 -0700107 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_ATM;
Jorim Jaggif9704102016-05-05 19:14:22 -0700108
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800109 // Window modes we are interested in logging. If we ever introduce a new type, we need to add
110 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array.
111 private static final int WINDOW_STATE_STANDARD = 0;
112 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1;
113 private static final int WINDOW_STATE_FREEFORM = 2;
Winson Chung83471632016-12-13 11:02:12 -0800114 private static final int WINDOW_STATE_ASSISTANT = 3;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800115 private static final int WINDOW_STATE_INVALID = -1;
116
Jorim Jaggi275561a2016-02-23 10:11:02 -0500117 private static final long INVALID_START_TIME = -1;
Vishnu Nair132ee832018-09-28 15:00:05 -0700118 private static final int INVALID_DELAY = -1;
119 private static final int INVALID_TRANSITION_TYPE = -1;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500120
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200121 private static final int MSG_CHECK_VISIBILITY = 0;
122
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800123 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every
124 // time we log.
125 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = {
Winson Chung83471632016-12-13 11:02:12 -0800126 "window_time_0", "window_time_1", "window_time_2", "window_time_3"};
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800127
128 private int mWindowState = WINDOW_STATE_STANDARD;
129 private long mLastLogTimeSecs;
130 private final ActivityStackSupervisor mSupervisor;
131 private final Context mContext;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800132 private final MetricsLogger mMetricsLogger = new MetricsLogger();
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800133
Igor Murashkin212d06c2018-10-22 16:34:39 -0700134 // set to INVALID_START_TIME in reset.
135 // set to valid value in notifyActivityLaunching
Jorim Jaggi275561a2016-02-23 10:11:02 -0500136 private long mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200137 private long mLastTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800138
139 private int mCurrentTransitionDeviceUptime;
140 private int mCurrentTransitionDelayMs;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700141
142 /** If the any app transitions have been logged as starting, after the latest reset. */
Jorim Jaggi275561a2016-02-23 10:11:02 -0500143 private boolean mLoggedTransitionStarting;
144
Igor Murashkin212d06c2018-10-22 16:34:39 -0700145 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100146 private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo =
147 new SparseArray<>();
Igor Murashkin212d06c2018-10-22 16:34:39 -0700148 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100149 private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo =
150 new SparseArray<>();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200151 private final H mHandler;
Calin Juravle759fbda2018-02-20 19:52:30 +0000152
153 private ArtManagerInternal mArtManagerInternal;
Vishnu Nair132ee832018-09-28 15:00:05 -0700154 private final StringBuilder mStringBuilder = new StringBuilder();
Calin Juravle759fbda2018-02-20 19:52:30 +0000155
Igor Murashkin212d06c2018-10-22 16:34:39 -0700156 /**
157 * Due to the global single concurrent launch sequence, all calls to this observer must be made
158 * in-order on the same thread to fulfill the "happens-before" guarantee in LaunchObserver.
159 */
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800160 private final LaunchObserverRegistryImpl mLaunchObserver;
161 @VisibleForTesting static final int LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE = 512;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700162
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200163 private final class H extends Handler {
164
165 public H(Looper looper) {
166 super(looper);
167 }
168
169 @Override
170 public void handleMessage(Message msg) {
171 switch (msg.what) {
172 case MSG_CHECK_VISIBILITY:
173 final SomeArgs args = (SomeArgs) msg.obj;
174 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2);
175 break;
176 }
177 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000178 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800179
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100180 private final class WindowingModeTransitionInfo {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700181 /** The latest activity to have been launched. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800182 private ActivityRecord launchedActivity;
183 private int startResult;
184 private boolean currentTransitionProcessRunning;
Vishnu Nair132ee832018-09-28 15:00:05 -0700185 /** Elapsed time from when we launch an activity to when its windows are drawn. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800186 private int windowsDrawnDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700187 private int startingWindowDelayMs = INVALID_DELAY;
188 private int bindApplicationDelayMs = INVALID_DELAY;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800189 private int reason = APP_TRANSITION_TIMEOUT;
190 private boolean loggedWindowsDrawn;
191 private boolean loggedStartingWindowDrawn;
Vishnu Nair132ee832018-09-28 15:00:05 -0700192 private boolean launchTraceActive;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800193 }
194
Vishnu Nair132ee832018-09-28 15:00:05 -0700195 final class WindowingModeTransitionInfoSnapshot {
Calin Juravle759fbda2018-02-20 19:52:30 +0000196 final private ApplicationInfo applicationInfo;
Wale Ogunwalef6733932018-06-27 05:14:34 -0700197 final private WindowProcessController processRecord;
Vishnu Nair132ee832018-09-28 15:00:05 -0700198 final String packageName;
199 final String launchedActivityName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000200 final private String launchedActivityLaunchedFromPackage;
201 final private String launchedActivityLaunchToken;
202 final private String launchedActivityAppRecordRequiredAbi;
Vishnu Nair132ee832018-09-28 15:00:05 -0700203 final String launchedActivityShortComponentName;
Ng Zhi An83473542018-02-20 09:02:14 -0800204 final private String processName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000205 final private int reason;
206 final private int startingWindowDelayMs;
207 final private int bindApplicationDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700208 final int windowsDrawnDelayMs;
209 final int type;
210 final int userId;
211 /**
212 * Elapsed time from when we launch an activity to when the app reported it was
213 * fully drawn. If this is not reported then the value is set to INVALID_DELAY.
214 */
215 final int windowsFullyDrawnDelayMs;
216 final int activityRecordIdHashCode;
Calin Juravle759fbda2018-02-20 19:52:30 +0000217
218 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700219 this(info, info.launchedActivity);
220 }
221
222 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
223 ActivityRecord launchedActivity) {
224 this(info, launchedActivity, INVALID_DELAY);
225 }
226
227 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
228 ActivityRecord launchedActivity, int windowsFullyDrawnDelayMs) {
Andrii Kulianeceebbf2019-06-26 17:36:51 -0700229 applicationInfo = launchedActivity.info.applicationInfo;
Vishnu Nair132ee832018-09-28 15:00:05 -0700230 packageName = launchedActivity.packageName;
231 launchedActivityName = launchedActivity.info.name;
232 launchedActivityLaunchedFromPackage = launchedActivity.launchedFromPackage;
233 launchedActivityLaunchToken = launchedActivity.info.launchToken;
234 launchedActivityAppRecordRequiredAbi = launchedActivity.app == null
Calin Juravle759fbda2018-02-20 19:52:30 +0000235 ? null
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700236 : launchedActivity.app.getRequiredAbi();
Calin Juravle759fbda2018-02-20 19:52:30 +0000237 reason = info.reason;
238 startingWindowDelayMs = info.startingWindowDelayMs;
239 bindApplicationDelayMs = info.bindApplicationDelayMs;
240 windowsDrawnDelayMs = info.windowsDrawnDelayMs;
241 type = getTransitionType(info);
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700242 processRecord = findProcessForActivity(launchedActivity);
243 processName = launchedActivity.processName;
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800244 userId = launchedActivity.mUserId;
Vishnu Nair132ee832018-09-28 15:00:05 -0700245 launchedActivityShortComponentName = launchedActivity.shortComponentName;
246 activityRecordIdHashCode = System.identityHashCode(launchedActivity);
247 this.windowsFullyDrawnDelayMs = windowsFullyDrawnDelayMs;
Calin Juravle759fbda2018-02-20 19:52:30 +0000248 }
Vishnu Nairbb9ab4b2018-12-13 10:29:46 -0800249
250 @WaitResult.LaunchState int getLaunchState() {
251 switch (type) {
252 case TYPE_TRANSITION_WARM_LAUNCH:
253 return LAUNCH_STATE_WARM;
254 case TYPE_TRANSITION_HOT_LAUNCH:
255 return LAUNCH_STATE_HOT;
256 case TYPE_TRANSITION_COLD_LAUNCH:
257 return LAUNCH_STATE_COLD;
258 default:
259 return -1;
260 }
261 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000262 }
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;
Wale Ogunwaled32da472018-11-16 07:19:28 -0800284 ActivityStack stack =
285 mSupervisor.mRootActivityContainer.getTopDisplayFocusedStack();
lumarkf6c4a982018-06-15 15:43:12 +0800286 if (stack == null) {
287 return;
288 }
289
Wale Ogunwale926aade2017-08-29 11:24:37 -0700290 if (stack.isActivityTypeAssistant()) {
291 mWindowState = WINDOW_STATE_ASSISTANT;
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800292 return;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800293 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700294
Igor Murashkin212d06c2018-10-22 16:34:39 -0700295 @WindowingMode int windowingMode = stack.getWindowingMode();
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700296 if (windowingMode == WINDOWING_MODE_PINNED) {
Wale Ogunwaled32da472018-11-16 07:19:28 -0800297 stack = mSupervisor.mRootActivityContainer.findStackBehind(stack);
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700298 windowingMode = stack.getWindowingMode();
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800299 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700300 switch (windowingMode) {
301 case WINDOWING_MODE_FULLSCREEN:
302 mWindowState = WINDOW_STATE_STANDARD;
303 break;
304 case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY:
305 case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY:
306 mWindowState = WINDOW_STATE_SIDE_BY_SIDE;
307 break;
Bryce Lee6c605092017-10-12 11:14:49 -0700308 case WINDOWING_MODE_FREEFORM:
Wale Ogunwale926aade2017-08-29 11:24:37 -0700309 mWindowState = WINDOW_STATE_FREEFORM;
310 break;
311 default:
312 if (windowingMode != WINDOWING_MODE_UNDEFINED) {
313 throw new IllegalStateException("Unknown windowing mode for stack=" + stack
314 + " windowingMode=" + windowingMode);
315 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800316 }
317 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500318
319 /**
320 * Notifies the tracker at the earliest possible point when we are starting to launch an
321 * activity.
322 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700323 void notifyActivityLaunching(Intent intent) {
324 if (DEBUG_METRICS) {
325 Slog.i(TAG, String.format("notifyActivityLaunching: active:%b, intent:%s",
326 isAnyTransitionActive(),
327 intent));
328 }
329
Jorim Jaggi6cb6ba52019-05-06 14:14:22 +0200330 if (mCurrentTransitionStartTime == INVALID_START_TIME) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700331
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400332 mCurrentTransitionStartTime = SystemClock.uptimeMillis();
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200333 mLastTransitionStartTime = mCurrentTransitionStartTime;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700334
335 launchObserverNotifyIntentStarted(intent);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800336 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500337 }
338
339 /**
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700340 * Notifies the tracker that the activity is actually launching.
341 *
342 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
343 * launch
344 * @param launchedActivity the activity that is being launched
345 */
346 void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) {
Wale Ogunwalef6733932018-06-27 05:14:34 -0700347 final WindowProcessController processRecord = findProcessForActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700348 final boolean processRunning = processRecord != null;
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700349
350 // We consider this a "process switch" if the process of the activity that gets launched
351 // didn't have an activity that was in started state. In this case, we assume that lot
352 // of caches might be purged so the time until it produces the first frame is very
353 // interesting.
354 final boolean processSwitch = processRecord == null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700355 || !processRecord.hasStartedActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700356
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800357 notifyActivityLaunched(resultCode, launchedActivity, processRunning, processSwitch);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700358 }
359
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700360 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500361 * Notifies the tracker the the activity is actually launching.
362 *
363 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
364 * launch
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800365 * @param launchedActivity the activity being launched
Jorim Jaggi275561a2016-02-23 10:11:02 -0500366 * @param processRunning whether the process that will contains the activity is already running
Jorim Jaggibe67c902016-04-12 00:53:16 -0700367 * @param processSwitch whether the process that will contain the activity didn't have any
368 * activity that was stopped, i.e. the started activity is "switching"
369 * processes
Jorim Jaggi275561a2016-02-23 10:11:02 -0500370 */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800371 private void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity,
Jorim Jaggibe67c902016-04-12 00:53:16 -0700372 boolean processRunning, boolean processSwitch) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500373
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200374 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched"
375 + " resultCode=" + resultCode
376 + " launchedActivity=" + launchedActivity
377 + " processRunning=" + processRunning
378 + " processSwitch=" + processSwitch);
379
Igor Murashkin212d06c2018-10-22 16:34:39 -0700380 // If we are already in an existing transition, only update the activity name, but not the
381 // other attributes.
382 final @WindowingMode int windowingMode = launchedActivity != null
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100383 ? launchedActivity.getWindowingMode()
384 : WINDOWING_MODE_UNDEFINED;
Vishnu Nairf8accc52018-10-11 10:19:54 -0700385 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200386 if (mCurrentTransitionStartTime == INVALID_START_TIME) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700387 // No transition is active ignore this launch.
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200388 return;
389 }
390
Vishnu Nair9ba31652018-11-13 14:34:05 -0800391 if (launchedActivity != null && launchedActivity.mDrawn) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700392 // Launched activity is already visible. We cannot measure windows drawn delay.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700393 reset(true /* abort */, info, "launched activity already visible");
Vishnu Nairf8accc52018-10-11 10:19:54 -0700394 return;
395 }
396
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800397 if (launchedActivity != null && info != null) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700398 // If we are already in an existing transition, only update the activity name, but not
399 // the other attributes.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700400
401 // Coalesce multiple (trampoline) activities from a single sequence together.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800402 info.launchedActivity = launchedActivity;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500403 return;
404 }
405
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100406 final boolean otherWindowModesLaunching =
407 mWindowingModeTransitionInfo.size() > 0 && info == null;
Jorim Jaggi54cff642018-03-15 15:51:32 +0100408 if ((!isLoggableResultCode(resultCode) || launchedActivity == null || !processSwitch
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100409 || windowingMode == WINDOWING_MODE_UNDEFINED) && !otherWindowModesLaunching) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800410 // 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 -0700411 reset(true /* abort */, info, "failed to launch or not a process switch");
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800412 return;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100413 } else if (otherWindowModesLaunching) {
414 // Don't log this windowing mode but continue with the other windowing modes.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800415 return;
416 }
417
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200418 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful");
419
Igor Murashkin212d06c2018-10-22 16:34:39 -0700420 // A new launch sequence [with the windowingMode] has begun.
421 // Start tracking it.
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100422 final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo();
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800423 newInfo.launchedActivity = launchedActivity;
424 newInfo.currentTransitionProcessRunning = processRunning;
425 newInfo.startResult = resultCode;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100426 mWindowingModeTransitionInfo.put(windowingMode, newInfo);
427 mLastWindowingModeTransitionInfo.put(windowingMode, newInfo);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800428 mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000);
Vishnu Nair132ee832018-09-28 15:00:05 -0700429 startTraces(newInfo);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700430 launchObserverNotifyActivityLaunched(newInfo);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500431 }
432
433 /**
Jorim Jaggi54cff642018-03-15 15:51:32 +0100434 * @return True if we should start logging an event for an activity start that returned
435 * {@code resultCode} and that we'll indeed get a windows drawn event.
436 */
437 private boolean isLoggableResultCode(int resultCode) {
438 return resultCode == START_SUCCESS || resultCode == START_TASK_TO_FRONT;
439 }
440
441 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500442 * Notifies the tracker that all windows of the app have been drawn.
443 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700444 WindowingModeTransitionInfoSnapshot notifyWindowsDrawn(@WindowingMode int windowingMode,
445 long timestamp) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100446 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200447
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100448 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800449 if (info == null || info.loggedWindowsDrawn) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700450 return null;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500451 }
Sudheer Shankac766db02017-06-12 10:37:29 -0700452 info.windowsDrawnDelayMs = calculateDelay(timestamp);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800453 info.loggedWindowsDrawn = true;
Vishnu Nair132ee832018-09-28 15:00:05 -0700454 final WindowingModeTransitionInfoSnapshot infoSnapshot =
455 new WindowingModeTransitionInfoSnapshot(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100456 if (allWindowsDrawn() && mLoggedTransitionStarting) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700457 reset(false /* abort */, info, "notifyWindowsDrawn - all windows drawn");
Jorim Jaggi275561a2016-02-23 10:11:02 -0500458 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700459 return infoSnapshot;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500460 }
461
462 /**
463 * Notifies the tracker that the starting window was drawn.
464 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700465 void notifyStartingWindowDrawn(@WindowingMode int windowingMode, long timestamp) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100466 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800467 if (info == null || info.loggedStartingWindowDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500468 return;
469 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800470 info.loggedStartingWindowDrawn = true;
Sudheer Shankac766db02017-06-12 10:37:29 -0700471 info.startingWindowDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500472 }
473
474 /**
475 * Notifies the tracker that the app transition is starting.
476 *
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100477 * @param windowingModeToReason A map from windowing mode to a reason integer, which must be on
Vishnu Nair132ee832018-09-28 15:00:05 -0700478 * of ActivityTaskManagerInternal.APP_TRANSITION_* reasons.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500479 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100480 void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) {
Jorim Jaggid8a57772017-04-14 16:50:42 -0700481 if (!isAnyTransitionActive() || mLoggedTransitionStarting) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700482 // Ignore calls to this made after a reset and prior to notifyActivityLaunching.
483
484 // Ignore any subsequent notifyTransitionStarting until the next reset.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500485 return;
486 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200487 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting");
Sudheer Shankac766db02017-06-12 10:37:29 -0700488 mCurrentTransitionDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500489 mLoggedTransitionStarting = true;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700490
491 WindowingModeTransitionInfo foundInfo = null;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100492 for (int index = windowingModeToReason.size() - 1; index >= 0; index--) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700493 final @WindowingMode int windowingMode = windowingModeToReason.keyAt(index);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100494 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
495 windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800496 if (info == null) {
497 continue;
498 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100499 info.reason = windowingModeToReason.valueAt(index);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700500 foundInfo = info;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800501 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100502 if (allWindowsDrawn()) {
Vishnu Naira62534b2018-11-09 09:13:22 -0800503 // abort metrics collection if we cannot find a matching transition.
504 final boolean abortMetrics = foundInfo == null;
505 reset(abortMetrics, foundInfo, "notifyTransitionStarting - all windows drawn");
Jorim Jaggi275561a2016-02-23 10:11:02 -0500506 }
507 }
508
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200509 /**
510 * Notifies the tracker that the visibility of an app is changing.
511 *
512 * @param activityRecord the app that is changing its visibility
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200513 */
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200514 void notifyVisibilityChanged(ActivityRecord activityRecord) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100515 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
516 activityRecord.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200517 if (info == null) {
518 return;
519 }
520 if (info.launchedActivity != activityRecord) {
521 return;
522 }
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800523 final TaskRecord t = activityRecord.getTaskRecord();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200524 final SomeArgs args = SomeArgs.obtain();
525 args.arg1 = t;
526 args.arg2 = activityRecord;
527 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget();
528 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200529
Vishnu Nairb1de42d2019-01-28 09:49:51 -0800530 private boolean hasVisibleNonFinishingActivity(TaskRecord t) {
531 for (int i = t.mActivities.size() - 1; i >= 0; --i) {
532 final ActivityRecord r = t.mActivities.get(i);
533 if (r.visible && !r.finishing) {
534 return true;
535 }
536 }
537 return false;
538 }
539
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200540 private void checkVisibility(TaskRecord t, ActivityRecord r) {
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700541 synchronized (mSupervisor.mService.mGlobalLock) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200542
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100543 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
544 r.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200545
546 // If we have an active transition that's waiting on a certain activity that will be
547 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
Vishnu Naird15063b2019-06-11 08:08:25 -0700548
549 // We have no active transitions.
550 if (info == null) {
551 return;
552 }
553
554 // The notified activity whose visibility changed is no longer the launched activity.
555 // We can still wait to get onWindowsDrawn.
556 if (info.launchedActivity != r) {
557 return;
558 }
559
560 // Check if there is any activity in the task that is visible and not finishing. If the
561 // launched activity finished before it is drawn and if there is another activity in
562 // the task then that activity will be draw on screen.
563 if (hasVisibleNonFinishingActivity(t)) {
564 return;
565 }
566
567 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible activity=" + r);
568 logAppTransitionCancel(info);
569 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
570 if (mWindowingModeTransitionInfo.size() == 0) {
571 reset(true /* abort */, info, "notifyVisibilityChanged to invisible");
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200572 }
573 }
574 }
575
Jorim Jaggi515dd682017-05-05 15:05:07 +0200576 /**
577 * Notifies the tracker that we called immediately before we call bindApplication on the client.
578 *
Wale Ogunwale31913b52018-10-13 08:29:31 -0700579 * @param appInfo The client into which we'll call bindApplication.
Jorim Jaggi515dd682017-05-05 15:05:07 +0200580 */
Wale Ogunwale31913b52018-10-13 08:29:31 -0700581 void notifyBindApplication(ApplicationInfo appInfo) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100582 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
583 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200584
585 // App isn't attached to record yet, so match with info.
Andrii Kulianeceebbf2019-06-26 17:36:51 -0700586 if (info.launchedActivity.info.applicationInfo == appInfo) {
Jorim Jaggi515dd682017-05-05 15:05:07 +0200587 info.bindApplicationDelayMs = calculateCurrentDelay();
588 }
589 }
590 }
591
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100592 private boolean allWindowsDrawn() {
593 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
594 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800595 return false;
596 }
597 }
598 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500599 }
600
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800601 private boolean isAnyTransitionActive() {
602 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100603 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800604 }
605
Igor Murashkin212d06c2018-10-22 16:34:39 -0700606 private void reset(boolean abort, WindowingModeTransitionInfo info, String cause) {
607 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort + ",cause=" + cause);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800608 if (!abort && isAnyTransitionActive()) {
609 logAppTransitionMultiEvents();
610 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700611 stopLaunchTrace(info);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700612
613 // Ignore reset-after reset.
614 if (isAnyTransitionActive()) {
615 // LaunchObserver callbacks.
616 if (abort) {
617 launchObserverNotifyActivityLaunchCancelled(info);
618 } else {
619 launchObserverNotifyActivityLaunchFinished(info);
620 }
621 } else {
622 launchObserverNotifyIntentFailed();
623 }
624
Jorim Jaggi275561a2016-02-23 10:11:02 -0500625 mCurrentTransitionStartTime = INVALID_START_TIME;
Vishnu Nair132ee832018-09-28 15:00:05 -0700626 mCurrentTransitionDelayMs = INVALID_DELAY;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500627 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100628 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500629 }
630
631 private int calculateCurrentDelay() {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500632 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400633 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500634 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800635
Sudheer Shankac766db02017-06-12 10:37:29 -0700636 private int calculateDelay(long timestamp) {
637 // Shouldn't take more than 25 days to launch an app, so int is fine here.
638 return (int) (timestamp - mCurrentTransitionStartTime);
639 }
640
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100641 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200642 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700643 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200644 return;
645 }
646 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
647 builder.setPackageName(info.launchedActivity.packageName);
648 builder.setType(type);
649 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
650 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000651 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800652 StatsLog.APP_START_CANCELED,
Andrii Kulianeceebbf2019-06-26 17:36:51 -0700653 info.launchedActivity.info.applicationInfo.uid,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000654 info.launchedActivity.packageName,
655 convertAppStartTransitionType(type),
656 info.launchedActivity.info.name);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700657 if (DEBUG_METRICS) {
658 Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)",
Andrii Kulianeceebbf2019-06-26 17:36:51 -0700659 info.launchedActivity.info.applicationInfo.uid,
Igor Murashkin212d06c2018-10-22 16:34:39 -0700660 info.launchedActivity.packageName,
661 convertAppStartTransitionType(type),
662 info.launchedActivity.info.name));
663 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200664 }
665
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800666 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200667 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100668 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
669 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800670 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700671 if (type == INVALID_TRANSITION_TYPE) {
Vishnu Nair194c64f2019-04-12 13:51:40 -0700672 if (DEBUG_METRICS) {
673 Slog.i(TAG, "invalid transition type"
674 + " processRunning=" + info.currentTransitionProcessRunning
675 + " startResult=" + info.startResult);
676 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800677 return;
678 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000679
680 // Take a snapshot of the transition info before sending it to the handler for logging.
681 // This will avoid any races with other operations that modify the ActivityRecord.
682 final WindowingModeTransitionInfoSnapshot infoSnapshot =
683 new WindowingModeTransitionInfoSnapshot(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800684 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime;
685 final int currentTransitionDelayMs = mCurrentTransitionDelayMs;
686 BackgroundThread.getHandler().post(() -> logAppTransition(
687 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot));
Vishnu Nair132ee832018-09-28 15:00:05 -0700688 BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot));
Calin Juravle759fbda2018-02-20 19:52:30 +0000689
690 info.launchedActivity.info.launchToken = null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800691 }
692 }
693
Ng Zhi An83473542018-02-20 09:02:14 -0800694 // This gets called on a background thread without holding the activity manager lock.
Calin Juravle759fbda2018-02-20 19:52:30 +0000695 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
696 WindowingModeTransitionInfoSnapshot info) {
697 final LogMaker builder = new LogMaker(APP_TRANSITION);
698 builder.setPackageName(info.packageName);
699 builder.setType(info.type);
700 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
701 final boolean isInstantApp = info.applicationInfo.isInstantApp();
702 if (info.launchedActivityLaunchedFromPackage != null) {
703 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
704 info.launchedActivityLaunchedFromPackage);
705 }
706 String launchToken = info.launchedActivityLaunchToken;
707 if (launchToken != null) {
708 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
709 }
710 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
711 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
712 currentTransitionDeviceUptime);
713 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
714 builder.setSubtype(info.reason);
Vishnu Nair132ee832018-09-28 15:00:05 -0700715 if (info.startingWindowDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000716 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
717 info.startingWindowDelayMs);
718 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700719 if (info.bindApplicationDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000720 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
721 info.bindApplicationDelayMs);
722 }
723 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
724 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
725 final PackageOptimizationInfo packageOptimizationInfo =
726 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
727 ? PackageOptimizationInfo.createWithNoInfo()
728 : artManagerInternal.getPackageOptimizationInfo(
729 info.applicationInfo,
730 info.launchedActivityAppRecordRequiredAbi);
731 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
732 packageOptimizationInfo.getCompilationReason());
733 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
734 packageOptimizationInfo.getCompilationFilter());
735 mMetricsLogger.write(builder);
736 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800737 StatsLog.APP_START_OCCURRED,
Calin Juravle759fbda2018-02-20 19:52:30 +0000738 info.applicationInfo.uid,
739 info.packageName,
740 convertAppStartTransitionType(info.type),
741 info.launchedActivityName,
742 info.launchedActivityLaunchedFromPackage,
743 isInstantApp,
744 currentTransitionDeviceUptime * 1000,
745 info.reason,
746 currentTransitionDelayMs,
747 info.startingWindowDelayMs,
748 info.bindApplicationDelayMs,
749 info.windowsDrawnDelayMs,
750 launchToken,
751 packageOptimizationInfo.getCompilationReason(),
752 packageOptimizationInfo.getCompilationFilter());
Igor Murashkin212d06c2018-10-22 16:34:39 -0700753
754 if (DEBUG_METRICS) {
755 Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)",
756 info.applicationInfo.uid,
757 info.packageName,
758 convertAppStartTransitionType(info.type),
759 info.launchedActivityName,
760 info.launchedActivityLaunchedFromPackage));
761 }
762
763
Ng Zhi An83473542018-02-20 09:02:14 -0800764 logAppStartMemoryStateCapture(info);
Calin Juravle759fbda2018-02-20 19:52:30 +0000765 }
766
Vishnu Nair132ee832018-09-28 15:00:05 -0700767 private void logAppDisplayed(WindowingModeTransitionInfoSnapshot info) {
768 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
769 return;
770 }
771
772 EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME,
773 info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,
774 info.windowsDrawnDelayMs);
775
776 StringBuilder sb = mStringBuilder;
777 sb.setLength(0);
778 sb.append("Displayed ");
779 sb.append(info.launchedActivityShortComponentName);
780 sb.append(": ");
781 TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb);
782 Log.i(TAG, sb.toString());
783 }
784
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000785 private int convertAppStartTransitionType(int tronType) {
786 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800787 return StatsLog.APP_START_OCCURRED__TYPE__COLD;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000788 }
789 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800790 return StatsLog.APP_START_OCCURRED__TYPE__WARM;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000791 }
792 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800793 return StatsLog.APP_START_OCCURRED__TYPE__HOT;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000794 }
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800795 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000796 }
797
Vishnu Nair132ee832018-09-28 15:00:05 -0700798 WindowingModeTransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r,
799 boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100800 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
801 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200802 if (info == null) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700803 return null;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200804 }
Chris Wailes35c193c2018-10-09 18:12:00 -0700805
806 // Record the handling of the reportFullyDrawn callback in the trace system. This is not
807 // actually used to trace this function, but instead the logical task that this function
808 // fullfils (handling reportFullyDrawn() callbacks).
809 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
810 "ActivityManager:ReportingFullyDrawn " + info.launchedActivity.packageName);
811
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200812 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
813 builder.setPackageName(r.packageName);
814 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Yan Wang9eac5ec2019-09-30 15:42:18 -0700815 long currentTimestampNs = SystemClock.elapsedRealtimeNanos();
816 long startupTimeMs =
817 TimeUnit.NANOSECONDS.toMillis(currentTimestampNs) - mLastTransitionStartTime;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000818 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200819 builder.setType(restoredFromBundle
820 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
821 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
822 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
823 info.currentTransitionProcessRunning ? 1 : 0);
824 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000825 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800826 StatsLog.APP_START_FULLY_DRAWN,
Andrii Kulianeceebbf2019-06-26 17:36:51 -0700827 info.launchedActivity.info.applicationInfo.uid,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000828 info.launchedActivity.packageName,
829 restoredFromBundle
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800830 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE
831 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000832 info.launchedActivity.info.name,
833 info.currentTransitionProcessRunning,
834 startupTimeMs);
Chris Wailes35c193c2018-10-09 18:12:00 -0700835
836 // Ends the trace started at the beginning of this function. This is located here to allow
837 // the trace slice to have a noticable duration.
838 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
839
Vishnu Nair132ee832018-09-28 15:00:05 -0700840 final WindowingModeTransitionInfoSnapshot infoSnapshot =
841 new WindowingModeTransitionInfoSnapshot(info, r, (int) startupTimeMs);
842 BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot));
Yan Wang9eac5ec2019-09-30 15:42:18 -0700843
844 // Notify reportFullyDrawn event.
845 launchObserverNotifyReportFullyDrawn(r, currentTimestampNs);
846
Vishnu Nair132ee832018-09-28 15:00:05 -0700847 return infoSnapshot;
848 }
849
850 private void logAppFullyDrawn(WindowingModeTransitionInfoSnapshot info) {
851 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
852 return;
853 }
854
855 StringBuilder sb = mStringBuilder;
856 sb.setLength(0);
857 sb.append("Fully drawn ");
858 sb.append(info.launchedActivityShortComponentName);
859 sb.append(": ");
860 TimeUtils.formatDuration(info.windowsFullyDrawnDelayMs, sb);
861 Log.i(TAG, sb.toString());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200862 }
863
Michal Karpinski4fd5b842019-01-28 15:13:32 +0000864 void logAbortedBgActivityStart(Intent intent, WindowProcessController callerApp,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100865 int callingUid, String callingPackage, int callingUidProcState,
866 boolean callingUidHasAnyVisibleWindow,
867 int realCallingUid, int realCallingUidProcState,
868 boolean realCallingUidHasAnyVisibleWindow,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100869 boolean comingFromPendingIntent) {
870
871 final long nowElapsed = SystemClock.elapsedRealtime();
872 final long nowUptime = SystemClock.uptimeMillis();
873 final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START);
874 builder.setTimestamp(System.currentTimeMillis());
875 builder.addTaggedData(FIELD_CALLING_UID, callingUid);
876 builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage);
877 builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE,
878 processStateAmToProto(callingUidProcState));
879 builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
880 callingUidHasAnyVisibleWindow ? 1 : 0);
881 builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid);
882 builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE,
883 processStateAmToProto(realCallingUidProcState));
884 builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
885 realCallingUidHasAnyVisibleWindow ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100886 builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0);
Michal Karpinski8596ded2018-11-14 14:43:48 +0000887 if (intent != null) {
888 builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction());
Michal Karpinski319069b2019-03-27 15:46:50 +0000889 ComponentName component = intent.getComponent();
890 if (component != null) {
891 builder.addTaggedData(FIELD_TARGET_SHORT_COMPONENT_NAME,
892 component.flattenToShortString());
893 }
Michal Karpinski8596ded2018-11-14 14:43:48 +0000894 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100895 if (callerApp != null) {
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700896 builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100897 builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700898 processStateAmToProto(callerApp.getCurrentProcState()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100899 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700900 callerApp.hasClientActivities() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100901 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES,
902 callerApp.hasForegroundServices() ? 1 : 0);
903 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700904 callerApp.hasForegroundActivities() ? 1 : 0);
905 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100906 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700907 callerApp.hasOverlayUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100908 builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700909 callerApp.hasPendingUiClean() ? 1 : 0);
910 if (callerApp.getInteractionEventTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100911 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700912 (nowElapsed - callerApp.getInteractionEventTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100913 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700914 if (callerApp.getFgInteractionTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100915 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700916 (nowElapsed - callerApp.getFgInteractionTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100917 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700918 if (callerApp.getWhenUnimportant() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100919 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700920 (nowUptime - callerApp.getWhenUnimportant()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100921 }
922 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100923 mMetricsLogger.write(builder);
924 }
925
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100926 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800927 if (info.currentTransitionProcessRunning) {
928 if (info.startResult == START_SUCCESS) {
929 return TYPE_TRANSITION_WARM_LAUNCH;
930 } else if (info.startResult == START_TASK_TO_FRONT) {
931 return TYPE_TRANSITION_HOT_LAUNCH;
932 }
Vishnu Nair194c64f2019-04-12 13:51:40 -0700933 } else if (info.startResult == START_SUCCESS
934 || (info.startResult == START_TASK_TO_FRONT)) {
935 // TaskRecord may still exist when cold launching an activity and the start
936 // result will be set to START_TASK_TO_FRONT. Treat this as a COLD launch.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800937 return TYPE_TRANSITION_COLD_LAUNCH;
938 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700939 return INVALID_TRANSITION_TYPE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800940 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800941
Ng Zhi An83473542018-02-20 09:02:14 -0800942 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
943 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800944 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
945 return;
946 }
947
Wale Ogunwalef6733932018-06-27 05:14:34 -0700948 final int pid = info.processRecord.getPid();
Ng Zhi An83473542018-02-20 09:02:14 -0800949 final int uid = info.applicationInfo.uid;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +0000950 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800951 if (memoryStat == null) {
952 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
953 return;
954 }
955
956 StatsLog.write(
957 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
958 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800959 info.processName,
960 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800961 memoryStat.pgfault,
962 memoryStat.pgmajfault,
963 memoryStat.rssInBytes,
964 memoryStat.cacheInBytes,
965 memoryStat.swapInBytes);
966 }
967
Wale Ogunwalef6733932018-06-27 05:14:34 -0700968 private WindowProcessController findProcessForActivity(ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800969 return launchedActivity != null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700970 ? mSupervisor.mService.mProcessNames.get(
Andrii Kulianeceebbf2019-06-26 17:36:51 -0700971 launchedActivity.processName, launchedActivity.info.applicationInfo.uid)
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800972 : null;
973 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000974
975 private ArtManagerInternal getArtManagerInternal() {
976 if (mArtManagerInternal == null) {
977 // Note that this may be null.
978 // ArtManagerInternal is registered during PackageManagerService
979 // initialization which happens after ActivityManagerService.
980 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
981 }
982 return mArtManagerInternal;
983 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700984
985 /**
Chris Wailes35c193c2018-10-09 18:12:00 -0700986 * Starts traces for app launch.
Vishnu Nair132ee832018-09-28 15:00:05 -0700987 *
988 * @param info
989 * */
990 private void startTraces(WindowingModeTransitionInfo info) {
Ioannis Ilkos66e1cd82019-05-03 10:47:30 +0100991 if (!Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER) || info == null
992 || info.launchTraceActive) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700993 return;
994 }
Ioannis Ilkos66e1cd82019-05-03 10:47:30 +0100995 Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
996 + info.launchedActivity.packageName, 0);
997 info.launchTraceActive = true;
Vishnu Nair132ee832018-09-28 15:00:05 -0700998 }
999
1000 private void stopLaunchTrace(WindowingModeTransitionInfo info) {
1001 if (info == null) {
1002 return;
1003 }
1004 if (info.launchTraceActive) {
1005 Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
1006 + info.launchedActivity.packageName, 0);
1007 info.launchTraceActive = false;
1008 }
1009 }
Igor Murashkin212d06c2018-10-22 16:34:39 -07001010
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001011 public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() {
1012 return mLaunchObserver;
1013 }
1014
Igor Murashkin212d06c2018-10-22 16:34:39 -07001015 /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */
1016 private void launchObserverNotifyIntentStarted(Intent intent) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001017 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1018 "MetricsLogger:launchObserverNotifyIntentStarted");
1019
1020 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1021 mLaunchObserver.onIntentStarted(intent);
1022
1023 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001024 }
1025
1026 /**
1027 * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has
1028 * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or
1029 * intent being delivered to the top running activity.
1030 */
1031 private void launchObserverNotifyIntentFailed() {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001032 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1033 "MetricsLogger:launchObserverNotifyIntentFailed");
1034
1035 mLaunchObserver.onIntentFailed();
1036
1037 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001038 }
1039
1040 /**
1041 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1042 * has started.
1043 */
1044 private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001045 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1046 "MetricsLogger:launchObserverNotifyActivityLaunched");
1047
Igor Murashkin212d06c2018-10-22 16:34:39 -07001048 @ActivityMetricsLaunchObserver.Temperature int temperature =
1049 convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info));
1050
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001051 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1052 mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.launchedActivity),
1053 temperature);
1054
1055 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001056 }
1057
1058 /**
Yan Wang9eac5ec2019-09-30 15:42:18 -07001059 * Notifies the {@link ActivityMetricsLaunchObserver} the reportFullDrawn event.
1060 */
1061 private void launchObserverNotifyReportFullyDrawn(ActivityRecord r, long timestampNanos) {
1062 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1063 "MetricsLogger:launchObserverNotifyReportFullyDrawn");
1064 mLaunchObserver.onReportFullyDrawn(convertActivityRecordToProto(r), timestampNanos);
1065 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1066 }
1067
1068 /**
Igor Murashkin212d06c2018-10-22 16:34:39 -07001069 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is
1070 * cancelled.
1071 */
1072 private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001073 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1074 "MetricsLogger:launchObserverNotifyActivityLaunchCancelled");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001075
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001076 final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto =
1077 info != null ? convertActivityRecordToProto(info.launchedActivity) : null;
1078
1079 mLaunchObserver.onActivityLaunchCancelled(activityRecordProto);
1080
1081 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001082 }
1083
1084 /**
1085 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1086 * has fully finished (successfully).
1087 */
1088 private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001089 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1090 "MetricsLogger:launchObserverNotifyActivityLaunchFinished");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001091
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001092 mLaunchObserver.onActivityLaunchFinished(
1093 convertActivityRecordToProto(info.launchedActivity));
1094
1095 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1096 }
1097
1098 @VisibleForTesting
1099 static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[]
1100 convertActivityRecordToProto(ActivityRecord record) {
1101 // May take non-negligible amount of time to convert ActivityRecord into a proto,
1102 // so track the time.
1103 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1104 "MetricsLogger:convertActivityRecordToProto");
1105
1106 // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream,
1107 // so create a new one every time.
1108 final ProtoOutputStream protoOutputStream =
1109 new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE);
1110 // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object).
1111 record.writeToProto(protoOutputStream);
1112 final byte[] bytes = protoOutputStream.getBytes();
1113
1114 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1115
1116 return bytes;
Igor Murashkin212d06c2018-10-22 16:34:39 -07001117 }
1118
1119 private static @ActivityMetricsLaunchObserver.Temperature int
1120 convertTransitionTypeToLaunchObserverTemperature(int transitionType) {
1121 switch (transitionType) {
1122 case TYPE_TRANSITION_WARM_LAUNCH:
1123 return ActivityMetricsLaunchObserver.TEMPERATURE_WARM;
1124 case TYPE_TRANSITION_HOT_LAUNCH:
1125 return ActivityMetricsLaunchObserver.TEMPERATURE_HOT;
1126 case TYPE_TRANSITION_COLD_LAUNCH:
1127 return ActivityMetricsLaunchObserver.TEMPERATURE_COLD;
1128 default:
1129 return -1;
1130 }
1131 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -08001132}