Add Logging of the UI Latency for hotword invocation

Log the UI latency with UIActionLatencyReported atom. We plan to
calulate the latency from when the SoundTrigger HAL emits an event to
when the VoiceInteraction system UI view is shown.

Test: device_config put latency_tracker enabled true; verify traces
and latency is logged in WW.
Bug: 247879896

Change-Id: I3edb91691e81f8f23660c0823a6388338fe926ad

4 files changed, 86 insertions, 11 deletions

diff --git a/core/java/com/android/internal/util/LatencyTracker.java b/core/java/com/android/internal/util/LatencyTracker.java
index d3f9e0a2729e..8fcb6d5514d4 100644
--- a/core/java/com/android/internal/util/LatencyTracker.java
+++ b/core/java/com/android/internal/util/LatencyTracker.java
@@ -29,6 +29,7 @@ import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPOR
 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_ROTATE_SCREEN_SENSOR;
 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_BACK_ARROW;
 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_SELECTION_TOOLBAR;
+import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_VOICE_INTERACTION;
 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_START_RECENTS_ANIMATION;
 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_SWITCH_DISPLAY_UNFOLD;
 import static com.android.internal.util.FrameworkStatsLog.UIACTION_LATENCY_REPORTED__ACTION__ACTION_TOGGLE_RECENTS;
