blob: 40f10fd658981b1b10ce51a96150f3317636943f [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
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200547 private void checkVisibility(TaskRecord t, ActivityRecord r) {
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700548 synchronized (mSupervisor.mService.mGlobalLock) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200549
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100550 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
551 r.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200552
553 // If we have an active transition that's waiting on a certain activity that will be
554 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
555 if (info != null && !t.isVisible()) {
556 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible"
557 + " activity=" + r);
558 logAppTransitionCancel(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100559 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
560 if (mWindowingModeTransitionInfo.size() == 0) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700561 reset(true /* abort */, info, "notifyVisibilityChanged to invisible");
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200562 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200563 }
564 }
565 }
566
Jorim Jaggi515dd682017-05-05 15:05:07 +0200567 /**
568 * Notifies the tracker that we called immediately before we call bindApplication on the client.
569 *
Wale Ogunwale31913b52018-10-13 08:29:31 -0700570 * @param appInfo The client into which we'll call bindApplication.
Jorim Jaggi515dd682017-05-05 15:05:07 +0200571 */
Wale Ogunwale31913b52018-10-13 08:29:31 -0700572 void notifyBindApplication(ApplicationInfo appInfo) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100573 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
574 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200575
576 // App isn't attached to record yet, so match with info.
Wale Ogunwale31913b52018-10-13 08:29:31 -0700577 if (info.launchedActivity.appInfo == appInfo) {
Jorim Jaggi515dd682017-05-05 15:05:07 +0200578 info.bindApplicationDelayMs = calculateCurrentDelay();
579 }
580 }
581 }
582
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100583 private boolean allWindowsDrawn() {
584 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
585 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800586 return false;
587 }
588 }
589 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500590 }
591
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800592 private boolean isAnyTransitionActive() {
593 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100594 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800595 }
596
Igor Murashkin212d06c2018-10-22 16:34:39 -0700597 private void reset(boolean abort, WindowingModeTransitionInfo info, String cause) {
598 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort + ",cause=" + cause);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800599 if (!abort && isAnyTransitionActive()) {
600 logAppTransitionMultiEvents();
601 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700602 stopLaunchTrace(info);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700603
604 // Ignore reset-after reset.
605 if (isAnyTransitionActive()) {
606 // LaunchObserver callbacks.
607 if (abort) {
608 launchObserverNotifyActivityLaunchCancelled(info);
609 } else {
610 launchObserverNotifyActivityLaunchFinished(info);
611 }
612 } else {
613 launchObserverNotifyIntentFailed();
614 }
615
Jorim Jaggi275561a2016-02-23 10:11:02 -0500616 mCurrentTransitionStartTime = INVALID_START_TIME;
Vishnu Nair132ee832018-09-28 15:00:05 -0700617 mCurrentTransitionDelayMs = INVALID_DELAY;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500618 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100619 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500620 }
621
622 private int calculateCurrentDelay() {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500623 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400624 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500625 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800626
Sudheer Shankac766db02017-06-12 10:37:29 -0700627 private int calculateDelay(long timestamp) {
628 // Shouldn't take more than 25 days to launch an app, so int is fine here.
629 return (int) (timestamp - mCurrentTransitionStartTime);
630 }
631
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100632 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200633 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700634 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200635 return;
636 }
637 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
638 builder.setPackageName(info.launchedActivity.packageName);
639 builder.setType(type);
640 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
641 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000642 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800643 StatsLog.APP_START_CANCELED,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000644 info.launchedActivity.appInfo.uid,
645 info.launchedActivity.packageName,
646 convertAppStartTransitionType(type),
647 info.launchedActivity.info.name);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700648 if (DEBUG_METRICS) {
649 Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)",
650 info.launchedActivity.appInfo.uid,
651 info.launchedActivity.packageName,
652 convertAppStartTransitionType(type),
653 info.launchedActivity.info.name));
654 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200655 }
656
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800657 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200658 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100659 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
660 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800661 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700662 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800663 return;
664 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000665
666 // Take a snapshot of the transition info before sending it to the handler for logging.
667 // This will avoid any races with other operations that modify the ActivityRecord.
668 final WindowingModeTransitionInfoSnapshot infoSnapshot =
669 new WindowingModeTransitionInfoSnapshot(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800670 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime;
671 final int currentTransitionDelayMs = mCurrentTransitionDelayMs;
672 BackgroundThread.getHandler().post(() -> logAppTransition(
673 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot));
Vishnu Nair132ee832018-09-28 15:00:05 -0700674 BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot));
Calin Juravle759fbda2018-02-20 19:52:30 +0000675
676 info.launchedActivity.info.launchToken = null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800677 }
678 }
679
Ng Zhi An83473542018-02-20 09:02:14 -0800680 // This gets called on a background thread without holding the activity manager lock.
Calin Juravle759fbda2018-02-20 19:52:30 +0000681 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
682 WindowingModeTransitionInfoSnapshot info) {
683 final LogMaker builder = new LogMaker(APP_TRANSITION);
684 builder.setPackageName(info.packageName);
685 builder.setType(info.type);
686 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
687 final boolean isInstantApp = info.applicationInfo.isInstantApp();
688 if (info.launchedActivityLaunchedFromPackage != null) {
689 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
690 info.launchedActivityLaunchedFromPackage);
691 }
692 String launchToken = info.launchedActivityLaunchToken;
693 if (launchToken != null) {
694 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
695 }
696 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
697 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
698 currentTransitionDeviceUptime);
699 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
700 builder.setSubtype(info.reason);
Vishnu Nair132ee832018-09-28 15:00:05 -0700701 if (info.startingWindowDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000702 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
703 info.startingWindowDelayMs);
704 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700705 if (info.bindApplicationDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000706 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
707 info.bindApplicationDelayMs);
708 }
709 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
710 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
711 final PackageOptimizationInfo packageOptimizationInfo =
712 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
713 ? PackageOptimizationInfo.createWithNoInfo()
714 : artManagerInternal.getPackageOptimizationInfo(
715 info.applicationInfo,
716 info.launchedActivityAppRecordRequiredAbi);
717 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
718 packageOptimizationInfo.getCompilationReason());
719 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
720 packageOptimizationInfo.getCompilationFilter());
721 mMetricsLogger.write(builder);
722 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800723 StatsLog.APP_START_OCCURRED,
Calin Juravle759fbda2018-02-20 19:52:30 +0000724 info.applicationInfo.uid,
725 info.packageName,
726 convertAppStartTransitionType(info.type),
727 info.launchedActivityName,
728 info.launchedActivityLaunchedFromPackage,
729 isInstantApp,
730 currentTransitionDeviceUptime * 1000,
731 info.reason,
732 currentTransitionDelayMs,
733 info.startingWindowDelayMs,
734 info.bindApplicationDelayMs,
735 info.windowsDrawnDelayMs,
736 launchToken,
737 packageOptimizationInfo.getCompilationReason(),
738 packageOptimizationInfo.getCompilationFilter());
Igor Murashkin212d06c2018-10-22 16:34:39 -0700739
740 if (DEBUG_METRICS) {
741 Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)",
742 info.applicationInfo.uid,
743 info.packageName,
744 convertAppStartTransitionType(info.type),
745 info.launchedActivityName,
746 info.launchedActivityLaunchedFromPackage));
747 }
748
749
Ng Zhi An83473542018-02-20 09:02:14 -0800750 logAppStartMemoryStateCapture(info);
Calin Juravle759fbda2018-02-20 19:52:30 +0000751 }
752
Vishnu Nair132ee832018-09-28 15:00:05 -0700753 private void logAppDisplayed(WindowingModeTransitionInfoSnapshot info) {
754 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
755 return;
756 }
757
758 EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME,
759 info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,
760 info.windowsDrawnDelayMs);
761
762 StringBuilder sb = mStringBuilder;
763 sb.setLength(0);
764 sb.append("Displayed ");
765 sb.append(info.launchedActivityShortComponentName);
766 sb.append(": ");
767 TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb);
768 Log.i(TAG, sb.toString());
769 }
770
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000771 private int convertAppStartTransitionType(int tronType) {
772 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800773 return StatsLog.APP_START_OCCURRED__TYPE__COLD;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000774 }
775 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800776 return StatsLog.APP_START_OCCURRED__TYPE__WARM;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000777 }
778 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800779 return StatsLog.APP_START_OCCURRED__TYPE__HOT;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000780 }
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800781 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000782 }
783
Vishnu Nair132ee832018-09-28 15:00:05 -0700784 WindowingModeTransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r,
785 boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100786 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
787 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200788 if (info == null) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700789 return null;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200790 }
Chris Wailes35c193c2018-10-09 18:12:00 -0700791
792 // Record the handling of the reportFullyDrawn callback in the trace system. This is not
793 // actually used to trace this function, but instead the logical task that this function
794 // fullfils (handling reportFullyDrawn() callbacks).
795 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
796 "ActivityManager:ReportingFullyDrawn " + info.launchedActivity.packageName);
797
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200798 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
799 builder.setPackageName(r.packageName);
800 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000801 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
802 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200803 builder.setType(restoredFromBundle
804 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
805 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
806 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
807 info.currentTransitionProcessRunning ? 1 : 0);
808 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000809 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800810 StatsLog.APP_START_FULLY_DRAWN,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000811 info.launchedActivity.appInfo.uid,
812 info.launchedActivity.packageName,
813 restoredFromBundle
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800814 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE
815 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000816 info.launchedActivity.info.name,
817 info.currentTransitionProcessRunning,
818 startupTimeMs);
Chris Wailes35c193c2018-10-09 18:12:00 -0700819
820 // Ends the trace started at the beginning of this function. This is located here to allow
821 // the trace slice to have a noticable duration.
822 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
823
Vishnu Nair132ee832018-09-28 15:00:05 -0700824 final WindowingModeTransitionInfoSnapshot infoSnapshot =
825 new WindowingModeTransitionInfoSnapshot(info, r, (int) startupTimeMs);
826 BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot));
827 return infoSnapshot;
828 }
829
830 private void logAppFullyDrawn(WindowingModeTransitionInfoSnapshot info) {
831 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
832 return;
833 }
834
835 StringBuilder sb = mStringBuilder;
836 sb.setLength(0);
837 sb.append("Fully drawn ");
838 sb.append(info.launchedActivityShortComponentName);
839 sb.append(": ");
840 TimeUtils.formatDuration(info.windowsFullyDrawnDelayMs, sb);
841 Log.i(TAG, sb.toString());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200842 }
843
Michal Karpinski4fd5b842019-01-28 15:13:32 +0000844 void logAbortedBgActivityStart(Intent intent, WindowProcessController callerApp,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100845 int callingUid, String callingPackage, int callingUidProcState,
846 boolean callingUidHasAnyVisibleWindow,
847 int realCallingUid, int realCallingUidProcState,
848 boolean realCallingUidHasAnyVisibleWindow,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100849 boolean comingFromPendingIntent) {
850
851 final long nowElapsed = SystemClock.elapsedRealtime();
852 final long nowUptime = SystemClock.uptimeMillis();
853 final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START);
854 builder.setTimestamp(System.currentTimeMillis());
855 builder.addTaggedData(FIELD_CALLING_UID, callingUid);
856 builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage);
857 builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE,
858 processStateAmToProto(callingUidProcState));
859 builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
860 callingUidHasAnyVisibleWindow ? 1 : 0);
861 builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid);
862 builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE,
863 processStateAmToProto(realCallingUidProcState));
864 builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
865 realCallingUidHasAnyVisibleWindow ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100866 builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0);
Michal Karpinski8596ded2018-11-14 14:43:48 +0000867 if (intent != null) {
868 builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction());
869 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100870 if (callerApp != null) {
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700871 builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100872 builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700873 processStateAmToProto(callerApp.getCurrentProcState()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100874 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700875 callerApp.hasClientActivities() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100876 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES,
877 callerApp.hasForegroundServices() ? 1 : 0);
878 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700879 callerApp.hasForegroundActivities() ? 1 : 0);
880 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100881 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700882 callerApp.hasOverlayUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100883 builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700884 callerApp.hasPendingUiClean() ? 1 : 0);
885 if (callerApp.getInteractionEventTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100886 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700887 (nowElapsed - callerApp.getInteractionEventTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100888 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700889 if (callerApp.getFgInteractionTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100890 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700891 (nowElapsed - callerApp.getFgInteractionTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100892 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700893 if (callerApp.getWhenUnimportant() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100894 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700895 (nowUptime - callerApp.getWhenUnimportant()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100896 }
897 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100898 mMetricsLogger.write(builder);
899 }
900
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100901 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800902 if (info.currentTransitionProcessRunning) {
903 if (info.startResult == START_SUCCESS) {
904 return TYPE_TRANSITION_WARM_LAUNCH;
905 } else if (info.startResult == START_TASK_TO_FRONT) {
906 return TYPE_TRANSITION_HOT_LAUNCH;
907 }
908 } else if (info.startResult == START_SUCCESS) {
909 return TYPE_TRANSITION_COLD_LAUNCH;
910 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700911 return INVALID_TRANSITION_TYPE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800912 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800913
Ng Zhi An83473542018-02-20 09:02:14 -0800914 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
915 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800916 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
917 return;
918 }
919
Wale Ogunwalef6733932018-06-27 05:14:34 -0700920 final int pid = info.processRecord.getPid();
Ng Zhi An83473542018-02-20 09:02:14 -0800921 final int uid = info.applicationInfo.uid;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +0000922 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800923 if (memoryStat == null) {
924 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
925 return;
926 }
927
928 StatsLog.write(
929 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
930 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800931 info.processName,
932 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800933 memoryStat.pgfault,
934 memoryStat.pgmajfault,
935 memoryStat.rssInBytes,
936 memoryStat.cacheInBytes,
937 memoryStat.swapInBytes);
938 }
939
Wale Ogunwalef6733932018-06-27 05:14:34 -0700940 private WindowProcessController findProcessForActivity(ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800941 return launchedActivity != null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700942 ? mSupervisor.mService.mProcessNames.get(
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700943 launchedActivity.processName, launchedActivity.appInfo.uid)
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800944 : null;
945 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000946
947 private ArtManagerInternal getArtManagerInternal() {
948 if (mArtManagerInternal == null) {
949 // Note that this may be null.
950 // ArtManagerInternal is registered during PackageManagerService
951 // initialization which happens after ActivityManagerService.
952 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
953 }
954 return mArtManagerInternal;
955 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700956
957 /**
Chris Wailes35c193c2018-10-09 18:12:00 -0700958 * Starts traces for app launch.
Vishnu Nair132ee832018-09-28 15:00:05 -0700959 *
960 * @param info
961 * */
962 private void startTraces(WindowingModeTransitionInfo info) {
963 if (info == null) {
964 return;
965 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700966 int transitionType = getTransitionType(info);
967 if (!info.launchTraceActive && transitionType == TYPE_TRANSITION_WARM_LAUNCH
968 || transitionType == TYPE_TRANSITION_COLD_LAUNCH) {
969 Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
970 + info.launchedActivity.packageName, 0);
Vishnu Nair132ee832018-09-28 15:00:05 -0700971 info.launchTraceActive = true;
972 }
973 }
974
975 private void stopLaunchTrace(WindowingModeTransitionInfo info) {
976 if (info == null) {
977 return;
978 }
979 if (info.launchTraceActive) {
980 Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
981 + info.launchedActivity.packageName, 0);
982 info.launchTraceActive = false;
983 }
984 }
Igor Murashkin212d06c2018-10-22 16:34:39 -0700985
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800986 public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() {
987 return mLaunchObserver;
988 }
989
Igor Murashkin212d06c2018-10-22 16:34:39 -0700990 /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */
991 private void launchObserverNotifyIntentStarted(Intent intent) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800992 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
993 "MetricsLogger:launchObserverNotifyIntentStarted");
994
995 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
996 mLaunchObserver.onIntentStarted(intent);
997
998 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700999 }
1000
1001 /**
1002 * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has
1003 * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or
1004 * intent being delivered to the top running activity.
1005 */
1006 private void launchObserverNotifyIntentFailed() {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001007 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1008 "MetricsLogger:launchObserverNotifyIntentFailed");
1009
1010 mLaunchObserver.onIntentFailed();
1011
1012 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001013 }
1014
1015 /**
1016 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1017 * has started.
1018 */
1019 private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001020 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1021 "MetricsLogger:launchObserverNotifyActivityLaunched");
1022
Igor Murashkin212d06c2018-10-22 16:34:39 -07001023 @ActivityMetricsLaunchObserver.Temperature int temperature =
1024 convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info));
1025
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001026 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1027 mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.launchedActivity),
1028 temperature);
1029
1030 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001031 }
1032
1033 /**
1034 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is
1035 * cancelled.
1036 */
1037 private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001038 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1039 "MetricsLogger:launchObserverNotifyActivityLaunchCancelled");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001040
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001041 final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto =
1042 info != null ? convertActivityRecordToProto(info.launchedActivity) : null;
1043
1044 mLaunchObserver.onActivityLaunchCancelled(activityRecordProto);
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 current launch sequence's activity
1051 * has fully finished (successfully).
1052 */
1053 private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001054 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1055 "MetricsLogger:launchObserverNotifyActivityLaunchFinished");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001056
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001057 mLaunchObserver.onActivityLaunchFinished(
1058 convertActivityRecordToProto(info.launchedActivity));
1059
1060 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1061 }
1062
1063 @VisibleForTesting
1064 static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[]
1065 convertActivityRecordToProto(ActivityRecord record) {
1066 // May take non-negligible amount of time to convert ActivityRecord into a proto,
1067 // so track the time.
1068 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1069 "MetricsLogger:convertActivityRecordToProto");
1070
1071 // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream,
1072 // so create a new one every time.
1073 final ProtoOutputStream protoOutputStream =
1074 new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE);
1075 // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object).
1076 record.writeToProto(protoOutputStream);
1077 final byte[] bytes = protoOutputStream.getBytes();
1078
1079 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1080
1081 return bytes;
Igor Murashkin212d06c2018-10-22 16:34:39 -07001082 }
1083
1084 private static @ActivityMetricsLaunchObserver.Temperature int
1085 convertTransitionTypeToLaunchObserverTemperature(int transitionType) {
1086 switch (transitionType) {
1087 case TYPE_TRANSITION_WARM_LAUNCH:
1088 return ActivityMetricsLaunchObserver.TEMPERATURE_WARM;
1089 case TYPE_TRANSITION_HOT_LAUNCH:
1090 return ActivityMetricsLaunchObserver.TEMPERATURE_HOT;
1091 case TYPE_TRANSITION_COLD_LAUNCH:
1092 return ActivityMetricsLaunchObserver.TEMPERATURE_COLD;
1093 default:
1094 return -1;
1095 }
1096 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -08001097}