Wale Ogunwale | 5950709 | 2018-10-29 09:00:30 -0700 | [diff] [blame] | 1 | package com.android.server.wm; |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 2 | |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 3 | import static android.app.ActivityManager.START_SUCCESS; |
| 4 | import static android.app.ActivityManager.START_TASK_TO_FRONT; |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 5 | import static android.app.ActivityManager.processStateAmToProto; |
Vishnu Nair | bb9ab4b | 2018-12-13 10:29:46 -0800 | [diff] [blame] | 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; |
Bryce Lee | 6c60509 | 2017-10-12 11:14:49 -0700 | [diff] [blame] | 9 | import static android.app.WindowConfiguration.WINDOWING_MODE_FREEFORM; |
Wale Ogunwale | 3382ab1 | 2017-07-27 08:55:03 -0700 | [diff] [blame] | 10 | import static android.app.WindowConfiguration.WINDOWING_MODE_FULLSCREEN; |
| 11 | import static android.app.WindowConfiguration.WINDOWING_MODE_PINNED; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 12 | import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_PRIMARY; |
Wale Ogunwale | 926aade | 2017-08-29 11:24:37 -0700 | [diff] [blame] | 13 | import static android.app.WindowConfiguration.WINDOWING_MODE_SPLIT_SCREEN_SECONDARY; |
| 14 | import static android.app.WindowConfiguration.WINDOWING_MODE_UNDEFINED; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 15 | |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 16 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.ACTION_ACTIVITY_START; |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 17 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION; |
Jorim Jaggi | 515dd68 | 2017-05-05 15:05:07 +0200 | [diff] [blame] | 18 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_BIND_APPLICATION_DELAY_MS; |
Todd Kennedy | 50d946c1 | 2017-03-17 13:55:38 -0700 | [diff] [blame] | 19 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CALLING_PACKAGE_NAME; |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 20 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CANCELLED; |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 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; |
Todd Kennedy | 50d946c1 | 2017-03-17 13:55:38 -0700 | [diff] [blame] | 23 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_IS_EPHEMERAL; |
Jorim Jaggi | 4d27b84 | 2017-08-17 17:22:26 +0200 | [diff] [blame] | 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; |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 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; |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 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; |
Jorim Jaggi | cdfc04e | 2017-04-28 19:06:24 +0200 | [diff] [blame] | 33 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME; |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 34 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_COMING_FROM_PENDING_INTENT; |
Todd Kennedy | 50d946c1 | 2017-03-17 13:55:38 -0700 | [diff] [blame] | 35 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_INSTANT_APP_LAUNCH_TOKEN; |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 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; |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 49 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 50 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_REAL_CALLING_UID_PROC_STATE; |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 51 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_TARGET_SHORT_COMPONENT_NAME; |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 52 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_FILTER; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 53 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.PACKAGE_OPTIMIZATION_COMPILATION_REASON; |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 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; |
Jorim Jaggi | 4d27b84 | 2017-08-17 17:22:26 +0200 | [diff] [blame] | 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; |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 58 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH; |
Ng Zhi An | bbefdec | 2018-01-30 17:12:39 -0800 | [diff] [blame] | 59 | import static com.android.server.am.MemoryStatUtil.MemoryStat; |
Rajeev Kumar | bfcd920 | 2018-03-02 22:42:13 +0000 | [diff] [blame] | 60 | import static com.android.server.am.MemoryStatUtil.readMemoryStatFromFilesystem; |
Vishnu Nair | a62534b | 2018-11-09 09:13:22 -0800 | [diff] [blame] | 61 | import static com.android.server.wm.ActivityTaskManagerDebugConfig.DEBUG_METRICS; |
| 62 | import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_ATM; |
| 63 | import static com.android.server.wm.ActivityTaskManagerDebugConfig.TAG_WITH_CLASS_NAME; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 64 | import static com.android.server.wm.ActivityTaskManagerInternal.APP_TRANSITION_TIMEOUT; |
Jeff Chang | d136e77 | 2019-11-05 20:33:52 +0800 | [diff] [blame] | 65 | import static com.android.server.wm.EventLogTags.WM_ACTIVITY_LAUNCH_TIME; |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 66 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 67 | import android.annotation.NonNull; |
| 68 | import android.annotation.Nullable; |
Vishnu Nair | bb9ab4b | 2018-12-13 10:29:46 -0800 | [diff] [blame] | 69 | import android.app.WaitResult; |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 70 | import android.app.WindowConfiguration.WindowingMode; |
Michal Karpinski | 319069b | 2019-03-27 15:46:50 +0000 | [diff] [blame] | 71 | import android.content.ComponentName; |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 72 | import android.content.Intent; |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 73 | import android.content.pm.ApplicationInfo; |
| 74 | import android.content.pm.dex.ArtManagerInternal; |
| 75 | import android.content.pm.dex.PackageOptimizationInfo; |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 76 | import android.metrics.LogMaker; |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 77 | import android.os.Binder; |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 78 | import android.os.Looper; |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 79 | import android.os.SystemClock; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 80 | import android.os.Trace; |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 81 | import android.util.ArrayMap; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 82 | import android.util.EventLog; |
| 83 | import android.util.Log; |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 84 | import android.util.Slog; |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 85 | import android.util.StatsLog; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 86 | import android.util.TimeUtils; |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 87 | import android.util.proto.ProtoOutputStream; |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 88 | |
Vishnu Nair | bb9ab4b | 2018-12-13 10:29:46 -0800 | [diff] [blame] | 89 | import com.android.internal.annotations.VisibleForTesting; |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 90 | import com.android.internal.logging.MetricsLogger; |
Ng Zhi An | 8347354 | 2018-02-20 09:02:14 -0800 | [diff] [blame] | 91 | import com.android.internal.os.BackgroundThread; |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 92 | import com.android.internal.util.function.pooled.PooledLambda; |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 93 | import com.android.server.LocalServices; |
Louis Chang | cdec080 | 2019-11-11 11:45:07 +0800 | [diff] [blame] | 94 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 95 | import java.util.ArrayList; |
| 96 | import java.util.LinkedList; |
Yan Wang | 9eac5ec | 2019-09-30 15:42:18 -0700 | [diff] [blame] | 97 | import java.util.concurrent.TimeUnit; |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 98 | |
| 99 | /** |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 100 | * Listens to activity launches, transitions, visibility changes and window drawn callbacks to |
| 101 | * determine app launch times and draw delays. Source of truth for activity metrics and provides |
| 102 | * data for Tron, logcat, event logs and {@link android.app.WaitResult}. |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 103 | * <p> |
| 104 | * A typical sequence of a launch event could be: |
| 105 | * {@link #notifyActivityLaunching}, {@link #notifyActivityLaunched}, |
| 106 | * {@link #notifyStartingWindowDrawn} (optional), {@link #notifyTransitionStarting} |
| 107 | * {@link #notifyWindowsDrawn}. |
| 108 | * <p> |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 109 | * Tests: |
Tadashi G. Takaoka | 28bc370 | 2019-04-23 11:01:48 +0900 | [diff] [blame] | 110 | * atest CtsWindowManagerDeviceTestCases:ActivityMetricsLoggerTests |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 111 | */ |
| 112 | class ActivityMetricsLogger { |
Jorim Jaggi | f970410 | 2016-05-05 19:14:22 -0700 | [diff] [blame] | 113 | |
Wale Ogunwale | 9887561 | 2018-10-12 07:53:02 -0700 | [diff] [blame] | 114 | private static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityMetricsLogger" : TAG_ATM; |
Jorim Jaggi | f970410 | 2016-05-05 19:14:22 -0700 | [diff] [blame] | 115 | |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 116 | // Window modes we are interested in logging. If we ever introduce a new type, we need to add |
| 117 | // a value here and increase the {@link #TRON_WINDOW_STATE_VARZ_STRINGS} array. |
| 118 | private static final int WINDOW_STATE_STANDARD = 0; |
| 119 | private static final int WINDOW_STATE_SIDE_BY_SIDE = 1; |
| 120 | private static final int WINDOW_STATE_FREEFORM = 2; |
Winson Chung | 8347163 | 2016-12-13 11:02:12 -0800 | [diff] [blame] | 121 | private static final int WINDOW_STATE_ASSISTANT = 3; |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 122 | private static final int WINDOW_STATE_INVALID = -1; |
| 123 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 124 | /** |
| 125 | * The flag for {@link #notifyActivityLaunching} to skip associating a new launch with an active |
| 126 | * transition, in the case the launch is standalone (e.g. from recents). |
| 127 | */ |
| 128 | private static final int IGNORE_CALLER = -1; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 129 | private static final int INVALID_DELAY = -1; |
| 130 | private static final int INVALID_TRANSITION_TYPE = -1; |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 131 | |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 132 | // Preallocated strings we are sending to tron, so we don't have to allocate a new one every |
| 133 | // time we log. |
| 134 | private static final String[] TRON_WINDOW_STATE_VARZ_STRINGS = { |
Winson Chung | 8347163 | 2016-12-13 11:02:12 -0800 | [diff] [blame] | 135 | "window_time_0", "window_time_1", "window_time_2", "window_time_3"}; |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 136 | |
| 137 | private int mWindowState = WINDOW_STATE_STANDARD; |
| 138 | private long mLastLogTimeSecs; |
| 139 | private final ActivityStackSupervisor mSupervisor; |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 140 | private final MetricsLogger mMetricsLogger = new MetricsLogger(); |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 141 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 142 | /** All active transitions. */ |
| 143 | private final ArrayList<TransitionInfo> mTransitionInfoList = new ArrayList<>(); |
| 144 | /** Map : Last launched activity => {@link TransitionInfo} */ |
| 145 | private final ArrayMap<ActivityRecord, TransitionInfo> mLastTransitionInfo = new ArrayMap<>(); |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 146 | |
| 147 | private ArtManagerInternal mArtManagerInternal; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 148 | private final StringBuilder mStringBuilder = new StringBuilder(); |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 149 | |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 150 | /** |
| 151 | * Due to the global single concurrent launch sequence, all calls to this observer must be made |
| 152 | * in-order on the same thread to fulfill the "happens-before" guarantee in LaunchObserver. |
| 153 | */ |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 154 | private final LaunchObserverRegistryImpl mLaunchObserver; |
| 155 | @VisibleForTesting static final int LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE = 512; |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 156 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 157 | /** |
| 158 | * The information created when an intent is incoming but we do not yet know whether it will be |
| 159 | * launched successfully. |
| 160 | */ |
| 161 | static final class LaunchingState { |
| 162 | /** The timestamp of {@link #notifyActivityLaunching}. */ |
| 163 | private long mCurrentTransitionStartTimeNs; |
| 164 | /** Non-null when a {@link TransitionInfo} is created for this state. */ |
| 165 | private TransitionInfo mAssociatedTransitionInfo; |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 166 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 167 | @VisibleForTesting |
| 168 | boolean allDrawn() { |
| 169 | return mAssociatedTransitionInfo != null && mAssociatedTransitionInfo.allDrawn(); |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 170 | } |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 171 | } |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 172 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 173 | /** The information created when an activity is confirmed to be launched. */ |
| 174 | private static final class TransitionInfo { |
| 175 | /** |
| 176 | * The field to lookup and update an existing transition efficiently between |
| 177 | * {@link #notifyActivityLaunching} and {@link #notifyActivityLaunched}. |
| 178 | * |
| 179 | * @see LaunchingState#mAssociatedTransitionInfo |
| 180 | */ |
| 181 | final LaunchingState mLaunchingState; |
| 182 | /** |
| 183 | * The timestamp of the first {@link #notifyActivityLaunching}. It can be used as a key for |
| 184 | * observer to identify which callbacks belong to a launch event. |
| 185 | */ |
| 186 | final long mTransitionStartTimeNs; |
| 187 | /** The device uptime in seconds when this transition info is created. */ |
| 188 | final int mCurrentTransitionDeviceUptime; |
| 189 | /** The type can be cold (new process), warm (new activity), or hot (bring to front). */ |
| 190 | final int mTransitionType; |
| 191 | /** Whether the process was already running when the transition started. */ |
| 192 | final boolean mProcessRunning; |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 193 | /** whether the process of the launching activity didn't have any active activity. */ |
| 194 | final boolean mProcessSwitch; |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 195 | /** The activities that should be drawn. */ |
| 196 | final LinkedList<ActivityRecord> mPendingDrawActivities = new LinkedList<>(); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 197 | /** The latest activity to have been launched. */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 198 | @NonNull ActivityRecord mLastLaunchedActivity; |
| 199 | |
| 200 | /** The time from {@link #mTransitionStartTimeNs} to {@link #notifyTransitionStarting}. */ |
| 201 | int mCurrentTransitionDelayMs; |
| 202 | /** The time from {@link #mTransitionStartTimeNs} to {@link #notifyStartingWindowDrawn}. */ |
| 203 | int mStartingWindowDelayMs = INVALID_DELAY; |
| 204 | /** The time from {@link #mTransitionStartTimeNs} to {@link #notifyBindApplication}. */ |
| 205 | int mBindApplicationDelayMs = INVALID_DELAY; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 206 | /** Elapsed time from when we launch an activity to when its windows are drawn. */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 207 | int mWindowsDrawnDelayMs; |
| 208 | /** The reason why the transition started (see ActivityManagerInternal.APP_TRANSITION_*). */ |
| 209 | int mReason = APP_TRANSITION_TIMEOUT; |
| 210 | /** The flag ensures that {@link #mStartingWindowDelayMs} is only set once. */ |
| 211 | boolean mLoggedStartingWindowDrawn; |
| 212 | /** If the any app transitions have been logged as starting. */ |
| 213 | boolean mLoggedTransitionStarting; |
| 214 | |
Riddle Hsu | c1f8f9c | 2019-10-25 16:54:33 +0800 | [diff] [blame] | 215 | /** Non-null if the application has reported drawn but its window hasn't. */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 216 | @Nullable Runnable mPendingFullyDrawn; |
| 217 | /** Non-null if the trace is active. */ |
| 218 | @Nullable String mLaunchTraceName; |
| 219 | |
| 220 | /** @return Non-null if there will be a window drawn event for the launch. */ |
| 221 | @Nullable |
| 222 | static TransitionInfo create(@NonNull ActivityRecord r, |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 223 | @NonNull LaunchingState launchingState, boolean processRunning, |
| 224 | boolean processSwitch, int startResult) { |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 225 | int transitionType = INVALID_TRANSITION_TYPE; |
| 226 | if (processRunning) { |
| 227 | if (startResult == START_SUCCESS) { |
| 228 | transitionType = TYPE_TRANSITION_WARM_LAUNCH; |
| 229 | } else if (startResult == START_TASK_TO_FRONT) { |
| 230 | transitionType = TYPE_TRANSITION_HOT_LAUNCH; |
| 231 | } |
| 232 | } else if (startResult == START_SUCCESS || startResult == START_TASK_TO_FRONT) { |
| 233 | // Task may still exist when cold launching an activity and the start result will be |
| 234 | // set to START_TASK_TO_FRONT. Treat this as a COLD launch. |
| 235 | transitionType = TYPE_TRANSITION_COLD_LAUNCH; |
| 236 | } |
| 237 | if (transitionType == INVALID_TRANSITION_TYPE) { |
| 238 | // That means the startResult is neither START_SUCCESS nor START_TASK_TO_FRONT. |
| 239 | return null; |
| 240 | } |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 241 | return new TransitionInfo(r, launchingState, transitionType, processRunning, |
| 242 | processSwitch); |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 243 | } |
| 244 | |
| 245 | /** Use {@link TransitionInfo#create} instead to ensure the transition type is valid. */ |
| 246 | private TransitionInfo(ActivityRecord r, LaunchingState launchingState, int transitionType, |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 247 | boolean processRunning, boolean processSwitch) { |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 248 | mLaunchingState = launchingState; |
| 249 | mTransitionStartTimeNs = launchingState.mCurrentTransitionStartTimeNs; |
| 250 | mTransitionType = transitionType; |
| 251 | mProcessRunning = processRunning; |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 252 | mProcessSwitch = processSwitch; |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 253 | mCurrentTransitionDeviceUptime = |
| 254 | (int) TimeUnit.MILLISECONDS.toSeconds(SystemClock.uptimeMillis()); |
| 255 | setLatestLaunchedActivity(r); |
| 256 | launchingState.mAssociatedTransitionInfo = this; |
| 257 | } |
Riddle Hsu | 1c5d72e | 2019-10-09 20:54:26 +0800 | [diff] [blame] | 258 | |
| 259 | /** |
| 260 | * Remembers the latest launched activity to represent the final transition. This also |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 261 | * tracks the activities that should be drawn, so a consecutive launching sequence can be |
| 262 | * coalesced as one event. |
Riddle Hsu | 1c5d72e | 2019-10-09 20:54:26 +0800 | [diff] [blame] | 263 | */ |
| 264 | void setLatestLaunchedActivity(ActivityRecord r) { |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 265 | if (mLastLaunchedActivity == r) { |
Riddle Hsu | 1c5d72e | 2019-10-09 20:54:26 +0800 | [diff] [blame] | 266 | return; |
| 267 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 268 | mLastLaunchedActivity = r; |
| 269 | if (!r.noDisplay) { |
| 270 | if (DEBUG_METRICS) Slog.i(TAG, "Add pending draw " + r); |
| 271 | mPendingDrawActivities.add(r); |
| 272 | } |
| 273 | } |
| 274 | |
| 275 | /** @return {@code true} if the activity matches a launched activity in this transition. */ |
| 276 | boolean contains(ActivityRecord r) { |
| 277 | return r == mLastLaunchedActivity || mPendingDrawActivities.contains(r); |
| 278 | } |
| 279 | |
| 280 | /** Called when the activity is drawn or won't be drawn. */ |
| 281 | void removePendingDrawActivity(ActivityRecord r) { |
| 282 | if (DEBUG_METRICS) Slog.i(TAG, "Remove pending draw " + r); |
| 283 | mPendingDrawActivities.remove(r); |
| 284 | } |
| 285 | |
| 286 | boolean allDrawn() { |
| 287 | return mPendingDrawActivities.isEmpty(); |
| 288 | } |
| 289 | |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 290 | /** |
| 291 | * @return {@code true} if the transition info should be sent to MetricsLogger, StatsLog, or |
| 292 | * LaunchObserver. |
| 293 | */ |
| 294 | boolean isInterestingToLoggerAndObserver() { |
| 295 | return mProcessSwitch; |
| 296 | } |
| 297 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 298 | int calculateCurrentDelay() { |
| 299 | return calculateDelay(SystemClock.elapsedRealtimeNanos()); |
| 300 | } |
| 301 | |
| 302 | int calculateDelay(long timestampNs) { |
| 303 | // Shouldn't take more than 25 days to launch an app, so int is fine here. |
| 304 | return (int) TimeUnit.NANOSECONDS.toMillis(timestampNs - mTransitionStartTimeNs); |
| 305 | } |
| 306 | |
| 307 | @Override |
| 308 | public String toString() { |
| 309 | return "TransitionInfo{" + Integer.toHexString(System.identityHashCode(this)) |
| 310 | + " a=" + mLastLaunchedActivity + " ua=" + mPendingDrawActivities + "}"; |
Riddle Hsu | 1c5d72e | 2019-10-09 20:54:26 +0800 | [diff] [blame] | 311 | } |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 312 | } |
| 313 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 314 | static final class TransitionInfoSnapshot { |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 315 | final private ApplicationInfo applicationInfo; |
Wale Ogunwale | f673393 | 2018-06-27 05:14:34 -0700 | [diff] [blame] | 316 | final private WindowProcessController processRecord; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 317 | final String packageName; |
| 318 | final String launchedActivityName; |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 319 | final private String launchedActivityLaunchedFromPackage; |
| 320 | final private String launchedActivityLaunchToken; |
| 321 | final private String launchedActivityAppRecordRequiredAbi; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 322 | final String launchedActivityShortComponentName; |
Ng Zhi An | 8347354 | 2018-02-20 09:02:14 -0800 | [diff] [blame] | 323 | final private String processName; |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 324 | final private int reason; |
| 325 | final private int startingWindowDelayMs; |
| 326 | final private int bindApplicationDelayMs; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 327 | final int windowsDrawnDelayMs; |
| 328 | final int type; |
| 329 | final int userId; |
| 330 | /** |
| 331 | * Elapsed time from when we launch an activity to when the app reported it was |
| 332 | * fully drawn. If this is not reported then the value is set to INVALID_DELAY. |
| 333 | */ |
| 334 | final int windowsFullyDrawnDelayMs; |
| 335 | final int activityRecordIdHashCode; |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 336 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 337 | private TransitionInfoSnapshot(TransitionInfo info) { |
| 338 | this(info, info.mLastLaunchedActivity, INVALID_DELAY); |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 339 | } |
| 340 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 341 | private TransitionInfoSnapshot(TransitionInfo info, ActivityRecord launchedActivity, |
| 342 | int windowsFullyDrawnDelayMs) { |
Andrii Kulian | eceebbf | 2019-06-26 17:36:51 -0700 | [diff] [blame] | 343 | applicationInfo = launchedActivity.info.applicationInfo; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 344 | packageName = launchedActivity.packageName; |
| 345 | launchedActivityName = launchedActivity.info.name; |
| 346 | launchedActivityLaunchedFromPackage = launchedActivity.launchedFromPackage; |
| 347 | launchedActivityLaunchToken = launchedActivity.info.launchToken; |
| 348 | launchedActivityAppRecordRequiredAbi = launchedActivity.app == null |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 349 | ? null |
Vishnu Nair | af0ea31 | 2018-10-15 16:23:55 -0700 | [diff] [blame] | 350 | : launchedActivity.app.getRequiredAbi(); |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 351 | reason = info.mReason; |
| 352 | startingWindowDelayMs = info.mStartingWindowDelayMs; |
| 353 | bindApplicationDelayMs = info.mBindApplicationDelayMs; |
| 354 | windowsDrawnDelayMs = info.mWindowsDrawnDelayMs; |
| 355 | type = info.mTransitionType; |
| 356 | processRecord = launchedActivity.app; |
Vishnu Nair | af0ea31 | 2018-10-15 16:23:55 -0700 | [diff] [blame] | 357 | processName = launchedActivity.processName; |
Wale Ogunwale | 8b19de9 | 2018-11-29 19:58:26 -0800 | [diff] [blame] | 358 | userId = launchedActivity.mUserId; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 359 | launchedActivityShortComponentName = launchedActivity.shortComponentName; |
| 360 | activityRecordIdHashCode = System.identityHashCode(launchedActivity); |
| 361 | this.windowsFullyDrawnDelayMs = windowsFullyDrawnDelayMs; |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 362 | } |
Vishnu Nair | bb9ab4b | 2018-12-13 10:29:46 -0800 | [diff] [blame] | 363 | |
| 364 | @WaitResult.LaunchState int getLaunchState() { |
| 365 | switch (type) { |
| 366 | case TYPE_TRANSITION_WARM_LAUNCH: |
| 367 | return LAUNCH_STATE_WARM; |
| 368 | case TYPE_TRANSITION_HOT_LAUNCH: |
| 369 | return LAUNCH_STATE_HOT; |
| 370 | case TYPE_TRANSITION_COLD_LAUNCH: |
| 371 | return LAUNCH_STATE_COLD; |
| 372 | default: |
| 373 | return -1; |
| 374 | } |
| 375 | } |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 376 | } |
| 377 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 378 | ActivityMetricsLogger(ActivityStackSupervisor supervisor, Looper looper) { |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 379 | mLastLogTimeSecs = SystemClock.elapsedRealtime() / 1000; |
| 380 | mSupervisor = supervisor; |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 381 | mLaunchObserver = new LaunchObserverRegistryImpl(looper); |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 382 | } |
| 383 | |
| 384 | void logWindowState() { |
| 385 | final long now = SystemClock.elapsedRealtime() / 1000; |
| 386 | if (mWindowState != WINDOW_STATE_INVALID) { |
| 387 | // We log even if the window state hasn't changed, because the user might remain in |
| 388 | // home/fullscreen move forever and we would like to track this kind of behavior |
| 389 | // too. |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 390 | mMetricsLogger.count(TRON_WINDOW_STATE_VARZ_STRINGS[mWindowState], |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 391 | (int) (now - mLastLogTimeSecs)); |
| 392 | } |
| 393 | mLastLogTimeSecs = now; |
| 394 | |
Wale Ogunwale | 926aade | 2017-08-29 11:24:37 -0700 | [diff] [blame] | 395 | mWindowState = WINDOW_STATE_INVALID; |
Wale Ogunwale | d32da47 | 2018-11-16 07:19:28 -0800 | [diff] [blame] | 396 | ActivityStack stack = |
| 397 | mSupervisor.mRootActivityContainer.getTopDisplayFocusedStack(); |
lumark | f6c4a98 | 2018-06-15 15:43:12 +0800 | [diff] [blame] | 398 | if (stack == null) { |
| 399 | return; |
| 400 | } |
| 401 | |
Wale Ogunwale | 926aade | 2017-08-29 11:24:37 -0700 | [diff] [blame] | 402 | if (stack.isActivityTypeAssistant()) { |
| 403 | mWindowState = WINDOW_STATE_ASSISTANT; |
Filip Gruszczynski | caae14e | 2015-12-16 14:40:04 -0800 | [diff] [blame] | 404 | return; |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 405 | } |
Wale Ogunwale | 926aade | 2017-08-29 11:24:37 -0700 | [diff] [blame] | 406 | |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 407 | @WindowingMode int windowingMode = stack.getWindowingMode(); |
Wale Ogunwale | 3382ab1 | 2017-07-27 08:55:03 -0700 | [diff] [blame] | 408 | if (windowingMode == WINDOWING_MODE_PINNED) { |
Wale Ogunwale | d32da47 | 2018-11-16 07:19:28 -0800 | [diff] [blame] | 409 | stack = mSupervisor.mRootActivityContainer.findStackBehind(stack); |
Wale Ogunwale | 3382ab1 | 2017-07-27 08:55:03 -0700 | [diff] [blame] | 410 | windowingMode = stack.getWindowingMode(); |
Filip Gruszczynski | caae14e | 2015-12-16 14:40:04 -0800 | [diff] [blame] | 411 | } |
Wale Ogunwale | 926aade | 2017-08-29 11:24:37 -0700 | [diff] [blame] | 412 | switch (windowingMode) { |
| 413 | case WINDOWING_MODE_FULLSCREEN: |
| 414 | mWindowState = WINDOW_STATE_STANDARD; |
| 415 | break; |
| 416 | case WINDOWING_MODE_SPLIT_SCREEN_PRIMARY: |
| 417 | case WINDOWING_MODE_SPLIT_SCREEN_SECONDARY: |
| 418 | mWindowState = WINDOW_STATE_SIDE_BY_SIDE; |
| 419 | break; |
Bryce Lee | 6c60509 | 2017-10-12 11:14:49 -0700 | [diff] [blame] | 420 | case WINDOWING_MODE_FREEFORM: |
Wale Ogunwale | 926aade | 2017-08-29 11:24:37 -0700 | [diff] [blame] | 421 | mWindowState = WINDOW_STATE_FREEFORM; |
| 422 | break; |
| 423 | default: |
| 424 | if (windowingMode != WINDOWING_MODE_UNDEFINED) { |
| 425 | throw new IllegalStateException("Unknown windowing mode for stack=" + stack |
| 426 | + " windowingMode=" + windowingMode); |
| 427 | } |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 428 | } |
| 429 | } |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 430 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 431 | /** @return Non-null {@link TransitionInfo} if the activity is found in an active transition. */ |
| 432 | @Nullable |
| 433 | private TransitionInfo getActiveTransitionInfo(ActivityRecord r) { |
| 434 | for (int i = mTransitionInfoList.size() - 1; i >= 0; i--) { |
| 435 | final TransitionInfo info = mTransitionInfoList.get(i); |
| 436 | if (info.contains(r)) { |
| 437 | return info; |
| 438 | } |
| 439 | } |
| 440 | return null; |
| 441 | } |
| 442 | |
| 443 | /** |
| 444 | * This method should be only used by starting recents and starting from recents, or internal |
| 445 | * tests. Because it doesn't lookup caller and always creates a new launching state. |
| 446 | * |
| 447 | * @see #notifyActivityLaunching(Intent, ActivityRecord, int) |
| 448 | */ |
| 449 | LaunchingState notifyActivityLaunching(Intent intent) { |
| 450 | return notifyActivityLaunching(intent, null /* caller */, IGNORE_CALLER); |
| 451 | } |
| 452 | |
| 453 | /** |
| 454 | * If the caller is found in an active transition, it will be considered as consecutive launch |
| 455 | * and coalesced into the active transition. |
| 456 | * |
| 457 | * @see #notifyActivityLaunching(Intent, ActivityRecord, int) |
| 458 | */ |
| 459 | LaunchingState notifyActivityLaunching(Intent intent, @Nullable ActivityRecord caller) { |
| 460 | return notifyActivityLaunching(intent, caller, Binder.getCallingUid()); |
| 461 | } |
| 462 | |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 463 | /** |
| 464 | * Notifies the tracker at the earliest possible point when we are starting to launch an |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 465 | * activity. The caller must ensure that {@link #notifyActivityLaunched} will be called later |
| 466 | * with the returned {@link LaunchingState}. |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 467 | */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 468 | private LaunchingState notifyActivityLaunching(Intent intent, @Nullable ActivityRecord caller, |
| 469 | int callingUid) { |
| 470 | final long transitionStartTimeNs = SystemClock.elapsedRealtimeNanos(); |
| 471 | TransitionInfo existingInfo = null; |
| 472 | if (callingUid != IGNORE_CALLER) { |
| 473 | // Associate the launching event to an active transition if the caller is found in its |
| 474 | // launched activities. |
| 475 | for (int i = mTransitionInfoList.size() - 1; i >= 0; i--) { |
| 476 | final TransitionInfo info = mTransitionInfoList.get(i); |
| 477 | if (caller != null && info.contains(caller)) { |
| 478 | existingInfo = info; |
| 479 | break; |
| 480 | } |
| 481 | if (existingInfo == null && callingUid == info.mLastLaunchedActivity.getUid()) { |
| 482 | // Fallback to check the most recent matched uid for the case that the caller is |
| 483 | // not an activity. |
| 484 | existingInfo = info; |
| 485 | } |
| 486 | } |
| 487 | } |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 488 | if (DEBUG_METRICS) { |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 489 | Slog.i(TAG, "notifyActivityLaunching intent=" + intent |
| 490 | + " existingInfo=" + existingInfo); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 491 | } |
| 492 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 493 | if (existingInfo == null) { |
| 494 | // Only notify the observer for a new launching event. |
| 495 | launchObserverNotifyIntentStarted(intent, transitionStartTimeNs); |
| 496 | final LaunchingState launchingState = new LaunchingState(); |
| 497 | launchingState.mCurrentTransitionStartTimeNs = transitionStartTimeNs; |
| 498 | return launchingState; |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 499 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 500 | existingInfo.mLaunchingState.mCurrentTransitionStartTimeNs = transitionStartTimeNs; |
| 501 | return existingInfo.mLaunchingState; |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 502 | } |
| 503 | |
| 504 | /** |
Jorim Jaggi | 1e630c0 | 2016-05-16 12:13:13 -0700 | [diff] [blame] | 505 | * Notifies the tracker that the activity is actually launching. |
| 506 | * |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 507 | * @param launchingState The launching state to track the new or active transition. |
| 508 | * @param resultCode One of the {@link android.app.ActivityManager}.START_* flags, indicating |
| 509 | * the result of the launch. |
| 510 | * @param launchedActivity The activity that is being launched |
Jorim Jaggi | 1e630c0 | 2016-05-16 12:13:13 -0700 | [diff] [blame] | 511 | */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 512 | void notifyActivityLaunched(@NonNull LaunchingState launchingState, int resultCode, |
| 513 | @Nullable ActivityRecord launchedActivity) { |
| 514 | if (launchedActivity == null) { |
| 515 | // The launch is aborted, e.g. intent not resolved, class not found. |
| 516 | abort(null /* info */, "nothing launched"); |
| 517 | return; |
| 518 | } |
Jorim Jaggi | 1e630c0 | 2016-05-16 12:13:13 -0700 | [diff] [blame] | 519 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 520 | final WindowProcessController processRecord = launchedActivity.app != null |
| 521 | ? launchedActivity.app |
| 522 | : mSupervisor.mService.getProcessController( |
| 523 | launchedActivity.processName, launchedActivity.info.applicationInfo.uid); |
| 524 | // Whether the process that will contains the activity is already running. |
| 525 | final boolean processRunning = processRecord != null; |
Jorim Jaggi | 1e630c0 | 2016-05-16 12:13:13 -0700 | [diff] [blame] | 526 | // We consider this a "process switch" if the process of the activity that gets launched |
| 527 | // didn't have an activity that was in started state. In this case, we assume that lot |
| 528 | // of caches might be purged so the time until it produces the first frame is very |
| 529 | // interesting. |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 530 | final boolean processSwitch = !processRunning |
Wale Ogunwale | f673393 | 2018-06-27 05:14:34 -0700 | [diff] [blame] | 531 | || !processRecord.hasStartedActivity(launchedActivity); |
Jorim Jaggi | 1e630c0 | 2016-05-16 12:13:13 -0700 | [diff] [blame] | 532 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 533 | final TransitionInfo info = launchingState.mAssociatedTransitionInfo; |
| 534 | if (DEBUG_METRICS) { |
| 535 | Slog.i(TAG, "notifyActivityLaunched" + " resultCode=" + resultCode |
| 536 | + " launchedActivity=" + launchedActivity + " processRunning=" + processRunning |
| 537 | + " processSwitch=" + processSwitch + " info=" + info); |
Jorim Jaggi | cdfc04e | 2017-04-28 19:06:24 +0200 | [diff] [blame] | 538 | } |
| 539 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 540 | if (launchedActivity.mDrawn) { |
Vishnu Nair | f8accc5 | 2018-10-11 10:19:54 -0700 | [diff] [blame] | 541 | // Launched activity is already visible. We cannot measure windows drawn delay. |
Riddle Hsu | 1063b51 | 2019-10-22 21:12:23 +0800 | [diff] [blame] | 542 | abort(info, "launched activity already visible"); |
Vishnu Nair | f8accc5 | 2018-10-11 10:19:54 -0700 | [diff] [blame] | 543 | return; |
| 544 | } |
| 545 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 546 | if (info != null) { |
Vishnu Nair | f8accc5 | 2018-10-11 10:19:54 -0700 | [diff] [blame] | 547 | // If we are already in an existing transition, only update the activity name, but not |
| 548 | // the other attributes. |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 549 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 550 | if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched update launched activity"); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 551 | // Coalesce multiple (trampoline) activities from a single sequence together. |
Riddle Hsu | 1c5d72e | 2019-10-09 20:54:26 +0800 | [diff] [blame] | 552 | info.setLatestLaunchedActivity(launchedActivity); |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 553 | return; |
| 554 | } |
| 555 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 556 | final TransitionInfo newInfo = TransitionInfo.create(launchedActivity, launchingState, |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 557 | processRunning, processSwitch, resultCode); |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 558 | if (newInfo == null) { |
| 559 | abort(info, "unrecognized launch"); |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 560 | return; |
| 561 | } |
| 562 | |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 563 | if (DEBUG_METRICS) Slog.i(TAG, "notifyActivityLaunched successful"); |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 564 | // A new launch sequence has begun. Start tracking it. |
| 565 | mTransitionInfoList.add(newInfo); |
| 566 | mLastTransitionInfo.put(launchedActivity, newInfo); |
| 567 | startLaunchTrace(newInfo); |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 568 | if (newInfo.isInterestingToLoggerAndObserver()) { |
| 569 | launchObserverNotifyActivityLaunched(newInfo); |
| 570 | } else { |
| 571 | // As abort for no process switch. |
| 572 | launchObserverNotifyIntentFailed(); |
| 573 | } |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 574 | } |
| 575 | |
| 576 | /** |
| 577 | * Notifies the tracker that all windows of the app have been drawn. |
| 578 | */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 579 | @Nullable |
| 580 | TransitionInfoSnapshot notifyWindowsDrawn(@NonNull ActivityRecord r, long timestampNs) { |
| 581 | if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn " + r); |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 582 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 583 | final TransitionInfo info = getActiveTransitionInfo(r); |
| 584 | if (info == null || info.allDrawn()) { |
| 585 | if (DEBUG_METRICS) Slog.i(TAG, "notifyWindowsDrawn no activity to be drawn"); |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 586 | return null; |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 587 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 588 | // Always calculate the delay because the caller may need to know the individual drawn time. |
| 589 | info.mWindowsDrawnDelayMs = info.calculateDelay(timestampNs); |
| 590 | info.removePendingDrawActivity(r); |
| 591 | final TransitionInfoSnapshot infoSnapshot = new TransitionInfoSnapshot(info); |
| 592 | if (info.mLoggedTransitionStarting && info.allDrawn()) { |
| 593 | done(false /* abort */, info, "notifyWindowsDrawn - all windows drawn", timestampNs); |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 594 | } |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 595 | return infoSnapshot; |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 596 | } |
| 597 | |
| 598 | /** |
| 599 | * Notifies the tracker that the starting window was drawn. |
| 600 | */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 601 | void notifyStartingWindowDrawn(@NonNull ActivityRecord r) { |
| 602 | final TransitionInfo info = getActiveTransitionInfo(r); |
| 603 | if (info == null || info.mLoggedStartingWindowDrawn) { |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 604 | return; |
| 605 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 606 | if (DEBUG_METRICS) Slog.i(TAG, "notifyStartingWindowDrawn " + r); |
| 607 | info.mLoggedStartingWindowDrawn = true; |
| 608 | info.mStartingWindowDelayMs = info.calculateDelay(SystemClock.elapsedRealtimeNanos()); |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 609 | } |
| 610 | |
| 611 | /** |
| 612 | * Notifies the tracker that the app transition is starting. |
| 613 | * |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 614 | * @param activityToReason A map from activity to a reason integer, which must be on of |
| 615 | * ActivityTaskManagerInternal.APP_TRANSITION_* reasons. |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 616 | */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 617 | void notifyTransitionStarting(ArrayMap<ActivityRecord, Integer> activityToReason) { |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 618 | if (DEBUG_METRICS) Slog.i(TAG, "notifyTransitionStarting"); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 619 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 620 | final long timestampNs = SystemClock.elapsedRealtimeNanos(); |
| 621 | for (int index = activityToReason.size() - 1; index >= 0; index--) { |
| 622 | final ActivityRecord r = activityToReason.keyAt(index); |
| 623 | final TransitionInfo info = getActiveTransitionInfo(r); |
| 624 | if (info == null || info.mLoggedTransitionStarting) { |
| 625 | // Ignore any subsequent notifyTransitionStarting. |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 626 | continue; |
| 627 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 628 | if (DEBUG_METRICS) { |
| 629 | Slog.i(TAG, "notifyTransitionStarting activity=" + r + " info=" + info); |
| 630 | } |
| 631 | |
| 632 | info.mCurrentTransitionDelayMs = info.calculateDelay(timestampNs); |
| 633 | info.mReason = activityToReason.valueAt(index); |
| 634 | info.mLoggedTransitionStarting = true; |
| 635 | if (info.allDrawn()) { |
| 636 | done(false /* abort */, info, "notifyTransitionStarting - all windows drawn", |
| 637 | timestampNs); |
| 638 | } |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 639 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 640 | } |
| 641 | |
| 642 | /** Makes sure that the reference to the removed activity is cleared. */ |
| 643 | void notifyActivityRemoved(@NonNull ActivityRecord r) { |
| 644 | mLastTransitionInfo.remove(r); |
Jorim Jaggi | 275561a | 2016-02-23 10:11:02 -0500 | [diff] [blame] | 645 | } |
| 646 | |
Jorim Jaggi | cdfc04e | 2017-04-28 19:06:24 +0200 | [diff] [blame] | 647 | /** |
| 648 | * Notifies the tracker that the visibility of an app is changing. |
| 649 | * |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 650 | * @param r the app that is changing its visibility |
Jorim Jaggi | cdfc04e | 2017-04-28 19:06:24 +0200 | [diff] [blame] | 651 | */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 652 | void notifyVisibilityChanged(@NonNull ActivityRecord r) { |
| 653 | final TransitionInfo info = getActiveTransitionInfo(r); |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 654 | if (info == null) { |
| 655 | return; |
| 656 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 657 | if (DEBUG_METRICS) { |
| 658 | Slog.i(TAG, "notifyVisibilityChanged " + r + " visible=" + r.mVisibleRequested |
| 659 | + " state=" + r.getState() + " finishing=" + r.finishing); |
| 660 | } |
| 661 | if (!r.mVisibleRequested || r.finishing) { |
| 662 | info.removePendingDrawActivity(r); |
| 663 | } |
| 664 | if (info.mLastLaunchedActivity != r) { |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 665 | return; |
| 666 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 667 | // The activity and its task are passed separately because the activity may be removed from |
| 668 | // the task later. |
| 669 | r.mAtmService.mH.sendMessage(PooledLambda.obtainMessage( |
| 670 | ActivityMetricsLogger::checkVisibility, this, r.getTask(), r)); |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 671 | } |
Jorim Jaggi | cdfc04e | 2017-04-28 19:06:24 +0200 | [diff] [blame] | 672 | |
Riddle Hsu | 1063b51 | 2019-10-22 21:12:23 +0800 | [diff] [blame] | 673 | /** @return {@code true} if the given task has an activity will be drawn. */ |
Louis Chang | cdec080 | 2019-11-11 11:45:07 +0800 | [diff] [blame] | 674 | private static boolean hasActivityToBeDrawn(Task t) { |
Wale Ogunwale | a38654f | 2019-11-17 20:37:15 -0800 | [diff] [blame] | 675 | return t.forAllActivities((r) -> r.mVisibleRequested && !r.mDrawn && !r.finishing); |
Vishnu Nair | b1de42d | 2019-01-28 09:49:51 -0800 | [diff] [blame] | 676 | } |
| 677 | |
Louis Chang | cdec080 | 2019-11-11 11:45:07 +0800 | [diff] [blame] | 678 | private void checkVisibility(Task t, ActivityRecord r) { |
Wale Ogunwale | c9e57de | 2018-05-08 14:28:07 -0700 | [diff] [blame] | 679 | synchronized (mSupervisor.mService.mGlobalLock) { |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 680 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 681 | final TransitionInfo info = getActiveTransitionInfo(r); |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 682 | |
| 683 | // If we have an active transition that's waiting on a certain activity that will be |
| 684 | // invisible now, we'll never get onWindowsDrawn, so abort the transition if necessary. |
Vishnu Nair | d15063b | 2019-06-11 08:08:25 -0700 | [diff] [blame] | 685 | |
| 686 | // We have no active transitions. |
| 687 | if (info == null) { |
| 688 | return; |
| 689 | } |
| 690 | |
| 691 | // The notified activity whose visibility changed is no longer the launched activity. |
| 692 | // We can still wait to get onWindowsDrawn. |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 693 | if (info.mLastLaunchedActivity != r) { |
Vishnu Nair | d15063b | 2019-06-11 08:08:25 -0700 | [diff] [blame] | 694 | return; |
| 695 | } |
| 696 | |
Riddle Hsu | 1063b51 | 2019-10-22 21:12:23 +0800 | [diff] [blame] | 697 | // If the task of the launched activity contains any activity to be drawn, then the |
| 698 | // window drawn event should report later to complete the transition. Otherwise all |
| 699 | // activities in this task may be finished, invisible or drawn, so the transition event |
| 700 | // should be cancelled. |
| 701 | if (hasActivityToBeDrawn(t)) { |
Vishnu Nair | d15063b | 2019-06-11 08:08:25 -0700 | [diff] [blame] | 702 | return; |
| 703 | } |
| 704 | |
| 705 | if (DEBUG_METRICS) Slog.i(TAG, "notifyVisibilityChanged to invisible activity=" + r); |
| 706 | logAppTransitionCancel(info); |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 707 | abort(info, "notifyVisibilityChanged to invisible"); |
Jorim Jaggi | cdfc04e | 2017-04-28 19:06:24 +0200 | [diff] [blame] | 708 | } |
| 709 | } |
| 710 | |
Jorim Jaggi | 515dd68 | 2017-05-05 15:05:07 +0200 | [diff] [blame] | 711 | /** |
| 712 | * Notifies the tracker that we called immediately before we call bindApplication on the client. |
| 713 | * |
Wale Ogunwale | 31913b5 | 2018-10-13 08:29:31 -0700 | [diff] [blame] | 714 | * @param appInfo The client into which we'll call bindApplication. |
Jorim Jaggi | 515dd68 | 2017-05-05 15:05:07 +0200 | [diff] [blame] | 715 | */ |
Wale Ogunwale | 31913b5 | 2018-10-13 08:29:31 -0700 | [diff] [blame] | 716 | void notifyBindApplication(ApplicationInfo appInfo) { |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 717 | for (int i = mTransitionInfoList.size() - 1; i >= 0; i--) { |
| 718 | final TransitionInfo info = mTransitionInfoList.get(i); |
Jorim Jaggi | 515dd68 | 2017-05-05 15:05:07 +0200 | [diff] [blame] | 719 | |
| 720 | // App isn't attached to record yet, so match with info. |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 721 | if (info.mLastLaunchedActivity.info.applicationInfo == appInfo) { |
| 722 | info.mBindApplicationDelayMs = info.calculateCurrentDelay(); |
Jorim Jaggi | 515dd68 | 2017-05-05 15:05:07 +0200 | [diff] [blame] | 723 | } |
| 724 | } |
| 725 | } |
| 726 | |
Riddle Hsu | 1063b51 | 2019-10-22 21:12:23 +0800 | [diff] [blame] | 727 | /** Aborts tracking of current launch metrics. */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 728 | private void abort(TransitionInfo info, String cause) { |
| 729 | done(true /* abort */, info, cause, 0L /* timestampNs */); |
Riddle Hsu | 1063b51 | 2019-10-22 21:12:23 +0800 | [diff] [blame] | 730 | } |
| 731 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 732 | /** Called when the given transition (info) is no longer active. */ |
| 733 | private void done(boolean abort, @Nullable TransitionInfo info, String cause, |
Riddle Hsu | 1063b51 | 2019-10-22 21:12:23 +0800 | [diff] [blame] | 734 | long timestampNs) { |
Yan Wang | d47f90b | 2019-10-03 19:17:15 -0700 | [diff] [blame] | 735 | if (DEBUG_METRICS) { |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 736 | Slog.i(TAG, "done abort=" + abort + " cause=" + cause + " timestamp=" + timestampNs |
| 737 | + " info=" + info); |
Yan Wang | d47f90b | 2019-10-03 19:17:15 -0700 | [diff] [blame] | 738 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 739 | if (info == null) { |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 740 | launchObserverNotifyIntentFailed(); |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 741 | return; |
| 742 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 743 | |
| 744 | stopLaunchTrace(info); |
| 745 | if (abort) { |
| 746 | launchObserverNotifyActivityLaunchCancelled(info); |
| 747 | } else { |
| 748 | logAppTransitionFinished(info); |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 749 | if (info.isInterestingToLoggerAndObserver()) { |
| 750 | launchObserverNotifyActivityLaunchFinished(info, timestampNs); |
| 751 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 752 | } |
| 753 | info.mPendingDrawActivities.clear(); |
| 754 | mTransitionInfoList.remove(info); |
| 755 | } |
| 756 | |
| 757 | private void logAppTransitionCancel(TransitionInfo info) { |
| 758 | final int type = info.mTransitionType; |
| 759 | final ActivityRecord activity = info.mLastLaunchedActivity; |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 760 | final LogMaker builder = new LogMaker(APP_TRANSITION_CANCELLED); |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 761 | builder.setPackageName(activity.packageName); |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 762 | builder.setType(type); |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 763 | builder.addTaggedData(FIELD_CLASS_NAME, activity.info.name); |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 764 | mMetricsLogger.write(builder); |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 765 | StatsLog.write( |
Chenjie Yu | 5caaa9d | 2018-03-06 15:48:54 -0800 | [diff] [blame] | 766 | StatsLog.APP_START_CANCELED, |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 767 | activity.info.applicationInfo.uid, |
| 768 | activity.packageName, |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 769 | convertAppStartTransitionType(type), |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 770 | activity.info.name); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 771 | if (DEBUG_METRICS) { |
| 772 | Slog.i(TAG, String.format("APP_START_CANCELED(%s, %s, %s, %s)", |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 773 | activity.info.applicationInfo.uid, |
| 774 | activity.packageName, |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 775 | convertAppStartTransitionType(type), |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 776 | activity.info.name)); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 777 | } |
Jorim Jaggi | 172e99f | 2017-10-20 14:33:18 +0200 | [diff] [blame] | 778 | } |
| 779 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 780 | private void logAppTransitionFinished(@NonNull TransitionInfo info) { |
| 781 | if (DEBUG_METRICS) Slog.i(TAG, "logging finished transition " + info); |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 782 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 783 | // Take a snapshot of the transition info before sending it to the handler for logging. |
| 784 | // This will avoid any races with other operations that modify the ActivityRecord. |
| 785 | final TransitionInfoSnapshot infoSnapshot = new TransitionInfoSnapshot(info); |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 786 | if (info.isInterestingToLoggerAndObserver()) { |
| 787 | BackgroundThread.getHandler().post(() -> logAppTransition( |
| 788 | info.mCurrentTransitionDeviceUptime, info.mCurrentTransitionDelayMs, |
| 789 | infoSnapshot)); |
| 790 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 791 | BackgroundThread.getHandler().post(() -> logAppDisplayed(infoSnapshot)); |
| 792 | if (info.mPendingFullyDrawn != null) { |
| 793 | info.mPendingFullyDrawn.run(); |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 794 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 795 | |
| 796 | info.mLastLaunchedActivity.info.launchToken = null; |
Jorim Jaggi | 3878ca3 | 2017-02-02 17:13:05 -0800 | [diff] [blame] | 797 | } |
| 798 | |
Ng Zhi An | 8347354 | 2018-02-20 09:02:14 -0800 | [diff] [blame] | 799 | // This gets called on a background thread without holding the activity manager lock. |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 800 | private void logAppTransition(int currentTransitionDeviceUptime, int currentTransitionDelayMs, |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 801 | TransitionInfoSnapshot info) { |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 802 | final LogMaker builder = new LogMaker(APP_TRANSITION); |
| 803 | builder.setPackageName(info.packageName); |
| 804 | builder.setType(info.type); |
| 805 | builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName); |
| 806 | final boolean isInstantApp = info.applicationInfo.isInstantApp(); |
| 807 | if (info.launchedActivityLaunchedFromPackage != null) { |
| 808 | builder.addTaggedData(APP_TRANSITION_CALLING_PACKAGE_NAME, |
| 809 | info.launchedActivityLaunchedFromPackage); |
| 810 | } |
| 811 | String launchToken = info.launchedActivityLaunchToken; |
| 812 | if (launchToken != null) { |
| 813 | builder.addTaggedData(FIELD_INSTANT_APP_LAUNCH_TOKEN, launchToken); |
| 814 | } |
| 815 | builder.addTaggedData(APP_TRANSITION_IS_EPHEMERAL, isInstantApp ? 1 : 0); |
| 816 | builder.addTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS, |
| 817 | currentTransitionDeviceUptime); |
| 818 | builder.addTaggedData(APP_TRANSITION_DELAY_MS, currentTransitionDelayMs); |
| 819 | builder.setSubtype(info.reason); |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 820 | if (info.startingWindowDelayMs != INVALID_DELAY) { |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 821 | builder.addTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS, |
| 822 | info.startingWindowDelayMs); |
| 823 | } |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 824 | if (info.bindApplicationDelayMs != INVALID_DELAY) { |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 825 | builder.addTaggedData(APP_TRANSITION_BIND_APPLICATION_DELAY_MS, |
| 826 | info.bindApplicationDelayMs); |
| 827 | } |
| 828 | builder.addTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS, info.windowsDrawnDelayMs); |
| 829 | final ArtManagerInternal artManagerInternal = getArtManagerInternal(); |
| 830 | final PackageOptimizationInfo packageOptimizationInfo = |
| 831 | (artManagerInternal == null) || (info.launchedActivityAppRecordRequiredAbi == null) |
| 832 | ? PackageOptimizationInfo.createWithNoInfo() |
| 833 | : artManagerInternal.getPackageOptimizationInfo( |
| 834 | info.applicationInfo, |
| 835 | info.launchedActivityAppRecordRequiredAbi); |
| 836 | builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_REASON, |
| 837 | packageOptimizationInfo.getCompilationReason()); |
| 838 | builder.addTaggedData(PACKAGE_OPTIMIZATION_COMPILATION_FILTER, |
| 839 | packageOptimizationInfo.getCompilationFilter()); |
| 840 | mMetricsLogger.write(builder); |
| 841 | StatsLog.write( |
Chenjie Yu | 5caaa9d | 2018-03-06 15:48:54 -0800 | [diff] [blame] | 842 | StatsLog.APP_START_OCCURRED, |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 843 | info.applicationInfo.uid, |
| 844 | info.packageName, |
| 845 | convertAppStartTransitionType(info.type), |
| 846 | info.launchedActivityName, |
| 847 | info.launchedActivityLaunchedFromPackage, |
| 848 | isInstantApp, |
| 849 | currentTransitionDeviceUptime * 1000, |
| 850 | info.reason, |
| 851 | currentTransitionDelayMs, |
| 852 | info.startingWindowDelayMs, |
| 853 | info.bindApplicationDelayMs, |
| 854 | info.windowsDrawnDelayMs, |
| 855 | launchToken, |
| 856 | packageOptimizationInfo.getCompilationReason(), |
| 857 | packageOptimizationInfo.getCompilationFilter()); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 858 | |
| 859 | if (DEBUG_METRICS) { |
| 860 | Slog.i(TAG, String.format("APP_START_OCCURRED(%s, %s, %s, %s, %s)", |
| 861 | info.applicationInfo.uid, |
| 862 | info.packageName, |
| 863 | convertAppStartTransitionType(info.type), |
| 864 | info.launchedActivityName, |
| 865 | info.launchedActivityLaunchedFromPackage)); |
| 866 | } |
| 867 | |
| 868 | |
Ng Zhi An | 8347354 | 2018-02-20 09:02:14 -0800 | [diff] [blame] | 869 | logAppStartMemoryStateCapture(info); |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 870 | } |
| 871 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 872 | private void logAppDisplayed(TransitionInfoSnapshot info) { |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 873 | if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) { |
| 874 | return; |
| 875 | } |
| 876 | |
Jeff Chang | d136e77 | 2019-11-05 20:33:52 +0800 | [diff] [blame] | 877 | EventLog.writeEvent(WM_ACTIVITY_LAUNCH_TIME, |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 878 | info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName, |
| 879 | info.windowsDrawnDelayMs); |
| 880 | |
| 881 | StringBuilder sb = mStringBuilder; |
| 882 | sb.setLength(0); |
| 883 | sb.append("Displayed "); |
| 884 | sb.append(info.launchedActivityShortComponentName); |
| 885 | sb.append(": "); |
| 886 | TimeUtils.formatDuration(info.windowsDrawnDelayMs, sb); |
| 887 | Log.i(TAG, sb.toString()); |
| 888 | } |
| 889 | |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 890 | private int convertAppStartTransitionType(int tronType) { |
| 891 | if (tronType == TYPE_TRANSITION_COLD_LAUNCH) { |
Chenjie Yu | 5caaa9d | 2018-03-06 15:48:54 -0800 | [diff] [blame] | 892 | return StatsLog.APP_START_OCCURRED__TYPE__COLD; |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 893 | } |
| 894 | if (tronType == TYPE_TRANSITION_WARM_LAUNCH) { |
Chenjie Yu | 5caaa9d | 2018-03-06 15:48:54 -0800 | [diff] [blame] | 895 | return StatsLog.APP_START_OCCURRED__TYPE__WARM; |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 896 | } |
| 897 | if (tronType == TYPE_TRANSITION_HOT_LAUNCH) { |
Chenjie Yu | 5caaa9d | 2018-03-06 15:48:54 -0800 | [diff] [blame] | 898 | return StatsLog.APP_START_OCCURRED__TYPE__HOT; |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 899 | } |
Chenjie Yu | 5caaa9d | 2018-03-06 15:48:54 -0800 | [diff] [blame] | 900 | return StatsLog.APP_START_OCCURRED__TYPE__UNKNOWN; |
Riddle Hsu | c48c891 | 2019-10-31 13:34:27 +0800 | [diff] [blame] | 901 | } |
| 902 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 903 | /** @return the last known window drawn delay of the given activity. */ |
| 904 | int getLastDrawnDelayMs(ActivityRecord r) { |
| 905 | final TransitionInfo info = mLastTransitionInfo.get(r); |
| 906 | return info != null ? info.mWindowsDrawnDelayMs : INVALID_DELAY; |
Riddle Hsu | c48c891 | 2019-10-31 13:34:27 +0800 | [diff] [blame] | 907 | } |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 908 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 909 | /** @see android.app.Activity#reportFullyDrawn */ |
| 910 | TransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r, |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 911 | boolean restoredFromBundle) { |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 912 | final TransitionInfo info = mLastTransitionInfo.get(r); |
Jorim Jaggi | 4d27b84 | 2017-08-17 17:22:26 +0200 | [diff] [blame] | 913 | if (info == null) { |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 914 | return null; |
Jorim Jaggi | 4d27b84 | 2017-08-17 17:22:26 +0200 | [diff] [blame] | 915 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 916 | if (!info.allDrawn() && info.mPendingFullyDrawn == null) { |
Riddle Hsu | c1f8f9c | 2019-10-25 16:54:33 +0800 | [diff] [blame] | 917 | // There are still undrawn activities, postpone reporting fully drawn until all of its |
| 918 | // windows are drawn. So that is closer to an usable state. |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 919 | info.mPendingFullyDrawn = () -> { |
Riddle Hsu | c1f8f9c | 2019-10-25 16:54:33 +0800 | [diff] [blame] | 920 | logAppTransitionReportedDrawn(r, restoredFromBundle); |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 921 | info.mPendingFullyDrawn = null; |
Riddle Hsu | c1f8f9c | 2019-10-25 16:54:33 +0800 | [diff] [blame] | 922 | }; |
| 923 | return null; |
| 924 | } |
Chris Wailes | 35c193c | 2018-10-09 18:12:00 -0700 | [diff] [blame] | 925 | |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 926 | final long currentTimestampNs = SystemClock.elapsedRealtimeNanos(); |
| 927 | final long startupTimeMs = info.mPendingFullyDrawn != null |
| 928 | ? info.mWindowsDrawnDelayMs |
| 929 | : TimeUnit.NANOSECONDS.toMillis(currentTimestampNs - info.mTransitionStartTimeNs); |
| 930 | final TransitionInfoSnapshot infoSnapshot = |
| 931 | new TransitionInfoSnapshot(info, r, (int) startupTimeMs); |
| 932 | BackgroundThread.getHandler().post(() -> logAppFullyDrawn(infoSnapshot)); |
| 933 | |
| 934 | if (!info.isInterestingToLoggerAndObserver()) { |
| 935 | return infoSnapshot; |
| 936 | } |
| 937 | |
Chris Wailes | 35c193c | 2018-10-09 18:12:00 -0700 | [diff] [blame] | 938 | // Record the handling of the reportFullyDrawn callback in the trace system. This is not |
| 939 | // actually used to trace this function, but instead the logical task that this function |
| 940 | // fullfils (handling reportFullyDrawn() callbacks). |
| 941 | Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 942 | "ActivityManager:ReportingFullyDrawn " + info.mLastLaunchedActivity.packageName); |
Chris Wailes | 35c193c | 2018-10-09 18:12:00 -0700 | [diff] [blame] | 943 | |
Jorim Jaggi | 4d27b84 | 2017-08-17 17:22:26 +0200 | [diff] [blame] | 944 | final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN); |
| 945 | builder.setPackageName(r.packageName); |
| 946 | builder.addTaggedData(FIELD_CLASS_NAME, r.info.name); |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 947 | builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs); |
Jorim Jaggi | 4d27b84 | 2017-08-17 17:22:26 +0200 | [diff] [blame] | 948 | builder.setType(restoredFromBundle |
| 949 | ? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE |
| 950 | : TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE); |
| 951 | builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING, |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 952 | info.mProcessRunning ? 1 : 0); |
Jorim Jaggi | 4d27b84 | 2017-08-17 17:22:26 +0200 | [diff] [blame] | 953 | mMetricsLogger.write(builder); |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 954 | StatsLog.write( |
Chenjie Yu | 5caaa9d | 2018-03-06 15:48:54 -0800 | [diff] [blame] | 955 | StatsLog.APP_START_FULLY_DRAWN, |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 956 | info.mLastLaunchedActivity.info.applicationInfo.uid, |
| 957 | info.mLastLaunchedActivity.packageName, |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 958 | restoredFromBundle |
Chenjie Yu | 5caaa9d | 2018-03-06 15:48:54 -0800 | [diff] [blame] | 959 | ? StatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE |
| 960 | : StatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE, |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 961 | info.mLastLaunchedActivity.info.name, |
| 962 | info.mProcessRunning, |
Olivier Gaillard | aed7f12 | 2017-12-12 14:26:22 +0000 | [diff] [blame] | 963 | startupTimeMs); |
Chris Wailes | 35c193c | 2018-10-09 18:12:00 -0700 | [diff] [blame] | 964 | |
| 965 | // Ends the trace started at the beginning of this function. This is located here to allow |
| 966 | // the trace slice to have a noticable duration. |
| 967 | Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); |
| 968 | |
Yan Wang | 9eac5ec | 2019-09-30 15:42:18 -0700 | [diff] [blame] | 969 | // Notify reportFullyDrawn event. |
| 970 | launchObserverNotifyReportFullyDrawn(r, currentTimestampNs); |
| 971 | |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 972 | return infoSnapshot; |
| 973 | } |
| 974 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 975 | private void logAppFullyDrawn(TransitionInfoSnapshot info) { |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 976 | if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) { |
| 977 | return; |
| 978 | } |
| 979 | |
| 980 | StringBuilder sb = mStringBuilder; |
| 981 | sb.setLength(0); |
| 982 | sb.append("Fully drawn "); |
| 983 | sb.append(info.launchedActivityShortComponentName); |
| 984 | sb.append(": "); |
| 985 | TimeUtils.formatDuration(info.windowsFullyDrawnDelayMs, sb); |
| 986 | Log.i(TAG, sb.toString()); |
Jorim Jaggi | 4d27b84 | 2017-08-17 17:22:26 +0200 | [diff] [blame] | 987 | } |
| 988 | |
Michal Karpinski | 4fd5b84 | 2019-01-28 15:13:32 +0000 | [diff] [blame] | 989 | void logAbortedBgActivityStart(Intent intent, WindowProcessController callerApp, |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 990 | int callingUid, String callingPackage, int callingUidProcState, |
| 991 | boolean callingUidHasAnyVisibleWindow, |
| 992 | int realCallingUid, int realCallingUidProcState, |
| 993 | boolean realCallingUidHasAnyVisibleWindow, |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 994 | boolean comingFromPendingIntent) { |
| 995 | |
| 996 | final long nowElapsed = SystemClock.elapsedRealtime(); |
| 997 | final long nowUptime = SystemClock.uptimeMillis(); |
| 998 | final LogMaker builder = new LogMaker(ACTION_ACTIVITY_START); |
| 999 | builder.setTimestamp(System.currentTimeMillis()); |
| 1000 | builder.addTaggedData(FIELD_CALLING_UID, callingUid); |
| 1001 | builder.addTaggedData(FIELD_CALLING_PACKAGE_NAME, callingPackage); |
| 1002 | builder.addTaggedData(FIELD_CALLING_UID_PROC_STATE, |
| 1003 | processStateAmToProto(callingUidProcState)); |
| 1004 | builder.addTaggedData(FIELD_CALLING_UID_HAS_ANY_VISIBLE_WINDOW, |
| 1005 | callingUidHasAnyVisibleWindow ? 1 : 0); |
| 1006 | builder.addTaggedData(FIELD_REAL_CALLING_UID, realCallingUid); |
| 1007 | builder.addTaggedData(FIELD_REAL_CALLING_UID_PROC_STATE, |
| 1008 | processStateAmToProto(realCallingUidProcState)); |
| 1009 | builder.addTaggedData(FIELD_REAL_CALLING_UID_HAS_ANY_VISIBLE_WINDOW, |
| 1010 | realCallingUidHasAnyVisibleWindow ? 1 : 0); |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1011 | builder.addTaggedData(FIELD_COMING_FROM_PENDING_INTENT, comingFromPendingIntent ? 1 : 0); |
Michal Karpinski | 8596ded | 2018-11-14 14:43:48 +0000 | [diff] [blame] | 1012 | if (intent != null) { |
| 1013 | builder.addTaggedData(FIELD_INTENT_ACTION, intent.getAction()); |
Michal Karpinski | 319069b | 2019-03-27 15:46:50 +0000 | [diff] [blame] | 1014 | ComponentName component = intent.getComponent(); |
| 1015 | if (component != null) { |
| 1016 | builder.addTaggedData(FIELD_TARGET_SHORT_COMPONENT_NAME, |
| 1017 | component.flattenToShortString()); |
| 1018 | } |
Michal Karpinski | 8596ded | 2018-11-14 14:43:48 +0000 | [diff] [blame] | 1019 | } |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1020 | if (callerApp != null) { |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1021 | builder.addTaggedData(FIELD_PROCESS_RECORD_PROCESS_NAME, callerApp.mName); |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1022 | builder.addTaggedData(FIELD_PROCESS_RECORD_CUR_PROC_STATE, |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1023 | processStateAmToProto(callerApp.getCurrentProcState())); |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1024 | builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_CLIENT_ACTIVITIES, |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1025 | callerApp.hasClientActivities() ? 1 : 0); |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1026 | builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_SERVICES, |
| 1027 | callerApp.hasForegroundServices() ? 1 : 0); |
| 1028 | builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_FOREGROUND_ACTIVITIES, |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1029 | callerApp.hasForegroundActivities() ? 1 : 0); |
| 1030 | builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_TOP_UI, callerApp.hasTopUi() ? 1 : 0); |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1031 | builder.addTaggedData(FIELD_PROCESS_RECORD_HAS_OVERLAY_UI, |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1032 | callerApp.hasOverlayUi() ? 1 : 0); |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1033 | builder.addTaggedData(FIELD_PROCESS_RECORD_PENDING_UI_CLEAN, |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1034 | callerApp.hasPendingUiClean() ? 1 : 0); |
| 1035 | if (callerApp.getInteractionEventTime() != 0) { |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1036 | builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_LAST_INTERACTION_EVENT, |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1037 | (nowElapsed - callerApp.getInteractionEventTime())); |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1038 | } |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1039 | if (callerApp.getFgInteractionTime() != 0) { |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1040 | builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_FG_INTERACTION, |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1041 | (nowElapsed - callerApp.getFgInteractionTime())); |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1042 | } |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1043 | if (callerApp.getWhenUnimportant() != 0) { |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1044 | builder.addTaggedData(FIELD_PROCESS_RECORD_MILLIS_SINCE_UNIMPORTANT, |
Wale Ogunwale | 342fbe9 | 2018-10-09 08:44:10 -0700 | [diff] [blame] | 1045 | (nowUptime - callerApp.getWhenUnimportant())); |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1046 | } |
| 1047 | } |
Michal Karpinski | 201bc0c | 2018-07-20 15:32:00 +0100 | [diff] [blame] | 1048 | mMetricsLogger.write(builder); |
| 1049 | } |
| 1050 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1051 | private void logAppStartMemoryStateCapture(TransitionInfoSnapshot info) { |
Ng Zhi An | 8347354 | 2018-02-20 09:02:14 -0800 | [diff] [blame] | 1052 | if (info.processRecord == null) { |
Ng Zhi An | bbefdec | 2018-01-30 17:12:39 -0800 | [diff] [blame] | 1053 | if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture processRecord null"); |
| 1054 | return; |
| 1055 | } |
| 1056 | |
Wale Ogunwale | f673393 | 2018-06-27 05:14:34 -0700 | [diff] [blame] | 1057 | final int pid = info.processRecord.getPid(); |
Ng Zhi An | 8347354 | 2018-02-20 09:02:14 -0800 | [diff] [blame] | 1058 | final int uid = info.applicationInfo.uid; |
Rajeev Kumar | bfcd920 | 2018-03-02 22:42:13 +0000 | [diff] [blame] | 1059 | final MemoryStat memoryStat = readMemoryStatFromFilesystem(uid, pid); |
Ng Zhi An | bbefdec | 2018-01-30 17:12:39 -0800 | [diff] [blame] | 1060 | if (memoryStat == null) { |
| 1061 | if (DEBUG_METRICS) Slog.i(TAG, "logAppStartMemoryStateCapture memoryStat null"); |
| 1062 | return; |
| 1063 | } |
| 1064 | |
| 1065 | StatsLog.write( |
| 1066 | StatsLog.APP_START_MEMORY_STATE_CAPTURED, |
| 1067 | uid, |
Ng Zhi An | 8347354 | 2018-02-20 09:02:14 -0800 | [diff] [blame] | 1068 | info.processName, |
| 1069 | info.launchedActivityName, |
Ng Zhi An | bbefdec | 2018-01-30 17:12:39 -0800 | [diff] [blame] | 1070 | memoryStat.pgfault, |
| 1071 | memoryStat.pgmajfault, |
| 1072 | memoryStat.rssInBytes, |
| 1073 | memoryStat.cacheInBytes, |
| 1074 | memoryStat.swapInBytes); |
| 1075 | } |
| 1076 | |
Calin Juravle | 759fbda | 2018-02-20 19:52:30 +0000 | [diff] [blame] | 1077 | private ArtManagerInternal getArtManagerInternal() { |
| 1078 | if (mArtManagerInternal == null) { |
| 1079 | // Note that this may be null. |
| 1080 | // ArtManagerInternal is registered during PackageManagerService |
| 1081 | // initialization which happens after ActivityManagerService. |
| 1082 | mArtManagerInternal = LocalServices.getService(ArtManagerInternal.class); |
| 1083 | } |
| 1084 | return mArtManagerInternal; |
| 1085 | } |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 1086 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1087 | /** Starts trace for an activity is actually launching. */ |
| 1088 | private void startLaunchTrace(@NonNull TransitionInfo info) { |
| 1089 | if (DEBUG_METRICS) Slog.i(TAG, "startLaunchTrace " + info); |
| 1090 | if (!Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) { |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 1091 | return; |
| 1092 | } |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1093 | info.mLaunchTraceName = "launching: " + info.mLastLaunchedActivity.packageName; |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 1094 | Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, info.mLaunchTraceName, |
| 1095 | (int) info.mTransitionStartTimeNs /* cookie */); |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 1096 | } |
| 1097 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1098 | /** Stops trace for the launch is completed or cancelled. */ |
| 1099 | private void stopLaunchTrace(@NonNull TransitionInfo info) { |
| 1100 | if (DEBUG_METRICS) Slog.i(TAG, "stopLaunchTrace " + info); |
| 1101 | if (info.mLaunchTraceName == null) { |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 1102 | return; |
| 1103 | } |
Riddle Hsu | e8d3d19 | 2019-11-26 18:56:39 +0800 | [diff] [blame] | 1104 | Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER, info.mLaunchTraceName, |
| 1105 | (int) info.mTransitionStartTimeNs /* cookie */); |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1106 | info.mLaunchTraceName = null; |
Vishnu Nair | 132ee83 | 2018-09-28 15:00:05 -0700 | [diff] [blame] | 1107 | } |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1108 | |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1109 | public ActivityMetricsLaunchObserverRegistry getLaunchObserverRegistry() { |
| 1110 | return mLaunchObserver; |
| 1111 | } |
| 1112 | |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1113 | /** Notify the {@link ActivityMetricsLaunchObserver} that a new launch sequence has begun. */ |
Yan Wang | d47f90b | 2019-10-03 19:17:15 -0700 | [diff] [blame] | 1114 | private void launchObserverNotifyIntentStarted(Intent intent, long timestampNs) { |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1115 | Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, |
| 1116 | "MetricsLogger:launchObserverNotifyIntentStarted"); |
| 1117 | |
| 1118 | // Beginning a launch is timing sensitive and so should be observed as soon as possible. |
Yan Wang | d47f90b | 2019-10-03 19:17:15 -0700 | [diff] [blame] | 1119 | mLaunchObserver.onIntentStarted(intent, timestampNs); |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1120 | |
| 1121 | Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1122 | } |
| 1123 | |
| 1124 | /** |
| 1125 | * Notify the {@link ActivityMetricsLaunchObserver} that the previous launch sequence has |
| 1126 | * aborted due to intent failure (e.g. intent resolve failed or security error, etc) or |
| 1127 | * intent being delivered to the top running activity. |
| 1128 | */ |
| 1129 | private void launchObserverNotifyIntentFailed() { |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1130 | Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, |
| 1131 | "MetricsLogger:launchObserverNotifyIntentFailed"); |
| 1132 | |
| 1133 | mLaunchObserver.onIntentFailed(); |
| 1134 | |
| 1135 | Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1136 | } |
| 1137 | |
| 1138 | /** |
| 1139 | * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity |
| 1140 | * has started. |
| 1141 | */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1142 | private void launchObserverNotifyActivityLaunched(TransitionInfo info) { |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1143 | Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, |
| 1144 | "MetricsLogger:launchObserverNotifyActivityLaunched"); |
| 1145 | |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1146 | @ActivityMetricsLaunchObserver.Temperature int temperature = |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1147 | convertTransitionTypeToLaunchObserverTemperature(info.mTransitionType); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1148 | |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1149 | // Beginning a launch is timing sensitive and so should be observed as soon as possible. |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1150 | mLaunchObserver.onActivityLaunched(convertActivityRecordToProto(info.mLastLaunchedActivity), |
| 1151 | temperature); |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1152 | |
| 1153 | Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1154 | } |
| 1155 | |
| 1156 | /** |
Yan Wang | 9eac5ec | 2019-09-30 15:42:18 -0700 | [diff] [blame] | 1157 | * Notifies the {@link ActivityMetricsLaunchObserver} the reportFullDrawn event. |
| 1158 | */ |
Yan Wang | d47f90b | 2019-10-03 19:17:15 -0700 | [diff] [blame] | 1159 | private void launchObserverNotifyReportFullyDrawn(ActivityRecord r, long timestampNs) { |
Yan Wang | 9eac5ec | 2019-09-30 15:42:18 -0700 | [diff] [blame] | 1160 | Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, |
| 1161 | "MetricsLogger:launchObserverNotifyReportFullyDrawn"); |
Yan Wang | d47f90b | 2019-10-03 19:17:15 -0700 | [diff] [blame] | 1162 | mLaunchObserver.onReportFullyDrawn(convertActivityRecordToProto(r), timestampNs); |
Yan Wang | 9eac5ec | 2019-09-30 15:42:18 -0700 | [diff] [blame] | 1163 | Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); |
| 1164 | } |
| 1165 | |
| 1166 | /** |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1167 | * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence is |
| 1168 | * cancelled. |
| 1169 | */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1170 | private void launchObserverNotifyActivityLaunchCancelled(TransitionInfo info) { |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1171 | Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, |
| 1172 | "MetricsLogger:launchObserverNotifyActivityLaunchCancelled"); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1173 | |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1174 | final @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] activityRecordProto = |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1175 | info != null ? convertActivityRecordToProto(info.mLastLaunchedActivity) : null; |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1176 | |
| 1177 | mLaunchObserver.onActivityLaunchCancelled(activityRecordProto); |
| 1178 | |
| 1179 | Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1180 | } |
| 1181 | |
| 1182 | /** |
| 1183 | * Notify the {@link ActivityMetricsLaunchObserver} that the current launch sequence's activity |
| 1184 | * has fully finished (successfully). |
| 1185 | */ |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1186 | private void launchObserverNotifyActivityLaunchFinished(TransitionInfo info, long timestampNs) { |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1187 | Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, |
| 1188 | "MetricsLogger:launchObserverNotifyActivityLaunchFinished"); |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1189 | |
Riddle Hsu | fd66d4d | 2019-11-14 10:35:55 +0800 | [diff] [blame] | 1190 | mLaunchObserver.onActivityLaunchFinished( |
| 1191 | convertActivityRecordToProto(info.mLastLaunchedActivity), timestampNs); |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1192 | |
| 1193 | Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); |
| 1194 | } |
| 1195 | |
| 1196 | @VisibleForTesting |
| 1197 | static @ActivityMetricsLaunchObserver.ActivityRecordProto byte[] |
| 1198 | convertActivityRecordToProto(ActivityRecord record) { |
| 1199 | // May take non-negligible amount of time to convert ActivityRecord into a proto, |
| 1200 | // so track the time. |
| 1201 | Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, |
| 1202 | "MetricsLogger:convertActivityRecordToProto"); |
| 1203 | |
| 1204 | // There does not appear to be a way to 'reset' a ProtoOutputBuffer stream, |
| 1205 | // so create a new one every time. |
| 1206 | final ProtoOutputStream protoOutputStream = |
| 1207 | new ProtoOutputStream(LAUNCH_OBSERVER_ACTIVITY_RECORD_PROTO_CHUNK_SIZE); |
| 1208 | // Write this data out as the top-most ActivityRecordProto (i.e. it is not a sub-object). |
Jeffrey Huang | cb78285 | 2019-12-05 11:28:11 -0800 | [diff] [blame] | 1209 | record.dumpDebug(protoOutputStream); |
Igor Murashkin | c0b47e4 | 2018-11-07 15:54:18 -0800 | [diff] [blame] | 1210 | final byte[] bytes = protoOutputStream.getBytes(); |
| 1211 | |
| 1212 | Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER); |
| 1213 | |
| 1214 | return bytes; |
Igor Murashkin | 212d06c | 2018-10-22 16:34:39 -0700 | [diff] [blame] | 1215 | } |
| 1216 | |
| 1217 | private static @ActivityMetricsLaunchObserver.Temperature int |
| 1218 | convertTransitionTypeToLaunchObserverTemperature(int transitionType) { |
| 1219 | switch (transitionType) { |
| 1220 | case TYPE_TRANSITION_WARM_LAUNCH: |
| 1221 | return ActivityMetricsLaunchObserver.TEMPERATURE_WARM; |
| 1222 | case TYPE_TRANSITION_HOT_LAUNCH: |
| 1223 | return ActivityMetricsLaunchObserver.TEMPERATURE_HOT; |
| 1224 | case TYPE_TRANSITION_COLD_LAUNCH: |
| 1225 | return ActivityMetricsLaunchObserver.TEMPERATURE_COLD; |
| 1226 | default: |
| 1227 | return -1; |
| 1228 | } |
| 1229 | } |
Filip Gruszczynski | 77d9448 | 2015-12-11 13:59:52 -0800 | [diff] [blame] | 1230 | } |