@@ -174,6 +175,12 @@ public class LatencyTracker {
      */
     public static final int ACTION_FOLD_TO_AOD = 18;
 
+    /**
+     * Time it takes to show the {@link android.service.voice.VoiceInteractionSession} system UI
+     * after a {@link android.hardware.soundtrigger3.ISoundTriggerHw} voice trigger.
+     */
+    public static final int ACTION_SHOW_VOICE_INTERACTION = 19;
+
     private static final int[] ACTIONS_ALL = {
         ACTION_EXPAND_PANEL,
         ACTION_TOGGLE_RECENTS,
@@ -194,6 +201,7 @@ public class LatencyTracker {
         ACTION_LOAD_SHARE_SHEET,
         ACTION_SHOW_SELECTION_TOOLBAR,
         ACTION_FOLD_TO_AOD,
+        ACTION_SHOW_VOICE_INTERACTION,
     };
 
     /** @hide */
@@ -217,6 +225,7 @@ public class LatencyTracker {
         ACTION_LOAD_SHARE_SHEET,
         ACTION_SHOW_SELECTION_TOOLBAR,
         ACTION_FOLD_TO_AOD,
+        ACTION_SHOW_VOICE_INTERACTION,
     })
     @Retention(RetentionPolicy.SOURCE)
     public @interface Action {
@@ -243,6 +252,7 @@ public class LatencyTracker {
             UIACTION_LATENCY_REPORTED__ACTION__ACTION_LOAD_SHARE_SHEET,
             UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_SELECTION_TOOLBAR,
             UIACTION_LATENCY_REPORTED__ACTION__ACTION_FOLD_TO_AOD,
+            UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_VOICE_INTERACTION,
     };
 
     private static LatencyTracker sLatencyTracker;
@@ -340,6 +350,8 @@ public class LatencyTracker {
                 return "ACTION_SHOW_SELECTION_TOOLBAR";
             case UIACTION_LATENCY_REPORTED__ACTION__ACTION_FOLD_TO_AOD:
                 return "ACTION_FOLD_TO_AOD";
+            case UIACTION_LATENCY_REPORTED__ACTION__ACTION_SHOW_VOICE_INTERACTION:
+                return "ACTION_SHOW_VOICE_INTERACTION";
             default:
                 throw new IllegalArgumentException("Invalid action");
         }
diff --git a/services/core/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLogging.java b/services/core/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLogging.java
index dc4bdaaa8158..ce1157e1d80c 100644
--- a/services/core/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLogging.java
+++ b/services/core/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLogging.java
@@ -18,6 +18,7 @@ package com.android.server.soundtrigger_middleware;
 
 import android.annotation.NonNull;
 import android.annotation.Nullable;
+import android.content.Context;
 import android.media.permission.Identity;
 import android.media.permission.IdentityContext;
 import android.media.soundtrigger.ModelParameterRange;
@@ -33,6 +34,8 @@ import android.os.IBinder;
 import android.os.RemoteException;
 import android.util.Log;
 
+import com.android.internal.util.LatencyTracker;
+
 import java.io.PrintWriter;
 import java.text.SimpleDateFormat;
 import java.util.Date;
@@ -65,9 +68,12 @@ import java.util.Objects;
 public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInternal, Dumpable {
     private static final String TAG = "SoundTriggerMiddlewareLogging";
     private final @NonNull ISoundTriggerMiddlewareInternal mDelegate;
+    private final @NonNull Context mContext;
 
-    public SoundTriggerMiddlewareLogging(@NonNull ISoundTriggerMiddlewareInternal delegate) {
+    public SoundTriggerMiddlewareLogging(@NonNull Context context,
+            @NonNull ISoundTriggerMiddlewareInternal delegate) {
         mDelegate = delegate;
+        mContext = context;
     }
 
     @Override
@@ -298,6 +304,7 @@ public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInt
                     int captureSession)
                     throws RemoteException {
                 try {
+                    startKeyphraseEventLatencyTracking(event);
                     mCallbackDelegate.onPhraseRecognition(modelHandle, event, captureSession);
                     logVoidReturn("onPhraseRecognition", modelHandle, event);
                 } catch (Exception e) {
@@ -347,6 +354,26 @@ public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInt
                 logVoidReturnWithObject(this, mOriginatorIdentity, methodName, args);
             }
 
+            /**
+             * Starts the latency tracking log for keyphrase hotword invocation.
+             * The measurement covers from when the SoundTrigger HAL emits an event to when the
+             * {@link android.service.voice.VoiceInteractionSession} system UI view is shown.
+             */
+            private void startKeyphraseEventLatencyTracking(PhraseRecognitionEvent event) {
+                String latencyTrackerTag = null;
+                if (event.phraseExtras.length > 0) {
+                    latencyTrackerTag = "KeyphraseId=" + event.phraseExtras[0].id;
+                }
+                LatencyTracker latencyTracker = LatencyTracker.getInstance(mContext);
+                // To avoid adding cancel to all of the different failure modes between here and
+                // showing the system UI, we defensively cancel once.
+                // Either we hit the LatencyTracker timeout of 15 seconds or we defensively cancel
+                // here if any error occurs.
+                latencyTracker.onActionCancel(LatencyTracker.ACTION_SHOW_VOICE_INTERACTION);
+                latencyTracker.onActionStart(LatencyTracker.ACTION_SHOW_VOICE_INTERACTION,
+                        latencyTrackerTag);
+            }
+
             @Override
             public IBinder asBinder() {
                 return mCallbackDelegate.asBinder();
diff --git a/services/core/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareService.java b/services/core/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareService.java
index 1995e5497e55..807ed14e85ce 100644
--- a/services/core/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareService.java
+++ b/services/core/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareService.java
@@ -20,14 +20,14 @@ import static android.Manifest.permission.SOUNDTRIGGER_DELEGATE_IDENTITY;
 
 import android.annotation.NonNull;
 import android.content.Context;
-import android.media.soundtrigger.ModelParameterRange;
-import android.media.soundtrigger.PhraseSoundModel;
-import android.media.soundtrigger.RecognitionConfig;
-import android.media.soundtrigger.SoundModel;
 import android.media.permission.ClearCallingIdentityContext;
 import android.media.permission.Identity;
 import android.media.permission.PermissionUtil;
 import android.media.permission.SafeCloseable;
+import android.media.soundtrigger.ModelParameterRange;
+import android.media.soundtrigger.PhraseSoundModel;
+import android.media.soundtrigger.RecognitionConfig;
+import android.media.soundtrigger.SoundModel;
 import android.media.soundtrigger_middleware.ISoundTriggerCallback;
 import android.media.soundtrigger_middleware.ISoundTriggerMiddlewareService;
 import android.media.soundtrigger_middleware.ISoundTriggerModule;
@@ -226,12 +226,13 @@ public class SoundTriggerMiddlewareService extends ISoundTriggerMiddlewareServic
             HalFactory[] factories = new HalFactory[]{new DefaultHalFactory()};
 
             publishBinderService(Context.SOUND_TRIGGER_MIDDLEWARE_SERVICE,
-                    new SoundTriggerMiddlewareService(new SoundTriggerMiddlewareLogging(
-                            new SoundTriggerMiddlewarePermission(
-                                    new SoundTriggerMiddlewareValidation(
-                                            new SoundTriggerMiddlewareImpl(factories,
-                                                    new AudioSessionProviderImpl())),
-                                    getContext())), getContext()));
+                    new SoundTriggerMiddlewareService(
+                            new SoundTriggerMiddlewareLogging(getContext(),
+                                new SoundTriggerMiddlewarePermission(
+                                        new SoundTriggerMiddlewareValidation(
+                                                new SoundTriggerMiddlewareImpl(factories,
+                                                        new AudioSessionProviderImpl())),
+                                        getContext())), getContext()));
         }
     }
 }
diff --git a/services/voiceinteraction/java/com/android/server/voiceinteraction/VoiceInteractionManagerService.java b/services/voiceinteraction/java/com/android/server/voiceinteraction/VoiceInteractionManagerService.java
index 0ce0265c3dc5..3da47110fb49 100644
--- a/services/voiceinteraction/java/com/android/server/voiceinteraction/VoiceInteractionManagerService.java
+++ b/services/voiceinteraction/java/com/android/server/voiceinteraction/VoiceInteractionManagerService.java
@@ -95,6 +95,7 @@ import com.android.internal.app.IVoiceInteractor;
 import com.android.internal.content.PackageMonitor;
 import com.android.internal.os.BackgroundThread;
 import com.android.internal.util.DumpUtils;
+import com.android.internal.util.LatencyTracker;
 import com.android.server.FgThread;
 import com.android.server.LocalServices;
 import com.android.server.SystemService;
@@ -191,6 +192,8 @@ public class VoiceInteractionManagerService extends SystemService {
             mSoundTriggerInternal = LocalServices.getService(SoundTriggerInternal.class);
         } else if (phase == PHASE_THIRD_PARTY_APPS_CAN_START) {
             mServiceStub.systemRunning(isSafeMode());
+        } else if (phase == PHASE_BOOT_COMPLETED) {
+            mServiceStub.registerVoiceInteractionSessionListener(mLatencyLoggingListener);
         }
     }
 
