blob: 12690a99062e9529c351b9d09f4abb19e8fba4ac [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;
Bryce Lee6c605092017-10-12 11:14:49 -07006import static android.app.WindowConfiguration.WINDOWING_MODE_FREEFORM;
Wale Ogunwale3382ab12017-07-27 08:55:03 -07007import static android.app.WindowConfiguration.WINDOWING_MODE_FULLSCREEN;
8import static android.app.WindowConfiguration.WINDOWING_MODE_PINNED;
Vishnu Nair132ee832018-09-28 15:00:05 -07009import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_PRIMARY;
Wale Ogunwale926aade2017-08-29 11:24:37 -070010import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_SECONDARY;
11import static android.app.WindowConfiguration.WINDOWING_MODE_UNDEFINED;
Vishnu Nair132ee832018-09-28 15:00:05 -070012
Michal Karpinski201bc0c2018-07-20 15:32:00 +010013import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.ACTION_ACTIVITY_START;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080014import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION;
Jorim Jaggi515dd682017-05-05 15:05:07 +020015import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_BIND_APPLICATION_DELAY_MS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070016import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CALLING_PACKAGE_NAME;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020017import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CANCELLED;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080018import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DELAY_MS;
19import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS;
Todd Kennedy50d946c12017-03-17 13:55:38 -070020import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_IS_EPHEMERAL;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020021import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_PROCESS_RUNNING;
22import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN;
23import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN_MS;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080024import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_STARTING_WINDOW_DELAY_MS;
25import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010026import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_FLAGS;
27import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_FULLSCREEN;
28import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_NO_DISPLAY;
29import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_VISIBLE;
30import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_IS_VISIBLE_IGNORING_KEYGUARD;
Vishnu Nair132ee832018-09-28 15:00:05 -070031import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_LAUNCH_MODE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010032import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_LAUNCH;
33import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_VISIBLE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010034import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_PROCESS_NAME;
35import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_REAL_ACTIVITY;
36import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_RESULT_TO_PKG_NAME;
37import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_RESULT_TO_SHORT_COMPONENT_NAME;
38import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_SHORT_COMPONENT_NAME;
39import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_ACTIVITY_RECORD_TARGET_ACTIVITY;
40import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_PACKAGE_NAME;
41import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID;
42import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW;
43import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_PROC_STATE;
Jorim Jaggicdfc04e2017-04-28 19:06:24 +020044import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010045import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_COMING_FROM_PENDING_INTENT;
Todd Kennedy50d946c12017-03-17 13:55:38 -070046import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INSTANT_APP_LAUNCH_TOKEN;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010047import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INTENT_ACTION;
48import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_CUR_PROC_STATE;
49import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES;
50import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES;
51import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES;
52import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_OVERLAY_UI;
53import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_TOP_UI;
54import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION;
55import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT;
56import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT;
57import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PENDING_UI_CLEAN;
58import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PROCESS_NAME;
59import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010060import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW;
Vishnu Nair132ee832018-09-28 15:00:05 -070061import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_PROC_STATE;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010062import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_PACKAGE_NAME;
63import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_SHORT_COMPONENT_NAME;
64import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_UID;
65import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_UID_HAS_ANY_VISIBLE_WINDOW;
66import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_UID_PROC_STATE;
67import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_WHITELIST_TAG;
Calin Juravle759fbda2018-02-20 19:52:30 +000068import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_FILTER;
Vishnu Nair132ee832018-09-28 15:00:05 -070069import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_REASON;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080070import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_COLD_LAUNCH;
71import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_HOT_LAUNCH;
Jorim Jaggi4d27b842017-08-17 17:22:26 +020072import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE;
73import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080074import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH;
Vishnu Nair132ee832018-09-28 15:00:05 -070075import static com.android.server.am.EventLogTags.AM_ACTIVITY_LAUNCH_TIME;
Ng Zhi Anbbefdec2018-01-30 17:12:39 -080076import static com.android.server.am.MemoryStatUtil.MemoryStat;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +000077import static com.android.server.am.MemoryStatUtil.readMemoryStatFromFilesystem;
Vishnu Naira62534b2018-11-09 09:13:22 -080078import static com.android.server.wm.ActivityTaskManagerDebugConfig.DEBUG_METRICS;
79import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_ATM;
80import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_WITH_CLASS_NAME;
Vishnu Nair132ee832018-09-28 15:00:05 -070081import static com.android.server.wm.ActivityTaskManagerInternal.APP_TRANSITION_TIMEOUT;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080082
Igor Murashkin212d06c2018-10-22 16:34:39 -070083import android.app.WindowConfiguration.WindowingMode;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080084import android.content.Context;
Michal Karpinski201bc0c2018-07-20 15:32:00 +010085import android.content.Intent;
Calin Juravle759fbda2018-02-20 19:52:30 +000086import android.content.pm.ApplicationInfo;
87import android.content.pm.dex.ArtManagerInternal;
88import android.content.pm.dex.PackageOptimizationInfo;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080089import android.metrics.LogMaker;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020090import android.os.Handler;
91import android.os.Looper;
92import android.os.Message;
Filip Gruszczynski77d94482015-12-11 13:59:52 -080093import android.os.SystemClock;
Vishnu Nair132ee832018-09-28 15:00:05 -070094import android.os.Trace;
95import android.util.EventLog;
96import android.util.Log;
Jorim Jaggi172e99f2017-10-20 14:33:18 +020097import android.util.Slog;
Jorim Jaggi3878ca32017-02-02 17:13:05 -080098import android.util.SparseArray;
99import android.util.SparseIntArray;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000100import android.util.StatsLog;
Vishnu Nair132ee832018-09-28 15:00:05 -0700101import android.util.TimeUtils;
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800102import android.util.proto.ProtoOutputStream;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800103
104import com.android.internal.logging.MetricsLogger;
Ng Zhi An83473542018-02-20 09:02:14 -0800105import com.android.internal.os.BackgroundThread;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200106import com.android.internal.os.SomeArgs;
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800107import com.android.internal.annotations.VisibleForTesting;
Calin Juravle759fbda2018-02-20 19:52:30 +0000108import com.android.server.LocalServices;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800109
110/**
Vishnu Nair132ee832018-09-28 15:00:05 -0700111 * Listens to activity launches, transitions, visibility changes and window drawn callbacks to
112 * determine app launch times and draw delays. Source of truth for activity metrics and provides
113 * data for Tron, logcat, event logs and {@link android.app.WaitResult}.
114 *
115 * Tests:
Vishnu Nairf8accc52018-10-11 10:19:54 -0700116 * atest CtsActivityManagerDeviceTestCases:ActivityMetricsLoggerTests
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800117 */
118class ActivityMetricsLogger {
Jorim Jaggif9704102016-05-05 19:14:22 -0700119
Wale Ogunwale98875612018-10-12 07:53:02 -0700120 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_ATM;
Jorim Jaggif9704102016-05-05 19:14:22 -0700121
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800122 // Window modes we are interested in logging. If we ever introduce a new type, we need to add
123 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array.
124 private static final int WINDOW_STATE_STANDARD = 0;
125 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1;
126 private static final int WINDOW_STATE_FREEFORM = 2;
Winson Chung83471632016-12-13 11:02:12 -0800127 private static final int WINDOW_STATE_ASSISTANT = 3;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800128 private static final int WINDOW_STATE_INVALID = -1;
129
Jorim Jaggi275561a2016-02-23 10:11:02 -0500130 private static final long INVALID_START_TIME = -1;
Vishnu Nair132ee832018-09-28 15:00:05 -0700131 private static final int INVALID_DELAY = -1;
132 private static final int INVALID_TRANSITION_TYPE = -1;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500133
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200134 private static final int MSG_CHECK_VISIBILITY = 0;
135
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800136 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every
137 // time we log.
138 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = {
Winson Chung83471632016-12-13 11:02:12 -0800139 "window_time_0", "window_time_1", "window_time_2", "window_time_3"};
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800140
141 private int mWindowState = WINDOW_STATE_STANDARD;
142 private long mLastLogTimeSecs;
143 private final ActivityStackSupervisor mSupervisor;
144 private final Context mContext;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800145 private final MetricsLogger mMetricsLogger = new MetricsLogger();
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800146
Igor Murashkin212d06c2018-10-22 16:34:39 -0700147 // set to INVALID_START_TIME in reset.
148 // set to valid value in notifyActivityLaunching
Jorim Jaggi275561a2016-02-23 10:11:02 -0500149 private long mCurrentTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200150 private long mLastTransitionStartTime = INVALID_START_TIME;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800151
152 private int mCurrentTransitionDeviceUptime;
153 private int mCurrentTransitionDelayMs;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700154
155 /** If the any app transitions have been logged as starting, after the latest reset. */
Jorim Jaggi275561a2016-02-23 10:11:02 -0500156 private boolean mLoggedTransitionStarting;
157
Igor Murashkin212d06c2018-10-22 16:34:39 -0700158 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100159 private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo =
160 new SparseArray<>();
Igor Murashkin212d06c2018-10-22 16:34:39 -0700161 /** Map : @WindowingMode int => WindowingModeTransitionInfo */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100162 private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo =
163 new SparseArray<>();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200164 private final H mHandler;
Calin Juravle759fbda2018-02-20 19:52:30 +0000165
166 private ArtManagerInternal mArtManagerInternal;
Vishnu Nair132ee832018-09-28 15:00:05 -0700167 private final StringBuilder mStringBuilder = new StringBuilder();
Calin Juravle759fbda2018-02-20 19:52:30 +0000168
Igor Murashkin212d06c2018-10-22 16:34:39 -0700169 /**
170 * Due to the global single concurrent launch sequence, all calls to this observer must be made
171 * in-order on the same thread to fulfill the "happens-before" guarantee in LaunchObserver.
172 */
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800173 private final LaunchObserverRegistryImpl mLaunchObserver;
174 @VisibleForTesting static final int LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE = 512;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700175
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200176 private final class H extends Handler {
177
178 public H(Looper looper) {
179 super(looper);
180 }
181
182 @Override
183 public void handleMessage(Message msg) {
184 switch (msg.what) {
185 case MSG_CHECK_VISIBILITY:
186 final SomeArgs args = (SomeArgs) msg.obj;
187 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2);
188 break;
189 }
190 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000191 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800192
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100193 private final class WindowingModeTransitionInfo {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700194 /** The latest activity to have been launched. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800195 private ActivityRecord launchedActivity;
196 private int startResult;
197 private boolean currentTransitionProcessRunning;
Vishnu Nair132ee832018-09-28 15:00:05 -0700198 /** Elapsed time from when we launch an activity to when its windows are drawn. */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800199 private int windowsDrawnDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700200 private int startingWindowDelayMs = INVALID_DELAY;
201 private int bindApplicationDelayMs = INVALID_DELAY;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800202 private int reason = APP_TRANSITION_TIMEOUT;
203 private boolean loggedWindowsDrawn;
204 private boolean loggedStartingWindowDrawn;
Vishnu Nair132ee832018-09-28 15:00:05 -0700205 private boolean launchTraceActive;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800206 }
207
Vishnu Nair132ee832018-09-28 15:00:05 -0700208 final class WindowingModeTransitionInfoSnapshot {
Calin Juravle759fbda2018-02-20 19:52:30 +0000209 final private ApplicationInfo applicationInfo;
Wale Ogunwalef6733932018-06-27 05:14:34 -0700210 final private WindowProcessController processRecord;
Vishnu Nair132ee832018-09-28 15:00:05 -0700211 final String packageName;
212 final String launchedActivityName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000213 final private String launchedActivityLaunchedFromPackage;
214 final private String launchedActivityLaunchToken;
215 final private String launchedActivityAppRecordRequiredAbi;
Vishnu Nair132ee832018-09-28 15:00:05 -0700216 final String launchedActivityShortComponentName;
Ng Zhi An83473542018-02-20 09:02:14 -0800217 final private String processName;
Calin Juravle759fbda2018-02-20 19:52:30 +0000218 final private int reason;
219 final private int startingWindowDelayMs;
220 final private int bindApplicationDelayMs;
Vishnu Nair132ee832018-09-28 15:00:05 -0700221 final int windowsDrawnDelayMs;
222 final int type;
223 final int userId;
224 /**
225 * Elapsed time from when we launch an activity to when the app reported it was
226 * fully drawn. If this is not reported then the value is set to INVALID_DELAY.
227 */
228 final int windowsFullyDrawnDelayMs;
229 final int activityRecordIdHashCode;
Calin Juravle759fbda2018-02-20 19:52:30 +0000230
231 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700232 this(info, info.launchedActivity);
233 }
234
235 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
236 ActivityRecord launchedActivity) {
237 this(info, launchedActivity, INVALID_DELAY);
238 }
239
240 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info,
241 ActivityRecord launchedActivity, int windowsFullyDrawnDelayMs) {
242 applicationInfo = launchedActivity.appInfo;
243 packageName = launchedActivity.packageName;
244 launchedActivityName = launchedActivity.info.name;
245 launchedActivityLaunchedFromPackage = launchedActivity.launchedFromPackage;
246 launchedActivityLaunchToken = launchedActivity.info.launchToken;
247 launchedActivityAppRecordRequiredAbi = launchedActivity.app == null
Calin Juravle759fbda2018-02-20 19:52:30 +0000248 ? null
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700249 : launchedActivity.app.getRequiredAbi();
Calin Juravle759fbda2018-02-20 19:52:30 +0000250 reason = info.reason;
251 startingWindowDelayMs = info.startingWindowDelayMs;
252 bindApplicationDelayMs = info.bindApplicationDelayMs;
253 windowsDrawnDelayMs = info.windowsDrawnDelayMs;
254 type = getTransitionType(info);
Vishnu Nairaf0ea312018-10-15 16:23:55 -0700255 processRecord = findProcessForActivity(launchedActivity);
256 processName = launchedActivity.processName;
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800257 userId = launchedActivity.mUserId;
Vishnu Nair132ee832018-09-28 15:00:05 -0700258 launchedActivityShortComponentName = launchedActivity.shortComponentName;
259 activityRecordIdHashCode = System.identityHashCode(launchedActivity);
260 this.windowsFullyDrawnDelayMs = windowsFullyDrawnDelayMs;
Calin Juravle759fbda2018-02-20 19:52:30 +0000261 }
262 }
263
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200264 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper) {
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800265 mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000;
266 mSupervisor = supervisor;
267 mContext = context;
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200268 mHandler = new H(looper);
Igor Murashkinc0b47e42018-11-07 15:54:18 -0800269 mLaunchObserver = new LaunchObserverRegistryImpl(looper);
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800270 }
271
272 void logWindowState() {
273 final long now = SystemClock.elapsedRealtime() / 1000;
274 if (mWindowState != WINDOW_STATE_INVALID) {
275 // We log even if the window state hasn't changed, because the user might remain in
276 // home/fullscreen move forever and we would like to track this kind of behavior
277 // too.
278 MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState],
279 (int) (now - mLastLogTimeSecs));
280 }
281 mLastLogTimeSecs = now;
282
Wale Ogunwale926aade2017-08-29 11:24:37 -0700283 mWindowState = WINDOW_STATE_INVALID;
Wale Ogunwaled32da472018-11-16 07:19:28 -0800284 ActivityStack stack =
285 mSupervisor.mRootActivityContainer.getTopDisplayFocusedStack();
lumarkf6c4a982018-06-15 15:43:12 +0800286 if (stack == null) {
287 return;
288 }
289
Wale Ogunwale926aade2017-08-29 11:24:37 -0700290 if (stack.isActivityTypeAssistant()) {
291 mWindowState = WINDOW_STATE_ASSISTANT;
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800292 return;
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800293 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700294
Igor Murashkin212d06c2018-10-22 16:34:39 -0700295 @WindowingMode int windowingMode = stack.getWindowingMode();
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700296 if (windowingMode == WINDOWING_MODE_PINNED) {
Wale Ogunwaled32da472018-11-16 07:19:28 -0800297 stack = mSupervisor.mRootActivityContainer.findStackBehind(stack);
Wale Ogunwale3382ab12017-07-27 08:55:03 -0700298 windowingMode = stack.getWindowingMode();
Filip Gruszczynskicaae14e2015-12-16 14:40:04 -0800299 }
Wale Ogunwale926aade2017-08-29 11:24:37 -0700300 switch (windowingMode) {
301 case WINDOWING_MODE_FULLSCREEN:
302 mWindowState = WINDOW_STATE_STANDARD;
303 break;
304 case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY:
305 case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY:
306 mWindowState = WINDOW_STATE_SIDE_BY_SIDE;
307 break;
Bryce Lee6c605092017-10-12 11:14:49 -0700308 case WINDOWING_MODE_FREEFORM:
Wale Ogunwale926aade2017-08-29 11:24:37 -0700309 mWindowState = WINDOW_STATE_FREEFORM;
310 break;
311 default:
312 if (windowingMode != WINDOWING_MODE_UNDEFINED) {
313 throw new IllegalStateException("Unknown windowing mode for stack=" + stack
314 + " windowingMode=" + windowingMode);
315 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -0800316 }
317 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500318
319 /**
320 * Notifies the tracker at the earliest possible point when we are starting to launch an
321 * activity.
322 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700323 void notifyActivityLaunching(Intent intent) {
324 if (DEBUG_METRICS) {
325 Slog.i(TAG, String.format("notifyActivityLaunching: active:%b, intent:%s",
326 isAnyTransitionActive(),
327 intent));
328 }
329
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800330 if (!isAnyTransitionActive()) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700331
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400332 mCurrentTransitionStartTime = SystemClock.uptimeMillis();
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200333 mLastTransitionStartTime = mCurrentTransitionStartTime;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700334
335 launchObserverNotifyIntentStarted(intent);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800336 }
Jorim Jaggi275561a2016-02-23 10:11:02 -0500337 }
338
339 /**
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700340 * Notifies the tracker that the activity is actually launching.
341 *
342 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
343 * launch
344 * @param launchedActivity the activity that is being launched
345 */
346 void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) {
Wale Ogunwalef6733932018-06-27 05:14:34 -0700347 final WindowProcessController processRecord = findProcessForActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700348 final boolean processRunning = processRecord != null;
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700349
350 // We consider this a "process switch" if the process of the activity that gets launched
351 // didn't have an activity that was in started state. In this case, we assume that lot
352 // of caches might be purged so the time until it produces the first frame is very
353 // interesting.
354 final boolean processSwitch = processRecord == null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700355 || !processRecord.hasStartedActivity(launchedActivity);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700356
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800357 notifyActivityLaunched(resultCode, launchedActivity, processRunning, processSwitch);
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700358 }
359
Jorim Jaggi1e630c02016-05-16 12:13:13 -0700360 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500361 * Notifies the tracker the the activity is actually launching.
362 *
363 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the
364 * launch
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800365 * @param launchedActivity the activity being launched
Jorim Jaggi275561a2016-02-23 10:11:02 -0500366 * @param processRunning whether the process that will contains the activity is already running
Jorim Jaggibe67c902016-04-12 00:53:16 -0700367 * @param processSwitch whether the process that will contain the activity didn't have any
368 * activity that was stopped, i.e. the started activity is "switching"
369 * processes
Jorim Jaggi275561a2016-02-23 10:11:02 -0500370 */
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800371 private void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity,
Jorim Jaggibe67c902016-04-12 00:53:16 -0700372 boolean processRunning, boolean processSwitch) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500373
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200374 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched"
375 + " resultCode=" + resultCode
376 + " launchedActivity=" + launchedActivity
377 + " processRunning=" + processRunning
378 + " processSwitch=" + processSwitch);
379
Igor Murashkin212d06c2018-10-22 16:34:39 -0700380 // If we are already in an existing transition, only update the activity name, but not the
381 // other attributes.
382 final @WindowingMode int windowingMode = launchedActivity != null
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100383 ? launchedActivity.getWindowingMode()
384 : WINDOWING_MODE_UNDEFINED;
Vishnu Nairf8accc52018-10-11 10:19:54 -0700385 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200386 if (mCurrentTransitionStartTime == INVALID_START_TIME) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700387 // No transition is active ignore this launch.
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200388 return;
389 }
390
Vishnu Nair9ba31652018-11-13 14:34:05 -0800391 if (launchedActivity != null && launchedActivity.mDrawn) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700392 // Launched activity is already visible. We cannot measure windows drawn delay.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700393 reset(true /* abort */, info, "launched activity already visible");
Vishnu Nairf8accc52018-10-11 10:19:54 -0700394 return;
395 }
396
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800397 if (launchedActivity != null && info != null) {
Vishnu Nairf8accc52018-10-11 10:19:54 -0700398 // If we are already in an existing transition, only update the activity name, but not
399 // the other attributes.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700400
401 // Coalesce multiple (trampoline) activities from a single sequence together.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800402 info.launchedActivity = launchedActivity;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500403 return;
404 }
405
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100406 final boolean otherWindowModesLaunching =
407 mWindowingModeTransitionInfo.size() > 0 && info == null;
Jorim Jaggi54cff642018-03-15 15:51:32 +0100408 if ((!isLoggableResultCode(resultCode) || launchedActivity == null || !processSwitch
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100409 || windowingMode == WINDOWING_MODE_UNDEFINED) && !otherWindowModesLaunching) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800410 // Failed to launch or it was not a process switch, so we don't care about the timing.
Igor Murashkin212d06c2018-10-22 16:34:39 -0700411 reset(true /* abort */, info, "failed to launch or not a process switch");
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800412 return;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100413 } else if (otherWindowModesLaunching) {
414 // Don't log this windowing mode but continue with the other windowing modes.
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800415 return;
416 }
417
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200418 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful");
419
Igor Murashkin212d06c2018-10-22 16:34:39 -0700420 // A new launch sequence [with the windowingMode] has begun.
421 // Start tracking it.
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100422 final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo();
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800423 newInfo.launchedActivity = launchedActivity;
424 newInfo.currentTransitionProcessRunning = processRunning;
425 newInfo.startResult = resultCode;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100426 mWindowingModeTransitionInfo.put(windowingMode, newInfo);
427 mLastWindowingModeTransitionInfo.put(windowingMode, newInfo);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800428 mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000);
Vishnu Nair132ee832018-09-28 15:00:05 -0700429 startTraces(newInfo);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700430 launchObserverNotifyActivityLaunched(newInfo);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500431 }
432
433 /**
Jorim Jaggi54cff642018-03-15 15:51:32 +0100434 * @return True if we should start logging an event for an activity start that returned
435 * {@code resultCode} and that we'll indeed get a windows drawn event.
436 */
437 private boolean isLoggableResultCode(int resultCode) {
438 return resultCode == START_SUCCESS || resultCode == START_TASK_TO_FRONT;
439 }
440
441 /**
Jorim Jaggi275561a2016-02-23 10:11:02 -0500442 * Notifies the tracker that all windows of the app have been drawn.
443 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700444 WindowingModeTransitionInfoSnapshot notifyWindowsDrawn(@WindowingMode int windowingMode,
445 long timestamp) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100446 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode);
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200447
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100448 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800449 if (info == null || info.loggedWindowsDrawn) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700450 return null;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500451 }
Sudheer Shankac766db02017-06-12 10:37:29 -0700452 info.windowsDrawnDelayMs = calculateDelay(timestamp);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800453 info.loggedWindowsDrawn = true;
Vishnu Nair132ee832018-09-28 15:00:05 -0700454 final WindowingModeTransitionInfoSnapshot infoSnapshot =
455 new WindowingModeTransitionInfoSnapshot(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100456 if (allWindowsDrawn() && mLoggedTransitionStarting) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700457 reset(false /* abort */, info, "notifyWindowsDrawn - all windows drawn");
Jorim Jaggi275561a2016-02-23 10:11:02 -0500458 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700459 return infoSnapshot;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500460 }
461
462 /**
463 * Notifies the tracker that the starting window was drawn.
464 */
Igor Murashkin212d06c2018-10-22 16:34:39 -0700465 void notifyStartingWindowDrawn(@WindowingMode int windowingMode, long timestamp) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100466 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800467 if (info == null || info.loggedStartingWindowDrawn) {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500468 return;
469 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800470 info.loggedStartingWindowDrawn = true;
Sudheer Shankac766db02017-06-12 10:37:29 -0700471 info.startingWindowDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500472 }
473
474 /**
475 * Notifies the tracker that the app transition is starting.
476 *
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100477 * @param windowingModeToReason A map from windowing mode to a reason integer, which must be on
Vishnu Nair132ee832018-09-28 15:00:05 -0700478 * of ActivityTaskManagerInternal.APP_TRANSITION_* reasons.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500479 */
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100480 void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) {
Jorim Jaggid8a57772017-04-14 16:50:42 -0700481 if (!isAnyTransitionActive() || mLoggedTransitionStarting) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700482 // Ignore calls to this made after a reset and prior to notifyActivityLaunching.
483
484 // Ignore any subsequent notifyTransitionStarting until the next reset.
Jorim Jaggi275561a2016-02-23 10:11:02 -0500485 return;
486 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200487 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting");
Sudheer Shankac766db02017-06-12 10:37:29 -0700488 mCurrentTransitionDelayMs = calculateDelay(timestamp);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500489 mLoggedTransitionStarting = true;
Igor Murashkin212d06c2018-10-22 16:34:39 -0700490
491 WindowingModeTransitionInfo foundInfo = null;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100492 for (int index = windowingModeToReason.size() - 1; index >= 0; index--) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700493 final @WindowingMode int windowingMode = windowingModeToReason.keyAt(index);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100494 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
495 windowingMode);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800496 if (info == null) {
497 continue;
498 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100499 info.reason = windowingModeToReason.valueAt(index);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700500 foundInfo = info;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800501 }
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100502 if (allWindowsDrawn()) {
Vishnu Naira62534b2018-11-09 09:13:22 -0800503 // abort metrics collection if we cannot find a matching transition.
504 final boolean abortMetrics = foundInfo == null;
505 reset(abortMetrics, foundInfo, "notifyTransitionStarting - all windows drawn");
Jorim Jaggi275561a2016-02-23 10:11:02 -0500506 }
507 }
508
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200509 /**
510 * Notifies the tracker that the visibility of an app is changing.
511 *
512 * @param activityRecord the app that is changing its visibility
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200513 */
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200514 void notifyVisibilityChanged(ActivityRecord activityRecord) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100515 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
516 activityRecord.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200517 if (info == null) {
518 return;
519 }
520 if (info.launchedActivity != activityRecord) {
521 return;
522 }
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800523 final TaskRecord t = activityRecord.getTaskRecord();
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200524 final SomeArgs args = SomeArgs.obtain();
525 args.arg1 = t;
526 args.arg2 = activityRecord;
527 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget();
528 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200529
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200530 private void checkVisibility(TaskRecord t, ActivityRecord r) {
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700531 synchronized (mSupervisor.mService.mGlobalLock) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200532
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100533 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(
534 r.getWindowingMode());
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200535
536 // If we have an active transition that's waiting on a certain activity that will be
537 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary.
538 if (info != null && !t.isVisible()) {
539 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible"
540 + " activity=" + r);
541 logAppTransitionCancel(info);
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100542 mWindowingModeTransitionInfo.remove(r.getWindowingMode());
543 if (mWindowingModeTransitionInfo.size() == 0) {
Igor Murashkin212d06c2018-10-22 16:34:39 -0700544 reset(true /* abort */, info, "notifyVisibilityChanged to invisible");
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200545 }
Jorim Jaggicdfc04e2017-04-28 19:06:24 +0200546 }
547 }
548 }
549
Jorim Jaggi515dd682017-05-05 15:05:07 +0200550 /**
551 * Notifies the tracker that we called immediately before we call bindApplication on the client.
552 *
Wale Ogunwale31913b52018-10-13 08:29:31 -0700553 * @param appInfo The client into which we'll call bindApplication.
Jorim Jaggi515dd682017-05-05 15:05:07 +0200554 */
Wale Ogunwale31913b52018-10-13 08:29:31 -0700555 void notifyBindApplication(ApplicationInfo appInfo) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100556 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) {
557 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i);
Jorim Jaggi515dd682017-05-05 15:05:07 +0200558
559 // App isn't attached to record yet, so match with info.
Wale Ogunwale31913b52018-10-13 08:29:31 -0700560 if (info.launchedActivity.appInfo == appInfo) {
Jorim Jaggi515dd682017-05-05 15:05:07 +0200561 info.bindApplicationDelayMs = calculateCurrentDelay();
562 }
563 }
564 }
565
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100566 private boolean allWindowsDrawn() {
567 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
568 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800569 return false;
570 }
571 }
572 return true;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500573 }
574
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800575 private boolean isAnyTransitionActive() {
576 return mCurrentTransitionStartTime != INVALID_START_TIME
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100577 && mWindowingModeTransitionInfo.size() > 0;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800578 }
579
Igor Murashkin212d06c2018-10-22 16:34:39 -0700580 private void reset(boolean abort, WindowingModeTransitionInfo info, String cause) {
581 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort + ",cause=" + cause);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800582 if (!abort && isAnyTransitionActive()) {
583 logAppTransitionMultiEvents();
584 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700585 stopLaunchTrace(info);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700586
587 // Ignore reset-after reset.
588 if (isAnyTransitionActive()) {
589 // LaunchObserver callbacks.
590 if (abort) {
591 launchObserverNotifyActivityLaunchCancelled(info);
592 } else {
593 launchObserverNotifyActivityLaunchFinished(info);
594 }
595 } else {
596 launchObserverNotifyIntentFailed();
597 }
598
Jorim Jaggi275561a2016-02-23 10:11:02 -0500599 mCurrentTransitionStartTime = INVALID_START_TIME;
Vishnu Nair132ee832018-09-28 15:00:05 -0700600 mCurrentTransitionDelayMs = INVALID_DELAY;
Jorim Jaggi275561a2016-02-23 10:11:02 -0500601 mLoggedTransitionStarting = false;
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100602 mWindowingModeTransitionInfo.clear();
Jorim Jaggi275561a2016-02-23 10:11:02 -0500603 }
604
605 private int calculateCurrentDelay() {
Jorim Jaggi275561a2016-02-23 10:11:02 -0500606 // Shouldn't take more than 25 days to launch an app, so int is fine here.
Alison Cichowlasb7f67ab2017-04-25 18:04:40 -0400607 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime);
Jorim Jaggi275561a2016-02-23 10:11:02 -0500608 }
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800609
Sudheer Shankac766db02017-06-12 10:37:29 -0700610 private int calculateDelay(long timestamp) {
611 // Shouldn't take more than 25 days to launch an app, so int is fine here.
612 return (int) (timestamp - mCurrentTransitionStartTime);
613 }
614
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100615 private void logAppTransitionCancel(WindowingModeTransitionInfo info) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200616 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700617 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200618 return;
619 }
620 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED);
621 builder.setPackageName(info.launchedActivity.packageName);
622 builder.setType(type);
623 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name);
624 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000625 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800626 StatsLog.APP_START_CANCELED,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000627 info.launchedActivity.appInfo.uid,
628 info.launchedActivity.packageName,
629 convertAppStartTransitionType(type),
630 info.launchedActivity.info.name);
Igor Murashkin212d06c2018-10-22 16:34:39 -0700631 if (DEBUG_METRICS) {
632 Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)",
633 info.launchedActivity.appInfo.uid,
634 info.launchedActivity.packageName,
635 convertAppStartTransitionType(type),
636 info.launchedActivity.info.name));
637 }
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200638 }
639
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800640 private void logAppTransitionMultiEvents() {
Jorim Jaggi172e99f2017-10-20 14:33:18 +0200641 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events");
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100642 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) {
643 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index);
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800644 final int type = getTransitionType(info);
Vishnu Nair132ee832018-09-28 15:00:05 -0700645 if (type == INVALID_TRANSITION_TYPE) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800646 return;
647 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000648
649 // Take a snapshot of the transition info before sending it to the handler for logging.
650 // This will avoid any races with other operations that modify the ActivityRecord.
651 final WindowingModeTransitionInfoSnapshot infoSnapshot =
652 new WindowingModeTransitionInfoSnapshot(info);
Ng Zhi An83473542018-02-20 09:02:14 -0800653 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime;
654 final int currentTransitionDelayMs = mCurrentTransitionDelayMs;
655 BackgroundThread.getHandler().post(() -> logAppTransition(
656 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot));
Vishnu Nair132ee832018-09-28 15:00:05 -0700657 BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot));
Calin Juravle759fbda2018-02-20 19:52:30 +0000658
659 info.launchedActivity.info.launchToken = null;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800660 }
661 }
662
Ng Zhi An83473542018-02-20 09:02:14 -0800663 // This gets called on a background thread without holding the activity manager lock.
Calin Juravle759fbda2018-02-20 19:52:30 +0000664 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs,
665 WindowingModeTransitionInfoSnapshot info) {
666 final LogMaker builder = new LogMaker(APP_TRANSITION);
667 builder.setPackageName(info.packageName);
668 builder.setType(info.type);
669 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
670 final boolean isInstantApp = info.applicationInfo.isInstantApp();
671 if (info.launchedActivityLaunchedFromPackage != null) {
672 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME,
673 info.launchedActivityLaunchedFromPackage);
674 }
675 String launchToken = info.launchedActivityLaunchToken;
676 if (launchToken != null) {
677 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken);
678 }
679 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0);
680 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS,
681 currentTransitionDeviceUptime);
682 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs);
683 builder.setSubtype(info.reason);
Vishnu Nair132ee832018-09-28 15:00:05 -0700684 if (info.startingWindowDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000685 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS,
686 info.startingWindowDelayMs);
687 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700688 if (info.bindApplicationDelayMs != INVALID_DELAY) {
Calin Juravle759fbda2018-02-20 19:52:30 +0000689 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS,
690 info.bindApplicationDelayMs);
691 }
692 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs);
693 final ArtManagerInternal artManagerInternal = getArtManagerInternal();
694 final PackageOptimizationInfo packageOptimizationInfo =
695 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null)
696 ? PackageOptimizationInfo.createWithNoInfo()
697 : artManagerInternal.getPackageOptimizationInfo(
698 info.applicationInfo,
699 info.launchedActivityAppRecordRequiredAbi);
700 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON,
701 packageOptimizationInfo.getCompilationReason());
702 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER,
703 packageOptimizationInfo.getCompilationFilter());
704 mMetricsLogger.write(builder);
705 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800706 StatsLog.APP_START_OCCURRED,
Calin Juravle759fbda2018-02-20 19:52:30 +0000707 info.applicationInfo.uid,
708 info.packageName,
709 convertAppStartTransitionType(info.type),
710 info.launchedActivityName,
711 info.launchedActivityLaunchedFromPackage,
712 isInstantApp,
713 currentTransitionDeviceUptime * 1000,
714 info.reason,
715 currentTransitionDelayMs,
716 info.startingWindowDelayMs,
717 info.bindApplicationDelayMs,
718 info.windowsDrawnDelayMs,
719 launchToken,
720 packageOptimizationInfo.getCompilationReason(),
721 packageOptimizationInfo.getCompilationFilter());
Igor Murashkin212d06c2018-10-22 16:34:39 -0700722
723 if (DEBUG_METRICS) {
724 Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)",
725 info.applicationInfo.uid,
726 info.packageName,
727 convertAppStartTransitionType(info.type),
728 info.launchedActivityName,
729 info.launchedActivityLaunchedFromPackage));
730 }
731
732
Ng Zhi An83473542018-02-20 09:02:14 -0800733 logAppStartMemoryStateCapture(info);
Calin Juravle759fbda2018-02-20 19:52:30 +0000734 }
735
Vishnu Nair132ee832018-09-28 15:00:05 -0700736 private void logAppDisplayed(WindowingModeTransitionInfoSnapshot info) {
737 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
738 return;
739 }
740
741 EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME,
742 info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,
743 info.windowsDrawnDelayMs);
744
745 StringBuilder sb = mStringBuilder;
746 sb.setLength(0);
747 sb.append("Displayed ");
748 sb.append(info.launchedActivityShortComponentName);
749 sb.append(": ");
750 TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb);
751 Log.i(TAG, sb.toString());
752 }
753
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000754 private int convertAppStartTransitionType(int tronType) {
755 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800756 return StatsLog.APP_START_OCCURRED__TYPE__COLD;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000757 }
758 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800759 return StatsLog.APP_START_OCCURRED__TYPE__WARM;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000760 }
761 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) {
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800762 return StatsLog.APP_START_OCCURRED__TYPE__HOT;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000763 }
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800764 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN;
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000765 }
766
Vishnu Nair132ee832018-09-28 15:00:05 -0700767 WindowingModeTransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r,
768 boolean restoredFromBundle) {
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100769 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get(
770 r.getWindowingMode());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200771 if (info == null) {
Vishnu Nair132ee832018-09-28 15:00:05 -0700772 return null;
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200773 }
Chris Wailes35c193c2018-10-09 18:12:00 -0700774
775 // Record the handling of the reportFullyDrawn callback in the trace system. This is not
776 // actually used to trace this function, but instead the logical task that this function
777 // fullfils (handling reportFullyDrawn() callbacks).
778 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
779 "ActivityManager:ReportingFullyDrawn " + info.launchedActivity.packageName);
780
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200781 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
782 builder.setPackageName(r.packageName);
783 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000784 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime;
785 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200786 builder.setType(restoredFromBundle
787 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
788 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
789 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
790 info.currentTransitionProcessRunning ? 1 : 0);
791 mMetricsLogger.write(builder);
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000792 StatsLog.write(
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800793 StatsLog.APP_START_FULLY_DRAWN,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000794 info.launchedActivity.appInfo.uid,
795 info.launchedActivity.packageName,
796 restoredFromBundle
Chenjie Yu5caaa9d2018-03-06 15:48:54 -0800797 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE
798 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE,
Olivier Gaillardaed7f122017-12-12 14:26:22 +0000799 info.launchedActivity.info.name,
800 info.currentTransitionProcessRunning,
801 startupTimeMs);
Chris Wailes35c193c2018-10-09 18:12:00 -0700802
803 // Ends the trace started at the beginning of this function. This is located here to allow
804 // the trace slice to have a noticable duration.
805 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
806
Vishnu Nair132ee832018-09-28 15:00:05 -0700807 final WindowingModeTransitionInfoSnapshot infoSnapshot =
808 new WindowingModeTransitionInfoSnapshot(info, r, (int) startupTimeMs);
809 BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot));
810 return infoSnapshot;
811 }
812
813 private void logAppFullyDrawn(WindowingModeTransitionInfoSnapshot info) {
814 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
815 return;
816 }
817
818 StringBuilder sb = mStringBuilder;
819 sb.setLength(0);
820 sb.append("Fully drawn ");
821 sb.append(info.launchedActivityShortComponentName);
822 sb.append(": ");
823 TimeUtils.formatDuration(info.windowsFullyDrawnDelayMs, sb);
824 Log.i(TAG, sb.toString());
Jorim Jaggi4d27b842017-08-17 17:22:26 +0200825 }
826
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700827 void logActivityStart(Intent intent, WindowProcessController callerApp, ActivityRecord r,
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100828 int callingUid, String callingPackage, int callingUidProcState,
829 boolean callingUidHasAnyVisibleWindow,
830 int realCallingUid, int realCallingUidProcState,
831 boolean realCallingUidHasAnyVisibleWindow,
832 int targetUid, String targetPackage, int targetUidProcState,
833 boolean targetUidHasAnyVisibleWindow, String targetWhitelistTag,
834 boolean comingFromPendingIntent) {
835
836 final long nowElapsed = SystemClock.elapsedRealtime();
837 final long nowUptime = SystemClock.uptimeMillis();
838 final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START);
839 builder.setTimestamp(System.currentTimeMillis());
840 builder.addTaggedData(FIELD_CALLING_UID, callingUid);
841 builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage);
842 builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE,
843 processStateAmToProto(callingUidProcState));
844 builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
845 callingUidHasAnyVisibleWindow ? 1 : 0);
846 builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid);
847 builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE,
848 processStateAmToProto(realCallingUidProcState));
849 builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW,
850 realCallingUidHasAnyVisibleWindow ? 1 : 0);
851 builder.addTaggedData(FIELD_TARGET_UID, targetUid);
852 builder.addTaggedData(FIELD_TARGET_PACKAGE_NAME, targetPackage);
853 builder.addTaggedData(FIELD_TARGET_UID_PROC_STATE,
854 processStateAmToProto(targetUidProcState));
855 builder.addTaggedData(FIELD_TARGET_UID_HAS_ANY_VISIBLE_WINDOW,
856 targetUidHasAnyVisibleWindow ? 1 : 0);
857 builder.addTaggedData(FIELD_TARGET_WHITELIST_TAG, targetWhitelistTag);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100858 builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0);
Michal Karpinski8596ded2018-11-14 14:43:48 +0000859 if (intent != null) {
860 builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction());
861 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100862 if (callerApp != null) {
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700863 builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100864 builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700865 processStateAmToProto(callerApp.getCurrentProcState()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100866 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700867 callerApp.hasClientActivities() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100868 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES,
869 callerApp.hasForegroundServices() ? 1 : 0);
870 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700871 callerApp.hasForegroundActivities() ? 1 : 0);
872 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100873 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700874 callerApp.hasOverlayUi() ? 1 : 0);
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100875 builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700876 callerApp.hasPendingUiClean() ? 1 : 0);
877 if (callerApp.getInteractionEventTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100878 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700879 (nowElapsed - callerApp.getInteractionEventTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100880 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700881 if (callerApp.getFgInteractionTime() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100882 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700883 (nowElapsed - callerApp.getFgInteractionTime()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100884 }
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700885 if (callerApp.getWhenUnimportant() != 0) {
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100886 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT,
Wale Ogunwale342fbe92018-10-09 08:44:10 -0700887 (nowUptime - callerApp.getWhenUnimportant()));
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100888 }
889 }
Michal Karpinski8596ded2018-11-14 14:43:48 +0000890 if (r != null) {
891 builder.addTaggedData(FIELD_TARGET_SHORT_COMPONENT_NAME, r.shortComponentName);
892 builder.addTaggedData(FIELD_ACTIVITY_RECORD_LAUNCH_MODE, r.info.launchMode);
893 builder.addTaggedData(FIELD_ACTIVITY_RECORD_TARGET_ACTIVITY, r.info.targetActivity);
894 builder.addTaggedData(FIELD_ACTIVITY_RECORD_FLAGS, r.info.flags);
895 builder.addTaggedData(FIELD_ACTIVITY_RECORD_REAL_ACTIVITY,
Wale Ogunwale8b19de92018-11-29 19:58:26 -0800896 r.mActivityComponent.toShortString());
Michal Karpinski8596ded2018-11-14 14:43:48 +0000897 builder.addTaggedData(FIELD_ACTIVITY_RECORD_SHORT_COMPONENT_NAME, r.shortComponentName);
898 builder.addTaggedData(FIELD_ACTIVITY_RECORD_PROCESS_NAME, r.processName);
899 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_FULLSCREEN, r.fullscreen ? 1 : 0);
900 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_NO_DISPLAY, r.noDisplay ? 1 : 0);
901 if (r.lastVisibleTime != 0) {
902 builder.addTaggedData(FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_VISIBLE,
903 (nowUptime - r.lastVisibleTime));
904 }
905 if (r.resultTo != null) {
906 builder.addTaggedData(FIELD_ACTIVITY_RECORD_RESULT_TO_PKG_NAME,
907 r.resultTo.packageName);
908 builder.addTaggedData(FIELD_ACTIVITY_RECORD_RESULT_TO_SHORT_COMPONENT_NAME,
909 r.resultTo.shortComponentName);
910 }
911 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_VISIBLE, r.visible ? 1 : 0);
912 builder.addTaggedData(FIELD_ACTIVITY_RECORD_IS_VISIBLE_IGNORING_KEYGUARD,
913 r.visibleIgnoringKeyguard ? 1 : 0);
914 if (r.lastLaunchTime != 0) {
915 builder.addTaggedData(FIELD_ACTIVITY_RECORD_MILLIS_SINCE_LAST_LAUNCH,
916 (nowUptime - r.lastLaunchTime));
917 }
Michal Karpinski201bc0c2018-07-20 15:32:00 +0100918 }
919 mMetricsLogger.write(builder);
920 }
921
Jorim Jaggi9b58f2d2018-02-19 17:48:44 +0100922 private int getTransitionType(WindowingModeTransitionInfo info) {
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800923 if (info.currentTransitionProcessRunning) {
924 if (info.startResult == START_SUCCESS) {
925 return TYPE_TRANSITION_WARM_LAUNCH;
926 } else if (info.startResult == START_TASK_TO_FRONT) {
927 return TYPE_TRANSITION_HOT_LAUNCH;
928 }
929 } else if (info.startResult == START_SUCCESS) {
930 return TYPE_TRANSITION_COLD_LAUNCH;
931 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700932 return INVALID_TRANSITION_TYPE;
Jorim Jaggi3878ca32017-02-02 17:13:05 -0800933 }
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800934
Ng Zhi An83473542018-02-20 09:02:14 -0800935 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) {
936 if (info.processRecord == null) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800937 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null");
938 return;
939 }
940
Wale Ogunwalef6733932018-06-27 05:14:34 -0700941 final int pid = info.processRecord.getPid();
Ng Zhi An83473542018-02-20 09:02:14 -0800942 final int uid = info.applicationInfo.uid;
Rajeev Kumarbfcd9202018-03-02 22:42:13 +0000943 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid);
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800944 if (memoryStat == null) {
945 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null");
946 return;
947 }
948
949 StatsLog.write(
950 StatsLog.APP_START_MEMORY_STATE_CAPTURED,
951 uid,
Ng Zhi An83473542018-02-20 09:02:14 -0800952 info.processName,
953 info.launchedActivityName,
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800954 memoryStat.pgfault,
955 memoryStat.pgmajfault,
956 memoryStat.rssInBytes,
957 memoryStat.cacheInBytes,
958 memoryStat.swapInBytes);
959 }
960
Wale Ogunwalef6733932018-06-27 05:14:34 -0700961 private WindowProcessController findProcessForActivity(ActivityRecord launchedActivity) {
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800962 return launchedActivity != null
Wale Ogunwalef6733932018-06-27 05:14:34 -0700963 ? mSupervisor.mService.mProcessNames.get(
Wale Ogunwalec9e57de2018-05-08 14:28:07 -0700964 launchedActivity.processName, launchedActivity.appInfo.uid)
Ng Zhi Anbbefdec2018-01-30 17:12:39 -0800965 : null;
966 }
Calin Juravle759fbda2018-02-20 19:52:30 +0000967
968 private ArtManagerInternal getArtManagerInternal() {
969 if (mArtManagerInternal == null) {
970 // Note that this may be null.
971 // ArtManagerInternal is registered during PackageManagerService
972 // initialization which happens after ActivityManagerService.
973 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class);
974 }
975 return mArtManagerInternal;
976 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700977
978 /**
Chris Wailes35c193c2018-10-09 18:12:00 -0700979 * Starts traces for app launch.
Vishnu Nair132ee832018-09-28 15:00:05 -0700980 *
981 * @param info
982 * */
983 private void startTraces(WindowingModeTransitionInfo info) {
984 if (info == null) {
985 return;
986 }
Vishnu Nair132ee832018-09-28 15:00:05 -0700987 int transitionType = getTransitionType(info);
988 if (!info.launchTraceActive && transitionType == TYPE_TRANSITION_WARM_LAUNCH
989 || transitionType == TYPE_TRANSITION_COLD_LAUNCH) {
990 Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
991 + info.launchedActivity.packageName, 0);
Vishnu Nair132ee832018-09-28 15:00:05 -0700992 info.launchTraceActive = true;
993 }
994 }
995
996 private void stopLaunchTrace(WindowingModeTransitionInfo info) {
997 if (info == null) {
998 return;
999 }
1000 if (info.launchTraceActive) {
1001 Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: "
1002 + info.launchedActivity.packageName, 0);
1003 info.launchTraceActive = false;
1004 }
1005 }
Igor Murashkin212d06c2018-10-22 16:34:39 -07001006
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001007 public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() {
1008 return mLaunchObserver;
1009 }
1010
Igor Murashkin212d06c2018-10-22 16:34:39 -07001011 /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */
1012 private void launchObserverNotifyIntentStarted(Intent intent) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001013 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1014 "MetricsLogger:launchObserverNotifyIntentStarted");
1015
1016 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1017 mLaunchObserver.onIntentStarted(intent);
1018
1019 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001020 }
1021
1022 /**
1023 * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has
1024 * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or
1025 * intent being delivered to the top running activity.
1026 */
1027 private void launchObserverNotifyIntentFailed() {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001028 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1029 "MetricsLogger:launchObserverNotifyIntentFailed");
1030
1031 mLaunchObserver.onIntentFailed();
1032
1033 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001034 }
1035
1036 /**
1037 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1038 * has started.
1039 */
1040 private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001041 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1042 "MetricsLogger:launchObserverNotifyActivityLaunched");
1043
Igor Murashkin212d06c2018-10-22 16:34:39 -07001044 @ActivityMetricsLaunchObserver.Temperature int temperature =
1045 convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info));
1046
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001047 // Beginning a launch is timing sensitive and so should be observed as soon as possible.
1048 mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.launchedActivity),
1049 temperature);
1050
1051 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001052 }
1053
1054 /**
1055 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is
1056 * cancelled.
1057 */
1058 private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001059 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1060 "MetricsLogger:launchObserverNotifyActivityLaunchCancelled");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001061
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001062 final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto =
1063 info != null ? convertActivityRecordToProto(info.launchedActivity) : null;
1064
1065 mLaunchObserver.onActivityLaunchCancelled(activityRecordProto);
1066
1067 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
Igor Murashkin212d06c2018-10-22 16:34:39 -07001068 }
1069
1070 /**
1071 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity
1072 * has fully finished (successfully).
1073 */
1074 private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) {
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001075 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1076 "MetricsLogger:launchObserverNotifyActivityLaunchFinished");
Igor Murashkin212d06c2018-10-22 16:34:39 -07001077
Igor Murashkinc0b47e42018-11-07 15:54:18 -08001078 mLaunchObserver.onActivityLaunchFinished(
1079 convertActivityRecordToProto(info.launchedActivity));
1080
1081 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1082 }
1083
1084 @VisibleForTesting
1085 static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[]
1086 convertActivityRecordToProto(ActivityRecord record) {
1087 // May take non-negligible amount of time to convert ActivityRecord into a proto,
1088 // so track the time.
1089 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
1090 "MetricsLogger:convertActivityRecordToProto");
1091
1092 // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream,
1093 // so create a new one every time.
1094 final ProtoOutputStream protoOutputStream =
1095 new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE);
1096 // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object).
1097 record.writeToProto(protoOutputStream);
1098 final byte[] bytes = protoOutputStream.getBytes();
1099
1100 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
1101
1102 return bytes;
Igor Murashkin212d06c2018-10-22 16:34:39 -07001103 }
1104
1105 private static @ActivityMetricsLaunchObserver.Temperature int
1106 convertTransitionTypeToLaunchObserverTemperature(int transitionType) {
1107 switch (transitionType) {
1108 case TYPE_TRANSITION_WARM_LAUNCH:
1109 return ActivityMetricsLaunchObserver.TEMPERATURE_WARM;
1110 case TYPE_TRANSITION_HOT_LAUNCH:
1111 return ActivityMetricsLaunchObserver.TEMPERATURE_HOT;
1112 case TYPE_TRANSITION_COLD_LAUNCH:
1113 return ActivityMetricsLaunchObserver.TEMPERATURE_COLD;
1114 default:
1115 return -1;
1116 }
1117 }
Filip Gruszczynski77d94482015-12-11 13:59:52 -08001118}