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