blob: feef5e27d26a1fc526444e8b4b306d4ad1f815c4 [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 Nairb1de42d2019-01-28 09:49:51 -0800547 if (info != null && !hasVisibleNonFinishingActivity(t)) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200548 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible"
549 + " activity=" + r);
550 logAppTransitionCancel(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100551 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
552 if (mWindowingModeTransitionInfo.size() == 0) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700553 reset(true /* abort */, info, "notifyVisibilityChanged to invisible");
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200554 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200555 }
556 }
557 }
558
Jorim Jaggi515dd682017-05-05 15:05:07 +0200559 /**
560 * Notifies the tracker that we called immediately before we call bindApplication on the client.
561 *
Wale Ogunwale31913b52018-10-13 08:29:31 -0700562 * @param appInfo The client into which we'll call bindApplication.
Jorim Jaggi515dd682017-05-05 15:05:07 +0200563 */
Wale Ogunwale31913b52018-10-13 08:29:31 -0700564 void notifyBindApplication(ApplicationInfo appInfo) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100565 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
566 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200567
568 // App isn't attached to record yet, so match with info.
Wale Ogunwale31913b52018-10-13 08:29:31 -0700569 if (info.launchedActivity.appInfo == appInfo) {
Jorim Jaggi515dd682017-05-05 15:05:07 +0200570 info.bindApplicationDelayMs = calculateCurrentDelay();
571 }
572 }
573 }
574
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100575 private boolean allWindowsDrawn() {
576 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
577 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800578 return false;
579 }
580 }
581 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500582 }
583
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800584 private boolean isAnyTransitionActive() {
585 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100586 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800587 }
588
Igor Murashkin212d06c2018-10-22 16:34:39 -0700589 private void reset(boolean abort, WindowingModeTransitionInfo info, String cause) {
590 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort + ",cause=" + cause);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800591 if (!abort && isAnyTransitionActive()) {
592 logAppTransitionMultiEvents();
593 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700594 stopLaunchTrace(info);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700595
596 // Ignore reset-after reset.
597 if (isAnyTransitionActive()) {
598 // LaunchObserver callbacks.
599 if (abort) {
600 launchObserverNotifyActivityLaunchCancelled(info);
601 } else {
602 launchObserverNotifyActivityLaunchFinished(info);
603 }
604 } else {
605 launchObserverNotifyIntentFailed();
606 }
607
Jorim Jaggi275561a2016-02-23 10:11:02 -0500608 mCurrentTransitionStartTime = INVALID_START_TIME;
Vishnu Nair132ee832018-09-28 15:00:05 -0700609 mCurrentTransitionDelayMs = INVALID_DELAY;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500610 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100611 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500612 }
613
614 private int calculateCurrentDelay() {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500615 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400616 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500617 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800618
Sudheer Shankac766db02017-06-12 10:37:29 -0700619 private int calculateDelay(long timestamp) {
620 // Shouldn't take more than 25 days to launch an app, so int is fine here.
621 return (int) (timestamp - mCurrentTransitionStartTime);
622 }
623
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100624 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200625 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700626 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200627 return;
628 }
629 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
630 builder.setPackageName(info.launchedActivity.packageName);
631 builder.setType(type);
632 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
633 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000634 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800635 StatsLog.APP_START_CANCELED,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000636 info.launchedActivity.appInfo.uid,
637 info.launchedActivity.packageName,
638 convertAppStartTransitionType(type),
639 info.launchedActivity.info.name);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700640 if (DEBUG_METRICS) {
641 Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)",
642 info.launchedActivity.appInfo.uid,
643 info.launchedActivity.packageName,
644 convertAppStartTransitionType(type),
645 info.launchedActivity.info.name));
646 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200647 }
648
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800649 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200650 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100651 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
652 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800653 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700654 if (type == INVALID_TRANSITION_TYPE) {
Vishnu Nair194c64f2019-04-12 13:51:40 -0700655 if (DEBUG_METRICS) {
656 Slog.i(TAG, "invalid transition type"
657 + " processRunning=" + info.currentTransitionProcessRunning
658 + " startResult=" + info.startResult);
659 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800660 return;
661 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000662
663 // Take a snapshot of the transition info before sending it to the handler for logging.
664 // This will avoid any races with other operations that modify the ActivityRecord.
665 final WindowingModeTransitionInfoSnapshot infoSnapshot =
666 new WindowingModeTransitionInfoSnapshot(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800667 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime;
668 final int currentTransitionDelayMs = mCurrentTransitionDelayMs;
669 BackgroundThread.getHandler().post(() -> logAppTransition(
670 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot));
Vishnu Nair132ee832018-09-28 15:00:05 -0700671 BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot));
Calin Juravle759fbda2018-02-20 19:52:30 +0000672
673 info.launchedActivity.info.launchToken = null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800674 }
675 }
676
Ng Zhi An83473542018-02-20 09:02:14 -0800677 // This gets called on a background thread without holding the activity manager lock.
Calin Juravle759fbda2018-02-20 19:52:30 +0000678 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
679 WindowingModeTransitionInfoSnapshot info) {
680 final LogMaker builder = new LogMaker(APP_TRANSITION);
681 builder.setPackageName(info.packageName);
682 builder.setType(info.type);
683 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
684 final boolean isInstantApp = info.applicationInfo.isInstantApp();
685 if (info.launchedActivityLaunchedFromPackage != null) {
686 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
687 info.launchedActivityLaunchedFromPackage);
688 }
689 String launchToken = info.launchedActivityLaunchToken;
690 if (launchToken != null) {
691 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
692 }
693 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
694 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
695 currentTransitionDeviceUptime);
696 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
697 builder.setSubtype(info.reason);
Vishnu Nair132ee832018-09-28 15:00:05 -0700698 if (info.startingWindowDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000699 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
700 info.startingWindowDelayMs);
701 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700702 if (info.bindApplicationDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000703 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
704 info.bindApplicationDelayMs);
705 }
706 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
707 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
708 final PackageOptimizationInfo packageOptimizationInfo =
709 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
710 ? PackageOptimizationInfo.createWithNoInfo()
711 : artManagerInternal.getPackageOptimizationInfo(
712 info.applicationInfo,
713 info.launchedActivityAppRecordRequiredAbi);
714 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
715 packageOptimizationInfo.getCompilationReason());
716 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
717 packageOptimizationInfo.getCompilationFilter());
718 mMetricsLogger.write(builder);
719 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800720 StatsLog.APP_START_OCCURRED,
Calin Juravle759fbda2018-02-20 19:52:30 +0000721 info.applicationInfo.uid,
722 info.packageName,
723 convertAppStartTransitionType(info.type),
724 info.launchedActivityName,
725 info.launchedActivityLaunchedFromPackage,
726 isInstantApp,
727 currentTransitionDeviceUptime * 1000,
728 info.reason,
729 currentTransitionDelayMs,
730 info.startingWindowDelayMs,
731 info.bindApplicationDelayMs,
732 info.windowsDrawnDelayMs,
733 launchToken,
734 packageOptimizationInfo.getCompilationReason(),
735 packageOptimizationInfo.getCompilationFilter());
Igor Murashkin212d06c2018-10-22 16:34:39 -0700736
737 if (DEBUG_METRICS) {
738 Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)",
739 info.applicationInfo.uid,
740 info.packageName,
741 convertAppStartTransitionType(info.type),
742 info.launchedActivityName,
743 info.launchedActivityLaunchedFromPackage));
744 }
745
746
Ng Zhi An83473542018-02-20 09:02:14 -0800747 logAppStartMemoryStateCapture(info);
Calin Juravle759fbda2018-02-20 19:52:30 +0000748 }
749
Vishnu Nair132ee832018-09-28 15:00:05 -0700750 private void logAppDisplayed(WindowingModeTransitionInfoSnapshot info) {
751 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
752 return;
753 }
754
755 EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME,
756 info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,
757 info.windowsDrawnDelayMs);
758
759 StringBuilder sb = mStringBuilder;
760 sb.setLength(0);
761 sb.append("Displayed ");
762 sb.append(info.launchedActivityShortComponentName);
763 sb.append(": ");
764 TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb);
765 Log.i(TAG, sb.toString());
766 }
767
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000768 private int convertAppStartTransitionType(int tronType) {
769 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800770 return StatsLog.APP_START_OCCURRED__TYPE__COLD;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000771 }
772 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800773 return StatsLog.APP_START_OCCURRED__TYPE__WARM;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000774 }
775 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800776 return StatsLog.APP_START_OCCURRED__TYPE__HOT;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000777 }
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800778 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000779 }
780
Vishnu Nair132ee832018-09-28 15:00:05 -0700781 WindowingModeTransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r,
782 boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100783 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
784 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200785 if (info == null) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700786 return null;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200787 }
Chris Wailes35c193c2018-10-09 18:12:00 -0700788
789 // Record the handling of the reportFullyDrawn callback in the trace system. This is not
790 // actually used to trace this function, but instead the logical task that this function
791 // fullfils (handling reportFullyDrawn() callbacks).
792 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
793 "ActivityManager:ReportingFullyDrawn " + info.launchedActivity.packageName);
794
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200795 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
796 builder.setPackageName(r.packageName);
797 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000798 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
799 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200800 builder.setType(restoredFromBundle
801 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
802 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
803 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
804 info.currentTransitionProcessRunning ? 1 : 0);
805 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000806 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800807 StatsLog.APP_START_FULLY_DRAWN,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000808 info.launchedActivity.appInfo.uid,
809 info.launchedActivity.packageName,
810 restoredFromBundle
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800811 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE
812 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000813 info.launchedActivity.info.name,
814 info.currentTransitionProcessRunning,
815 startupTimeMs);
Chris Wailes35c193c2018-10-09 18:12:00 -0700816
817 // Ends the trace started at the beginning of this function. This is located here to allow
818 // the trace slice to have a noticable duration.
819 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
820
Vishnu Nair132ee832018-09-28 15:00:05 -0700821 final WindowingModeTransitionInfoSnapshot infoSnapshot =
822 new WindowingModeTransitionInfoSnapshot(info, r, (int) startupTimeMs);
823 BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot));
824 return infoSnapshot;
825 }
826
827 private void logAppFullyDrawn(WindowingModeTransitionInfoSnapshot info) {
828 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
829 return;
830 }
831
832 StringBuilder sb = mStringBuilder;
833 sb.setLength(0);
834 sb.append("Fully drawn ");
835 sb.append(info.launchedActivityShortComponentName);
836 sb.append(": ");
837 TimeUtils.formatDuration(info.windowsFullyDrawnDelayMs, sb);
838 Log.i(TAG, sb.toString());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200839 }
840
Michal Karpinski4fd5b842019-01-28 15:13:32 +0000841 void logAbortedBgActivityStart(Intent intent, WindowProcessController callerApp,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100842 int callingUid, String callingPackage, int callingUidProcState,
843 boolean callingUidHasAnyVisibleWindow,
844 int realCallingUid, int realCallingUidProcState,
845 boolean realCallingUidHasAnyVisibleWindow,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100846 boolean comingFromPendingIntent) {
847
848 final long nowElapsed = SystemClock.elapsedRealtime();
849 final long nowUptime = SystemClock.uptimeMillis();
850 final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START);
851 builder.setTimestamp(System.currentTimeMillis());
852 builder.addTaggedData(FIELD_CALLING_UID, callingUid);
853 builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage);
854 builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE,
855 processStateAmToProto(callingUidProcState));
856 builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
857 callingUidHasAnyVisibleWindow ? 1 : 0);
858 builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid);
859 builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE,
860 processStateAmToProto(realCallingUidProcState));
861 builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
862 realCallingUidHasAnyVisibleWindow ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100863 builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0);
Michal Karpinski8596ded2018-11-14 14:43:48 +0000864 if (intent != null) {
865 builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction());
Michal Karpinski319069b2019-03-27 15:46:50 +0000866 ComponentName component = intent.getComponent();
867 if (component != null) {
868 builder.addTaggedData(FIELD_TARGET_SHORT_COMPONENT_NAME,
869 component.flattenToShortString());
870 }
Michal Karpinski8596ded2018-11-14 14:43:48 +0000871 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100872 if (callerApp != null) {
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700873 builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100874 builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700875 processStateAmToProto(callerApp.getCurrentProcState()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100876 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700877 callerApp.hasClientActivities() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100878 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES,
879 callerApp.hasForegroundServices() ? 1 : 0);
880 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700881 callerApp.hasForegroundActivities() ? 1 : 0);
882 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100883 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700884 callerApp.hasOverlayUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100885 builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700886 callerApp.hasPendingUiClean() ? 1 : 0);
887 if (callerApp.getInteractionEventTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100888 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700889 (nowElapsed - callerApp.getInteractionEventTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100890 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700891 if (callerApp.getFgInteractionTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100892 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700893 (nowElapsed - callerApp.getFgInteractionTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100894 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700895 if (callerApp.getWhenUnimportant() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100896 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700897 (nowUptime - callerApp.getWhenUnimportant()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100898 }
899 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100900 mMetricsLogger.write(builder);
901 }
902
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100903 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800904 if (info.currentTransitionProcessRunning) {
905 if (info.startResult == START_SUCCESS) {
906 return TYPE_TRANSITION_WARM_LAUNCH;
907 } else if (info.startResult == START_TASK_TO_FRONT) {
908 return TYPE_TRANSITION_HOT_LAUNCH;
909 }
Vishnu Nair194c64f2019-04-12 13:51:40 -0700910 } else if (info.startResult == START_SUCCESS
911 || (info.startResult == START_TASK_TO_FRONT)) {
912 // TaskRecord may still exist when cold launching an activity and the start
913 // result will be set to START_TASK_TO_FRONT. Treat this as a COLD launch.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800914 return TYPE_TRANSITION_COLD_LAUNCH;
915 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700916 return INVALID_TRANSITION_TYPE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800917 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800918
Ng Zhi An83473542018-02-20 09:02:14 -0800919 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
920 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800921 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
922 return;
923 }
924
Wale Ogunwalef6733932018-06-27 05:14:34 -0700925 final int pid = info.processRecord.getPid();
Ng Zhi An83473542018-02-20 09:02:14 -0800926 final int uid = info.applicationInfo.uid;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +0000927 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800928 if (memoryStat == null) {
929 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
930 return;
931 }
932
933 StatsLog.write(
934 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
935 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800936 info.processName,
937 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800938 memoryStat.pgfault,
939 memoryStat.pgmajfault,
940 memoryStat.rssInBytes,
941 memoryStat.cacheInBytes,
942 memoryStat.swapInBytes);
943 }
944
Wale Ogunwalef6733932018-06-27 05:14:34 -0700945 private WindowProcessController findProcessForActivity(ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800946 return launchedActivity != null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700947 ? mSupervisor.mService.mProcessNames.get(
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700948 launchedActivity.processName, launchedActivity.appInfo.uid)
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800949 : null;
950 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000951
952 private ArtManagerInternal getArtManagerInternal() {
953 if (mArtManagerInternal == null) {
954 // Note that this may be null.
955 // ArtManagerInternal is registered during PackageManagerService
956 // initialization which happens after ActivityManagerService.
957 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
958 }
959 return mArtManagerInternal;
960 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700961
962 /**
Chris Wailes35c193c2018-10-09 18:12:00 -0700963 * Starts traces for app launch.
Vishnu Nair132ee832018-09-28 15:00:05 -0700964 *
965 * @param info
966 * */
967 private void startTraces(WindowingModeTransitionInfo info) {
Ioannis Ilkos66e1cd82019-05-03 10:47:30 +0100968 if (!Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER) || info == null
969 || info.launchTraceActive) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700970 return;
971 }
Ioannis Ilkos66e1cd82019-05-03 10:47:30 +0100972 Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
973 + info.launchedActivity.packageName, 0);
974 info.launchTraceActive = true;
Vishnu Nair132ee832018-09-28 15:00:05 -0700975 }
976
977 private void stopLaunchTrace(WindowingModeTransitionInfo info) {
978 if (info == null) {
979 return;
980 }
981 if (info.launchTraceActive) {
982 Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
983 + info.launchedActivity.packageName, 0);
984 info.launchTraceActive = false;
985 }
986 }
Igor Murashkin212d06c2018-10-22 16:34:39 -0700987
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800988 public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() {
989 return mLaunchObserver;
990 }
991
Igor Murashkin212d06c2018-10-22 16:34:39 -0700992 /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */
993 private void launchObserverNotifyIntentStarted(Intent intent) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800994 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
995 "MetricsLogger:launchObserverNotifyIntentStarted");
996
997 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
998 mLaunchObserver.onIntentStarted(intent);
999
1000 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001001 }
1002
1003 /**
1004 * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has
1005 * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or
1006 * intent being delivered to the top running activity.
1007 */
1008 private void launchObserverNotifyIntentFailed() {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001009 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1010 "MetricsLogger:launchObserverNotifyIntentFailed");
1011
1012 mLaunchObserver.onIntentFailed();
1013
1014 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001015 }
1016
1017 /**
1018 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1019 * has started.
1020 */
1021 private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001022 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1023 "MetricsLogger:launchObserverNotifyActivityLaunched");
1024
Igor Murashkin212d06c2018-10-22 16:34:39 -07001025 @ActivityMetricsLaunchObserver.Temperature int temperature =
1026 convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info));
1027
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001028 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1029 mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.launchedActivity),
1030 temperature);
1031
1032 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001033 }
1034
1035 /**
1036 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is
1037 * cancelled.
1038 */
1039 private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001040 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1041 "MetricsLogger:launchObserverNotifyActivityLaunchCancelled");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001042
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001043 final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto =
1044 info != null ? convertActivityRecordToProto(info.launchedActivity) : null;
1045
1046 mLaunchObserver.onActivityLaunchCancelled(activityRecordProto);
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's activity
1053 * has fully finished (successfully).
1054 */
1055 private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001056 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1057 "MetricsLogger:launchObserverNotifyActivityLaunchFinished");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001058
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001059 mLaunchObserver.onActivityLaunchFinished(
1060 convertActivityRecordToProto(info.launchedActivity));
1061
1062 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1063 }
1064
1065 @VisibleForTesting
1066 static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[]
1067 convertActivityRecordToProto(ActivityRecord record) {
1068 // May take non-negligible amount of time to convert ActivityRecord into a proto,
1069 // so track the time.
1070 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1071 "MetricsLogger:convertActivityRecordToProto");
1072
1073 // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream,
1074 // so create a new one every time.
1075 final ProtoOutputStream protoOutputStream =
1076 new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE);
1077 // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object).
1078 record.writeToProto(protoOutputStream);
1079 final byte[] bytes = protoOutputStream.getBytes();
1080
1081 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1082
1083 return bytes;
Igor Murashkin212d06c2018-10-22 16:34:39 -07001084 }
1085
1086 private static @ActivityMetricsLaunchObserver.Temperature int
1087 convertTransitionTypeToLaunchObserverTemperature(int transitionType) {
1088 switch (transitionType) {
1089 case TYPE_TRANSITION_WARM_LAUNCH:
1090 return ActivityMetricsLaunchObserver.TEMPERATURE_WARM;
1091 case TYPE_TRANSITION_HOT_LAUNCH:
1092 return ActivityMetricsLaunchObserver.TEMPERATURE_HOT;
1093 case TYPE_TRANSITION_COLD_LAUNCH:
1094 return ActivityMetricsLaunchObserver.TEMPERATURE_COLD;
1095 default:
1096 return -1;
1097 }
1098 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -08001099}