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 static android.Manifest.permission.READ_DEVICE_CONFIG; 18 import static android.content.pm.PackageManager.PERMISSION_GRANTED; 19 import static android.os.Trace.TRACE_TAG_APP; 20 import static android.provider.DeviceConfig.NAMESPACE_LATENCY_TRACKER; 21 22 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_BACK_SYSTEM_ANIMATION; 23 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_CHECK_CREDENTIAL; 24 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_CHECK_CREDENTIAL_UNLOCKED; 25 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_EXPAND_PANEL; 26 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_FACE_WAKE_AND_UNLOCK; 27 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_FINGERPRINT_WAKE_AND_UNLOCK; 28 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_FOLD_TO_AOD; 29 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE; 30 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE_WITH_SHADE_OPEN; 31 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_KEYGUARD_FPS_UNLOCK_TO_HOME; 32 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_LOAD_SHARE_SHEET; 33 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_LOCKSCREEN_UNLOCK; 34 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_NOTIFICATION_BIG_PICTURE_LOADED; 35 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_REQUEST_IME_HIDDEN; 36 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_REQUEST_IME_SHOWN; 37 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN; 38 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN_CAMERA_CHECK; 39 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN_SENSOR; 40 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_BACK_ARROW; 41 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_SELECTION_TOOLBAR; 42 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_VOICE_INTERACTION; 43 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_SMARTSPACE_DOORBELL; 44 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_START_RECENTS_ANIMATION; 45 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_SWITCH_DISPLAY_UNFOLD; 46 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_TOGGLE_RECENTS; 47 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_TURN_ON_SCREEN; 48 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_UDFPS_ILLUMINATE; 49 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_USER_SWITCH; 50 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__UNKNOWN_ACTION; 51 import static com.android.internal.util.LatencyTracker.ActionProperties.ENABLE_SUFFIX; 52 import static com.android.internal.util.LatencyTracker.ActionProperties.LEGACY_TRACE_THRESHOLD_SUFFIX; 53 import static com.android.internal.util.LatencyTracker.ActionProperties.SAMPLE_INTERVAL_SUFFIX; 54 import static com.android.internal.util.LatencyTracker.ActionProperties.TRACE_THRESHOLD_SUFFIX; 55 56 import android.Manifest; 57 import android.annotation.ElapsedRealtimeLong; 58 import android.annotation.IntDef; 59 import android.annotation.NonNull; 60 import android.annotation.Nullable; 61 import android.annotation.RequiresPermission; 62 import android.app.ActivityThread; 63 import android.content.Context; 64 import android.os.Build; 65 import android.os.SystemClock; 66 import android.os.Trace; 67 import android.provider.DeviceConfig; 68 import android.text.TextUtils; 69 import android.util.EventLog; 70 import android.util.Log; 71 import android.util.SparseArray; 72 73 import com.android.internal.annotations.GuardedBy; 74 import com.android.internal.annotations.VisibleForTesting; 75 import com.android.internal.logging.EventLogTags; 76 import com.android.internal.os.BackgroundThread; 77 78 import java.lang.annotation.Retention; 79 import java.lang.annotation.RetentionPolicy; 80 import java.util.Locale; 81 import java.util.concurrent.ThreadLocalRandom; 82 import java.util.concurrent.TimeUnit; 83 84 /** 85 * Class to track various latencies in SystemUI. It then writes the latency to statsd and also 86 * outputs it to logcat so these latencies can be captured by tests and then used for dashboards. 87 * <p> 88 * This is currently only in Keyguard. It can be shared between SystemUI and Keyguard, but 89 * eventually we'd want to merge these two packages together so Keyguard can use common classes 90 * that are shared with SystemUI. 91 */ 92 public class LatencyTracker { 93 private static final String TAG = "LatencyTracker"; 94 public static final String SETTINGS_ENABLED_KEY = "enabled"; 95 private static final String SETTINGS_SAMPLING_INTERVAL_KEY = "sampling_interval"; 96 private static final boolean DEBUG = false; 97 /** Default to being enabled on debug builds. */ 98 private static final boolean DEFAULT_ENABLED = Build.IS_DEBUGGABLE; 99 /** Default to collecting data for 1/5 of all actions (randomly sampled). */ 100 private static final int DEFAULT_SAMPLING_INTERVAL = 5; 101 102 /** 103 * Time it takes until the first frame of the notification panel to be displayed while expanding 104 */ 105 public static final int ACTION_EXPAND_PANEL = 0; 106 107 /** 108 * Time it takes until the first frame of recents is drawn after invoking it with the button. 109 */ 110 public static final int ACTION_TOGGLE_RECENTS = 1; 111 112 /** 113 * Time between we get a fingerprint acquired signal until we start with the unlock animation 114 */ 115 public static final int ACTION_FINGERPRINT_WAKE_AND_UNLOCK = 2; 116 117 /** 118 * Time it takes to check PIN/Pattern/Password. 119 */ 120 public static final int ACTION_CHECK_CREDENTIAL = 3; 121 122 /** 123 * Time it takes to check fully PIN/Pattern/Password, i.e. that's the time spent including the 124 * actions to unlock a user. 125 */ 126 public static final int ACTION_CHECK_CREDENTIAL_UNLOCKED = 4; 127 128 /** 129 * Time it takes to turn on the screen. 130 */ 131 public static final int ACTION_TURN_ON_SCREEN = 5; 132 133 /** 134 * Time it takes to rotate the screen. 135 */ 136 public static final int ACTION_ROTATE_SCREEN = 6; 137 138 /* 139 * Time between we get a face acquired signal until we start with the unlock animation 140 */ 141 public static final int ACTION_FACE_WAKE_AND_UNLOCK = 7; 142 143 /** 144 * Time between the swipe-up gesture and window drawn of recents activity. 145 */ 146 public static final int ACTION_START_RECENTS_ANIMATION = 8; 147 148 /** 149 * Time it takes to for the camera based algorithm to rotate the screen. 150 */ 151 public static final int ACTION_ROTATE_SCREEN_CAMERA_CHECK = 9; 152 153 /** 154 * Time it takes the sensor to detect rotation. 155 */ 156 public static final int ACTION_ROTATE_SCREEN_SENSOR = 10; 157 158 /** 159 * Time it takes to start unlock animation . 160 */ 161 public static final int ACTION_LOCKSCREEN_UNLOCK = 11; 162 163 /** 164 * Time it takes to switch users. 165 */ 166 public static final int ACTION_USER_SWITCH = 12; 167 168 /** 169 * Time it takes to turn on the inner screen for a foldable device. 170 */ 171 public static final int ACTION_SWITCH_DISPLAY_UNFOLD = 13; 172 173 /** 174 * Time it takes for a UDFPS sensor to appear ready after it is touched. 175 */ 176 public static final int ACTION_UDFPS_ILLUMINATE = 14; 177 178 /** 179 * Time it takes for the gesture back affordance arrow to show up. 180 */ 181 public static final int ACTION_SHOW_BACK_ARROW = 15; 182 183 /** 184 * Time it takes for loading share sheet. 185 */ 186 public static final int ACTION_LOAD_SHARE_SHEET = 16; 187 188 /** 189 * Time it takes for showing the selection toolbar. 190 */ 191 public static final int ACTION_SHOW_SELECTION_TOOLBAR = 17; 192 193 /** 194 * Time it takes to show AOD display after folding the device. 195 */ 196 public static final int ACTION_FOLD_TO_AOD = 18; 197 198 /** 199 * Time it takes to show the {@link android.service.voice.VoiceInteractionSession} system UI 200 * after a {@link android.hardware.soundtrigger3.ISoundTriggerHw} voice trigger. 201 */ 202 public static final int ACTION_SHOW_VOICE_INTERACTION = 19; 203 204 /** 205 * Time it takes to request IME shown animation. 206 */ 207 public static final int ACTION_REQUEST_IME_SHOWN = 20; 208 209 /** 210 * Time it takes to request IME hidden animation. 211 */ 212 public static final int ACTION_REQUEST_IME_HIDDEN = 21; 213 214 /** 215 * Time it takes to load the animation frames in smart space doorbell card. 216 * It measures the duration from the images uris are passed into the view 217 * to all the frames are loaded. 218 * <p/> 219 * A long latency makes the doorbell animation looks janky until all the frames are loaded. 220 */ 221 public static final int ACTION_SMARTSPACE_DOORBELL = 22; 222 223 /** 224 * Time it takes to lazy-load the image of a {@link android.app.Notification.BigPictureStyle} 225 * notification. 226 */ 227 public static final int ACTION_NOTIFICATION_BIG_PICTURE_LOADED = 23; 228 229 /** 230 * Time it takes to unlock the device via udfps, until the whole launcher appears. 231 */ 232 public static final int ACTION_KEYGUARD_FPS_UNLOCK_TO_HOME = 24; 233 234 /** 235 * Time it takes to start back preview surface animation after a back gesture starts. 236 */ 237 public static final int ACTION_BACK_SYSTEM_ANIMATION = 25; 238 239 /** 240 * Time notifications spent in hidden state for performance reasons. We might temporary 241 * hide notifications after display size changes (e.g. fold/unfold of a foldable device) 242 * and measure them while they are hidden to unblock rendering of the rest of the UI. 243 */ 244 public static final int ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE = 26; 245 246 /** 247 * The same as {@link ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE} but tracks time only 248 * when the notifications are hidden and when the shade is open or keyguard is visible. 249 */ 250 public static final int ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE_WITH_SHADE_OPEN = 27; 251 252 private static final int[] ACTIONS_ALL = { 253 ACTION_EXPAND_PANEL, 254 ACTION_TOGGLE_RECENTS, 255 ACTION_FINGERPRINT_WAKE_AND_UNLOCK, 256 ACTION_CHECK_CREDENTIAL, 257 ACTION_CHECK_CREDENTIAL_UNLOCKED, 258 ACTION_TURN_ON_SCREEN, 259 ACTION_ROTATE_SCREEN, 260 ACTION_FACE_WAKE_AND_UNLOCK, 261 ACTION_START_RECENTS_ANIMATION, 262 ACTION_ROTATE_SCREEN_CAMERA_CHECK, 263 ACTION_ROTATE_SCREEN_SENSOR, 264 ACTION_LOCKSCREEN_UNLOCK, 265 ACTION_USER_SWITCH, 266 ACTION_SWITCH_DISPLAY_UNFOLD, 267 ACTION_UDFPS_ILLUMINATE, 268 ACTION_SHOW_BACK_ARROW, 269 ACTION_LOAD_SHARE_SHEET, 270 ACTION_SHOW_SELECTION_TOOLBAR, 271 ACTION_FOLD_TO_AOD, 272 ACTION_SHOW_VOICE_INTERACTION, 273 ACTION_REQUEST_IME_SHOWN, 274 ACTION_REQUEST_IME_HIDDEN, 275 ACTION_SMARTSPACE_DOORBELL, 276 ACTION_NOTIFICATION_BIG_PICTURE_LOADED, 277 ACTION_KEYGUARD_FPS_UNLOCK_TO_HOME, 278 ACTION_BACK_SYSTEM_ANIMATION, 279 ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE, 280 ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE_WITH_SHADE_OPEN, 281 }; 282 283 /** @hide */ 284 @IntDef({ 285 ACTION_EXPAND_PANEL, 286 ACTION_TOGGLE_RECENTS, 287 ACTION_FINGERPRINT_WAKE_AND_UNLOCK, 288 ACTION_CHECK_CREDENTIAL, 289 ACTION_CHECK_CREDENTIAL_UNLOCKED, 290 ACTION_TURN_ON_SCREEN, 291 ACTION_ROTATE_SCREEN, 292 ACTION_FACE_WAKE_AND_UNLOCK, 293 ACTION_START_RECENTS_ANIMATION, 294 ACTION_ROTATE_SCREEN_CAMERA_CHECK, 295 ACTION_ROTATE_SCREEN_SENSOR, 296 ACTION_LOCKSCREEN_UNLOCK, 297 ACTION_USER_SWITCH, 298 ACTION_SWITCH_DISPLAY_UNFOLD, 299 ACTION_UDFPS_ILLUMINATE, 300 ACTION_SHOW_BACK_ARROW, 301 ACTION_LOAD_SHARE_SHEET, 302 ACTION_SHOW_SELECTION_TOOLBAR, 303 ACTION_FOLD_TO_AOD, 304 ACTION_SHOW_VOICE_INTERACTION, 305 ACTION_REQUEST_IME_SHOWN, 306 ACTION_REQUEST_IME_HIDDEN, 307 ACTION_SMARTSPACE_DOORBELL, 308 ACTION_NOTIFICATION_BIG_PICTURE_LOADED, 309 ACTION_KEYGUARD_FPS_UNLOCK_TO_HOME, 310 ACTION_BACK_SYSTEM_ANIMATION, 311 ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE, 312 ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE_WITH_SHADE_OPEN, 313 }) 314 @Retention(RetentionPolicy.SOURCE) 315 public @interface Action { 316 } 317 318 @VisibleForTesting 319 public static final int[] STATSD_ACTION = new int[] { 320 UIACTION_LATENCY_REPORTED__ACTION__ACTION_EXPAND_PANEL, 321 UIACTION_LATENCY_REPORTED__ACTION__ACTION_TOGGLE_RECENTS, 322 UIACTION_LATENCY_REPORTED__ACTION__ACTION_FINGERPRINT_WAKE_AND_UNLOCK, 323 UIACTION_LATENCY_REPORTED__ACTION__ACTION_CHECK_CREDENTIAL, 324 UIACTION_LATENCY_REPORTED__ACTION__ACTION_CHECK_CREDENTIAL_UNLOCKED, 325 UIACTION_LATENCY_REPORTED__ACTION__ACTION_TURN_ON_SCREEN, 326 UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN, 327 UIACTION_LATENCY_REPORTED__ACTION__ACTION_FACE_WAKE_AND_UNLOCK, 328 UIACTION_LATENCY_REPORTED__ACTION__ACTION_START_RECENTS_ANIMATION, 329 UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN_CAMERA_CHECK, 330 UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN_SENSOR, 331 UIACTION_LATENCY_REPORTED__ACTION__ACTION_LOCKSCREEN_UNLOCK, 332 UIACTION_LATENCY_REPORTED__ACTION__ACTION_USER_SWITCH, 333 UIACTION_LATENCY_REPORTED__ACTION__ACTION_SWITCH_DISPLAY_UNFOLD, 334 UIACTION_LATENCY_REPORTED__ACTION__ACTION_UDFPS_ILLUMINATE, 335 UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_BACK_ARROW, 336 UIACTION_LATENCY_REPORTED__ACTION__ACTION_LOAD_SHARE_SHEET, 337 UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_SELECTION_TOOLBAR, 338 UIACTION_LATENCY_REPORTED__ACTION__ACTION_FOLD_TO_AOD, 339 UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_VOICE_INTERACTION, 340 UIACTION_LATENCY_REPORTED__ACTION__ACTION_REQUEST_IME_SHOWN, 341 UIACTION_LATENCY_REPORTED__ACTION__ACTION_REQUEST_IME_HIDDEN, 342 UIACTION_LATENCY_REPORTED__ACTION__ACTION_SMARTSPACE_DOORBELL, 343 UIACTION_LATENCY_REPORTED__ACTION__ACTION_NOTIFICATION_BIG_PICTURE_LOADED, 344 UIACTION_LATENCY_REPORTED__ACTION__ACTION_KEYGUARD_FPS_UNLOCK_TO_HOME, 345 UIACTION_LATENCY_REPORTED__ACTION__ACTION_BACK_SYSTEM_ANIMATION, 346 UIACTION_LATENCY_REPORTED__ACTION__ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE, 347 UIACTION_LATENCY_REPORTED__ACTION__ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE_WITH_SHADE_OPEN, 348 }; 349 350 private final Object mLock = new Object(); 351 @GuardedBy("mLock") 352 private final SparseArray<Session> mSessions = new SparseArray<>(); 353 @GuardedBy("mLock") 354 private final SparseArray<ActionProperties> mActionPropertiesMap = new SparseArray<>(); 355 @GuardedBy("mLock") 356 private boolean mEnabled; 357 private final DeviceConfig.OnPropertiesChangedListener mOnPropertiesChangedListener = 358 this::updateProperties; 359 360 // Wrapping this in a holder class achieves lazy loading behavior 361 private static final class SLatencyTrackerHolder { 362 private static final LatencyTracker sLatencyTracker; 363 364 static { 365 sLatencyTracker = new LatencyTracker(); sLatencyTracker.startListeningForLatencyTrackerConfigChanges()366 sLatencyTracker.startListeningForLatencyTrackerConfigChanges(); 367 } 368 } 369 getInstance(Context context)370 public static LatencyTracker getInstance(Context context) { 371 return SLatencyTrackerHolder.sLatencyTracker; 372 } 373 374 /** 375 * Constructor for LatencyTracker 376 * 377 * <p>This constructor is only visible for test classes to inject their own consumer callbacks 378 * 379 * @param startListeningForPropertyChanges If set, constructor will register for device config 380 * property updates prior to returning. If not set, 381 * {@link #startListeningForLatencyTrackerConfigChanges} must be called 382 * to start listening. 383 */ 384 @RequiresPermission(Manifest.permission.READ_DEVICE_CONFIG) 385 @VisibleForTesting LatencyTracker()386 public LatencyTracker() { 387 mEnabled = DEFAULT_ENABLED; 388 } 389 updateProperties(DeviceConfig.Properties properties)390 private void updateProperties(DeviceConfig.Properties properties) { 391 synchronized (mLock) { 392 int samplingInterval = properties.getInt(SETTINGS_SAMPLING_INTERVAL_KEY, 393 DEFAULT_SAMPLING_INTERVAL); 394 boolean wasEnabled = mEnabled; 395 mEnabled = properties.getBoolean(SETTINGS_ENABLED_KEY, DEFAULT_ENABLED); 396 if (wasEnabled != mEnabled) { 397 Log.d(TAG, "Latency tracker " + (mEnabled ? "enabled" : "disabled") + "."); 398 } 399 for (int action : ACTIONS_ALL) { 400 String actionName = getNameOfAction(STATSD_ACTION[action]).toLowerCase(Locale.ROOT); 401 int legacyActionTraceThreshold = properties.getInt( 402 actionName + LEGACY_TRACE_THRESHOLD_SUFFIX, -1); 403 mActionPropertiesMap.put(action, new ActionProperties(action, 404 properties.getBoolean(actionName + ENABLE_SUFFIX, mEnabled), 405 properties.getInt(actionName + SAMPLE_INTERVAL_SUFFIX, samplingInterval), 406 properties.getInt(actionName + TRACE_THRESHOLD_SUFFIX, 407 legacyActionTraceThreshold))); 408 } 409 onDeviceConfigPropertiesUpdated(mActionPropertiesMap); 410 } 411 } 412 413 /** 414 * Test method to start listening to {@link DeviceConfig} properties changes. 415 * 416 * <p>During testing, a {@link LatencyTracker} it is desired to stop and start listening for 417 * config updates. 418 * 419 * <p>This is not used for production usages of this class outside of testing as we are 420 * using a single static object. 421 */ 422 @VisibleForTesting 423 @RequiresPermission(Manifest.permission.READ_DEVICE_CONFIG) startListeningForLatencyTrackerConfigChanges()424 public void startListeningForLatencyTrackerConfigChanges() { 425 final Context context = ActivityThread.currentApplication(); 426 if (context == null) { 427 if (DEBUG) { 428 Log.d(TAG, "No application for package: " + ActivityThread.currentPackageName()); 429 } 430 return; 431 } 432 if (context.checkCallingOrSelfPermission(READ_DEVICE_CONFIG) != PERMISSION_GRANTED) { 433 if (DEBUG) { 434 synchronized (mLock) { 435 Log.d(TAG, "Initialized the LatencyTracker." 436 + " (No READ_DEVICE_CONFIG permission to change configs)" 437 + " enabled=" + mEnabled + ", package=" + context.getPackageName()); 438 } 439 } 440 return; 441 } 442 443 // Post initialization to the background in case we're running on the main thread. 444 BackgroundThread.getHandler().post(() -> { 445 try { 446 this.updateProperties( 447 DeviceConfig.getProperties(NAMESPACE_LATENCY_TRACKER)); 448 DeviceConfig.addOnPropertiesChangedListener(NAMESPACE_LATENCY_TRACKER, 449 BackgroundThread.getExecutor(), mOnPropertiesChangedListener); 450 } catch (SecurityException ex) { 451 // In case of running tests that the main thread passes the check, 452 // but the background thread doesn't have necessary permissions. 453 // Swallow it since it's ok to ignore device config changes in the tests. 454 Log.d(TAG, "Can't get properties: READ_DEVICE_CONFIG granted=" 455 + context.checkCallingOrSelfPermission(READ_DEVICE_CONFIG) 456 + ", package=" + context.getPackageName()); 457 } 458 }); 459 } 460 461 /** 462 * Test method to stop listening to {@link DeviceConfig} properties changes. 463 * 464 * <p>During testing, a {@link LatencyTracker} it is desired to stop and start listening for 465 * config updates. 466 * 467 * <p>This is not used for production usages of this class outside of testing as we are 468 * using a single static object. 469 */ 470 @VisibleForTesting stopListeningForLatencyTrackerConfigChanges()471 public void stopListeningForLatencyTrackerConfigChanges() { 472 DeviceConfig.removeOnPropertiesChangedListener(mOnPropertiesChangedListener); 473 } 474 475 /** 476 * A helper method to translate action type to name. 477 * 478 * @param atomsProtoAction the action type defined in AtomsProto.java 479 * @return the name of the action 480 */ getNameOfAction(int atomsProtoAction)481 public static String getNameOfAction(int atomsProtoAction) { 482 // Defined in AtomsProto.java 483 switch (atomsProtoAction) { 484 case UIACTION_LATENCY_REPORTED__ACTION__UNKNOWN_ACTION: 485 return "UNKNOWN"; 486 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_EXPAND_PANEL: 487 return "ACTION_EXPAND_PANEL"; 488 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_TOGGLE_RECENTS: 489 return "ACTION_TOGGLE_RECENTS"; 490 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_FINGERPRINT_WAKE_AND_UNLOCK: 491 return "ACTION_FINGERPRINT_WAKE_AND_UNLOCK"; 492 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_CHECK_CREDENTIAL: 493 return "ACTION_CHECK_CREDENTIAL"; 494 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_CHECK_CREDENTIAL_UNLOCKED: 495 return "ACTION_CHECK_CREDENTIAL_UNLOCKED"; 496 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_TURN_ON_SCREEN: 497 return "ACTION_TURN_ON_SCREEN"; 498 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN: 499 return "ACTION_ROTATE_SCREEN"; 500 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_FACE_WAKE_AND_UNLOCK: 501 return "ACTION_FACE_WAKE_AND_UNLOCK"; 502 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_START_RECENTS_ANIMATION: 503 return "ACTION_START_RECENTS_ANIMATION"; 504 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN_CAMERA_CHECK: 505 return "ACTION_ROTATE_SCREEN_CAMERA_CHECK"; 506 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN_SENSOR: 507 return "ACTION_ROTATE_SCREEN_SENSOR"; 508 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_LOCKSCREEN_UNLOCK: 509 return "ACTION_LOCKSCREEN_UNLOCK"; 510 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_USER_SWITCH: 511 return "ACTION_USER_SWITCH"; 512 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_SWITCH_DISPLAY_UNFOLD: 513 return "ACTION_SWITCH_DISPLAY_UNFOLD"; 514 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_UDFPS_ILLUMINATE: 515 return "ACTION_UDFPS_ILLUMINATE"; 516 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_BACK_ARROW: 517 return "ACTION_SHOW_BACK_ARROW"; 518 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_LOAD_SHARE_SHEET: 519 return "ACTION_LOAD_SHARE_SHEET"; 520 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_SELECTION_TOOLBAR: 521 return "ACTION_SHOW_SELECTION_TOOLBAR"; 522 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_FOLD_TO_AOD: 523 return "ACTION_FOLD_TO_AOD"; 524 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_VOICE_INTERACTION: 525 return "ACTION_SHOW_VOICE_INTERACTION"; 526 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_REQUEST_IME_SHOWN: 527 return "ACTION_REQUEST_IME_SHOWN"; 528 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_REQUEST_IME_HIDDEN: 529 return "ACTION_REQUEST_IME_HIDDEN"; 530 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_SMARTSPACE_DOORBELL: 531 return "ACTION_SMARTSPACE_DOORBELL"; 532 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_NOTIFICATION_BIG_PICTURE_LOADED: 533 return "ACTION_NOTIFICATION_BIG_PICTURE_LOADED"; 534 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_KEYGUARD_FPS_UNLOCK_TO_HOME: 535 return "ACTION_KEYGUARD_FPS_UNLOCK_TO_HOME"; 536 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_BACK_SYSTEM_ANIMATION: 537 return "ACTION_BACK_SYSTEM_ANIMATION"; 538 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE: 539 return "ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE"; 540 case UIACTION_LATENCY_REPORTED__ACTION__ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE_WITH_SHADE_OPEN: 541 return "ACTION_NOTIFICATIONS_HIDDEN_FOR_MEASURE_WITH_SHADE_OPEN"; 542 default: 543 throw new IllegalArgumentException("Invalid action"); 544 } 545 } 546 getTraceNameOfAction(@ction int action, String tag)547 private static String getTraceNameOfAction(@Action int action, String tag) { 548 if (TextUtils.isEmpty(tag)) { 549 return "L<" + getNameOfAction(STATSD_ACTION[action]) + ">"; 550 } else { 551 return "L<" + getNameOfAction(STATSD_ACTION[action]) + "::" + tag + ">"; 552 } 553 } 554 getTraceTriggerNameForAction(@ction int action)555 private static String getTraceTriggerNameForAction(@Action int action) { 556 return "com.android.telemetry.latency-tracker-" + getNameOfAction(STATSD_ACTION[action]); 557 } 558 559 /** 560 * @deprecated Use {@link #isEnabled(Context, int)} 561 */ 562 @Deprecated isEnabled(Context ctx)563 public static boolean isEnabled(Context ctx) { 564 return getInstance(ctx).isEnabled(); 565 } 566 567 /** 568 * @deprecated Used {@link #isEnabled(int)} 569 */ 570 @Deprecated isEnabled()571 public boolean isEnabled() { 572 synchronized (mLock) { 573 return mEnabled; 574 } 575 } 576 isEnabled(Context ctx, int action)577 public static boolean isEnabled(Context ctx, int action) { 578 return getInstance(ctx).isEnabled(action); 579 } 580 isEnabled(int action)581 public boolean isEnabled(int action) { 582 synchronized (mLock) { 583 ActionProperties actionProperties = mActionPropertiesMap.get(action); 584 if (actionProperties != null) { 585 return actionProperties.isEnabled(); 586 } 587 return false; 588 } 589 } 590 591 /** 592 * Notifies that an action is starting. <s>This needs to be called from the main thread.</s> 593 * 594 * @param action The action to start. One of the ACTION_* values. 595 */ onActionStart(@ction int action)596 public void onActionStart(@Action int action) { 597 onActionStart(action, null); 598 } 599 600 /** 601 * Notifies that an action is starting. <s>This needs to be called from the main thread.</s> 602 * 603 * @param action The action to start. One of the ACTION_* values. 604 * @param tag The brief description of the action. 605 */ onActionStart(@ction int action, String tag)606 public void onActionStart(@Action int action, String tag) { 607 synchronized (mLock) { 608 if (!isEnabled(action)) { 609 return; 610 } 611 // skip if the action is already instrumenting. 612 if (mSessions.get(action) != null) { 613 return; 614 } 615 Session session = new Session(action, tag); 616 session.begin(() -> onActionCancel(action)); 617 mSessions.put(action, session); 618 619 if (DEBUG) { 620 Log.d(TAG, "onActionStart: " + session.name() + ", start=" + session.mStartRtc); 621 } 622 } 623 } 624 625 /** 626 * Notifies that an action has ended. <s>This needs to be called from the main thread.</s> 627 * 628 * @param action The action to end. One of the ACTION_* values. 629 */ onActionEnd(@ction int action)630 public void onActionEnd(@Action int action) { 631 synchronized (mLock) { 632 if (!isEnabled(action)) { 633 return; 634 } 635 Session session = mSessions.get(action); 636 if (session == null) { 637 return; 638 } 639 session.end(); 640 mSessions.delete(action); 641 logAction(action, session.duration()); 642 643 if (DEBUG) { 644 Log.d(TAG, "onActionEnd:" + session.name() + ", duration=" + session.duration()); 645 } 646 } 647 } 648 649 /** 650 * Notifies that an action has canceled. <s>This needs to be called from the main thread.</s> 651 * 652 * @param action The action to cancel. One of the ACTION_* values. 653 * @hide 654 */ onActionCancel(@ction int action)655 public void onActionCancel(@Action int action) { 656 synchronized (mLock) { 657 Session session = mSessions.get(action); 658 if (session == null) { 659 return; 660 } 661 session.cancel(); 662 mSessions.delete(action); 663 664 if (DEBUG) { 665 Log.d(TAG, "onActionCancel: " + session.name()); 666 } 667 } 668 } 669 670 /** 671 * Testing API to get the time when a given action was started. 672 * 673 * @param action Action which to retrieve start time from 674 * @return Elapsed realtime timestamp when the action started. -1 if the action is not active. 675 * @hide 676 */ 677 @VisibleForTesting 678 @ElapsedRealtimeLong getActiveActionStartTime(@ction int action)679 public long getActiveActionStartTime(@Action int action) { 680 synchronized (mLock) { 681 if (mSessions.contains(action)) { 682 return mSessions.get(action).mStartRtc; 683 } 684 return -1; 685 } 686 } 687 688 /** 689 * Logs an action that has started and ended. This needs to be called from the main thread. 690 * 691 * @param action The action to end. One of the ACTION_* values. 692 * @param duration The duration of the action in ms. 693 */ logAction(@ction int action, int duration)694 public void logAction(@Action int action, int duration) { 695 boolean shouldSample; 696 int traceThreshold; 697 synchronized (mLock) { 698 if (!isEnabled(action)) { 699 return; 700 } 701 ActionProperties actionProperties = mActionPropertiesMap.get(action); 702 if (actionProperties == null) { 703 return; 704 } 705 int nextRandNum = ThreadLocalRandom.current().nextInt( 706 actionProperties.getSamplingInterval()); 707 shouldSample = nextRandNum == 0; 708 traceThreshold = actionProperties.getTraceThreshold(); 709 } 710 711 boolean shouldTriggerPerfettoTrace = traceThreshold > 0 && duration >= traceThreshold; 712 713 if (DEBUG) { 714 Log.i(TAG, "logAction: " + getNameOfAction(STATSD_ACTION[action]) 715 + " duration=" + duration 716 + " shouldSample=" + shouldSample 717 + " shouldTriggerPerfettoTrace=" + shouldTriggerPerfettoTrace); 718 } 719 720 EventLog.writeEvent(EventLogTags.SYSUI_LATENCY, action, duration); 721 if (shouldTriggerPerfettoTrace) { 722 onTriggerPerfetto(getTraceTriggerNameForAction(action)); 723 } 724 if (shouldSample) { 725 onLogToFrameworkStats( 726 new FrameworkStatsLogEvent(action, FrameworkStatsLog.UI_ACTION_LATENCY_REPORTED, 727 STATSD_ACTION[action], duration) 728 ); 729 } 730 } 731 732 static class Session { 733 @Action 734 private final int mAction; 735 private final String mTag; 736 private final String mName; 737 private Runnable mTimeoutRunnable; 738 private long mStartRtc = -1; 739 private long mEndRtc = -1; 740 Session(@ction int action, @Nullable String tag)741 Session(@Action int action, @Nullable String tag) { 742 mAction = action; 743 mTag = tag; 744 mName = TextUtils.isEmpty(mTag) 745 ? getNameOfAction(STATSD_ACTION[mAction]) 746 : getNameOfAction(STATSD_ACTION[mAction]) + "::" + mTag; 747 } 748 name()749 String name() { 750 return mName; 751 } 752 traceName()753 String traceName() { 754 return getTraceNameOfAction(mAction, mTag); 755 } 756 begin(@onNull Runnable timeoutAction)757 void begin(@NonNull Runnable timeoutAction) { 758 mStartRtc = SystemClock.elapsedRealtime(); 759 Trace.asyncTraceForTrackBegin(TRACE_TAG_APP, traceName(), traceName(), 0); 760 761 // start counting timeout. 762 mTimeoutRunnable = () -> { 763 Trace.instantForTrack(TRACE_TAG_APP, traceName(), "timeout"); 764 timeoutAction.run(); 765 }; 766 BackgroundThread.getHandler() 767 .postDelayed(mTimeoutRunnable, TimeUnit.SECONDS.toMillis(15)); 768 } 769 end()770 void end() { 771 mEndRtc = SystemClock.elapsedRealtime(); 772 Trace.asyncTraceForTrackEnd(TRACE_TAG_APP, traceName(), 0); 773 BackgroundThread.getHandler().removeCallbacks(mTimeoutRunnable); 774 mTimeoutRunnable = null; 775 } 776 cancel()777 void cancel() { 778 Trace.instantForTrack(TRACE_TAG_APP, traceName(), "cancel"); 779 Trace.asyncTraceForTrackEnd(TRACE_TAG_APP, traceName(), 0); 780 BackgroundThread.getHandler().removeCallbacks(mTimeoutRunnable); 781 mTimeoutRunnable = null; 782 } 783 duration()784 int duration() { 785 return (int) (mEndRtc - mStartRtc); 786 } 787 } 788 789 @VisibleForTesting 790 public static class ActionProperties { 791 static final String ENABLE_SUFFIX = "_enable"; 792 static final String SAMPLE_INTERVAL_SUFFIX = "_sample_interval"; 793 // TODO: migrate all usages of the legacy trace threshold property 794 static final String LEGACY_TRACE_THRESHOLD_SUFFIX = ""; 795 static final String TRACE_THRESHOLD_SUFFIX = "_trace_threshold"; 796 797 @Action 798 private final int mAction; 799 private final boolean mEnabled; 800 private final int mSamplingInterval; 801 private final int mTraceThreshold; 802 803 @VisibleForTesting ActionProperties( @ction int action, boolean enabled, int samplingInterval, int traceThreshold)804 public ActionProperties( 805 @Action int action, 806 boolean enabled, 807 int samplingInterval, 808 int traceThreshold) { 809 this.mAction = action; 810 com.android.internal.util.AnnotationValidations.validate( 811 Action.class, null, mAction); 812 this.mEnabled = enabled; 813 this.mSamplingInterval = samplingInterval; 814 this.mTraceThreshold = traceThreshold; 815 } 816 817 @VisibleForTesting 818 @Action getAction()819 public int getAction() { 820 return mAction; 821 } 822 823 @VisibleForTesting isEnabled()824 public boolean isEnabled() { 825 return mEnabled; 826 } 827 828 @VisibleForTesting getSamplingInterval()829 public int getSamplingInterval() { 830 return mSamplingInterval; 831 } 832 833 @VisibleForTesting getTraceThreshold()834 public int getTraceThreshold() { 835 return mTraceThreshold; 836 } 837 838 @Override toString()839 public String toString() { 840 return "ActionProperties{" 841 + " mAction=" + mAction 842 + ", mEnabled=" + mEnabled 843 + ", mSamplingInterval=" + mSamplingInterval 844 + ", mTraceThreshold=" + mTraceThreshold 845 + "}"; 846 } 847 848 @Override equals(@ullable Object o)849 public boolean equals(@Nullable Object o) { 850 if (this == o) { 851 return true; 852 } 853 if (o == null) { 854 return false; 855 } 856 if (!(o instanceof ActionProperties)) { 857 return false; 858 } 859 ActionProperties that = (ActionProperties) o; 860 return mAction == that.mAction 861 && mEnabled == that.mEnabled 862 && mSamplingInterval == that.mSamplingInterval 863 && mTraceThreshold == that.mTraceThreshold; 864 } 865 866 @Override hashCode()867 public int hashCode() { 868 int _hash = 1; 869 _hash = 31 * _hash + mAction; 870 _hash = 31 * _hash + Boolean.hashCode(mEnabled); 871 _hash = 31 * _hash + mSamplingInterval; 872 _hash = 31 * _hash + mTraceThreshold; 873 return _hash; 874 } 875 } 876 877 /** 878 * Testing method intended to be overridden to determine when the LatencyTracker's device 879 * properties are updated. 880 */ 881 @VisibleForTesting onDeviceConfigPropertiesUpdated(SparseArray<ActionProperties> actionProperties)882 public void onDeviceConfigPropertiesUpdated(SparseArray<ActionProperties> actionProperties) { 883 if (DEBUG) { 884 Log.d(TAG, "onDeviceConfigPropertiesUpdated: " + actionProperties); 885 } 886 } 887 888 /** 889 * Testing class intended to be overridden to determine when LatencyTracker triggers perfetto. 890 */ 891 @VisibleForTesting onTriggerPerfetto(String triggerName)892 public void onTriggerPerfetto(String triggerName) { 893 if (DEBUG) { 894 Log.i(TAG, "onTriggerPerfetto: triggerName=" + triggerName); 895 } 896 PerfettoTrigger.trigger(triggerName); 897 } 898 899 /** 900 * Testing method intended to be overridden to determine when LatencyTracker writes to 901 * FrameworkStatsLog. 902 */ 903 @VisibleForTesting onLogToFrameworkStats(FrameworkStatsLogEvent event)904 public void onLogToFrameworkStats(FrameworkStatsLogEvent event) { 905 if (DEBUG) { 906 Log.i(TAG, "onLogToFrameworkStats: event=" + event); 907 } 908 FrameworkStatsLog.write(event.logCode, event.statsdAction, event.durationMillis); 909 } 910 911 /** 912 * Testing class intended to reject what should be written to the {@link FrameworkStatsLog} 913 * 914 * <p>This class is used in {@link #onLogToFrameworkStats(FrameworkStatsLogEvent)} for test code 915 * to observer when and what information is being logged by {@link LatencyTracker} 916 */ 917 @VisibleForTesting 918 public static class FrameworkStatsLogEvent { 919 920 @VisibleForTesting 921 public final int action; 922 @VisibleForTesting 923 public final int logCode; 924 @VisibleForTesting 925 public final int statsdAction; 926 @VisibleForTesting 927 public final int durationMillis; 928 FrameworkStatsLogEvent(int action, int logCode, int statsdAction, int durationMillis)929 private FrameworkStatsLogEvent(int action, int logCode, int statsdAction, 930 int durationMillis) { 931 this.action = action; 932 this.logCode = logCode; 933 this.statsdAction = statsdAction; 934 this.durationMillis = durationMillis; 935 } 936 937 @Override toString()938 public String toString() { 939 return "FrameworkStatsLogEvent{" 940 + " logCode=" + logCode 941 + ", statsdAction=" + statsdAction 942 + ", durationMillis=" + durationMillis 943 + "}"; 944 } 945 } 946 } 947