1 package com.android.server.am; 2 3 import static android.app.ActivityManager.START_SUCCESS; 4 import static android.app.ActivityManager.START_TASK_TO_FRONT; 5 import static android.app.ActivityManagerInternal.APP_TRANSITION_TIMEOUT; 6 import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_PRIMARY; 7 import static android.app.WindowConfiguration.WINDOWING_MODE_FREEFORM; 8 import static android.app.WindowConfiguration.WINDOWING_MODE_FULLSCREEN; 9 import static android.app.WindowConfiguration.WINDOWING_MODE_PINNED; 10 import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_SECONDARY; 11 import static android.app.WindowConfiguration.WINDOWING_MODE_UNDEFINED; 12 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION; 13 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_BIND_APPLICATION_DELAY_MS; 14 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CALLING_PACKAGE_NAME; 15 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CANCELLED; 16 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DELAY_MS; 17 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS; 18 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_IS_EPHEMERAL; 19 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_PROCESS_RUNNING; 20 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN; 21 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN_MS; 22 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_STARTING_WINDOW_DELAY_MS; 23 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS; 24 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME; 25 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INSTANT_APP_LAUNCH_TOKEN; 26 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_REASON; 27 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_FILTER; 28 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_COLD_LAUNCH; 29 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_HOT_LAUNCH; 30 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE; 31 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE; 32 import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH; 33 import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_METRICS; 34 import static com.android.server.am.ActivityManagerDebugConfig.TAG_AM; 35 import static com.android.server.am.ActivityManagerDebugConfig.TAG_WITH_CLASS_NAME; 36 import static com.android.server.am.MemoryStatUtil.MemoryStat; 37 import static com.android.server.am.MemoryStatUtil.readMemoryStatFromFilesystem; 38 39 import android.content.Context; 40 import android.content.pm.ApplicationInfo; 41 import android.content.pm.dex.ArtManagerInternal; 42 import android.content.pm.dex.PackageOptimizationInfo; 43 import android.metrics.LogMaker; 44 import android.os.Handler; 45 import android.os.Looper; 46 import android.os.Message; 47 import android.os.SystemClock; 48 import android.util.Slog; 49 import android.util.SparseArray; 50 import android.util.SparseIntArray; 51 import android.util.StatsLog; 52 53 import com.android.internal.logging.MetricsLogger; 54 import com.android.internal.os.BackgroundThread; 55 import com.android.internal.os.SomeArgs; 56 import com.android.server.LocalServices; 57 58 import java.util.ArrayList; 59 60 /** 61 * Handles logging into Tron. 62 */ 63 class ActivityMetricsLogger { 64 65 private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_AM; 66 67 // Window modes we are interested in logging. If we ever introduce a new type, we need to add 68 // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array. 69 private static final int WINDOW_STATE_STANDARD = 0; 70 private static final int WINDOW_STATE_SIDE_BY_SIDE = 1; 71 private static final int WINDOW_STATE_FREEFORM = 2; 72 private static final int WINDOW_STATE_ASSISTANT = 3; 73 private static final int WINDOW_STATE_INVALID = -1; 74 75 private static final long INVALID_START_TIME = -1; 76 77 private static final int MSG_CHECK_VISIBILITY = 0; 78 79 // Preallocated strings we are sending to tron, so we don't have to allocate a new one every 80 // time we log. 81 private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = { 82 "window_time_0", "window_time_1", "window_time_2", "window_time_3"}; 83 84 private int mWindowState = WINDOW_STATE_STANDARD; 85 private long mLastLogTimeSecs; 86 private final ActivityStackSupervisor mSupervisor; 87 private final Context mContext; 88 private final MetricsLogger mMetricsLogger = new MetricsLogger(); 89 90 private long mCurrentTransitionStartTime = INVALID_START_TIME; 91 private long mLastTransitionStartTime = INVALID_START_TIME; 92 93 private int mCurrentTransitionDeviceUptime; 94 private int mCurrentTransitionDelayMs; 95 private boolean mLoggedTransitionStarting; 96 97 private final SparseArray<WindowingModeTransitionInfo> mWindowingModeTransitionInfo = 98 new SparseArray<>(); 99 private final SparseArray<WindowingModeTransitionInfo> mLastWindowingModeTransitionInfo = 100 new SparseArray<>(); 101 private final H mHandler; 102 103 private ArtManagerInternal mArtManagerInternal; 104 105 private final class H extends Handler { 106 H(Looper looper)107 public H(Looper looper) { 108 super(looper); 109 } 110 111 @Override handleMessage(Message msg)112 public void handleMessage(Message msg) { 113 switch (msg.what) { 114 case MSG_CHECK_VISIBILITY: 115 final SomeArgs args = (SomeArgs) msg.obj; 116 checkVisibility((TaskRecord) args.arg1, (ActivityRecord) args.arg2); 117 break; 118 } 119 } 120 } 121 122 private final class WindowingModeTransitionInfo { 123 private ActivityRecord launchedActivity; 124 private int startResult; 125 private boolean currentTransitionProcessRunning; 126 private int windowsDrawnDelayMs; 127 private int startingWindowDelayMs = -1; 128 private int bindApplicationDelayMs = -1; 129 private int reason = APP_TRANSITION_TIMEOUT; 130 private boolean loggedWindowsDrawn; 131 private boolean loggedStartingWindowDrawn; 132 } 133 134 private final class WindowingModeTransitionInfoSnapshot { 135 final private ApplicationInfo applicationInfo; 136 final private ProcessRecord processRecord; 137 final private String packageName; 138 final private String launchedActivityName; 139 final private String launchedActivityLaunchedFromPackage; 140 final private String launchedActivityLaunchToken; 141 final private String launchedActivityAppRecordRequiredAbi; 142 final private String processName; 143 final private int reason; 144 final private int startingWindowDelayMs; 145 final private int bindApplicationDelayMs; 146 final private int windowsDrawnDelayMs; 147 final private int type; 148 WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info)149 private WindowingModeTransitionInfoSnapshot(WindowingModeTransitionInfo info) { 150 applicationInfo = info.launchedActivity.appInfo; 151 packageName = info.launchedActivity.packageName; 152 launchedActivityName = info.launchedActivity.info.name; 153 launchedActivityLaunchedFromPackage = info.launchedActivity.launchedFromPackage; 154 launchedActivityLaunchToken = info.launchedActivity.info.launchToken; 155 launchedActivityAppRecordRequiredAbi = info.launchedActivity.app == null 156 ? null 157 : info.launchedActivity.app.requiredAbi; 158 reason = info.reason; 159 startingWindowDelayMs = info.startingWindowDelayMs; 160 bindApplicationDelayMs = info.bindApplicationDelayMs; 161 windowsDrawnDelayMs = info.windowsDrawnDelayMs; 162 type = getTransitionType(info); 163 processRecord = findProcessForActivity(info.launchedActivity); 164 processName = info.launchedActivity.processName; 165 } 166 } 167 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper)168 ActivityMetricsLogger(ActivityStackSupervisor supervisor, Context context, Looper looper) { 169 mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000; 170 mSupervisor = supervisor; 171 mContext = context; 172 mHandler = new H(looper); 173 } 174 logWindowState()175 void logWindowState() { 176 final long now = SystemClock.elapsedRealtime() / 1000; 177 if (mWindowState != WINDOW_STATE_INVALID) { 178 // We log even if the window state hasn't changed, because the user might remain in 179 // home/fullscreen move forever and we would like to track this kind of behavior 180 // too. 181 MetricsLogger.count(mContext, TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState], 182 (int) (now - mLastLogTimeSecs)); 183 } 184 mLastLogTimeSecs = now; 185 186 mWindowState = WINDOW_STATE_INVALID; 187 ActivityStack stack = mSupervisor.getFocusedStack(); 188 if (stack.isActivityTypeAssistant()) { 189 mWindowState = WINDOW_STATE_ASSISTANT; 190 return; 191 } 192 193 int windowingMode = stack.getWindowingMode(); 194 if (windowingMode == WINDOWING_MODE_PINNED) { 195 stack = mSupervisor.findStackBehind(stack); 196 windowingMode = stack.getWindowingMode(); 197 } 198 switch (windowingMode) { 199 case WINDOWING_MODE_FULLSCREEN: 200 mWindowState = WINDOW_STATE_STANDARD; 201 break; 202 case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY: 203 case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY: 204 mWindowState = WINDOW_STATE_SIDE_BY_SIDE; 205 break; 206 case WINDOWING_MODE_FREEFORM: 207 mWindowState = WINDOW_STATE_FREEFORM; 208 break; 209 default: 210 if (windowingMode != WINDOWING_MODE_UNDEFINED) { 211 throw new IllegalStateException("Unknown windowing mode for stack=" + stack 212 + " windowingMode=" + windowingMode); 213 } 214 } 215 } 216 217 /** 218 * Notifies the tracker at the earliest possible point when we are starting to launch an 219 * activity. 220 */ notifyActivityLaunching()221 void notifyActivityLaunching() { 222 if (!isAnyTransitionActive()) { 223 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunching"); 224 mCurrentTransitionStartTime = SystemClock.uptimeMillis(); 225 mLastTransitionStartTime = mCurrentTransitionStartTime; 226 } 227 } 228 229 /** 230 * Notifies the tracker that the activity is actually launching. 231 * 232 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the 233 * launch 234 * @param launchedActivity the activity that is being launched 235 */ notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity)236 void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity) { 237 final ProcessRecord processRecord = findProcessForActivity(launchedActivity); 238 final boolean processRunning = processRecord != null; 239 240 // We consider this a "process switch" if the process of the activity that gets launched 241 // didn't have an activity that was in started state. In this case, we assume that lot 242 // of caches might be purged so the time until it produces the first frame is very 243 // interesting. 244 final boolean processSwitch = processRecord == null 245 || !hasStartedActivity(processRecord, launchedActivity); 246 247 notifyActivityLaunched(resultCode, launchedActivity, processRunning, processSwitch); 248 } 249 hasStartedActivity(ProcessRecord record, ActivityRecord launchedActivity)250 private boolean hasStartedActivity(ProcessRecord record, ActivityRecord launchedActivity) { 251 final ArrayList<ActivityRecord> activities = record.activities; 252 for (int i = activities.size() - 1; i >= 0; i--) { 253 final ActivityRecord activity = activities.get(i); 254 if (launchedActivity == activity) { 255 continue; 256 } 257 if (!activity.stopped) { 258 return true; 259 } 260 } 261 return false; 262 } 263 264 /** 265 * Notifies the tracker the the activity is actually launching. 266 * 267 * @param resultCode one of the ActivityManager.START_* flags, indicating the result of the 268 * launch 269 * @param launchedActivity the activity being launched 270 * @param processRunning whether the process that will contains the activity is already running 271 * @param processSwitch whether the process that will contain the activity didn't have any 272 * activity that was stopped, i.e. the started activity is "switching" 273 * processes 274 */ notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity, boolean processRunning, boolean processSwitch)275 private void notifyActivityLaunched(int resultCode, ActivityRecord launchedActivity, 276 boolean processRunning, boolean processSwitch) { 277 278 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched" 279 + " resultCode=" + resultCode 280 + " launchedActivity=" + launchedActivity 281 + " processRunning=" + processRunning 282 + " processSwitch=" + processSwitch); 283 284 // If we are already in an existing transition, only update the activity name, but not the 285 // other attributes. 286 final int windowingMode = launchedActivity != null 287 ? launchedActivity.getWindowingMode() 288 : WINDOWING_MODE_UNDEFINED; 289 290 if (mCurrentTransitionStartTime == INVALID_START_TIME) { 291 return; 292 } 293 294 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode); 295 if (launchedActivity != null && info != null) { 296 info.launchedActivity = launchedActivity; 297 return; 298 } 299 300 final boolean otherWindowModesLaunching = 301 mWindowingModeTransitionInfo.size() > 0 && info == null; 302 if ((!isLoggableResultCode(resultCode) || launchedActivity == null || !processSwitch 303 || windowingMode == WINDOWING_MODE_UNDEFINED) && !otherWindowModesLaunching) { 304 305 // Failed to launch or it was not a process switch, so we don't care about the timing. 306 reset(true /* abort */); 307 return; 308 } else if (otherWindowModesLaunching) { 309 // Don't log this windowing mode but continue with the other windowing modes. 310 return; 311 } 312 313 if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful"); 314 315 final WindowingModeTransitionInfo newInfo = new WindowingModeTransitionInfo(); 316 newInfo.launchedActivity = launchedActivity; 317 newInfo.currentTransitionProcessRunning = processRunning; 318 newInfo.startResult = resultCode; 319 mWindowingModeTransitionInfo.put(windowingMode, newInfo); 320 mLastWindowingModeTransitionInfo.put(windowingMode, newInfo); 321 mCurrentTransitionDeviceUptime = (int) (SystemClock.uptimeMillis() / 1000); 322 } 323 324 /** 325 * @return True if we should start logging an event for an activity start that returned 326 * {@code resultCode} and that we'll indeed get a windows drawn event. 327 */ isLoggableResultCode(int resultCode)328 private boolean isLoggableResultCode(int resultCode) { 329 return resultCode == START_SUCCESS || resultCode == START_TASK_TO_FRONT; 330 } 331 332 /** 333 * Notifies the tracker that all windows of the app have been drawn. 334 */ notifyWindowsDrawn(int windowingMode, long timestamp)335 void notifyWindowsDrawn(int windowingMode, long timestamp) { 336 if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn windowingMode=" + windowingMode); 337 338 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode); 339 if (info == null || info.loggedWindowsDrawn) { 340 return; 341 } 342 info.windowsDrawnDelayMs = calculateDelay(timestamp); 343 info.loggedWindowsDrawn = true; 344 if (allWindowsDrawn() && mLoggedTransitionStarting) { 345 reset(false /* abort */); 346 } 347 } 348 349 /** 350 * Notifies the tracker that the starting window was drawn. 351 */ notifyStartingWindowDrawn(int windowingMode, long timestamp)352 void notifyStartingWindowDrawn(int windowingMode, long timestamp) { 353 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get(windowingMode); 354 if (info == null || info.loggedStartingWindowDrawn) { 355 return; 356 } 357 info.loggedStartingWindowDrawn = true; 358 info.startingWindowDelayMs = calculateDelay(timestamp); 359 } 360 361 /** 362 * Notifies the tracker that the app transition is starting. 363 * 364 * @param windowingModeToReason A map from windowing mode to a reason integer, which must be on 365 * of ActivityManagerInternal.APP_TRANSITION_* reasons. 366 */ notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp)367 void notifyTransitionStarting(SparseIntArray windowingModeToReason, long timestamp) { 368 if (!isAnyTransitionActive() || mLoggedTransitionStarting) { 369 return; 370 } 371 if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting"); 372 mCurrentTransitionDelayMs = calculateDelay(timestamp); 373 mLoggedTransitionStarting = true; 374 for (int index = windowingModeToReason.size() - 1; index >= 0; index--) { 375 final int windowingMode = windowingModeToReason.keyAt(index); 376 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get( 377 windowingMode); 378 if (info == null) { 379 continue; 380 } 381 info.reason = windowingModeToReason.valueAt(index); 382 } 383 if (allWindowsDrawn()) { 384 reset(false /* abort */); 385 } 386 } 387 388 /** 389 * Notifies the tracker that the visibility of an app is changing. 390 * 391 * @param activityRecord the app that is changing its visibility 392 */ notifyVisibilityChanged(ActivityRecord activityRecord)393 void notifyVisibilityChanged(ActivityRecord activityRecord) { 394 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get( 395 activityRecord.getWindowingMode()); 396 if (info == null) { 397 return; 398 } 399 if (info.launchedActivity != activityRecord) { 400 return; 401 } 402 final TaskRecord t = activityRecord.getTask(); 403 final SomeArgs args = SomeArgs.obtain(); 404 args.arg1 = t; 405 args.arg2 = activityRecord; 406 mHandler.obtainMessage(MSG_CHECK_VISIBILITY, args).sendToTarget(); 407 } 408 checkVisibility(TaskRecord t, ActivityRecord r)409 private void checkVisibility(TaskRecord t, ActivityRecord r) { 410 synchronized (mSupervisor.mService) { 411 412 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.get( 413 r.getWindowingMode()); 414 415 // If we have an active transition that's waiting on a certain activity that will be 416 // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary. 417 if (info != null && !t.isVisible()) { 418 if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible" 419 + " activity=" + r); 420 logAppTransitionCancel(info); 421 mWindowingModeTransitionInfo.remove(r.getWindowingMode()); 422 if (mWindowingModeTransitionInfo.size() == 0) { 423 reset(true /* abort */); 424 } 425 } 426 } 427 } 428 429 /** 430 * Notifies the tracker that we called immediately before we call bindApplication on the client. 431 * 432 * @param app The client into which we'll call bindApplication. 433 */ notifyBindApplication(ProcessRecord app)434 void notifyBindApplication(ProcessRecord app) { 435 for (int i = mWindowingModeTransitionInfo.size() - 1; i >= 0; i--) { 436 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(i); 437 438 // App isn't attached to record yet, so match with info. 439 if (info.launchedActivity.appInfo == app.info) { 440 info.bindApplicationDelayMs = calculateCurrentDelay(); 441 } 442 } 443 } 444 allWindowsDrawn()445 private boolean allWindowsDrawn() { 446 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) { 447 if (!mWindowingModeTransitionInfo.valueAt(index).loggedWindowsDrawn) { 448 return false; 449 } 450 } 451 return true; 452 } 453 isAnyTransitionActive()454 private boolean isAnyTransitionActive() { 455 return mCurrentTransitionStartTime != INVALID_START_TIME 456 && mWindowingModeTransitionInfo.size() > 0; 457 } 458 reset(boolean abort)459 private void reset(boolean abort) { 460 if (DEBUG_METRICS) Slog.i(TAG, "reset abort=" + abort); 461 if (!abort && isAnyTransitionActive()) { 462 logAppTransitionMultiEvents(); 463 } 464 mCurrentTransitionStartTime = INVALID_START_TIME; 465 mCurrentTransitionDelayMs = -1; 466 mLoggedTransitionStarting = false; 467 mWindowingModeTransitionInfo.clear(); 468 } 469 calculateCurrentDelay()470 private int calculateCurrentDelay() { 471 472 // Shouldn't take more than 25 days to launch an app, so int is fine here. 473 return (int) (SystemClock.uptimeMillis() - mCurrentTransitionStartTime); 474 } 475 calculateDelay(long timestamp)476 private int calculateDelay(long timestamp) { 477 // Shouldn't take more than 25 days to launch an app, so int is fine here. 478 return (int) (timestamp - mCurrentTransitionStartTime); 479 } 480 logAppTransitionCancel(WindowingModeTransitionInfo info)481 private void logAppTransitionCancel(WindowingModeTransitionInfo info) { 482 final int type = getTransitionType(info); 483 if (type == -1) { 484 return; 485 } 486 final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED); 487 builder.setPackageName(info.launchedActivity.packageName); 488 builder.setType(type); 489 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivity.info.name); 490 mMetricsLogger.write(builder); 491 StatsLog.write( 492 StatsLog.APP_START_CANCELED, 493 info.launchedActivity.appInfo.uid, 494 info.launchedActivity.packageName, 495 convertAppStartTransitionType(type), 496 info.launchedActivity.info.name); 497 } 498 logAppTransitionMultiEvents()499 private void logAppTransitionMultiEvents() { 500 if (DEBUG_METRICS) Slog.i(TAG, "logging transition events"); 501 for (int index = mWindowingModeTransitionInfo.size() - 1; index >= 0; index--) { 502 final WindowingModeTransitionInfo info = mWindowingModeTransitionInfo.valueAt(index); 503 final int type = getTransitionType(info); 504 if (type == -1) { 505 return; 506 } 507 508 // Take a snapshot of the transition info before sending it to the handler for logging. 509 // This will avoid any races with other operations that modify the ActivityRecord. 510 final WindowingModeTransitionInfoSnapshot infoSnapshot = 511 new WindowingModeTransitionInfoSnapshot(info); 512 final int currentTransitionDeviceUptime = mCurrentTransitionDeviceUptime; 513 final int currentTransitionDelayMs = mCurrentTransitionDelayMs; 514 BackgroundThread.getHandler().post(() -> logAppTransition( 515 currentTransitionDeviceUptime, currentTransitionDelayMs, infoSnapshot)); 516 517 info.launchedActivity.info.launchToken = null; 518 } 519 } 520 521 // This gets called on a background thread without holding the activity manager lock. logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs, WindowingModeTransitionInfoSnapshot info)522 private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs, 523 WindowingModeTransitionInfoSnapshot info) { 524 final LogMaker builder = new LogMaker(APP_TRANSITION); 525 builder.setPackageName(info.packageName); 526 builder.setType(info.type); 527 builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName); 528 final boolean isInstantApp = info.applicationInfo.isInstantApp(); 529 if (info.launchedActivityLaunchedFromPackage != null) { 530 builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME, 531 info.launchedActivityLaunchedFromPackage); 532 } 533 String launchToken = info.launchedActivityLaunchToken; 534 if (launchToken != null) { 535 builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken); 536 } 537 builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0); 538 builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS, 539 currentTransitionDeviceUptime); 540 builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs); 541 builder.setSubtype(info.reason); 542 if (info.startingWindowDelayMs != -1) { 543 builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS, 544 info.startingWindowDelayMs); 545 } 546 if (info.bindApplicationDelayMs != -1) { 547 builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS, 548 info.bindApplicationDelayMs); 549 } 550 builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs); 551 final ArtManagerInternal artManagerInternal = getArtManagerInternal(); 552 final PackageOptimizationInfo packageOptimizationInfo = 553 (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null) 554 ? PackageOptimizationInfo.createWithNoInfo() 555 : artManagerInternal.getPackageOptimizationInfo( 556 info.applicationInfo, 557 info.launchedActivityAppRecordRequiredAbi); 558 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON, 559 packageOptimizationInfo.getCompilationReason()); 560 builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER, 561 packageOptimizationInfo.getCompilationFilter()); 562 mMetricsLogger.write(builder); 563 StatsLog.write( 564 StatsLog.APP_START_OCCURRED, 565 info.applicationInfo.uid, 566 info.packageName, 567 convertAppStartTransitionType(info.type), 568 info.launchedActivityName, 569 info.launchedActivityLaunchedFromPackage, 570 isInstantApp, 571 currentTransitionDeviceUptime * 1000, 572 info.reason, 573 currentTransitionDelayMs, 574 info.startingWindowDelayMs, 575 info.bindApplicationDelayMs, 576 info.windowsDrawnDelayMs, 577 launchToken, 578 packageOptimizationInfo.getCompilationReason(), 579 packageOptimizationInfo.getCompilationFilter()); 580 logAppStartMemoryStateCapture(info); 581 } 582 convertAppStartTransitionType(int tronType)583 private int convertAppStartTransitionType(int tronType) { 584 if (tronType == TYPE_TRANSITION_COLD_LAUNCH) { 585 return StatsLog.APP_START_OCCURRED__TYPE__COLD; 586 } 587 if (tronType == TYPE_TRANSITION_WARM_LAUNCH) { 588 return StatsLog.APP_START_OCCURRED__TYPE__WARM; 589 } 590 if (tronType == TYPE_TRANSITION_HOT_LAUNCH) { 591 return StatsLog.APP_START_OCCURRED__TYPE__HOT; 592 } 593 return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN; 594 } 595 logAppTransitionReportedDrawn(ActivityRecord r, boolean restoredFromBundle)596 void logAppTransitionReportedDrawn(ActivityRecord r, boolean restoredFromBundle) { 597 final WindowingModeTransitionInfo info = mLastWindowingModeTransitionInfo.get( 598 r.getWindowingMode()); 599 if (info == null) { 600 return; 601 } 602 final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN); 603 builder.setPackageName(r.packageName); 604 builder.addTaggedData(FIELD_CLASS_NAME, r.info.name); 605 long startupTimeMs = SystemClock.uptimeMillis() - mLastTransitionStartTime; 606 builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs); 607 builder.setType(restoredFromBundle 608 ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE 609 : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE); 610 builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING, 611 info.currentTransitionProcessRunning ? 1 : 0); 612 mMetricsLogger.write(builder); 613 StatsLog.write( 614 StatsLog.APP_START_FULLY_DRAWN, 615 info.launchedActivity.appInfo.uid, 616 info.launchedActivity.packageName, 617 restoredFromBundle 618 ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE 619 : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE, 620 info.launchedActivity.info.name, 621 info.currentTransitionProcessRunning, 622 startupTimeMs); 623 } 624 getTransitionType(WindowingModeTransitionInfo info)625 private int getTransitionType(WindowingModeTransitionInfo info) { 626 if (info.currentTransitionProcessRunning) { 627 if (info.startResult == START_SUCCESS) { 628 return TYPE_TRANSITION_WARM_LAUNCH; 629 } else if (info.startResult == START_TASK_TO_FRONT) { 630 return TYPE_TRANSITION_HOT_LAUNCH; 631 } 632 } else if (info.startResult == START_SUCCESS) { 633 return TYPE_TRANSITION_COLD_LAUNCH; 634 } 635 return -1; 636 } 637 logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info)638 private void logAppStartMemoryStateCapture(WindowingModeTransitionInfoSnapshot info) { 639 if (info.processRecord == null) { 640 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null"); 641 return; 642 } 643 644 final int pid = info.processRecord.pid; 645 final int uid = info.applicationInfo.uid; 646 final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid); 647 if (memoryStat == null) { 648 if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null"); 649 return; 650 } 651 652 StatsLog.write( 653 StatsLog.APP_START_MEMORY_STATE_CAPTURED, 654 uid, 655 info.processName, 656 info.launchedActivityName, 657 memoryStat.pgfault, 658 memoryStat.pgmajfault, 659 memoryStat.rssInBytes, 660 memoryStat.cacheInBytes, 661 memoryStat.swapInBytes); 662 } 663 findProcessForActivity(ActivityRecord launchedActivity)664 private ProcessRecord findProcessForActivity(ActivityRecord launchedActivity) { 665 return launchedActivity != null 666 ? mSupervisor.mService.mProcessNames.get(launchedActivity.processName, 667 launchedActivity.appInfo.uid) 668 : null; 669 } 670 getArtManagerInternal()671 private ArtManagerInternal getArtManagerInternal() { 672 if (mArtManagerInternal == null) { 673 // Note that this may be null. 674 // ArtManagerInternal is registered during PackageManagerService 675 // initialization which happens after ActivityManagerService. 676 mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class); 677 } 678 return mArtManagerInternal; 679 } 680 } 681