@@ -2334,4 +2337,36 @@ public class VoiceInteractionManagerService extends SystemService {
             }
         };
     }
+
+    /**
+     * End the latency tracking log for keyphrase hotword invocation.
+     * The measurement covers from when the SoundTrigger HAL emits an event, captured in
+     * {@link com.android.server.soundtrigger_middleware.SoundTriggerMiddlewareLogging}
+     * to when the {@link android.service.voice.VoiceInteractionSession} system UI view is shown.
+     */
+    private final IVoiceInteractionSessionListener mLatencyLoggingListener =
+            new IVoiceInteractionSessionListener.Stub() {
+                @Override
+                public void onVoiceSessionShown() throws RemoteException {}
+
+                @Override
+                public void onVoiceSessionHidden() throws RemoteException {}
+
+                @Override
+                public void onVoiceSessionWindowVisibilityChanged(boolean visible)
+                        throws RemoteException {
+                    if (visible) {
+                        LatencyTracker.getInstance(mContext)
+                                .onActionEnd(LatencyTracker.ACTION_SHOW_VOICE_INTERACTION);
+                    }
+                }
+
+                @Override
+                public void onSetUiHints(Bundle args) throws RemoteException {}
+
+                @Override
+                public IBinder asBinder() {
+                    return mServiceStub;
+                }
+            };
 }