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