Merge changes from topic "latencytracker-vi-fix" into tm-qpr-dev

* changes:
  cancel VI latency tracking for non ST triggers
  only start latency measurement on successful phrase triggers
  fix enable checks to check use action in LatencyTracker
  add LatencyTracker tracing cancel / timeout events

core/java/com/android/internal/util/LatencyTracker.java

@@ -471,7 +471,7 @@ public class LatencyTracker {
      */
     public void onActionStart(@Action int action, String tag) {
         synchronized (mLock) {
-            if (!isEnabled()) {
+            if (!isEnabled(action)) {
                 return;
             }
             // skip if the action is already instrumenting.
@@ -495,7 +495,7 @@ public class LatencyTracker {
      */
     public void onActionEnd(@Action int action) {
         synchronized (mLock) {
-            if (!isEnabled()) {
+            if (!isEnabled(action)) {
                 return;
             }
             Session session = mSessions.get(action);
@@ -605,23 +605,27 @@ public class LatencyTracker {
 
         void begin(@NonNull Runnable timeoutAction) {
             mStartRtc = SystemClock.elapsedRealtime();
-            Trace.asyncTraceBegin(TRACE_TAG_APP, traceName(), 0);
+            Trace.asyncTraceForTrackBegin(TRACE_TAG_APP, traceName(), traceName(), 0);
 
             // start counting timeout.
-            mTimeoutRunnable = timeoutAction;
+            mTimeoutRunnable = () -> {
+                Trace.instantForTrack(TRACE_TAG_APP, traceName(), "timeout");
+                timeoutAction.run();
+            };
             BackgroundThread.getHandler()
                     .postDelayed(mTimeoutRunnable, TimeUnit.SECONDS.toMillis(15));
         }
 
         void end() {
             mEndRtc = SystemClock.elapsedRealtime();
-            Trace.asyncTraceEnd(TRACE_TAG_APP, traceName(), 0);
+            Trace.asyncTraceForTrackEnd(TRACE_TAG_APP, traceName(), "end", 0);
             BackgroundThread.getHandler().removeCallbacks(mTimeoutRunnable);
             mTimeoutRunnable = null;
         }
 
         void cancel() {
-            Trace.asyncTraceEnd(TRACE_TAG_APP, traceName(), 0);
+            Trace.instantForTrack(TRACE_TAG_APP, traceName(), "cancel");
+            Trace.asyncTraceForTrackEnd(TRACE_TAG_APP, traceName(), "cancel", 0);
             BackgroundThread.getHandler().removeCallbacks(mTimeoutRunnable);
             mTimeoutRunnable = null;
         }

services/core/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLogging.java

@@ -26,6 +26,7 @@ import android.media.soundtrigger.PhraseRecognitionEvent;
 import android.media.soundtrigger.PhraseSoundModel;
 import android.media.soundtrigger.RecognitionConfig;
 import android.media.soundtrigger.RecognitionEvent;
+import android.media.soundtrigger.RecognitionStatus;
 import android.media.soundtrigger.SoundModel;
 import android.media.soundtrigger_middleware.ISoundTriggerCallback;
 import android.media.soundtrigger_middleware.ISoundTriggerModule;
@@ -34,6 +35,7 @@ import android.os.IBinder;
 import android.os.RemoteException;
 import android.util.Log;
 
+import com.android.internal.util.ArrayUtils;
 import com.android.internal.util.LatencyTracker;
 
 import java.io.PrintWriter;
@@ -358,14 +360,19 @@ public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInt
              * 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.
+             *
+             * <p>The session is only started if the {@link PhraseRecognitionEvent} has a status of
+             * {@link RecognitionStatus#SUCCESS}
              */
             private void startKeyphraseEventLatencyTracking(PhraseRecognitionEvent event) {
-                String latencyTrackerTag = null;
+                if (event.common.status != RecognitionStatus.SUCCESS
-                if (event.phraseExtras.length > 0) {
+                        || ArrayUtils.isEmpty(event.phraseExtras)) {
-                    latencyTrackerTag = "KeyphraseId=" + event.phraseExtras[0].id;
+                    return;
                 }
+
                 LatencyTracker latencyTracker = LatencyTracker.getInstance(mContext);
-                // To avoid adding cancel to all of the different failure modes between here and
+                String latencyTrackerTag = "KeyphraseId=" + event.phraseExtras[0].id;
+                // To avoid adding cancel to all 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.

services/voiceinteraction/java/com/android/server/voiceinteraction/HotwordMetricsLogger.java

@@ -34,10 +34,13 @@ import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_EVENT
 import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__DETECTOR_TYPE__NORMAL_DETECTOR;
 import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__DETECTOR_TYPE__TRUSTED_DETECTOR_DSP;
 import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__DETECTOR_TYPE__TRUSTED_DETECTOR_SOFTWARE;
+import static com.android.internal.util.LatencyTracker.ACTION_SHOW_VOICE_INTERACTION;
 
+import android.content.Context;
 import android.service.voice.HotwordDetector;
 
 import com.android.internal.util.FrameworkStatsLog;
+import com.android.internal.util.LatencyTracker;
 
 /**
  * A utility class for logging hotword statistics event.
@@ -116,6 +119,46 @@ public final class HotwordMetricsLogger {
                 metricsDetectorType, event, uid, streamSizeBytes, bundleSizeBytes, streamCount);
     }
 
+    /**
+     * Starts a {@link LatencyTracker} log for the time it takes to show the
+     * {@link android.service.voice.VoiceInteractionSession} system UI after a voice trigger.
+     *
+     * @see LatencyTracker
+     *
+     * @param tag Extra tag to separate different sessions from each other.
+     */
+    public static void startHotwordTriggerToUiLatencySession(Context context, String tag) {
+        LatencyTracker.getInstance(context).onActionStart(ACTION_SHOW_VOICE_INTERACTION, tag);
+    }
+
+    /**
+     * Completes a {@link LatencyTracker} log for the time it takes to show the
+     * {@link android.service.voice.VoiceInteractionSession} system UI after a voice trigger.
+     *
+     * <p>Completing this session will result in logging metric data.</p>
+     *
+     * @see LatencyTracker
+     */
+    public static void stopHotwordTriggerToUiLatencySession(Context context) {
+        LatencyTracker.getInstance(context).onActionEnd(ACTION_SHOW_VOICE_INTERACTION);
+    }
+
+    /**
+     * Cancels a {@link LatencyTracker} log for the time it takes to show the
+     * {@link android.service.voice.VoiceInteractionSession} system UI after a voice trigger.
+     *
+     * <p>Cancels typically occur when the VoiceInteraction session UI is shown for reasons outside
+     * of a {@link android.hardware.soundtrigger.SoundTrigger.RecognitionEvent} such as an
+     * invocation from an external source or service.</p>
+     *
+     * <p>Canceling this session will not result in logging metric data.
+     *
+     * @see LatencyTracker
+     */
+    public static void cancelHotwordTriggerToUiLatencySession(Context context) {
+        LatencyTracker.getInstance(context).onActionCancel(ACTION_SHOW_VOICE_INTERACTION);
+    }
+
     private static int getCreateMetricsDetectorType(int detectorType) {
         switch (detectorType) {
             case HotwordDetector.DETECTOR_TYPE_TRUSTED_HOTWORD_SOFTWARE:

services/voiceinteraction/java/com/android/server/voiceinteraction/VoiceInteractionManagerService.java

@@ -95,7 +95,6 @@ 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;
@@ -404,6 +403,10 @@ public class VoiceInteractionManagerService extends SystemService {
             final int callingUid = Binder.getCallingUid();
             final long caller = Binder.clearCallingIdentity();
             try {
+                // HotwordDetector trigger uses VoiceInteractionService#showSession
+                // We need to cancel here because UI is not being shown due to a SoundTrigger
+                // HAL event.
+                HotwordMetricsLogger.cancelHotwordTriggerToUiLatencySession(mContext);
                 mImpl.showSessionLocked(options,
                         VoiceInteractionSession.SHOW_SOURCE_ACTIVITY,
                         new IVoiceInteractionSessionShowCallback.Stub() {
@@ -954,6 +957,13 @@ public class VoiceInteractionManagerService extends SystemService {
                     Slog.w(TAG, "showSessionFromSession without running voice interaction service");
                     return false;
                 }
+                // If the token is null, then the request to show the session is not coming from
+                // the active VoiceInteractionService session.
+                // We need to cancel here because UI is not being shown due to a SoundTrigger
+                // HAL event.
+                if (token == null) {
+                    HotwordMetricsLogger.cancelHotwordTriggerToUiLatencySession(mContext);
+                }
                 final long caller = Binder.clearCallingIdentity();
                 try {
                     return mImpl.showSessionLocked(sessionArgs, flags, null, null);
@@ -1718,6 +1728,11 @@ public class VoiceInteractionManagerService extends SystemService {
 
                 final long caller = Binder.clearCallingIdentity();
                 try {
+                    // HotwordDetector trigger uses VoiceInteractionService#showSession
+                    // We need to cancel here because UI is not being shown due to a SoundTrigger
+                    // HAL event.
+                    HotwordMetricsLogger.cancelHotwordTriggerToUiLatencySession(mContext);
+
                     return mImpl.showSessionLocked(args,
                             sourceFlags
                                     | VoiceInteractionSession.SHOW_WITH_ASSIST
@@ -2361,8 +2376,11 @@ public class VoiceInteractionManagerService extends SystemService {
                 public void onVoiceSessionWindowVisibilityChanged(boolean visible)
                         throws RemoteException {
                     if (visible) {
-                        LatencyTracker.getInstance(mContext)
+                        // The AlwaysOnHotwordDetector trigger latency is always completed here even
-                                .onActionEnd(LatencyTracker.ACTION_SHOW_VOICE_INTERACTION);
+                        // if the reason the window was shown was not due to a SoundTrigger HAL
+                        // event. It is expected that the latency will be canceled if shown for
+                        // other invocation reasons, and this call becomes a noop.
+                        HotwordMetricsLogger.stopHotwordTriggerToUiLatencySession(mContext);
                     }
                 }