1 /* 2 * Copyright (C) 2017 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file 5 * except in compliance with the License. You may obtain a copy of the License at 6 * 7 * http://www.apache.org/licenses/LICENSE-2.0 8 * 9 * Unless required by applicable law or agreed to in writing, software distributed under the 10 * License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY 11 * KIND, either express or implied. See the License for the specific language governing 12 * permissions and limitations under the License. 13 */ 14 15 package com.android.internal.util; 16 17 import android.annotation.IntDef; 18 import android.content.Context; 19 import android.os.Build; 20 import android.os.SystemClock; 21 import android.os.Trace; 22 import android.provider.DeviceConfig; 23 import android.util.EventLog; 24 import android.util.Log; 25 import android.util.SparseLongArray; 26 27 import com.android.internal.annotations.GuardedBy; 28 import com.android.internal.logging.EventLogTags; 29 import com.android.internal.os.BackgroundThread; 30 31 import java.lang.annotation.Retention; 32 import java.lang.annotation.RetentionPolicy; 33 import java.util.concurrent.ThreadLocalRandom; 34 35 /** 36 * Class to track various latencies in SystemUI. It then writes the latency to statsd and also 37 * outputs it to logcat so these latencies can be captured by tests and then used for dashboards. 38 * <p> 39 * This is currently only in Keyguard so it can be shared between SystemUI and Keyguard, but 40 * eventually we'd want to merge these two packages together so Keyguard can use common classes 41 * that are shared with SystemUI. 42 */ 43 public class LatencyTracker { 44 private static final String TAG = "LatencyTracker"; 45 private static final String SETTINGS_ENABLED_KEY = "enabled"; 46 private static final String SETTINGS_SAMPLING_INTERVAL_KEY = "sampling_interval"; 47 /** Default to being enabled on debug builds. */ 48 private static final boolean DEFAULT_ENABLED = Build.IS_DEBUGGABLE; 49 /** Default to collecting data for 1/5 of all actions (randomly sampled). */ 50 private static final int DEFAULT_SAMPLING_INTERVAL = 5; 51 52 /** 53 * Time it takes until the first frame of the notification panel to be displayed while expanding 54 */ 55 public static final int ACTION_EXPAND_PANEL = 0; 56 57 /** 58 * Time it takes until the first frame of recents is drawn after invoking it with the button. 59 */ 60 public static final int ACTION_TOGGLE_RECENTS = 1; 61 62 /** 63 * Time between we get a fingerprint acquired signal until we start with the unlock animation 64 */ 65 public static final int ACTION_FINGERPRINT_WAKE_AND_UNLOCK = 2; 66 67 /** 68 * Time it takes to check PIN/Pattern/Password. 69 */ 70 public static final int ACTION_CHECK_CREDENTIAL = 3; 71 72 /** 73 * Time it takes to check fully PIN/Pattern/Password, i.e. that's the time spent including the 74 * actions to unlock a user. 75 */ 76 public static final int ACTION_CHECK_CREDENTIAL_UNLOCKED = 4; 77 78 /** 79 * Time it takes to turn on the screen. 80 */ 81 public static final int ACTION_TURN_ON_SCREEN = 5; 82 83 /** 84 * Time it takes to rotate the screen. 85 */ 86 public static final int ACTION_ROTATE_SCREEN = 6; 87 88 /* 89 * Time between we get a face acquired signal until we start with the unlock animation 90 */ 91 public static final int ACTION_FACE_WAKE_AND_UNLOCK = 7; 92 93 /** 94 * Time between the swipe-up gesture and window drawn of recents activity. 95 */ 96 public static final int ACTION_START_RECENTS_ANIMATION = 8; 97 98 /** 99 * Time it takes the sensor to detect rotation. 100 */ 101 public static final int ACTION_ROTATE_SCREEN_SENSOR = 9; 102 103 /** 104 * Time it takes to for the camera based algorithm to rotate the screen. 105 */ 106 public static final int ACTION_ROTATE_SCREEN_CAMERA_CHECK = 10; 107 108 /** 109 * Time it takes to start unlock animation . 110 */ 111 public static final int ACTION_LOCKSCREEN_UNLOCK = 11; 112 113 private static final int[] ACTIONS_ALL = { 114 ACTION_EXPAND_PANEL, 115 ACTION_TOGGLE_RECENTS, 116 ACTION_FINGERPRINT_WAKE_AND_UNLOCK, 117 ACTION_CHECK_CREDENTIAL, 118 ACTION_CHECK_CREDENTIAL_UNLOCKED, 119 ACTION_TURN_ON_SCREEN, 120 ACTION_ROTATE_SCREEN, 121 ACTION_FACE_WAKE_AND_UNLOCK, 122 ACTION_START_RECENTS_ANIMATION, 123 ACTION_ROTATE_SCREEN_SENSOR, 124 ACTION_ROTATE_SCREEN_CAMERA_CHECK, 125 ACTION_LOCKSCREEN_UNLOCK 126 }; 127 128 /** @hide */ 129 @IntDef({ 130 ACTION_EXPAND_PANEL, 131 ACTION_TOGGLE_RECENTS, 132 ACTION_FINGERPRINT_WAKE_AND_UNLOCK, 133 ACTION_CHECK_CREDENTIAL, 134 ACTION_CHECK_CREDENTIAL_UNLOCKED, 135 ACTION_TURN_ON_SCREEN, 136 ACTION_ROTATE_SCREEN, 137 ACTION_FACE_WAKE_AND_UNLOCK, 138 ACTION_START_RECENTS_ANIMATION, 139 ACTION_ROTATE_SCREEN_SENSOR, 140 ACTION_ROTATE_SCREEN_CAMERA_CHECK, 141 ACTION_LOCKSCREEN_UNLOCK 142 }) 143 @Retention(RetentionPolicy.SOURCE) 144 public @interface Action { 145 } 146 147 private static final int[] STATSD_ACTION = new int[]{ 148 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_EXPAND_PANEL, 149 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_TOGGLE_RECENTS, 150 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_FINGERPRINT_WAKE_AND_UNLOCK, 151 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_CHECK_CREDENTIAL, 152 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_CHECK_CREDENTIAL_UNLOCKED, 153 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_TURN_ON_SCREEN, 154 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN, 155 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_FACE_WAKE_AND_UNLOCK, 156 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_START_RECENTS_ANIMATION, 157 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN_SENSOR, 158 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN_CAMERA_CHECK, 159 FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_LOCKSCREEN_UNLOCK 160 }; 161 162 private static LatencyTracker sLatencyTracker; 163 164 private final Object mLock = new Object(); 165 private final SparseLongArray mStartRtc = new SparseLongArray(); 166 @GuardedBy("mLock") 167 private final int[] mTraceThresholdPerAction = new int[ACTIONS_ALL.length]; 168 @GuardedBy("mLock") 169 private int mSamplingInterval; 170 @GuardedBy("mLock") 171 private boolean mEnabled; 172 getInstance(Context context)173 public static LatencyTracker getInstance(Context context) { 174 if (sLatencyTracker == null) { 175 synchronized (LatencyTracker.class) { 176 if (sLatencyTracker == null) { 177 sLatencyTracker = new LatencyTracker(); 178 } 179 } 180 } 181 return sLatencyTracker; 182 } 183 LatencyTracker()184 private LatencyTracker() { 185 mEnabled = DEFAULT_ENABLED; 186 mSamplingInterval = DEFAULT_SAMPLING_INTERVAL; 187 188 // Post initialization to the background in case we're running on the main thread. 189 BackgroundThread.getHandler().post(() -> this.updateProperties( 190 DeviceConfig.getProperties(DeviceConfig.NAMESPACE_LATENCY_TRACKER))); 191 DeviceConfig.addOnPropertiesChangedListener(DeviceConfig.NAMESPACE_LATENCY_TRACKER, 192 BackgroundThread.getExecutor(), this::updateProperties); 193 } 194 updateProperties(DeviceConfig.Properties properties)195 private void updateProperties(DeviceConfig.Properties properties) { 196 synchronized (mLock) { 197 mSamplingInterval = properties.getInt(SETTINGS_SAMPLING_INTERVAL_KEY, 198 DEFAULT_SAMPLING_INTERVAL); 199 mEnabled = properties.getBoolean(SETTINGS_ENABLED_KEY, DEFAULT_ENABLED); 200 for (int action : ACTIONS_ALL) { 201 mTraceThresholdPerAction[action] = 202 properties.getInt(getNameOfAction(STATSD_ACTION[action]), -1); 203 } 204 } 205 } 206 207 /** 208 * A helper method to translate action type to name. 209 * 210 * @param atomsProtoAction the action type defined in AtomsProto.java 211 * @return the name of the action 212 */ getNameOfAction(int atomsProtoAction)213 public static String getNameOfAction(int atomsProtoAction) { 214 // Defined in AtomsProto.java 215 switch (atomsProtoAction) { 216 case 0: 217 return "UNKNOWN"; 218 case 1: 219 return "ACTION_EXPAND_PANEL"; 220 case 2: 221 return "ACTION_TOGGLE_RECENTS"; 222 case 3: 223 return "ACTION_FINGERPRINT_WAKE_AND_UNLOCK"; 224 case 4: 225 return "ACTION_CHECK_CREDENTIAL"; 226 case 5: 227 return "ACTION_CHECK_CREDENTIAL_UNLOCKED"; 228 case 6: 229 return "ACTION_TURN_ON_SCREEN"; 230 case 7: 231 return "ACTION_ROTATE_SCREEN"; 232 case 8: 233 return "ACTION_FACE_WAKE_AND_UNLOCK"; 234 case 9: 235 return "ACTION_START_RECENTS_ANIMATION"; 236 case 10: 237 return "ACTION_ROTATE_SCREEN_CAMERA_CHECK"; 238 case 11: 239 return "ACTION_ROTATE_SCREEN_SENSOR"; 240 case 12: 241 return "ACTION_LOCKSCREEN_UNLOCK"; 242 default: 243 throw new IllegalArgumentException("Invalid action"); 244 } 245 } 246 getTraceNameOfAction(@ction int action)247 private static String getTraceNameOfAction(@Action int action) { 248 return "L<" + getNameOfAction(STATSD_ACTION[action]) + ">"; 249 } 250 getTraceTriggerNameForAction(@ction int action)251 private static String getTraceTriggerNameForAction(@Action int action) { 252 return "com.android.telemetry.latency-tracker-" + getNameOfAction(STATSD_ACTION[action]); 253 } 254 isEnabled(Context ctx)255 public static boolean isEnabled(Context ctx) { 256 return getInstance(ctx).isEnabled(); 257 } 258 isEnabled()259 public boolean isEnabled() { 260 synchronized (mLock) { 261 return mEnabled; 262 } 263 } 264 265 /** 266 * Notifies that an action is starting. This needs to be called from the main thread. 267 * 268 * @param action The action to start. One of the ACTION_* values. 269 */ onActionStart(@ction int action)270 public void onActionStart(@Action int action) { 271 if (!isEnabled()) { 272 return; 273 } 274 Trace.asyncTraceBegin(Trace.TRACE_TAG_APP, getTraceNameOfAction(action), 0); 275 mStartRtc.put(action, SystemClock.elapsedRealtime()); 276 } 277 278 /** 279 * Notifies that an action has ended. This needs to be called from the main thread. 280 * 281 * @param action The action to end. One of the ACTION_* values. 282 */ onActionEnd(@ction int action)283 public void onActionEnd(@Action int action) { 284 if (!isEnabled()) { 285 return; 286 } 287 long endRtc = SystemClock.elapsedRealtime(); 288 long startRtc = mStartRtc.get(action, -1); 289 if (startRtc == -1) { 290 return; 291 } 292 mStartRtc.delete(action); 293 Trace.asyncTraceEnd(Trace.TRACE_TAG_APP, getTraceNameOfAction(action), 0); 294 logAction(action, (int) (endRtc - startRtc)); 295 } 296 297 /** 298 * Logs an action that has started and ended. This needs to be called from the main thread. 299 * 300 * @param action The action to end. One of the ACTION_* values. 301 * @param duration The duration of the action in ms. 302 */ logAction(@ction int action, int duration)303 public void logAction(@Action int action, int duration) { 304 boolean shouldSample; 305 int traceThreshold; 306 synchronized (mLock) { 307 shouldSample = ThreadLocalRandom.current().nextInt() % mSamplingInterval == 0; 308 traceThreshold = mTraceThresholdPerAction[action]; 309 } 310 311 if (traceThreshold > 0 && duration >= traceThreshold) { 312 PerfettoTrigger.trigger(getTraceTriggerNameForAction(action)); 313 } 314 315 logActionDeprecated(action, duration, shouldSample); 316 } 317 318 /** 319 * Logs an action that has started and ended. This needs to be called from the main thread. 320 * 321 * @param action The action to end. One of the ACTION_* values. 322 * @param duration The duration of the action in ms. 323 * @param writeToStatsLog Whether to write the measured latency to FrameworkStatsLog. 324 */ logActionDeprecated( @ction int action, int duration, boolean writeToStatsLog)325 public static void logActionDeprecated( 326 @Action int action, int duration, boolean writeToStatsLog) { 327 Log.i(TAG, getNameOfAction(STATSD_ACTION[action]) + " latency=" + duration); 328 EventLog.writeEvent(EventLogTags.SYSUI_LATENCY, action, duration); 329 330 if (writeToStatsLog) { 331 FrameworkStatsLog.write( 332 FrameworkStatsLog.UI_ACTION_LATENCY_REPORTED, STATSD_ACTION[action], duration); 333 } 334 } 335 } 336