blob: c0924511384a64d89bba77c54165ac6a33d1cb07 [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
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700854 void logActivityStart(Intent intent, WindowProcessController callerApp, ActivityRecord r,
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,
859 int targetUid, String targetPackage, int targetUidProcState,
860 boolean targetUidHasAnyVisibleWindow, String targetWhitelistTag,
861 boolean comingFromPendingIntent) {
862
863 final long nowElapsed = SystemClock.elapsedRealtime();
864 final long nowUptime = SystemClock.uptimeMillis();
865 final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START);
866 builder.setTimestamp(System.currentTimeMillis());
867 builder.addTaggedData(FIELD_CALLING_UID, callingUid);
868 builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage);
869 builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE,
870 processStateAmToProto(callingUidProcState));
871 builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
872 callingUidHasAnyVisibleWindow ? 1 : 0);
873 builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid);
874 builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE,
875 processStateAmToProto(realCallingUidProcState));
876 builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
877 realCallingUidHasAnyVisibleWindow ? 1 : 0);
878 builder.addTaggedData(FIELD_TARGET_UID, targetUid);
879 builder.addTaggedData(FIELD_TARGET_PACKAGE_NAME, targetPackage);
880 builder.addTaggedData(FIELD_TARGET_UID_PROC_STATE,
881 processStateAmToProto(targetUidProcState));
882 builder.addTaggedData(FIELD_TARGET_UID_HAS_ANY_VISIBLE_WINDOW,
883 targetUidHasAnyVisibleWindow ? 1 : 0);
884 builder.addTaggedData(FIELD_TARGET_WHITELIST_TAG, targetWhitelistTag);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100885 builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0);
Michal Karpinski8596ded2018-11-14 14:43:48 +0000886 if (intent != null) {
887 builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction());
888 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100889 if (callerApp != null) {
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700890 builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100891 builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700892 processStateAmToProto(callerApp.getCurrentProcState()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100893 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700894 callerApp.hasClientActivities() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100895 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES,
896 callerApp.hasForegroundServices() ? 1 : 0);
897 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700898 callerApp.hasForegroundActivities() ? 1 : 0);
899 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100900 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700901 callerApp.hasOverlayUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100902 builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700903 callerApp.hasPendingUiClean() ? 1 : 0);
904 if (callerApp.getInteractionEventTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100905 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700906 (nowElapsed - callerApp.getInteractionEventTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100907 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700908 if (callerApp.getFgInteractionTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100909 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700910 (nowElapsed - callerApp.getFgInteractionTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100911 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700912 if (callerApp.getWhenUnimportant() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100913 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700914 (nowUptime - callerApp.getWhenUnimportant()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100915 }
916 }
Michal Karpinski8596ded2018-11-14 14:43:48 +0000917 if (r != null) {
918 builder.addTaggedData(FIELD_TARGET_SHORT_COMPONENT_NAME, r.shortComponentName);
919 builder.addTaggedData(FIELD_ACTIVITY_RECORD_LAUNCH_MODE, r.info.launchMode);
920 builder.addTaggedData(FIELD_ACTIVITY_RECORD_TARGET_ACTIVITY, r.info.targetActivity);
921 builder.addTaggedData(FIELD_ACTIVITY_RECORD_FLAGS, r.info.flags);
922 builder.addTaggedData(FIELD_ACTIVITY_RECORD_REAL_ACTIVITY,
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800923 r.mActivityComponent.toShortString());
Michal Karpinski8596ded2018-11-14 14:43:48 +0000924 builder.addTaggedData(FIELD_ACTIVITY_RECORD_SHORT_COMPONENT_NAME, r.shortComponentName);
925 builder.addTaggedData(FIELD_ACTIVITY_RECORD_PROCESS_NAME, r.processName);
926 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_FULLSCREEN, r.fullscreen ? 1 : 0);
927 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_NO_DISPLAY, r.noDisplay ? 1 : 0);
928 if (r.lastVisibleTime != 0) {
929 builder.addTaggedData(FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_VISIBLE,
930 (nowUptime - r.lastVisibleTime));
931 }
932 if (r.resultTo != null) {
933 builder.addTaggedData(FIELD_ACTIVITY_RECORD_RESULT_TO_PKG_NAME,
934 r.resultTo.packageName);
935 builder.addTaggedData(FIELD_ACTIVITY_RECORD_RESULT_TO_SHORT_COMPONENT_NAME,
936 r.resultTo.shortComponentName);
937 }
938 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_VISIBLE, r.visible ? 1 : 0);
939 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_VISIBLE_IGNORING_KEYGUARD,
940 r.visibleIgnoringKeyguard ? 1 : 0);
941 if (r.lastLaunchTime != 0) {
942 builder.addTaggedData(FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_LAUNCH,
943 (nowUptime - r.lastLaunchTime));
944 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100945 }
946 mMetricsLogger.write(builder);
947 }
948
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100949 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800950 if (info.currentTransitionProcessRunning) {
951 if (info.startResult == START_SUCCESS) {
952 return TYPE_TRANSITION_WARM_LAUNCH;
953 } else if (info.startResult == START_TASK_TO_FRONT) {
954 return TYPE_TRANSITION_HOT_LAUNCH;
955 }
956 } else if (info.startResult == START_SUCCESS) {
957 return TYPE_TRANSITION_COLD_LAUNCH;
958 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700959 return INVALID_TRANSITION_TYPE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800960 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800961
Ng Zhi An83473542018-02-20 09:02:14 -0800962 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
963 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800964 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
965 return;
966 }
967
Wale Ogunwalef6733932018-06-27 05:14:34 -0700968 final int pid = info.processRecord.getPid();
Ng Zhi An83473542018-02-20 09:02:14 -0800969 final int uid = info.applicationInfo.uid;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +0000970 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800971 if (memoryStat == null) {
972 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
973 return;
974 }
975
976 StatsLog.write(
977 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
978 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800979 info.processName,
980 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800981 memoryStat.pgfault,
982 memoryStat.pgmajfault,
983 memoryStat.rssInBytes,
984 memoryStat.cacheInBytes,
985 memoryStat.swapInBytes);
986 }
987
Wale Ogunwalef6733932018-06-27 05:14:34 -0700988 private WindowProcessController findProcessForActivity(ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800989 return launchedActivity != null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700990 ? mSupervisor.mService.mProcessNames.get(
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700991 launchedActivity.processName, launchedActivity.appInfo.uid)
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800992 : null;
993 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000994
995 private ArtManagerInternal getArtManagerInternal() {
996 if (mArtManagerInternal == null) {
997 // Note that this may be null.
998 // ArtManagerInternal is registered during PackageManagerService
999 // initialization which happens after ActivityManagerService.
1000 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
1001 }
1002 return mArtManagerInternal;
1003 }
Vishnu Nair132ee832018-09-28 15:00:05 -07001004
1005 /**
Chris Wailes35c193c2018-10-09 18:12:00 -07001006 * Starts traces for app launch.
Vishnu Nair132ee832018-09-28 15:00:05 -07001007 *
1008 * @param info
1009 * */
1010 private void startTraces(WindowingModeTransitionInfo info) {
1011 if (info == null) {
1012 return;
1013 }
Vishnu Nair132ee832018-09-28 15:00:05 -07001014 int transitionType = getTransitionType(info);
1015 if (!info.launchTraceActive && transitionType == TYPE_TRANSITION_WARM_LAUNCH
1016 || transitionType == TYPE_TRANSITION_COLD_LAUNCH) {
1017 Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
1018 + info.launchedActivity.packageName, 0);
Vishnu Nair132ee832018-09-28 15:00:05 -07001019 info.launchTraceActive = true;
1020 }
1021 }
1022
1023 private void stopLaunchTrace(WindowingModeTransitionInfo info) {
1024 if (info == null) {
1025 return;
1026 }
1027 if (info.launchTraceActive) {
1028 Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
1029 + info.launchedActivity.packageName, 0);
1030 info.launchTraceActive = false;
1031 }
1032 }
Igor Murashkin212d06c2018-10-22 16:34:39 -07001033
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001034 public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() {
1035 return mLaunchObserver;
1036 }
1037
Igor Murashkin212d06c2018-10-22 16:34:39 -07001038 /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */
1039 private void launchObserverNotifyIntentStarted(Intent intent) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001040 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1041 "MetricsLogger:launchObserverNotifyIntentStarted");
1042
1043 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1044 mLaunchObserver.onIntentStarted(intent);
1045
1046 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001047 }
1048
1049 /**
1050 * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has
1051 * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or
1052 * intent being delivered to the top running activity.
1053 */
1054 private void launchObserverNotifyIntentFailed() {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001055 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1056 "MetricsLogger:launchObserverNotifyIntentFailed");
1057
1058 mLaunchObserver.onIntentFailed();
1059
1060 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001061 }
1062
1063 /**
1064 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1065 * has started.
1066 */
1067 private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001068 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1069 "MetricsLogger:launchObserverNotifyActivityLaunched");
1070
Igor Murashkin212d06c2018-10-22 16:34:39 -07001071 @ActivityMetricsLaunchObserver.Temperature int temperature =
1072 convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info));
1073
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001074 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1075 mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.launchedActivity),
1076 temperature);
1077
1078 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001079 }
1080
1081 /**
1082 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is
1083 * cancelled.
1084 */
1085 private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001086 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1087 "MetricsLogger:launchObserverNotifyActivityLaunchCancelled");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001088
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001089 final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto =
1090 info != null ? convertActivityRecordToProto(info.launchedActivity) : null;
1091
1092 mLaunchObserver.onActivityLaunchCancelled(activityRecordProto);
1093
1094 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001095 }
1096
1097 /**
1098 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1099 * has fully finished (successfully).
1100 */
1101 private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001102 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1103 "MetricsLogger:launchObserverNotifyActivityLaunchFinished");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001104
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001105 mLaunchObserver.onActivityLaunchFinished(
1106 convertActivityRecordToProto(info.launchedActivity));
1107
1108 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1109 }
1110
1111 @VisibleForTesting
1112 static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[]
1113 convertActivityRecordToProto(ActivityRecord record) {
1114 // May take non-negligible amount of time to convert ActivityRecord into a proto,
1115 // so track the time.
1116 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1117 "MetricsLogger:convertActivityRecordToProto");
1118
1119 // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream,
1120 // so create a new one every time.
1121 final ProtoOutputStream protoOutputStream =
1122 new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE);
1123 // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object).
1124 record.writeToProto(protoOutputStream);
1125 final byte[] bytes = protoOutputStream.getBytes();
1126
1127 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1128
1129 return bytes;
Igor Murashkin212d06c2018-10-22 16:34:39 -07001130 }
1131
1132 private static @ActivityMetricsLaunchObserver.Temperature int
1133 convertTransitionTypeToLaunchObserverTemperature(int transitionType) {
1134 switch (transitionType) {
1135 case TYPE_TRANSITION_WARM_LAUNCH:
1136 return ActivityMetricsLaunchObserver.TEMPERATURE_WARM;
1137 case TYPE_TRANSITION_HOT_LAUNCH:
1138 return ActivityMetricsLaunchObserver.TEMPERATURE_HOT;
1139 case TYPE_TRANSITION_COLD_LAUNCH:
1140 return ActivityMetricsLaunchObserver.TEMPERATURE_COLD;
1141 default:
1142 return -1;
1143 }
1144 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -08001145}