blob: 2d89bc7c56137f7df391c1a247c0a16b7b707775 [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_ACTIVITY_RECORD_FLAGS;
30import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_FULLSCREEN;
31import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_NO_DISPLAY;
32import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_VISIBLE;
33import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_VISIBLE_IGNORING_KEYGUARD;
Vishnu Nair132ee832018-09-28 15:00:05 -070034import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_LAUNCH_MODE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010035import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_LAUNCH;
36import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_VISIBLE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010037import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_PROCESS_NAME;
38import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_REAL_ACTIVITY;
39import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_RESULT_TO_PKG_NAME;
40import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_RESULT_TO_SHORT_COMPONENT_NAME;
41import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_SHORT_COMPONENT_NAME;
42import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_TARGET_ACTIVITY;
43import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_PACKAGE_NAME;
44import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID;
45import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW;
46import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_PROC_STATE;
Jorim Jaggicdfc04e2017-04-28 19:06:24 +020047import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010048import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_COMING_FROM_PENDING_INTENT;
Todd Kennedy50d946c12017-03-17 13:55:38 -070049import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INSTANT_APP_LAUNCH_TOKEN;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010050import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INTENT_ACTION;
51import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_CUR_PROC_STATE;
52import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES;
53import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES;
54import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES;
55import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_OVERLAY_UI;
56import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_TOP_UI;
57import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION;
58import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT;
59import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT;
60import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PENDING_UI_CLEAN;
61import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PROCESS_NAME;
62import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010063import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW;
Vishnu Nair132ee832018-09-28 15:00:05 -070064import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_PROC_STATE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010065import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_PACKAGE_NAME;
66import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_SHORT_COMPONENT_NAME;
67import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_UID;
68import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_UID_HAS_ANY_VISIBLE_WINDOW;
69import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_UID_PROC_STATE;
70import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_WHITELIST_TAG;
Calin Juravle759fbda2018-02-20 19:52:30 +000071import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_FILTER;
Vishnu Nair132ee832018-09-28 15:00:05 -070072import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_REASON;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080073import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_COLD_LAUNCH;
74import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_HOT_LAUNCH;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020075import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE;
76import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080077import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH;
Vishnu Nair132ee832018-09-28 15:00:05 -070078import static com.android.server.am.EventLogTags.AM_ACTIVITY_LAUNCH_TIME;
Ng Zhi Anbbefdec2018-01-30 17:12:39 -080079import static com.android.server.am.MemoryStatUtil.MemoryStat;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +000080import static com.android.server.am.MemoryStatUtil.readMemoryStatFromFilesystem;
Vishnu Naira62534b2018-11-09 09:13:22 -080081import static com.android.server.wm.ActivityTaskManagerDebugConfig.DEBUG_METRICS;
82import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_ATM;
83import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_WITH_CLASS_NAME;
Vishnu Nair132ee832018-09-28 15:00:05 -070084import static com.android.server.wm.ActivityTaskManagerInternal.APP_TRANSITION_TIMEOUT;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080085
Vishnu Nairbb9ab4b2018-12-13 10:29:46 -080086import android.app.WaitResult;
Igor Murashkin212d06c2018-10-22 16:34:39 -070087import android.app.WindowConfiguration.WindowingMode;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080088import android.content.Context;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010089import android.content.Intent;
Calin Juravle759fbda2018-02-20 19:52:30 +000090import android.content.pm.ApplicationInfo;
91import android.content.pm.dex.ArtManagerInternal;
92import android.content.pm.dex.PackageOptimizationInfo;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080093import android.metrics.LogMaker;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020094import android.os.Handler;
95import android.os.Looper;
96import android.os.Message;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080097import android.os.SystemClock;
Vishnu Nair132ee832018-09-28 15:00:05 -070098import android.os.Trace;
99import android.util.EventLog;
100import android.util.Log;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200101import android.util.Slog;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800102import android.util.SparseArray;
103import android.util.SparseIntArray;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000104import android.util.StatsLog;
Vishnu Nair132ee832018-09-28 15:00:05 -0700105import android.util.TimeUtils;
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800106import android.util.proto.ProtoOutputStream;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800107
Vishnu Nairbb9ab4b2018-12-13 10:29:46 -0800108import com.android.internal.annotations.VisibleForTesting;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800109import com.android.internal.logging.MetricsLogger;
Ng Zhi An83473542018-02-20 09:02:14 -0800110import com.android.internal.os.BackgroundThread;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200111import com.android.internal.os.SomeArgs;
Calin Juravle759fbda2018-02-20 19:52:30 +0000112import com.android.server.LocalServices;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800113
114/**
Vishnu Nair132ee832018-09-28 15:00:05 -0700115 * Listens to activity launches, transitions, visibility changes and window drawn callbacks to
116 * determine app launch times and draw delays. Source of truth for activity metrics and provides
117 * data for Tron, logcat, event logs and {@link android.app.WaitResult}.
118 *
119 * Tests:
Vishnu Nairf8accc52018-10-11 10:19:54 -0700120 * atest CtsActivityManagerDeviceTestCases:ActivityMetricsLoggerTests
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800121 */
122class ActivityMetricsLogger {
Jorim Jaggif9704102016-05-05 19:14:22 -0700123
Wale Ogunwale98875612018-10-12 07:53:02 -0700124 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_ATM;
Jorim Jaggif9704102016-05-05 19:14:22 -0700125
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800126 // Window modes we are interested in logging. If we ever introduce a new type, we need to add
127 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array.
128 private static final int WINDOW_STATE_STANDARD = 0;
129 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1;
130 private static final int WINDOW_STATE_FREEFORM = 2;
Winson Chung83471632016-12-13 11:02:12 -0800131 private static final int WINDOW_STATE_ASSISTANT = 3;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800132 private static final int WINDOW_STATE_INVALID = -1;
133
Jorim Jaggi275561a2016-02-23 10:11:02 -0500134 private static final long INVALID_START_TIME = -1;
Vishnu Nair132ee832018-09-28 15:00:05 -0700135 private static final int INVALID_DELAY = -1;
136 private static final int INVALID_TRANSITION_TYPE = -1;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500137
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200138 private static final int MSG_CHECK_VISIBILITY = 0;
139
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800140 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every
141 // time we log.
142 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = {
Winson Chung83471632016-12-13 11:02:12 -0800143 "window_time_0", "window_time_1", "window_time_2", "window_time_3"};
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800144
145 private int mWindowState = WINDOW_STATE_STANDARD;
146 private long mLastLogTimeSecs;
147 private final ActivityStackSupervisor mSupervisor;
148 private final Context mContext;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800149 private final MetricsLogger mMetricsLogger = new MetricsLogger();
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800150
Igor Murashkin212d06c2018-10-22 16:34:39 -0700151 // set to INVALID_START_TIME in reset.
152 // set to valid value in notifyActivityLaunching
Jorim Jaggi275561a2016-02-23 10:11:02 -0500153 private long mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200154 private long mLastTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800155
156 private int mCurrentTransitionDeviceUptime;
157 private int mCurrentTransitionDelayMs;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700158
159 /** If the any app transitions have been logged as starting, after the latest reset. */
Jorim Jaggi275561a2016-02-23 10:11:02 -0500160 private boolean mLoggedTransitionStarting;
161
Igor Murashkin212d06c2018-10-22 16:34:39 -0700162 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100163 private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo =
164 new SparseArray<>();
Igor Murashkin212d06c2018-10-22 16:34:39 -0700165 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100166 private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo =
167 new SparseArray<>();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200168 private final H mHandler;
Calin Juravle759fbda2018-02-20 19:52:30 +0000169
170 private ArtManagerInternal mArtManagerInternal;
Vishnu Nair132ee832018-09-28 15:00:05 -0700171 private final StringBuilder mStringBuilder = new StringBuilder();
Calin Juravle759fbda2018-02-20 19:52:30 +0000172
Igor Murashkin212d06c2018-10-22 16:34:39 -0700173 /**
174 * Due to the global single concurrent launch sequence, all calls to this observer must be made
175 * in-order on the same thread to fulfill the "happens-before" guarantee in LaunchObserver.
176 */
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800177 private final LaunchObserverRegistryImpl mLaunchObserver;
178 @VisibleForTesting static final int LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE = 512;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700179
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200180 private final class H extends Handler {
181
182 public H(Looper looper) {
183 super(looper);
184 }
185
186 @Override
187 public void handleMessage(Message msg) {
188 switch (msg.what) {
189 case MSG_CHECK_VISIBILITY:
190 final SomeArgs args = (SomeArgs) msg.obj;
191 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2);
192 break;
193 }
194 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000195 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800196
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100197 private final class WindowingModeTransitionInfo {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700198 /** The latest activity to have been launched. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800199 private ActivityRecord launchedActivity;
200 private int startResult;
201 private boolean currentTransitionProcessRunning;
Vishnu Nair132ee832018-09-28 15:00:05 -0700202 /** Elapsed time from when we launch an activity to when its windows are drawn. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800203 private int windowsDrawnDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700204 private int startingWindowDelayMs = INVALID_DELAY;
205 private int bindApplicationDelayMs = INVALID_DELAY;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800206 private int reason = APP_TRANSITION_TIMEOUT;
207 private boolean loggedWindowsDrawn;
208 private boolean loggedStartingWindowDrawn;
Vishnu Nair132ee832018-09-28 15:00:05 -0700209 private boolean launchTraceActive;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800210 }
211
Vishnu Nair132ee832018-09-28 15:00:05 -0700212 final class WindowingModeTransitionInfoSnapshot {
Calin Juravle759fbda2018-02-20 19:52:30 +0000213 final private ApplicationInfo applicationInfo;
Wale Ogunwalef6733932018-06-27 05:14:34 -0700214 final private WindowProcessController processRecord;
Vishnu Nair132ee832018-09-28 15:00:05 -0700215 final String packageName;
216 final String launchedActivityName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000217 final private String launchedActivityLaunchedFromPackage;
218 final private String launchedActivityLaunchToken;
219 final private String launchedActivityAppRecordRequiredAbi;
Vishnu Nair132ee832018-09-28 15:00:05 -0700220 final String launchedActivityShortComponentName;
Ng Zhi An83473542018-02-20 09:02:14 -0800221 final private String processName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000222 final private int reason;
223 final private int startingWindowDelayMs;
224 final private int bindApplicationDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700225 final int windowsDrawnDelayMs;
226 final int type;
227 final int userId;
228 /**
229 * Elapsed time from when we launch an activity to when the app reported it was
230 * fully drawn. If this is not reported then the value is set to INVALID_DELAY.
231 */
232 final int windowsFullyDrawnDelayMs;
233 final int activityRecordIdHashCode;
Calin Juravle759fbda2018-02-20 19:52:30 +0000234
235 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700236 this(info, info.launchedActivity);
237 }
238
239 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
240 ActivityRecord launchedActivity) {
241 this(info, launchedActivity, INVALID_DELAY);
242 }
243
244 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
245 ActivityRecord launchedActivity, int windowsFullyDrawnDelayMs) {
246 applicationInfo = launchedActivity.appInfo;
247 packageName = launchedActivity.packageName;
248 launchedActivityName = launchedActivity.info.name;
249 launchedActivityLaunchedFromPackage = launchedActivity.launchedFromPackage;
250 launchedActivityLaunchToken = launchedActivity.info.launchToken;
251 launchedActivityAppRecordRequiredAbi = launchedActivity.app == null
Calin Juravle759fbda2018-02-20 19:52:30 +0000252 ? null
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700253 : launchedActivity.app.getRequiredAbi();
Calin Juravle759fbda2018-02-20 19:52:30 +0000254 reason = info.reason;
255 startingWindowDelayMs = info.startingWindowDelayMs;
256 bindApplicationDelayMs = info.bindApplicationDelayMs;
257 windowsDrawnDelayMs = info.windowsDrawnDelayMs;
258 type = getTransitionType(info);
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700259 processRecord = findProcessForActivity(launchedActivity);
260 processName = launchedActivity.processName;
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800261 userId = launchedActivity.mUserId;
Vishnu Nair132ee832018-09-28 15:00:05 -0700262 launchedActivityShortComponentName = launchedActivity.shortComponentName;
263 activityRecordIdHashCode = System.identityHashCode(launchedActivity);
264 this.windowsFullyDrawnDelayMs = windowsFullyDrawnDelayMs;
Calin Juravle759fbda2018-02-20 19:52:30 +0000265 }
Vishnu Nairbb9ab4b2018-12-13 10:29:46 -0800266
267 @WaitResult.LaunchState int getLaunchState() {
268 switch (type) {
269 case TYPE_TRANSITION_WARM_LAUNCH:
270 return LAUNCH_STATE_WARM;
271 case TYPE_TRANSITION_HOT_LAUNCH:
272 return LAUNCH_STATE_HOT;
273 case TYPE_TRANSITION_COLD_LAUNCH:
274 return LAUNCH_STATE_COLD;
275 default:
276 return -1;
277 }
278 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000279 }
280
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200281 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper) {
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800282 mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000;
283 mSupervisor = supervisor;
284 mContext = context;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200285 mHandler = new H(looper);
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800286 mLaunchObserver = new LaunchObserverRegistryImpl(looper);
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800287 }
288
289 void logWindowState() {
290 final long now = SystemClock.elapsedRealtime() / 1000;
291 if (mWindowState != WINDOW_STATE_INVALID) {
292 // We log even if the window state hasn't changed, because the user might remain in
293 // home/fullscreen move forever and we would like to track this kind of behavior
294 // too.
295 MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState],
296 (int) (now - mLastLogTimeSecs));
297 }
298 mLastLogTimeSecs = now;
299
Wale Ogunwale926aade2017-08-29 11:24:37 -0700300 mWindowState = WINDOW_STATE_INVALID;
Wale Ogunwaled32da472018-11-16 07:19:28 -0800301 ActivityStack stack =
302 mSupervisor.mRootActivityContainer.getTopDisplayFocusedStack();
lumarkf6c4a982018-06-15 15:43:12 +0800303 if (stack == null) {
304 return;
305 }
306
Wale Ogunwale926aade2017-08-29 11:24:37 -0700307 if (stack.isActivityTypeAssistant()) {
308 mWindowState = WINDOW_STATE_ASSISTANT;
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800309 return;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800310 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700311
Igor Murashkin212d06c2018-10-22 16:34:39 -0700312 @WindowingMode int windowingMode = stack.getWindowingMode();
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700313 if (windowingMode == WINDOWING_MODE_PINNED) {
Wale Ogunwaled32da472018-11-16 07:19:28 -0800314 stack = mSupervisor.mRootActivityContainer.findStackBehind(stack);
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700315 windowingMode = stack.getWindowingMode();
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800316 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700317 switch (windowingMode) {
318 case WINDOWING_MODE_FULLSCREEN:
319 mWindowState = WINDOW_STATE_STANDARD;
320 break;
321 case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY:
322 case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY:
323 mWindowState = WINDOW_STATE_SIDE_BY_SIDE;
324 break;
Bryce Lee6c605092017-10-12 11:14:49 -0700325 case WINDOWING_MODE_FREEFORM:
Wale Ogunwale926aade2017-08-29 11:24:37 -0700326 mWindowState = WINDOW_STATE_FREEFORM;
327 break;
328 default:
329 if (windowingMode != WINDOWING_MODE_UNDEFINED) {
330 throw new IllegalStateException("Unknown windowing mode for stack=" + stack
331 + " windowingMode=" + windowingMode);
332 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800333 }
334 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500335
336 /**
337 * Notifies the tracker at the earliest possible point when we are starting to launch an
338 * activity.
339 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700340 void notifyActivityLaunching(Intent intent) {
341 if (DEBUG_METRICS) {
342 Slog.i(TAG, String.format("notifyActivityLaunching: active:%b, intent:%s",
343 isAnyTransitionActive(),
344 intent));
345 }
346
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800347 if (!isAnyTransitionActive()) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700348
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400349 mCurrentTransitionStartTime = SystemClock.uptimeMillis();
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200350 mLastTransitionStartTime = mCurrentTransitionStartTime;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700351
352 launchObserverNotifyIntentStarted(intent);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800353 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500354 }
355
356 /**
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700357 * Notifies the tracker that the activity is actually launching.
358 *
359 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
360 * launch
361 * @param launchedActivity the activity that is being launched
362 */
363 void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) {
Wale Ogunwalef6733932018-06-27 05:14:34 -0700364 final WindowProcessController processRecord = findProcessForActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700365 final boolean processRunning = processRecord != null;
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700366
367 // We consider this a "process switch" if the process of the activity that gets launched
368 // didn't have an activity that was in started state. In this case, we assume that lot
369 // of caches might be purged so the time until it produces the first frame is very
370 // interesting.
371 final boolean processSwitch = processRecord == null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700372 || !processRecord.hasStartedActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700373
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800374 notifyActivityLaunched(resultCode, launchedActivity, processRunning, processSwitch);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700375 }
376
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700377 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500378 * Notifies the tracker the the activity is actually launching.
379 *
380 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
381 * launch
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800382 * @param launchedActivity the activity being launched
Jorim Jaggi275561a2016-02-23 10:11:02 -0500383 * @param processRunning whether the process that will contains the activity is already running
Jorim Jaggibe67c902016-04-12 00:53:16 -0700384 * @param processSwitch whether the process that will contain the activity didn't have any
385 * activity that was stopped, i.e. the started activity is "switching"
386 * processes
Jorim Jaggi275561a2016-02-23 10:11:02 -0500387 */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800388 private void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity,
Jorim Jaggibe67c902016-04-12 00:53:16 -0700389 boolean processRunning, boolean processSwitch) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500390
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200391 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched"
392 + " resultCode=" + resultCode
393 + " launchedActivity=" + launchedActivity
394 + " processRunning=" + processRunning
395 + " processSwitch=" + processSwitch);
396
Igor Murashkin212d06c2018-10-22 16:34:39 -0700397 // If we are already in an existing transition, only update the activity name, but not the
398 // other attributes.
399 final @WindowingMode int windowingMode = launchedActivity != null
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100400 ? launchedActivity.getWindowingMode()
401 : WINDOWING_MODE_UNDEFINED;
Vishnu Nairf8accc52018-10-11 10:19:54 -0700402 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200403 if (mCurrentTransitionStartTime == INVALID_START_TIME) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700404 // No transition is active ignore this launch.
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200405 return;
406 }
407
Vishnu Nair9ba31652018-11-13 14:34:05 -0800408 if (launchedActivity != null && launchedActivity.mDrawn) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700409 // Launched activity is already visible. We cannot measure windows drawn delay.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700410 reset(true /* abort */, info, "launched activity already visible");
Vishnu Nairf8accc52018-10-11 10:19:54 -0700411 return;
412 }
413
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800414 if (launchedActivity != null && info != null) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700415 // If we are already in an existing transition, only update the activity name, but not
416 // the other attributes.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700417
418 // Coalesce multiple (trampoline) activities from a single sequence together.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800419 info.launchedActivity = launchedActivity;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500420 return;
421 }
422
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100423 final boolean otherWindowModesLaunching =
424 mWindowingModeTransitionInfo.size() > 0 && info == null;
Jorim Jaggi54cff642018-03-15 15:51:32 +0100425 if ((!isLoggableResultCode(resultCode) || launchedActivity == null || !processSwitch
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100426 || windowingMode == WINDOWING_MODE_UNDEFINED) && !otherWindowModesLaunching) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800427 // 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 -0700428 reset(true /* abort */, info, "failed to launch or not a process switch");
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800429 return;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100430 } else if (otherWindowModesLaunching) {
431 // Don't log this windowing mode but continue with the other windowing modes.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800432 return;
433 }
434
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200435 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful");
436
Igor Murashkin212d06c2018-10-22 16:34:39 -0700437 // A new launch sequence [with the windowingMode] has begun.
438 // Start tracking it.
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100439 final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo();
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800440 newInfo.launchedActivity = launchedActivity;
441 newInfo.currentTransitionProcessRunning = processRunning;
442 newInfo.startResult = resultCode;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100443 mWindowingModeTransitionInfo.put(windowingMode, newInfo);
444 mLastWindowingModeTransitionInfo.put(windowingMode, newInfo);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800445 mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000);
Vishnu Nair132ee832018-09-28 15:00:05 -0700446 startTraces(newInfo);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700447 launchObserverNotifyActivityLaunched(newInfo);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500448 }
449
450 /**
Jorim Jaggi54cff642018-03-15 15:51:32 +0100451 * @return True if we should start logging an event for an activity start that returned
452 * {@code resultCode} and that we'll indeed get a windows drawn event.
453 */
454 private boolean isLoggableResultCode(int resultCode) {
455 return resultCode == START_SUCCESS || resultCode == START_TASK_TO_FRONT;
456 }
457
458 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500459 * Notifies the tracker that all windows of the app have been drawn.
460 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700461 WindowingModeTransitionInfoSnapshot notifyWindowsDrawn(@WindowingMode int windowingMode,
462 long timestamp) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100463 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200464
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.loggedWindowsDrawn) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700467 return null;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500468 }
Sudheer Shankac766db02017-06-12 10:37:29 -0700469 info.windowsDrawnDelayMs = calculateDelay(timestamp);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800470 info.loggedWindowsDrawn = true;
Vishnu Nair132ee832018-09-28 15:00:05 -0700471 final WindowingModeTransitionInfoSnapshot infoSnapshot =
472 new WindowingModeTransitionInfoSnapshot(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100473 if (allWindowsDrawn() && mLoggedTransitionStarting) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700474 reset(false /* abort */, info, "notifyWindowsDrawn - all windows drawn");
Jorim Jaggi275561a2016-02-23 10:11:02 -0500475 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700476 return infoSnapshot;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500477 }
478
479 /**
480 * Notifies the tracker that the starting window was drawn.
481 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700482 void notifyStartingWindowDrawn(@WindowingMode int windowingMode, long timestamp) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100483 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800484 if (info == null || info.loggedStartingWindowDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500485 return;
486 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800487 info.loggedStartingWindowDrawn = true;
Sudheer Shankac766db02017-06-12 10:37:29 -0700488 info.startingWindowDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500489 }
490
491 /**
492 * Notifies the tracker that the app transition is starting.
493 *
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100494 * @param windowingModeToReason A map from windowing mode to a reason integer, which must be on
Vishnu Nair132ee832018-09-28 15:00:05 -0700495 * of ActivityTaskManagerInternal.APP_TRANSITION_* reasons.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500496 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100497 void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) {
Jorim Jaggid8a57772017-04-14 16:50:42 -0700498 if (!isAnyTransitionActive() || mLoggedTransitionStarting) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700499 // Ignore calls to this made after a reset and prior to notifyActivityLaunching.
500
501 // Ignore any subsequent notifyTransitionStarting until the next reset.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500502 return;
503 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200504 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting");
Sudheer Shankac766db02017-06-12 10:37:29 -0700505 mCurrentTransitionDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500506 mLoggedTransitionStarting = true;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700507
508 WindowingModeTransitionInfo foundInfo = null;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100509 for (int index = windowingModeToReason.size() - 1; index >= 0; index--) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700510 final @WindowingMode int windowingMode = windowingModeToReason.keyAt(index);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100511 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
512 windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800513 if (info == null) {
514 continue;
515 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100516 info.reason = windowingModeToReason.valueAt(index);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700517 foundInfo = info;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800518 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100519 if (allWindowsDrawn()) {
Vishnu Naira62534b2018-11-09 09:13:22 -0800520 // abort metrics collection if we cannot find a matching transition.
521 final boolean abortMetrics = foundInfo == null;
522 reset(abortMetrics, foundInfo, "notifyTransitionStarting - all windows drawn");
Jorim Jaggi275561a2016-02-23 10:11:02 -0500523 }
524 }
525
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200526 /**
527 * Notifies the tracker that the visibility of an app is changing.
528 *
529 * @param activityRecord the app that is changing its visibility
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200530 */
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200531 void notifyVisibilityChanged(ActivityRecord activityRecord) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100532 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
533 activityRecord.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200534 if (info == null) {
535 return;
536 }
537 if (info.launchedActivity != activityRecord) {
538 return;
539 }
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800540 final TaskRecord t = activityRecord.getTaskRecord();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200541 final SomeArgs args = SomeArgs.obtain();
542 args.arg1 = t;
543 args.arg2 = activityRecord;
544 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget();
545 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200546
Vishnu Nairb1de42d2019-01-28 09:49:51 -0800547 private boolean hasVisibleNonFinishingActivity(TaskRecord t) {
548 for (int i = t.mActivities.size() - 1; i >= 0; --i) {
549 final ActivityRecord r = t.mActivities.get(i);
550 if (r.visible && !r.finishing) {
551 return true;
552 }
553 }
554 return false;
555 }
556
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200557 private void checkVisibility(TaskRecord t, ActivityRecord r) {
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700558 synchronized (mSupervisor.mService.mGlobalLock) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200559
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100560 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
561 r.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200562
563 // If we have an active transition that's waiting on a certain activity that will be
564 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
Vishnu Nairb1de42d2019-01-28 09:49:51 -0800565 if (info != null && !hasVisibleNonFinishingActivity(t)) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200566 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible"
567 + " activity=" + r);
568 logAppTransitionCancel(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100569 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
570 if (mWindowingModeTransitionInfo.size() == 0) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700571 reset(true /* abort */, info, "notifyVisibilityChanged to invisible");
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200572 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200573 }
574 }
575 }
576
Jorim Jaggi515dd682017-05-05 15:05:07 +0200577 /**
578 * Notifies the tracker that we called immediately before we call bindApplication on the client.
579 *
Wale Ogunwale31913b52018-10-13 08:29:31 -0700580 * @param appInfo The client into which we'll call bindApplication.
Jorim Jaggi515dd682017-05-05 15:05:07 +0200581 */
Wale Ogunwale31913b52018-10-13 08:29:31 -0700582 void notifyBindApplication(ApplicationInfo appInfo) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100583 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
584 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200585
586 // App isn't attached to record yet, so match with info.
Wale Ogunwale31913b52018-10-13 08:29:31 -0700587 if (info.launchedActivity.appInfo == appInfo) {
Jorim Jaggi515dd682017-05-05 15:05:07 +0200588 info.bindApplicationDelayMs = calculateCurrentDelay();
589 }
590 }
591 }
592
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100593 private boolean allWindowsDrawn() {
594 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
595 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800596 return false;
597 }
598 }
599 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500600 }
601
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800602 private boolean isAnyTransitionActive() {
603 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100604 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800605 }
606
Igor Murashkin212d06c2018-10-22 16:34:39 -0700607 private void reset(boolean abort, WindowingModeTransitionInfo info, String cause) {
608 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort + ",cause=" + cause);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800609 if (!abort && isAnyTransitionActive()) {
610 logAppTransitionMultiEvents();
611 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700612 stopLaunchTrace(info);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700613
614 // Ignore reset-after reset.
615 if (isAnyTransitionActive()) {
616 // LaunchObserver callbacks.
617 if (abort) {
618 launchObserverNotifyActivityLaunchCancelled(info);
619 } else {
620 launchObserverNotifyActivityLaunchFinished(info);
621 }
622 } else {
623 launchObserverNotifyIntentFailed();
624 }
625
Jorim Jaggi275561a2016-02-23 10:11:02 -0500626 mCurrentTransitionStartTime = INVALID_START_TIME;
Vishnu Nair132ee832018-09-28 15:00:05 -0700627 mCurrentTransitionDelayMs = INVALID_DELAY;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500628 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100629 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500630 }
631
632 private int calculateCurrentDelay() {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500633 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400634 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500635 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800636
Sudheer Shankac766db02017-06-12 10:37:29 -0700637 private int calculateDelay(long timestamp) {
638 // Shouldn't take more than 25 days to launch an app, so int is fine here.
639 return (int) (timestamp - mCurrentTransitionStartTime);
640 }
641
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100642 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200643 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700644 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200645 return;
646 }
647 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
648 builder.setPackageName(info.launchedActivity.packageName);
649 builder.setType(type);
650 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
651 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000652 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800653 StatsLog.APP_START_CANCELED,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000654 info.launchedActivity.appInfo.uid,
655 info.launchedActivity.packageName,
656 convertAppStartTransitionType(type),
657 info.launchedActivity.info.name);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700658 if (DEBUG_METRICS) {
659 Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)",
660 info.launchedActivity.appInfo.uid,
661 info.launchedActivity.packageName,
662 convertAppStartTransitionType(type),
663 info.launchedActivity.info.name));
664 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200665 }
666
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800667 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200668 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100669 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
670 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800671 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700672 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800673 return;
674 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000675
676 // Take a snapshot of the transition info before sending it to the handler for logging.
677 // This will avoid any races with other operations that modify the ActivityRecord.
678 final WindowingModeTransitionInfoSnapshot infoSnapshot =
679 new WindowingModeTransitionInfoSnapshot(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800680 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime;
681 final int currentTransitionDelayMs = mCurrentTransitionDelayMs;
682 BackgroundThread.getHandler().post(() -> logAppTransition(
683 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot));
Vishnu Nair132ee832018-09-28 15:00:05 -0700684 BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot));
Calin Juravle759fbda2018-02-20 19:52:30 +0000685
686 info.launchedActivity.info.launchToken = null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800687 }
688 }
689
Ng Zhi An83473542018-02-20 09:02:14 -0800690 // This gets called on a background thread without holding the activity manager lock.
Calin Juravle759fbda2018-02-20 19:52:30 +0000691 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
692 WindowingModeTransitionInfoSnapshot info) {
693 final LogMaker builder = new LogMaker(APP_TRANSITION);
694 builder.setPackageName(info.packageName);
695 builder.setType(info.type);
696 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
697 final boolean isInstantApp = info.applicationInfo.isInstantApp();
698 if (info.launchedActivityLaunchedFromPackage != null) {
699 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
700 info.launchedActivityLaunchedFromPackage);
701 }
702 String launchToken = info.launchedActivityLaunchToken;
703 if (launchToken != null) {
704 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
705 }
706 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
707 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
708 currentTransitionDeviceUptime);
709 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
710 builder.setSubtype(info.reason);
Vishnu Nair132ee832018-09-28 15:00:05 -0700711 if (info.startingWindowDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000712 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
713 info.startingWindowDelayMs);
714 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700715 if (info.bindApplicationDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000716 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
717 info.bindApplicationDelayMs);
718 }
719 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
720 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
721 final PackageOptimizationInfo packageOptimizationInfo =
722 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
723 ? PackageOptimizationInfo.createWithNoInfo()
724 : artManagerInternal.getPackageOptimizationInfo(
725 info.applicationInfo,
726 info.launchedActivityAppRecordRequiredAbi);
727 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
728 packageOptimizationInfo.getCompilationReason());
729 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
730 packageOptimizationInfo.getCompilationFilter());
731 mMetricsLogger.write(builder);
732 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800733 StatsLog.APP_START_OCCURRED,
Calin Juravle759fbda2018-02-20 19:52:30 +0000734 info.applicationInfo.uid,
735 info.packageName,
736 convertAppStartTransitionType(info.type),
737 info.launchedActivityName,
738 info.launchedActivityLaunchedFromPackage,
739 isInstantApp,
740 currentTransitionDeviceUptime * 1000,
741 info.reason,
742 currentTransitionDelayMs,
743 info.startingWindowDelayMs,
744 info.bindApplicationDelayMs,
745 info.windowsDrawnDelayMs,
746 launchToken,
747 packageOptimizationInfo.getCompilationReason(),
748 packageOptimizationInfo.getCompilationFilter());
Igor Murashkin212d06c2018-10-22 16:34:39 -0700749
750 if (DEBUG_METRICS) {
751 Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)",
752 info.applicationInfo.uid,
753 info.packageName,
754 convertAppStartTransitionType(info.type),
755 info.launchedActivityName,
756 info.launchedActivityLaunchedFromPackage));
757 }
758
759
Ng Zhi An83473542018-02-20 09:02:14 -0800760 logAppStartMemoryStateCapture(info);
Calin Juravle759fbda2018-02-20 19:52:30 +0000761 }
762
Vishnu Nair132ee832018-09-28 15:00:05 -0700763 private void logAppDisplayed(WindowingModeTransitionInfoSnapshot info) {
764 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
765 return;
766 }
767
768 EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME,
769 info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,
770 info.windowsDrawnDelayMs);
771
772 StringBuilder sb = mStringBuilder;
773 sb.setLength(0);
774 sb.append("Displayed ");
775 sb.append(info.launchedActivityShortComponentName);
776 sb.append(": ");
777 TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb);
778 Log.i(TAG, sb.toString());
779 }
780
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000781 private int convertAppStartTransitionType(int tronType) {
782 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800783 return StatsLog.APP_START_OCCURRED__TYPE__COLD;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000784 }
785 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800786 return StatsLog.APP_START_OCCURRED__TYPE__WARM;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000787 }
788 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800789 return StatsLog.APP_START_OCCURRED__TYPE__HOT;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000790 }
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800791 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000792 }
793
Vishnu Nair132ee832018-09-28 15:00:05 -0700794 WindowingModeTransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r,
795 boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100796 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
797 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200798 if (info == null) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700799 return null;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200800 }
Chris Wailes35c193c2018-10-09 18:12:00 -0700801
802 // Record the handling of the reportFullyDrawn callback in the trace system. This is not
803 // actually used to trace this function, but instead the logical task that this function
804 // fullfils (handling reportFullyDrawn() callbacks).
805 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
806 "ActivityManager:ReportingFullyDrawn " + info.launchedActivity.packageName);
807
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200808 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
809 builder.setPackageName(r.packageName);
810 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000811 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
812 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200813 builder.setType(restoredFromBundle
814 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
815 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
816 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
817 info.currentTransitionProcessRunning ? 1 : 0);
818 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000819 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800820 StatsLog.APP_START_FULLY_DRAWN,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000821 info.launchedActivity.appInfo.uid,
822 info.launchedActivity.packageName,
823 restoredFromBundle
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800824 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE
825 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000826 info.launchedActivity.info.name,
827 info.currentTransitionProcessRunning,
828 startupTimeMs);
Chris Wailes35c193c2018-10-09 18:12:00 -0700829
830 // Ends the trace started at the beginning of this function. This is located here to allow
831 // the trace slice to have a noticable duration.
832 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
833
Vishnu Nair132ee832018-09-28 15:00:05 -0700834 final WindowingModeTransitionInfoSnapshot infoSnapshot =
835 new WindowingModeTransitionInfoSnapshot(info, r, (int) startupTimeMs);
836 BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot));
837 return infoSnapshot;
838 }
839
840 private void logAppFullyDrawn(WindowingModeTransitionInfoSnapshot info) {
841 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
842 return;
843 }
844
845 StringBuilder sb = mStringBuilder;
846 sb.setLength(0);
847 sb.append("Fully drawn ");
848 sb.append(info.launchedActivityShortComponentName);
849 sb.append(": ");
850 TimeUtils.formatDuration(info.windowsFullyDrawnDelayMs, sb);
851 Log.i(TAG, sb.toString());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200852 }
853
Michal Karpinski4fd5b842019-01-28 15:13:32 +0000854 void logAbortedBgActivityStart(Intent intent, WindowProcessController callerApp,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100855 int callingUid, String callingPackage, int callingUidProcState,
856 boolean callingUidHasAnyVisibleWindow,
857 int realCallingUid, int realCallingUidProcState,
858 boolean realCallingUidHasAnyVisibleWindow,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100859 boolean comingFromPendingIntent) {
860
861 final long nowElapsed = SystemClock.elapsedRealtime();
862 final long nowUptime = SystemClock.uptimeMillis();
863 final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START);
864 builder.setTimestamp(System.currentTimeMillis());
865 builder.addTaggedData(FIELD_CALLING_UID, callingUid);
866 builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage);
867 builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE,
868 processStateAmToProto(callingUidProcState));
869 builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
870 callingUidHasAnyVisibleWindow ? 1 : 0);
871 builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid);
872 builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE,
873 processStateAmToProto(realCallingUidProcState));
874 builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
875 realCallingUidHasAnyVisibleWindow ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100876 builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0);
Michal Karpinski8596ded2018-11-14 14:43:48 +0000877 if (intent != null) {
878 builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction());
879 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100880 if (callerApp != null) {
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700881 builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100882 builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700883 processStateAmToProto(callerApp.getCurrentProcState()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100884 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700885 callerApp.hasClientActivities() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100886 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES,
887 callerApp.hasForegroundServices() ? 1 : 0);
888 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700889 callerApp.hasForegroundActivities() ? 1 : 0);
890 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100891 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700892 callerApp.hasOverlayUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100893 builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700894 callerApp.hasPendingUiClean() ? 1 : 0);
895 if (callerApp.getInteractionEventTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100896 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700897 (nowElapsed - callerApp.getInteractionEventTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100898 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700899 if (callerApp.getFgInteractionTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100900 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700901 (nowElapsed - callerApp.getFgInteractionTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100902 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700903 if (callerApp.getWhenUnimportant() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100904 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700905 (nowUptime - callerApp.getWhenUnimportant()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100906 }
907 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100908 mMetricsLogger.write(builder);
909 }
910
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100911 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800912 if (info.currentTransitionProcessRunning) {
913 if (info.startResult == START_SUCCESS) {
914 return TYPE_TRANSITION_WARM_LAUNCH;
915 } else if (info.startResult == START_TASK_TO_FRONT) {
916 return TYPE_TRANSITION_HOT_LAUNCH;
917 }
918 } else if (info.startResult == START_SUCCESS) {
919 return TYPE_TRANSITION_COLD_LAUNCH;
920 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700921 return INVALID_TRANSITION_TYPE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800922 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800923
Ng Zhi An83473542018-02-20 09:02:14 -0800924 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
925 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800926 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
927 return;
928 }
929
Wale Ogunwalef6733932018-06-27 05:14:34 -0700930 final int pid = info.processRecord.getPid();
Ng Zhi An83473542018-02-20 09:02:14 -0800931 final int uid = info.applicationInfo.uid;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +0000932 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800933 if (memoryStat == null) {
934 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
935 return;
936 }
937
938 StatsLog.write(
939 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
940 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800941 info.processName,
942 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800943 memoryStat.pgfault,
944 memoryStat.pgmajfault,
945 memoryStat.rssInBytes,
946 memoryStat.cacheInBytes,
947 memoryStat.swapInBytes);
948 }
949
Wale Ogunwalef6733932018-06-27 05:14:34 -0700950 private WindowProcessController findProcessForActivity(ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800951 return launchedActivity != null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700952 ? mSupervisor.mService.mProcessNames.get(
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700953 launchedActivity.processName, launchedActivity.appInfo.uid)
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800954 : null;
955 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000956
957 private ArtManagerInternal getArtManagerInternal() {
958 if (mArtManagerInternal == null) {
959 // Note that this may be null.
960 // ArtManagerInternal is registered during PackageManagerService
961 // initialization which happens after ActivityManagerService.
962 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
963 }
964 return mArtManagerInternal;
965 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700966
967 /**
Chris Wailes35c193c2018-10-09 18:12:00 -0700968 * Starts traces for app launch.
Vishnu Nair132ee832018-09-28 15:00:05 -0700969 *
970 * @param info
971 * */
972 private void startTraces(WindowingModeTransitionInfo info) {
973 if (info == null) {
974 return;
975 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700976 int transitionType = getTransitionType(info);
977 if (!info.launchTraceActive && transitionType == TYPE_TRANSITION_WARM_LAUNCH
978 || transitionType == TYPE_TRANSITION_COLD_LAUNCH) {
979 Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
980 + info.launchedActivity.packageName, 0);
Vishnu Nair132ee832018-09-28 15:00:05 -0700981 info.launchTraceActive = true;
982 }
983 }
984
985 private void stopLaunchTrace(WindowingModeTransitionInfo info) {
986 if (info == null) {
987 return;
988 }
989 if (info.launchTraceActive) {
990 Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
991 + info.launchedActivity.packageName, 0);
992 info.launchTraceActive = false;
993 }
994 }
Igor Murashkin212d06c2018-10-22 16:34:39 -0700995
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800996 public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() {
997 return mLaunchObserver;
998 }
999
Igor Murashkin212d06c2018-10-22 16:34:39 -07001000 /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */
1001 private void launchObserverNotifyIntentStarted(Intent intent) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001002 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1003 "MetricsLogger:launchObserverNotifyIntentStarted");
1004
1005 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1006 mLaunchObserver.onIntentStarted(intent);
1007
1008 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001009 }
1010
1011 /**
1012 * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has
1013 * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or
1014 * intent being delivered to the top running activity.
1015 */
1016 private void launchObserverNotifyIntentFailed() {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001017 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1018 "MetricsLogger:launchObserverNotifyIntentFailed");
1019
1020 mLaunchObserver.onIntentFailed();
1021
1022 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001023 }
1024
1025 /**
1026 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1027 * has started.
1028 */
1029 private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001030 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1031 "MetricsLogger:launchObserverNotifyActivityLaunched");
1032
Igor Murashkin212d06c2018-10-22 16:34:39 -07001033 @ActivityMetricsLaunchObserver.Temperature int temperature =
1034 convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info));
1035
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001036 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1037 mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.launchedActivity),
1038 temperature);
1039
1040 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001041 }
1042
1043 /**
1044 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is
1045 * cancelled.
1046 */
1047 private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001048 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1049 "MetricsLogger:launchObserverNotifyActivityLaunchCancelled");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001050
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001051 final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto =
1052 info != null ? convertActivityRecordToProto(info.launchedActivity) : null;
1053
1054 mLaunchObserver.onActivityLaunchCancelled(activityRecordProto);
1055
1056 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001057 }
1058
1059 /**
1060 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1061 * has fully finished (successfully).
1062 */
1063 private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001064 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1065 "MetricsLogger:launchObserverNotifyActivityLaunchFinished");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001066
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001067 mLaunchObserver.onActivityLaunchFinished(
1068 convertActivityRecordToProto(info.launchedActivity));
1069
1070 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1071 }
1072
1073 @VisibleForTesting
1074 static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[]
1075 convertActivityRecordToProto(ActivityRecord record) {
1076 // May take non-negligible amount of time to convert ActivityRecord into a proto,
1077 // so track the time.
1078 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1079 "MetricsLogger:convertActivityRecordToProto");
1080
1081 // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream,
1082 // so create a new one every time.
1083 final ProtoOutputStream protoOutputStream =
1084 new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE);
1085 // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object).
1086 record.writeToProto(protoOutputStream);
1087 final byte[] bytes = protoOutputStream.getBytes();
1088
1089 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1090
1091 return bytes;
Igor Murashkin212d06c2018-10-22 16:34:39 -07001092 }
1093
1094 private static @ActivityMetricsLaunchObserver.Temperature int
1095 convertTransitionTypeToLaunchObserverTemperature(int transitionType) {
1096 switch (transitionType) {
1097 case TYPE_TRANSITION_WARM_LAUNCH:
1098 return ActivityMetricsLaunchObserver.TEMPERATURE_WARM;
1099 case TYPE_TRANSITION_HOT_LAUNCH:
1100 return ActivityMetricsLaunchObserver.TEMPERATURE_HOT;
1101 case TYPE_TRANSITION_COLD_LAUNCH:
1102 return ActivityMetricsLaunchObserver.TEMPERATURE_COLD;
1103 default:
1104 return -1;
1105 }
1106 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -08001107}