1 package com.android.server.wm; 2 3 import static android.app.ActivityManager.START_SUCCESS; 4 import static android.app.ActivityManager.START_TASK_TO_FRONT; 5 import static android.app.ActivityManager.processStateAmToProto; 6 import static android.app.WaitResult.LAUNCH_STATE_COLD; 7 import static android.app.WaitResult.LAUNCH_STATE_HOT; 8 import static android.app.WaitResult.LAUNCH_STATE_WARM; 9 import static android.app.WindowConfiguration.WINDOWING_MODE_FREEFORM; 10 import static android.app.WindowConfiguration.WINDOWING_MODE_FULLSCREEN; 11 import static android.app.WindowConfiguration.WINDOWING_MODE_PINNED; 12 import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_PRIMARY; 13 import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_SECONDARY; 14 import static android.app.WindowConfiguration.WINDOWING_MODE_UNDEFINED; 15 16 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.ACTION_ACTIVITY_START; 17 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION; 18 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_BIND_APPLICATION_DELAY_MS; 19 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CALLING_PACKAGE_NAME; 20 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CANCELLED; 21 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DELAY_MS; 22 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS; 23 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_IS_EPHEMERAL; 24 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_PROCESS_RUNNING; 25 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN; 26 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN_MS; 27 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_STARTING_WINDOW_DELAY_MS; 28 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS; 29 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_PACKAGE_NAME; 30 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID; 31 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW; 32 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CALLING_UID_PROC_STATE; 33 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME; 34 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_COMING_FROM_PENDING_INTENT; 35 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INSTANT_APP_LAUNCH_TOKEN; 36 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INTENT_ACTION; 37 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_CUR_PROC_STATE; 38 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES; 39 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES; 40 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES; 41 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_OVERLAY_UI; 42 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_HAS_TOP_UI; 43 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION; 44 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT; 45 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT; 46 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PENDING_UI_CLEAN; 47 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_PROCESS_RECORD_PROCESS_NAME; 48 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID; 49 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW; 50 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_PROC_STATE; 51 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_SHORT_COMPONENT_NAME; 52 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_FILTER; 53 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_REASON; 54 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_COLD_LAUNCH; 55 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_HOT_LAUNCH; 56 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE; 57 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE; 58 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH; 59 import static com.android.server.am.EventLogTags.AM_ACTIVITY_LAUNCH_TIME; 60 import static com.android.server.am.MemoryStatUtil.MemoryStat; 61 import static com.android.server.am.MemoryStatUtil.readMemoryStatFromFilesystem; 62 import static com.android.server.wm.ActivityTaskManagerDebugConfig.DEBUG_METRICS; 63 import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_ATM; 64 import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_WITH_CLASS_NAME; 65 import static com.android.server.wm.ActivityTaskManagerInternal.APP_TRANSITION_TIMEOUT; 66 67 import android.app.WaitResult; 68 import android.app.WindowConfiguration.WindowingMode; 69 import android.content.ComponentName; 70 import android.content.Context; 71 import android.content.Intent; 72 import android.content.pm.ApplicationInfo; 73 import android.content.pm.dex.ArtManagerInternal; 74 import android.content.pm.dex.PackageOptimizationInfo; 75 import android.metrics.LogMaker; 76 import android.os.Handler; 77 import android.os.Looper; 78 import android.os.Message; 79 import android.os.SystemClock; 80 import android.os.Trace; 81 import android.util.EventLog; 82 import android.util.Log; 83 import android.util.Slog; 84 import android.util.SparseArray; 85 import android.util.SparseIntArray; 86 import android.util.StatsLog; 87 import android.util.TimeUtils; 88 import android.util.proto.ProtoOutputStream; 89 90 import com.android.internal.annotations.VisibleForTesting; 91 import com.android.internal.logging.MetricsLogger; 92 import com.android.internal.os.BackgroundThread; 93 import com.android.internal.os.SomeArgs; 94 import com.android.server.LocalServices; 95 96 /** 97 * Listens to activity launches, transitions, visibility changes and window drawn callbacks to 98 * determine app launch times and draw delays. Source of truth for activity metrics and provides 99 * data for Tron, logcat, event logs and {@link android.app.WaitResult}. 100 * 101 * Tests: 102 * atest CtsWindowManagerDeviceTestCases:ActivityMetricsLoggerTests 103 */ 104 class ActivityMetricsLogger { 105 106 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_ATM; 107 108 // Window modes we are interested in logging. If we ever introduce a new type, we need to add 109 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array. 110 private static final int WINDOW_STATE_STANDARD = 0; 111 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1; 112 private static final int WINDOW_STATE_FREEFORM = 2; 113 private static final int WINDOW_STATE_ASSISTANT = 3; 114 private static final int WINDOW_STATE_INVALID = -1; 115 116 private static final long INVALID_START_TIME = -1; 117 private static final int INVALID_DELAY = -1; 118 private static final int INVALID_TRANSITION_TYPE = -1; 119 120 private static final int MSG_CHECK_VISIBILITY = 0; 121 122 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every 123 // time we log. 124 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = { 125 "window_time_0", "window_time_1", "window_time_2", "window_time_3"}; 126 127 private int mWindowState = WINDOW_STATE_STANDARD; 128 private long mLastLogTimeSecs; 129 private final ActivityStackSupervisor mSupervisor; 130 private final Context mContext; 131 private final MetricsLogger mMetricsLogger = new MetricsLogger(); 132 133 // set to INVALID_START_TIME in reset. 134 // set to valid value in notifyActivityLaunching 135 private long mCurrentTransitionStartTime = INVALID_START_TIME; 136 private long mLastTransitionStartTime = INVALID_START_TIME; 137 138 private int mCurrentTransitionDeviceUptime; 139 private int mCurrentTransitionDelayMs; 140 141 /** If the any app transitions have been logged as starting, after the latest reset. */ 142 private boolean mLoggedTransitionStarting; 143 144 /** Map : @WindowingMode int => WindowingModeTransitionInfo */ 145 private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo = 146 new SparseArray<>(); 147 /** Map : @WindowingMode int => WindowingModeTransitionInfo */ 148 private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo = 149 new SparseArray<>(); 150 private final H mHandler; 151 152 private ArtManagerInternal mArtManagerInternal; 153 private final StringBuilder mStringBuilder = new StringBuilder(); 154 155 /** 156 * Due to the global single concurrent launch sequence, all calls to this observer must be made 157 * in-order on the same thread to fulfill the "happens-before" guarantee in LaunchObserver. 158 */ 159 private final LaunchObserverRegistryImpl mLaunchObserver; 160 @VisibleForTesting static final int LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE = 512; 161 162 private final class H extends Handler { 163 H(Looper looper)164 public H(Looper looper) { 165 super(looper); 166 } 167 168 @Override handleMessage(Message msg)169 public void handleMessage(Message msg) { 170 switch (msg.what) { 171 case MSG_CHECK_VISIBILITY: 172 final SomeArgs args = (SomeArgs) msg.obj; 173 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2); 174 break; 175 } 176 } 177 } 178 179 private final class WindowingModeTransitionInfo { 180 /** The latest activity to have been launched. */ 181 private ActivityRecord launchedActivity; 182 private int startResult; 183 private boolean currentTransitionProcessRunning; 184 /** Elapsed time from when we launch an activity to when its windows are drawn. */ 185 private int windowsDrawnDelayMs; 186 private int startingWindowDelayMs = INVALID_DELAY; 187 private int bindApplicationDelayMs = INVALID_DELAY; 188 private int reason = APP_TRANSITION_TIMEOUT; 189 private boolean loggedWindowsDrawn; 190 private boolean loggedStartingWindowDrawn; 191 private boolean launchTraceActive; 192 } 193 194 final class WindowingModeTransitionInfoSnapshot { 195 final private ApplicationInfo applicationInfo; 196 final private WindowProcessController processRecord; 197 final String packageName; 198 final String launchedActivityName; 199 final private String launchedActivityLaunchedFromPackage; 200 final private String launchedActivityLaunchToken; 201 final private String launchedActivityAppRecordRequiredAbi; 202 final String launchedActivityShortComponentName; 203 final private String processName; 204 final private int reason; 205 final private int startingWindowDelayMs; 206 final private int bindApplicationDelayMs; 207 final int windowsDrawnDelayMs; 208 final int type; 209 final int userId; 210 /** 211 * Elapsed time from when we launch an activity to when the app reported it was 212 * fully drawn. If this is not reported then the value is set to INVALID_DELAY. 213 */ 214 final int windowsFullyDrawnDelayMs; 215 final int activityRecordIdHashCode; 216 WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info)217 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info) { 218 this(info, info.launchedActivity); 219 } 220 WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info, ActivityRecord launchedActivity)221 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info, 222 ActivityRecord launchedActivity) { 223 this(info, launchedActivity, INVALID_DELAY); 224 } 225 WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info, ActivityRecord launchedActivity, int windowsFullyDrawnDelayMs)226 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info, 227 ActivityRecord launchedActivity, int windowsFullyDrawnDelayMs) { 228 applicationInfo = launchedActivity.appInfo; 229 packageName = launchedActivity.packageName; 230 launchedActivityName = launchedActivity.info.name; 231 launchedActivityLaunchedFromPackage = launchedActivity.launchedFromPackage; 232 launchedActivityLaunchToken = launchedActivity.info.launchToken; 233 launchedActivityAppRecordRequiredAbi = launchedActivity.app == null 234 ? null 235 : launchedActivity.app.getRequiredAbi(); 236 reason = info.reason; 237 startingWindowDelayMs = info.startingWindowDelayMs; 238 bindApplicationDelayMs = info.bindApplicationDelayMs; 239 windowsDrawnDelayMs = info.windowsDrawnDelayMs; 240 type = getTransitionType(info); 241 processRecord = findProcessForActivity(launchedActivity); 242 processName = launchedActivity.processName; 243 userId = launchedActivity.mUserId; 244 launchedActivityShortComponentName = launchedActivity.shortComponentName; 245 activityRecordIdHashCode = System.identityHashCode(launchedActivity); 246 this.windowsFullyDrawnDelayMs = windowsFullyDrawnDelayMs; 247 } 248 getLaunchState()249 @WaitResult.LaunchState int getLaunchState() { 250 switch (type) { 251 case TYPE_TRANSITION_WARM_LAUNCH: 252 return LAUNCH_STATE_WARM; 253 case TYPE_TRANSITION_HOT_LAUNCH: 254 return LAUNCH_STATE_HOT; 255 case TYPE_TRANSITION_COLD_LAUNCH: 256 return LAUNCH_STATE_COLD; 257 default: 258 return -1; 259 } 260 } 261 } 262 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper)263 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper) { 264 mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000; 265 mSupervisor = supervisor; 266 mContext = context; 267 mHandler = new H(looper); 268 mLaunchObserver = new LaunchObserverRegistryImpl(looper); 269 } 270 logWindowState()271 void logWindowState() { 272 final long now = SystemClock.elapsedRealtime() / 1000; 273 if (mWindowState != WINDOW_STATE_INVALID) { 274 // We log even if the window state hasn't changed, because the user might remain in 275 // home/fullscreen move forever and we would like to track this kind of behavior 276 // too. 277 MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState], 278 (int) (now - mLastLogTimeSecs)); 279 } 280 mLastLogTimeSecs = now; 281 282 mWindowState = WINDOW_STATE_INVALID; 283 ActivityStack stack = 284 mSupervisor.mRootActivityContainer.getTopDisplayFocusedStack(); 285 if (stack == null) { 286 return; 287 } 288 289 if (stack.isActivityTypeAssistant()) { 290 mWindowState = WINDOW_STATE_ASSISTANT; 291 return; 292 } 293 294 @WindowingMode int windowingMode = stack.getWindowingMode(); 295 if (windowingMode == WINDOWING_MODE_PINNED) { 296 stack = mSupervisor.mRootActivityContainer.findStackBehind(stack); 297 windowingMode = stack.getWindowingMode(); 298 } 299 switch (windowingMode) { 300 case WINDOWING_MODE_FULLSCREEN: 301 mWindowState = WINDOW_STATE_STANDARD; 302 break; 303 case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY: 304 case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY: 305 mWindowState = WINDOW_STATE_SIDE_BY_SIDE; 306 break; 307 case WINDOWING_MODE_FREEFORM: 308 mWindowState = WINDOW_STATE_FREEFORM; 309 break; 310 default: 311 if (windowingMode != WINDOWING_MODE_UNDEFINED) { 312 throw new IllegalStateException("Unknown windowing mode for stack=" + stack 313 + " windowingMode=" + windowingMode); 314 } 315 } 316 } 317 318 /** 319 * Notifies the tracker at the earliest possible point when we are starting to launch an 320 * activity. 321 */ notifyActivityLaunching(Intent intent)322 void notifyActivityLaunching(Intent intent) { 323 if (DEBUG_METRICS) { 324 Slog.i(TAG, String.format("notifyActivityLaunching: active:%b, intent:%s", 325 isAnyTransitionActive(), 326 intent)); 327 } 328 329 if (mCurrentTransitionStartTime == INVALID_START_TIME) { 330 331 mCurrentTransitionStartTime = SystemClock.uptimeMillis(); 332 mLastTransitionStartTime = mCurrentTransitionStartTime; 333 334 launchObserverNotifyIntentStarted(intent); 335 } 336 } 337 338 /** 339 * Notifies the tracker that the activity is actually launching. 340 * 341 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the 342 * launch 343 * @param launchedActivity the activity that is being launched 344 */ notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity)345 void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) { 346 final WindowProcessController processRecord = findProcessForActivity(launchedActivity); 347 final boolean processRunning = processRecord != null; 348 349 // We consider this a "process switch" if the process of the activity that gets launched 350 // didn't have an activity that was in started state. In this case, we assume that lot 351 // of caches might be purged so the time until it produces the first frame is very 352 // interesting. 353 final boolean processSwitch = processRecord == null 354 || !processRecord.hasStartedActivity(launchedActivity); 355 356 notifyActivityLaunched(resultCode, launchedActivity, processRunning, processSwitch); 357 } 358 359 /** 360 * Notifies the tracker the the activity is actually launching. 361 * 362 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the 363 * launch 364 * @param launchedActivity the activity being launched 365 * @param processRunning whether the process that will contains the activity is already running 366 * @param processSwitch whether the process that will contain the activity didn't have any 367 * activity that was stopped, i.e. the started activity is "switching" 368 * processes 369 */ notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity, boolean processRunning, boolean processSwitch)370 private void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity, 371 boolean processRunning, boolean processSwitch) { 372 373 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched" 374 + " resultCode=" + resultCode 375 + " launchedActivity=" + launchedActivity 376 + " processRunning=" + processRunning 377 + " processSwitch=" + processSwitch); 378 379 // If we are already in an existing transition, only update the activity name, but not the 380 // other attributes. 381 final @WindowingMode int windowingMode = launchedActivity != null 382 ? launchedActivity.getWindowingMode() 383 : WINDOWING_MODE_UNDEFINED; 384 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode); 385 if (mCurrentTransitionStartTime == INVALID_START_TIME) { 386 // No transition is active ignore this launch. 387 return; 388 } 389 390 if (launchedActivity != null && launchedActivity.mDrawn) { 391 // Launched activity is already visible. We cannot measure windows drawn delay. 392 reset(true /* abort */, info, "launched activity already visible"); 393 return; 394 } 395 396 if (launchedActivity != null && info != null) { 397 // If we are already in an existing transition, only update the activity name, but not 398 // the other attributes. 399 400 // Coalesce multiple (trampoline) activities from a single sequence together. 401 info.launchedActivity = launchedActivity; 402 return; 403 } 404 405 final boolean otherWindowModesLaunching = 406 mWindowingModeTransitionInfo.size() > 0 && info == null; 407 if ((!isLoggableResultCode(resultCode) || launchedActivity == null || !processSwitch 408 || windowingMode == WINDOWING_MODE_UNDEFINED) && !otherWindowModesLaunching) { 409 // Failed to launch or it was not a process switch, so we don't care about the timing. 410 reset(true /* abort */, info, "failed to launch or not a process switch"); 411 return; 412 } else if (otherWindowModesLaunching) { 413 // Don't log this windowing mode but continue with the other windowing modes. 414 return; 415 } 416 417 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful"); 418 419 // A new launch sequence [with the windowingMode] has begun. 420 // Start tracking it. 421 final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo(); 422 newInfo.launchedActivity = launchedActivity; 423 newInfo.currentTransitionProcessRunning = processRunning; 424 newInfo.startResult = resultCode; 425 mWindowingModeTransitionInfo.put(windowingMode, newInfo); 426 mLastWindowingModeTransitionInfo.put(windowingMode, newInfo); 427 mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000); 428 startTraces(newInfo); 429 launchObserverNotifyActivityLaunched(newInfo); 430 } 431 432 /** 433 * @return True if we should start logging an event for an activity start that returned 434 * {@code resultCode} and that we'll indeed get a windows drawn event. 435 */ isLoggableResultCode(int resultCode)436 private boolean isLoggableResultCode(int resultCode) { 437 return resultCode == START_SUCCESS || resultCode == START_TASK_TO_FRONT; 438 } 439 440 /** 441 * Notifies the tracker that all windows of the app have been drawn. 442 */ notifyWindowsDrawn(@indowingMode int windowingMode, long timestamp)443 WindowingModeTransitionInfoSnapshot notifyWindowsDrawn(@WindowingMode int windowingMode, 444 long timestamp) { 445 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode); 446 447 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode); 448 if (info == null || info.loggedWindowsDrawn) { 449 return null; 450 } 451 info.windowsDrawnDelayMs = calculateDelay(timestamp); 452 info.loggedWindowsDrawn = true; 453 final WindowingModeTransitionInfoSnapshot infoSnapshot = 454 new WindowingModeTransitionInfoSnapshot(info); 455 if (allWindowsDrawn() && mLoggedTransitionStarting) { 456 reset(false /* abort */, info, "notifyWindowsDrawn - all windows drawn"); 457 } 458 return infoSnapshot; 459 } 460 461 /** 462 * Notifies the tracker that the starting window was drawn. 463 */ notifyStartingWindowDrawn(@indowingMode int windowingMode, long timestamp)464 void notifyStartingWindowDrawn(@WindowingMode int windowingMode, long timestamp) { 465 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode); 466 if (info == null || info.loggedStartingWindowDrawn) { 467 return; 468 } 469 info.loggedStartingWindowDrawn = true; 470 info.startingWindowDelayMs = calculateDelay(timestamp); 471 } 472 473 /** 474 * Notifies the tracker that the app transition is starting. 475 * 476 * @param windowingModeToReason A map from windowing mode to a reason integer, which must be on 477 * of ActivityTaskManagerInternal.APP_TRANSITION_* reasons. 478 */ notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp)479 void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) { 480 if (!isAnyTransitionActive() || mLoggedTransitionStarting) { 481 // Ignore calls to this made after a reset and prior to notifyActivityLaunching. 482 483 // Ignore any subsequent notifyTransitionStarting until the next reset. 484 return; 485 } 486 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting"); 487 mCurrentTransitionDelayMs = calculateDelay(timestamp); 488 mLoggedTransitionStarting = true; 489 490 WindowingModeTransitionInfo foundInfo = null; 491 for (int index = windowingModeToReason.size() - 1; index >= 0; index--) { 492 final @WindowingMode int windowingMode = windowingModeToReason.keyAt(index); 493 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get( 494 windowingMode); 495 if (info == null) { 496 continue; 497 } 498 info.reason = windowingModeToReason.valueAt(index); 499 foundInfo = info; 500 } 501 if (allWindowsDrawn()) { 502 // abort metrics collection if we cannot find a matching transition. 503 final boolean abortMetrics = foundInfo == null; 504 reset(abortMetrics, foundInfo, "notifyTransitionStarting - all windows drawn"); 505 } 506 } 507 508 /** 509 * Notifies the tracker that the visibility of an app is changing. 510 * 511 * @param activityRecord the app that is changing its visibility 512 */ notifyVisibilityChanged(ActivityRecord activityRecord)513 void notifyVisibilityChanged(ActivityRecord activityRecord) { 514 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get( 515 activityRecord.getWindowingMode()); 516 if (info == null) { 517 return; 518 } 519 if (info.launchedActivity != activityRecord) { 520 return; 521 } 522 final TaskRecord t = activityRecord.getTaskRecord(); 523 final SomeArgs args = SomeArgs.obtain(); 524 args.arg1 = t; 525 args.arg2 = activityRecord; 526 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget(); 527 } 528 hasVisibleNonFinishingActivity(TaskRecord t)529 private boolean hasVisibleNonFinishingActivity(TaskRecord t) { 530 for (int i = t.mActivities.size() - 1; i >= 0; --i) { 531 final ActivityRecord r = t.mActivities.get(i); 532 if (r.visible && !r.finishing) { 533 return true; 534 } 535 } 536 return false; 537 } 538 checkVisibility(TaskRecord t, ActivityRecord r)539 private void checkVisibility(TaskRecord t, ActivityRecord r) { 540 synchronized (mSupervisor.mService.mGlobalLock) { 541 542 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get( 543 r.getWindowingMode()); 544 545 // If we have an active transition that's waiting on a certain activity that will be 546 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary. 547 548 // We have no active transitions. 549 if (info == null) { 550 return; 551 } 552 553 // The notified activity whose visibility changed is no longer the launched activity. 554 // We can still wait to get onWindowsDrawn. 555 if (info.launchedActivity != r) { 556 return; 557 } 558 559 // Check if there is any activity in the task that is visible and not finishing. If the 560 // launched activity finished before it is drawn and if there is another activity in 561 // the task then that activity will be draw on screen. 562 if (hasVisibleNonFinishingActivity(t)) { 563 return; 564 } 565 566 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible activity=" + r); 567 logAppTransitionCancel(info); 568 mWindowingModeTransitionInfo.remove(r.getWindowingMode()); 569 if (mWindowingModeTransitionInfo.size() == 0) { 570 reset(true /* abort */, info, "notifyVisibilityChanged to invisible"); 571 } 572 } 573 } 574 575 /** 576 * Notifies the tracker that we called immediately before we call bindApplication on the client. 577 * 578 * @param appInfo The client into which we'll call bindApplication. 579 */ notifyBindApplication(ApplicationInfo appInfo)580 void notifyBindApplication(ApplicationInfo appInfo) { 581 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) { 582 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i); 583 584 // App isn't attached to record yet, so match with info. 585 if (info.launchedActivity.appInfo == appInfo) { 586 info.bindApplicationDelayMs = calculateCurrentDelay(); 587 } 588 } 589 } 590 allWindowsDrawn()591 private boolean allWindowsDrawn() { 592 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) { 593 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) { 594 return false; 595 } 596 } 597 return true; 598 } 599 isAnyTransitionActive()600 private boolean isAnyTransitionActive() { 601 return mCurrentTransitionStartTime != INVALID_START_TIME 602 && mWindowingModeTransitionInfo.size() > 0; 603 } 604 reset(boolean abort, WindowingModeTransitionInfo info, String cause)605 private void reset(boolean abort, WindowingModeTransitionInfo info, String cause) { 606 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort + ",cause=" + cause); 607 if (!abort && isAnyTransitionActive()) { 608 logAppTransitionMultiEvents(); 609 } 610 stopLaunchTrace(info); 611 612 // Ignore reset-after reset. 613 if (isAnyTransitionActive()) { 614 // LaunchObserver callbacks. 615 if (abort) { 616 launchObserverNotifyActivityLaunchCancelled(info); 617 } else { 618 launchObserverNotifyActivityLaunchFinished(info); 619 } 620 } else { 621 launchObserverNotifyIntentFailed(); 622 } 623 624 mCurrentTransitionStartTime = INVALID_START_TIME; 625 mCurrentTransitionDelayMs = INVALID_DELAY; 626 mLoggedTransitionStarting = false; 627 mWindowingModeTransitionInfo.clear(); 628 } 629 calculateCurrentDelay()630 private int calculateCurrentDelay() { 631 // Shouldn't take more than 25 days to launch an app, so int is fine here. 632 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime); 633 } 634 calculateDelay(long timestamp)635 private int calculateDelay(long timestamp) { 636 // Shouldn't take more than 25 days to launch an app, so int is fine here. 637 return (int) (timestamp - mCurrentTransitionStartTime); 638 } 639 logAppTransitionCancel(WindowingModeTransitionInfo info)640 private void logAppTransitionCancel(WindowingModeTransitionInfo info) { 641 final int type = getTransitionType(info); 642 if (type == INVALID_TRANSITION_TYPE) { 643 return; 644 } 645 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED); 646 builder.setPackageName(info.launchedActivity.packageName); 647 builder.setType(type); 648 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name); 649 mMetricsLogger.write(builder); 650 StatsLog.write( 651 StatsLog.APP_START_CANCELED, 652 info.launchedActivity.appInfo.uid, 653 info.launchedActivity.packageName, 654 convertAppStartTransitionType(type), 655 info.launchedActivity.info.name); 656 if (DEBUG_METRICS) { 657 Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)", 658 info.launchedActivity.appInfo.uid, 659 info.launchedActivity.packageName, 660 convertAppStartTransitionType(type), 661 info.launchedActivity.info.name)); 662 } 663 } 664 logAppTransitionMultiEvents()665 private void logAppTransitionMultiEvents() { 666 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events"); 667 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) { 668 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index); 669 final int type = getTransitionType(info); 670 if (type == INVALID_TRANSITION_TYPE) { 671 if (DEBUG_METRICS) { 672 Slog.i(TAG, "invalid transition type" 673 + " processRunning=" + info.currentTransitionProcessRunning 674 + " startResult=" + info.startResult); 675 } 676 return; 677 } 678 679 // Take a snapshot of the transition info before sending it to the handler for logging. 680 // This will avoid any races with other operations that modify the ActivityRecord. 681 final WindowingModeTransitionInfoSnapshot infoSnapshot = 682 new WindowingModeTransitionInfoSnapshot(info); 683 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime; 684 final int currentTransitionDelayMs = mCurrentTransitionDelayMs; 685 BackgroundThread.getHandler().post(() -> logAppTransition( 686 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot)); 687 BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot)); 688 689 info.launchedActivity.info.launchToken = null; 690 } 691 } 692 693 // This gets called on a background thread without holding the activity manager lock. logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs, WindowingModeTransitionInfoSnapshot info)694 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs, 695 WindowingModeTransitionInfoSnapshot info) { 696 final LogMaker builder = new LogMaker(APP_TRANSITION); 697 builder.setPackageName(info.packageName); 698 builder.setType(info.type); 699 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName); 700 final boolean isInstantApp = info.applicationInfo.isInstantApp(); 701 if (info.launchedActivityLaunchedFromPackage != null) { 702 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME, 703 info.launchedActivityLaunchedFromPackage); 704 } 705 String launchToken = info.launchedActivityLaunchToken; 706 if (launchToken != null) { 707 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken); 708 } 709 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0); 710 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS, 711 currentTransitionDeviceUptime); 712 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs); 713 builder.setSubtype(info.reason); 714 if (info.startingWindowDelayMs != INVALID_DELAY) { 715 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS, 716 info.startingWindowDelayMs); 717 } 718 if (info.bindApplicationDelayMs != INVALID_DELAY) { 719 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS, 720 info.bindApplicationDelayMs); 721 } 722 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs); 723 final ArtManagerInternal artManagerInternal = getArtManagerInternal(); 724 final PackageOptimizationInfo packageOptimizationInfo = 725 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null) 726 ? PackageOptimizationInfo.createWithNoInfo() 727 : artManagerInternal.getPackageOptimizationInfo( 728 info.applicationInfo, 729 info.launchedActivityAppRecordRequiredAbi); 730 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON, 731 packageOptimizationInfo.getCompilationReason()); 732 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER, 733 packageOptimizationInfo.getCompilationFilter()); 734 mMetricsLogger.write(builder); 735 StatsLog.write( 736 StatsLog.APP_START_OCCURRED, 737 info.applicationInfo.uid, 738 info.packageName, 739 convertAppStartTransitionType(info.type), 740 info.launchedActivityName, 741 info.launchedActivityLaunchedFromPackage, 742 isInstantApp, 743 currentTransitionDeviceUptime * 1000, 744 info.reason, 745 currentTransitionDelayMs, 746 info.startingWindowDelayMs, 747 info.bindApplicationDelayMs, 748 info.windowsDrawnDelayMs, 749 launchToken, 750 packageOptimizationInfo.getCompilationReason(), 751 packageOptimizationInfo.getCompilationFilter()); 752 753 if (DEBUG_METRICS) { 754 Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)", 755 info.applicationInfo.uid, 756 info.packageName, 757 convertAppStartTransitionType(info.type), 758 info.launchedActivityName, 759 info.launchedActivityLaunchedFromPackage)); 760 } 761 762 763 logAppStartMemoryStateCapture(info); 764 } 765 logAppDisplayed(WindowingModeTransitionInfoSnapshot info)766 private void logAppDisplayed(WindowingModeTransitionInfoSnapshot info) { 767 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) { 768 return; 769 } 770 771 EventLog.writeEvent(AM_ACTIVITY_LAUNCH_TIME, 772 info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName, 773 info.windowsDrawnDelayMs); 774 775 StringBuilder sb = mStringBuilder; 776 sb.setLength(0); 777 sb.append("Displayed "); 778 sb.append(info.launchedActivityShortComponentName); 779 sb.append(": "); 780 TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb); 781 Log.i(TAG, sb.toString()); 782 } 783 convertAppStartTransitionType(int tronType)784 private int convertAppStartTransitionType(int tronType) { 785 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) { 786 return StatsLog.APP_START_OCCURRED__TYPE__COLD; 787 } 788 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) { 789 return StatsLog.APP_START_OCCURRED__TYPE__WARM; 790 } 791 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) { 792 return StatsLog.APP_START_OCCURRED__TYPE__HOT; 793 } 794 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN; 795 } 796 logAppTransitionReportedDrawn(ActivityRecord r, boolean restoredFromBundle)797 WindowingModeTransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r, 798 boolean restoredFromBundle) { 799 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get( 800 r.getWindowingMode()); 801 if (info == null) { 802 return null; 803 } 804 805 // Record the handling of the reportFullyDrawn callback in the trace system. This is not 806 // actually used to trace this function, but instead the logical task that this function 807 // fullfils (handling reportFullyDrawn() callbacks). 808 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, 809 "ActivityManager:ReportingFullyDrawn " + info.launchedActivity.packageName); 810 811 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN); 812 builder.setPackageName(r.packageName); 813 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name); 814 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime; 815 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs); 816 builder.setType(restoredFromBundle 817 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE 818 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE); 819 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING, 820 info.currentTransitionProcessRunning ? 1 : 0); 821 mMetricsLogger.write(builder); 822 StatsLog.write( 823 StatsLog.APP_START_FULLY_DRAWN, 824 info.launchedActivity.appInfo.uid, 825 info.launchedActivity.packageName, 826 restoredFromBundle 827 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE 828 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE, 829 info.launchedActivity.info.name, 830 info.currentTransitionProcessRunning, 831 startupTimeMs); 832 833 // Ends the trace started at the beginning of this function. This is located here to allow 834 // the trace slice to have a noticable duration. 835 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); 836 837 final WindowingModeTransitionInfoSnapshot infoSnapshot = 838 new WindowingModeTransitionInfoSnapshot(info, r, (int) startupTimeMs); 839 BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot)); 840 return infoSnapshot; 841 } 842 logAppFullyDrawn(WindowingModeTransitionInfoSnapshot info)843 private void logAppFullyDrawn(WindowingModeTransitionInfoSnapshot info) { 844 if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) { 845 return; 846 } 847 848 StringBuilder sb = mStringBuilder; 849 sb.setLength(0); 850 sb.append("Fully drawn "); 851 sb.append(info.launchedActivityShortComponentName); 852 sb.append(": "); 853 TimeUtils.formatDuration(info.windowsFullyDrawnDelayMs, sb); 854 Log.i(TAG, sb.toString()); 855 } 856 logAbortedBgActivityStart(Intent intent, WindowProcessController callerApp, int callingUid, String callingPackage, int callingUidProcState, boolean callingUidHasAnyVisibleWindow, int realCallingUid, int realCallingUidProcState, boolean realCallingUidHasAnyVisibleWindow, boolean comingFromPendingIntent)857 void logAbortedBgActivityStart(Intent intent, WindowProcessController callerApp, 858 int callingUid, String callingPackage, int callingUidProcState, 859 boolean callingUidHasAnyVisibleWindow, 860 int realCallingUid, int realCallingUidProcState, 861 boolean realCallingUidHasAnyVisibleWindow, 862 boolean comingFromPendingIntent) { 863 864 final long nowElapsed = SystemClock.elapsedRealtime(); 865 final long nowUptime = SystemClock.uptimeMillis(); 866 final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START); 867 builder.setTimestamp(System.currentTimeMillis()); 868 builder.addTaggedData(FIELD_CALLING_UID, callingUid); 869 builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage); 870 builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE, 871 processStateAmToProto(callingUidProcState)); 872 builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW, 873 callingUidHasAnyVisibleWindow ? 1 : 0); 874 builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid); 875 builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE, 876 processStateAmToProto(realCallingUidProcState)); 877 builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW, 878 realCallingUidHasAnyVisibleWindow ? 1 : 0); 879 builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0); 880 if (intent != null) { 881 builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction()); 882 ComponentName component = intent.getComponent(); 883 if (component != null) { 884 builder.addTaggedData(FIELD_TARGET_SHORT_COMPONENT_NAME, 885 component.flattenToShortString()); 886 } 887 } 888 if (callerApp != null) { 889 builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName); 890 builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE, 891 processStateAmToProto(callerApp.getCurrentProcState())); 892 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES, 893 callerApp.hasClientActivities() ? 1 : 0); 894 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES, 895 callerApp.hasForegroundServices() ? 1 : 0); 896 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES, 897 callerApp.hasForegroundActivities() ? 1 : 0); 898 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0); 899 builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI, 900 callerApp.hasOverlayUi() ? 1 : 0); 901 builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN, 902 callerApp.hasPendingUiClean() ? 1 : 0); 903 if (callerApp.getInteractionEventTime() != 0) { 904 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT, 905 (nowElapsed - callerApp.getInteractionEventTime())); 906 } 907 if (callerApp.getFgInteractionTime() != 0) { 908 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION, 909 (nowElapsed - callerApp.getFgInteractionTime())); 910 } 911 if (callerApp.getWhenUnimportant() != 0) { 912 builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT, 913 (nowUptime - callerApp.getWhenUnimportant())); 914 } 915 } 916 mMetricsLogger.write(builder); 917 } 918 getTransitionType(WindowingModeTransitionInfo info)919 private int getTransitionType(WindowingModeTransitionInfo info) { 920 if (info.currentTransitionProcessRunning) { 921 if (info.startResult == START_SUCCESS) { 922 return TYPE_TRANSITION_WARM_LAUNCH; 923 } else if (info.startResult == START_TASK_TO_FRONT) { 924 return TYPE_TRANSITION_HOT_LAUNCH; 925 } 926 } else if (info.startResult == START_SUCCESS 927 || (info.startResult == START_TASK_TO_FRONT)) { 928 // TaskRecord may still exist when cold launching an activity and the start 929 // result will be set to START_TASK_TO_FRONT. Treat this as a COLD launch. 930 return TYPE_TRANSITION_COLD_LAUNCH; 931 } 932 return INVALID_TRANSITION_TYPE; 933 } 934 logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info)935 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) { 936 if (info.processRecord == null) { 937 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null"); 938 return; 939 } 940 941 final int pid = info.processRecord.getPid(); 942 final int uid = info.applicationInfo.uid; 943 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid); 944 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, 952 info.processName, 953 info.launchedActivityName, 954 memoryStat.pgfault, 955 memoryStat.pgmajfault, 956 memoryStat.rssInBytes, 957 memoryStat.cacheInBytes, 958 memoryStat.swapInBytes); 959 } 960 findProcessForActivity(ActivityRecord launchedActivity)961 private WindowProcessController findProcessForActivity(ActivityRecord launchedActivity) { 962 return launchedActivity != null 963 ? mSupervisor.mService.mProcessNames.get( 964 launchedActivity.processName, launchedActivity.appInfo.uid) 965 : null; 966 } 967 getArtManagerInternal()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 } 977 978 /** 979 * Starts traces for app launch. 980 * 981 * @param info 982 * */ startTraces(WindowingModeTransitionInfo info)983 private void startTraces(WindowingModeTransitionInfo info) { 984 if (!Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER) || info == null 985 || info.launchTraceActive) { 986 return; 987 } 988 Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: " 989 + info.launchedActivity.packageName, 0); 990 info.launchTraceActive = true; 991 } 992 stopLaunchTrace(WindowingModeTransitionInfo info)993 private void stopLaunchTrace(WindowingModeTransitionInfo info) { 994 if (info == null) { 995 return; 996 } 997 if (info.launchTraceActive) { 998 Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, "launching: " 999 + info.launchedActivity.packageName, 0); 1000 info.launchTraceActive = false; 1001 } 1002 } 1003 getLaunchObserverRegistry()1004 public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() { 1005 return mLaunchObserver; 1006 } 1007 1008 /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */ launchObserverNotifyIntentStarted(Intent intent)1009 private void launchObserverNotifyIntentStarted(Intent intent) { 1010 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, 1011 "MetricsLogger:launchObserverNotifyIntentStarted"); 1012 1013 // Beginning a launch is timing sensitive and so should be observed as soon as possible. 1014 mLaunchObserver.onIntentStarted(intent); 1015 1016 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); 1017 } 1018 1019 /** 1020 * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has 1021 * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or 1022 * intent being delivered to the top running activity. 1023 */ launchObserverNotifyIntentFailed()1024 private void launchObserverNotifyIntentFailed() { 1025 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, 1026 "MetricsLogger:launchObserverNotifyIntentFailed"); 1027 1028 mLaunchObserver.onIntentFailed(); 1029 1030 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); 1031 } 1032 1033 /** 1034 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity 1035 * has started. 1036 */ launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info)1037 private void launchObserverNotifyActivityLaunched(WindowingModeTransitionInfo info) { 1038 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, 1039 "MetricsLogger:launchObserverNotifyActivityLaunched"); 1040 1041 @ActivityMetricsLaunchObserver.Temperature int temperature = 1042 convertTransitionTypeToLaunchObserverTemperature(getTransitionType(info)); 1043 1044 // Beginning a launch is timing sensitive and so should be observed as soon as possible. 1045 mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.launchedActivity), 1046 temperature); 1047 1048 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); 1049 } 1050 1051 /** 1052 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is 1053 * cancelled. 1054 */ launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info)1055 private void launchObserverNotifyActivityLaunchCancelled(WindowingModeTransitionInfo info) { 1056 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, 1057 "MetricsLogger:launchObserverNotifyActivityLaunchCancelled"); 1058 1059 final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto = 1060 info != null ? convertActivityRecordToProto(info.launchedActivity) : null; 1061 1062 mLaunchObserver.onActivityLaunchCancelled(activityRecordProto); 1063 1064 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); 1065 } 1066 1067 /** 1068 * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity 1069 * has fully finished (successfully). 1070 */ launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info)1071 private void launchObserverNotifyActivityLaunchFinished(WindowingModeTransitionInfo info) { 1072 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, 1073 "MetricsLogger:launchObserverNotifyActivityLaunchFinished"); 1074 1075 mLaunchObserver.onActivityLaunchFinished( 1076 convertActivityRecordToProto(info.launchedActivity)); 1077 1078 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); 1079 } 1080 1081 @VisibleForTesting 1082 static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] convertActivityRecordToProto(ActivityRecord record)1083 convertActivityRecordToProto(ActivityRecord record) { 1084 // May take non-negligible amount of time to convert ActivityRecord into a proto, 1085 // so track the time. 1086 Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, 1087 "MetricsLogger:convertActivityRecordToProto"); 1088 1089 // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream, 1090 // so create a new one every time. 1091 final ProtoOutputStream protoOutputStream = 1092 new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE); 1093 // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object). 1094 record.writeToProto(protoOutputStream); 1095 final byte[] bytes = protoOutputStream.getBytes(); 1096 1097 Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); 1098 1099 return bytes; 1100 } 1101 1102 private static @ActivityMetricsLaunchObserver.Temperature int convertTransitionTypeToLaunchObserverTemperature(int transitionType)1103 convertTransitionTypeToLaunchObserverTemperature(int transitionType) { 1104 switch (transitionType) { 1105 case TYPE_TRANSITION_WARM_LAUNCH: 1106 return ActivityMetricsLaunchObserver.TEMPERATURE_WARM; 1107 case TYPE_TRANSITION_HOT_LAUNCH: 1108 return ActivityMetricsLaunchObserver.TEMPERATURE_HOT; 1109 case TYPE_TRANSITION_COLD_LAUNCH: 1110 return ActivityMetricsLaunchObserver.TEMPERATURE_COLD; 1111 default: 1112 return -1; 1113 } 1114 } 1115 } 1116