Merge changes I212ad58c,Idf5dd82d into sc-dev

* changes:
  Provide the way to enable/disable debug mode for logging egressed data
  Set the Debug flag to false

core/java/android/service/voice/HotwordDetectionService.java

@@ -72,8 +72,7 @@ import java.util.function.IntConsumer;
 @SystemApi
 public abstract class HotwordDetectionService extends Service {
     private static final String TAG = "HotwordDetectionService";
-    // TODO (b/177502877): Set the Debug flag to false before shipping.
+    private static final boolean DBG = false;
-    private static final boolean DBG = true;
 
     private static final long UPDATE_TIMEOUT_MILLIS = 5000;
 
@@ -151,9 +150,7 @@ public abstract class HotwordDetectionService extends Service {
         @Override
         public void updateState(PersistableBundle options, SharedMemory sharedMemory,
                 IRemoteCallback callback) throws RemoteException {
-            if (DBG) {
+            Log.v(TAG, "#updateState" + (callback != null ? " with callback" : ""));
-                Log.d(TAG, "#updateState");
-            }
             HotwordDetectionService.this.onUpdateStateInternal(
                     options,
                     sharedMemory,

core/java/android/service/voice/SoftwareHotwordDetector.java

@@ -47,7 +47,7 @@ import java.io.PrintWriter;
  **/
 class SoftwareHotwordDetector extends AbstractHotwordDetector {
     private static final String TAG = SoftwareHotwordDetector.class.getSimpleName();
-    private static final boolean DEBUG = true;
+    private static final boolean DEBUG = false;
 
     private final IVoiceInteractionManagerService mManagerService;
     private final HotwordDetector.Callback mCallback;

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

@@ -87,14 +87,14 @@ import java.util.function.Function;
  */
 final class HotwordDetectionConnection {
     private static final String TAG = "HotwordDetectionConnection";
-    // TODO (b/177502877): Set the Debug flag to false before shipping.
+    static final boolean DEBUG = false;
-    static final boolean DEBUG = true;
 
     // TODO: These constants need to be refined.
     private static final long VALIDATION_TIMEOUT_MILLIS = 3000;
     private static final long MAX_UPDATE_TIMEOUT_MILLIS = 6000;
     private static final Duration MAX_UPDATE_TIMEOUT_DURATION =
             Duration.ofMillis(MAX_UPDATE_TIMEOUT_MILLIS);
+    private static final long RESET_DEBUG_HOTWORD_LOGGING_TIMEOUT_MILLIS = 60 * 60 * 1000; // 1 hour
 
     private final Executor mAudioCopyExecutor = Executors.newCachedThreadPool();
     // TODO: This may need to be a Handler(looper)
@@ -115,6 +115,7 @@ final class HotwordDetectionConnection {
     private Instant mLastRestartInstant;
 
     private ScheduledFuture<?> mCancellationTaskFuture;
+    private ScheduledFuture<?> mDebugHotwordLoggingTimeoutFuture = null;
 
     /** Identity used for attributing app ops when delivering data to the Interactor. */
     @GuardedBy("mLock")
@@ -128,6 +129,7 @@ final class HotwordDetectionConnection {
     private boolean mPerformingSoftwareHotwordDetection;
     private @NonNull ServiceConnection mRemoteHotwordDetectionService;
     private IBinder mAudioFlinger;
+    private boolean mDebugHotwordLogging = false;
 
     HotwordDetectionConnection(Object lock, Context context, int voiceInteractionServiceUid,
             Identity voiceInteractorIdentity, ComponentName serviceName, int userId,
@@ -159,10 +161,7 @@ final class HotwordDetectionConnection {
         // TODO(volnov): we need to be smarter here, e.g. schedule it a bit more often, but wait
         // until the current session is closed.
         mCancellationTaskFuture = mScheduledExecutorService.scheduleAtFixedRate(() -> {
-            if (DEBUG) {
+            Slog.v(TAG, "Time to restart the process, TTL has passed");
-                Slog.i(TAG, "Time to restart the process, TTL has passed");
-            }
-
             synchronized (mLock) {
                 restartProcessLocked();
             }
@@ -268,9 +267,9 @@ final class HotwordDetectionConnection {
     }
 
     void cancelLocked() {
-        if (DEBUG) {
+        Slog.v(TAG, "cancelLocked");
-            Slog.d(TAG, "cancelLocked");
+        clearDebugHotwordLoggingTimeoutLocked();
-        }
+        mDebugHotwordLogging = false;
         if (mRemoteHotwordDetectionService.isBound()) {
             mRemoteHotwordDetectionService.unbind();
             LocalServices.getService(PermissionManagerServiceInternal.class)
@@ -288,6 +287,7 @@ final class HotwordDetectionConnection {
         // TODO(b/191742511): this logic needs a test
         if (!mUpdateStateAfterStartFinished.get()
                 && Instant.now().minus(MAX_UPDATE_TIMEOUT_DURATION).isBefore(mLastRestartInstant)) {
+            Slog.v(TAG, "call updateStateAfterProcessStart");
             updateStateAfterProcessStart(options, sharedMemory);
         } else {
             mRemoteHotwordDetectionService.run(
@@ -330,6 +330,9 @@ final class HotwordDetectionConnection {
                         if (result != null) {
                             Slog.i(TAG, "Egressed " + HotwordDetectedResult.getUsageSize(result)
                                     + " bits from hotword trusted process");
+                            if (mDebugHotwordLogging) {
+                                Slog.i(TAG, "Egressed detected result: " + result);
+                            }
                         }
                     } else {
                         Slog.i(TAG, "Hotword detection has already completed");
@@ -407,15 +410,11 @@ final class HotwordDetectionConnection {
 
     private void detectFromDspSourceForTest(SoundTrigger.KeyphraseRecognitionEvent recognitionEvent,
             IHotwordRecognitionStatusCallback externalCallback) {
-        if (DEBUG) {
+        Slog.v(TAG, "detectFromDspSourceForTest");
-            Slog.d(TAG, "detectFromDspSourceForTest");
-        }
         IDspHotwordDetectionCallback internalCallback = new IDspHotwordDetectionCallback.Stub() {
             @Override
             public void onDetected(HotwordDetectedResult result) throws RemoteException {
-                if (DEBUG) {
+                Slog.v(TAG, "onDetected");
-                    Slog.d(TAG, "onDetected");
-                }
                 synchronized (mLock) {
                     if (mValidatingDspTrigger) {
                         mValidatingDspTrigger = false;
@@ -424,6 +423,9 @@ final class HotwordDetectionConnection {
                         if (result != null) {
                             Slog.i(TAG, "Egressed " + HotwordDetectedResult.getUsageSize(result)
                                     + " bits from hotword trusted process");
+                            if (mDebugHotwordLogging) {
+                                Slog.i(TAG, "Egressed detected result: " + result);
+                            }
                         }
                     } else {
                         Slog.i(TAG, "Ignored hotword detected since trigger has been handled");
@@ -433,13 +435,14 @@ final class HotwordDetectionConnection {
 
             @Override
             public void onRejected(HotwordRejectedResult result) throws RemoteException {
-                if (DEBUG) {
+                Slog.v(TAG, "onRejected");
-                    Slog.d(TAG, "onRejected");
-                }
                 synchronized (mLock) {
                     if (mValidatingDspTrigger) {
                         mValidatingDspTrigger = false;
                         externalCallback.onRejected(result);
+                        if (mDebugHotwordLogging && result != null) {
+                            Slog.i(TAG, "Egressed rejected result: " + result);
+                        }
                     } else {
                         Slog.i(TAG, "Ignored hotword rejected since trigger has been handled");
                     }
@@ -482,6 +485,9 @@ final class HotwordDetectionConnection {
                     if (result != null) {
                         Slog.i(TAG, "Egressed " + HotwordDetectedResult.getUsageSize(result)
                                 + " bits from hotword trusted process");
+                        if (mDebugHotwordLogging) {
+                            Slog.i(TAG, "Egressed detected result: " + result);
+                        }
                     }
                 }
             }
@@ -498,6 +504,9 @@ final class HotwordDetectionConnection {
                     }
                     mValidatingDspTrigger = false;
                     externalCallback.onRejected(result);
+                    if (mDebugHotwordLogging && result != null) {
+                        Slog.i(TAG, "Egressed rejected result: " + result);
+                    }
                 }
             }
         };
@@ -514,19 +523,37 @@ final class HotwordDetectionConnection {
     }
 
     void forceRestart() {
-        if (DEBUG) {
+        Slog.v(TAG, "Requested to restart the service internally. Performing the restart");
-            Slog.i(TAG, "Requested to restart the service internally. Performing the restart");
-        }
         synchronized (mLock) {
             restartProcessLocked();
         }
     }
 
-    private void restartProcessLocked() {
+    void setDebugHotwordLoggingLocked(boolean logging) {
-        if (DEBUG) {
+        Slog.v(TAG, "setDebugHotwordLoggingLocked: " + logging);
-            Slog.i(TAG, "Restarting hotword detection process");
+        clearDebugHotwordLoggingTimeoutLocked();
-        }
+        mDebugHotwordLogging = logging;
 
+        if (logging) {
+            // Reset mDebugHotwordLogging to false after one hour
+            mDebugHotwordLoggingTimeoutFuture = mScheduledExecutorService.schedule(() -> {
+                Slog.v(TAG, "Timeout to reset mDebugHotwordLogging to false");
+                synchronized (mLock) {
+                    mDebugHotwordLogging = false;
+                }
+            }, RESET_DEBUG_HOTWORD_LOGGING_TIMEOUT_MILLIS, TimeUnit.MILLISECONDS);
+        }
+    }
+
+    private void clearDebugHotwordLoggingTimeoutLocked() {
+        if (mDebugHotwordLoggingTimeoutFuture != null) {
+            mDebugHotwordLoggingTimeoutFuture.cancel(/* mayInterruptIfRunning= */true);
+            mDebugHotwordLoggingTimeoutFuture = null;
+        }
+    }
+
+    private void restartProcessLocked() {
+        Slog.v(TAG, "Restarting hotword detection process");
         ServiceConnection oldConnection = mRemoteHotwordDetectionService;
 
         // TODO(volnov): this can be done after connect() has been successful.
@@ -547,9 +574,7 @@ final class HotwordDetectionConnection {
         // Recreate connection to reset the cache.
         mRemoteHotwordDetectionService = mServiceConnectionFactory.createLocked();
 
-        if (DEBUG) {
+        Slog.v(TAG, "Started the new process, issuing #onProcessRestarted");
-            Slog.i(TAG, "Started the new process, issuing #onProcessRestarted");
-        }
         try {
             mCallback.onProcessRestarted();
         } catch (RemoteException e) {
@@ -700,6 +725,9 @@ final class HotwordDetectionConnection {
                                 bestEffortClose(serviceAudioSource);
                                 bestEffortClose(audioSource);
 
+                                if (mDebugHotwordLogging && result != null) {
+                                    Slog.i(TAG, "Egressed rejected result: " + result);
+                                }
                                 // TODO: Propagate the HotwordRejectedResult.
                             }
 
@@ -714,6 +742,9 @@ final class HotwordDetectionConnection {
                                 if (triggerResult != null) {
                                     Slog.i(TAG, "Egressed " + HotwordDetectedResult.getUsageSize(
                                             triggerResult) + " bits from hotword trusted process");
+                                    if (mDebugHotwordLogging) {
+                                        Slog.i(TAG, "Egressed detected result: " + triggerResult);
+                                    }
                                 }
                                 // TODO: Add a delay before closing.
                                 bestEffortClose(audioSource);
@@ -773,9 +804,7 @@ final class HotwordDetectionConnection {
             }
             synchronized (mLock) {
                 if (!mRespectServiceConnectionStatusChanged) {
-                    if (DEBUG) {
+                    Slog.v(TAG, "Ignored onServiceConnectionStatusChanged event");
-                        Slog.d(TAG, "Ignored onServiceConnectionStatusChanged event");
-                    }
                     return;
                 }
                 mIsBound = connected;
@@ -792,9 +821,7 @@ final class HotwordDetectionConnection {
             super.binderDied();
             synchronized (mLock) {
                 if (!mRespectServiceConnectionStatusChanged) {
-                    if (DEBUG) {
+                    Slog.v(TAG, "Ignored #binderDied event");
-                        Slog.d(TAG, "Ignored #binderDied event");
-                    }
                     return;
                 }
 

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

@@ -832,6 +832,17 @@ public class VoiceInteractionManagerService extends SystemService {
             mImpl.forceRestartHotwordDetector();
         }
 
+        // Called by Shell command
+        void setDebugHotwordLogging(boolean logging) {
+            synchronized (this) {
+                if (mImpl == null) {
+                    Slog.w(TAG, "setTemporaryLogging without running voice interaction service");
+                    return;
+                }
+                mImpl.setDebugHotwordLoggingLocked(logging);
+            }
+        }
+
         @Override
         public void showSession(Bundle args, int flags) {
             synchronized (this) {

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

@@ -79,8 +79,7 @@ import java.util.List;
 
 class VoiceInteractionManagerServiceImpl implements VoiceInteractionSessionConnection.Callback {
     final static String TAG = "VoiceInteractionServiceManager";
-    // TODO (b/177502877): Set the Debug flag to false before shipping.
+    static final boolean DEBUG = false;
-    static final boolean DEBUG = true;
 
     final static String CLOSE_REASON_VOICE_INTERACTION = "voiceinteraction";
 
@@ -420,9 +419,7 @@ class VoiceInteractionManagerServiceImpl implements VoiceInteractionSessionConne
             @Nullable PersistableBundle options,
             @Nullable SharedMemory sharedMemory,
             IHotwordRecognitionStatusCallback callback) {
-        if (DEBUG) {
+        Slog.v(TAG, "updateStateLocked");
-            Slog.d(TAG, "updateStateLocked");
-        }
         if (mHotwordDetectionComponentName == null) {
             Slog.w(TAG, "Hotword detection service name not found");
             throw new IllegalStateException("Hotword detection service name not found");
@@ -584,6 +581,14 @@ class VoiceInteractionManagerServiceImpl implements VoiceInteractionSessionConne
         mHotwordDetectionConnection.forceRestart();
     }
 
+    void setDebugHotwordLoggingLocked(boolean logging) {
+        if (mHotwordDetectionConnection == null) {
+            Slog.w(TAG, "Failed to set temporary debug logging: no hotword detection active");
+            return;
+        }
+        mHotwordDetectionConnection.setDebugHotwordLoggingLocked(logging);
+    }
+
     void resetHotwordDetectionConnectionLocked() {
         if (DEBUG) {
             Slog.d(TAG, "resetHotwordDetectionConnectionLocked");

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

@@ -56,6 +56,8 @@ final class VoiceInteractionManagerServiceShellCommand extends ShellCommand {
                 return requestDisable(pw);
             case "restart-detection":
                 return requestRestartDetection(pw);
+            case "set-debug-hotword-logging":
+                return setDebugHotwordLogging(pw);
             default:
                 return handleDefaultCommands(cmd);
         }
@@ -76,9 +78,14 @@ final class VoiceInteractionManagerServiceShellCommand extends ShellCommand {
             pw.println("");
             pw.println("  disable [true|false]");
             pw.println("    Temporarily disable (when true) service");
+            pw.println("");
             pw.println("  restart-detection");
             pw.println("    Force a restart of a hotword detection service");
             pw.println("");
+            pw.println("  set-debug-hotword-logging [true|false]");
+            pw.println("    Temporarily enable or disable debug logging for hotword result.");
+            pw.println("    The debug logging will be reset after one hour from last enable.");
+            pw.println("");
         }
     }
 
@@ -157,6 +164,17 @@ final class VoiceInteractionManagerServiceShellCommand extends ShellCommand {
         return 0;
     }
 
+    private int setDebugHotwordLogging(PrintWriter pw) {
+        boolean logging = Boolean.parseBoolean(getNextArgRequired());
+        Slog.i(TAG, "setDebugHotwordLogging(): " + logging);
+        try {
+            mService.setDebugHotwordLogging(logging);
+        } catch (Exception e) {
+            return handleError(pw, "setDebugHotwordLogging()", e);
+        }
+        return 0;
+    }
+
     private static int handleError(PrintWriter pw, String message, Exception e) {
         Slog.e(TAG,  "error calling " + message, e);
         pw.printf("Error calling %s: %s\n", message, e);