Merge "Add hotword detection metrics." into tm-dev (63762797) · Commits · e / os / android_frameworks_base

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

+144 −18

Original line number	Diff line number	Diff line
		@@ -23,6 +23,25 @@ import static android.service.voice.HotwordDetectionService.AUDIO_SOURCE_MICROPH
		import static android.service.voice.HotwordDetectionService.INITIALIZATION_STATUS_UNKNOWN;
		import static android.service.voice.HotwordDetectionService.KEY_INITIALIZATION_STATUS;

		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_ERROR;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_SUCCESS;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_UNKNOWN_NO_VALUE;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_UNKNOWN_OVER_MAX_CUSTOM_VALUE;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_UNKNOWN_TIMEOUT;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTION_SERVICE_RESTARTED__REASON__AUDIO_SERVICE_DIED;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTION_SERVICE_RESTARTED__REASON__SCHEDULE;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_EVENTS__EVENT__CALLBACK_UPDATE_STATE_AFTER_TIMEOUT;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_EVENTS__EVENT__ON_CONNECTED;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_EVENTS__EVENT__REQUEST_BIND_SERVICE;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_EVENTS__EVENT__REQUEST_BIND_SERVICE_FAIL;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_EVENTS__EVENT__REQUEST_UPDATE_STATE;
		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__RESULT__DETECTED;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__DETECT_EXCEPTION;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__DETECT_TIMEOUT;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__KEYPHRASE_TRIGGER;
		import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__REJECTED;
		import static com.android.server.voiceinteraction.SoundTriggerSessionPermissionsDecorator.enforcePermissionForPreflight;

		import android.annotation.NonNull;
		@@ -92,13 +111,25 @@ final class HotwordDetectionConnection {
		static final boolean DEBUG = false;

		// TODO: These constants need to be refined.
		private static final long VALIDATION_TIMEOUT_MILLIS = 3000;
		private static final long VALIDATION_TIMEOUT_MILLIS = 4000;
		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 static final int MAX_ISOLATED_PROCESS_NUMBER = 10;

		// Hotword metrics
		private static final int METRICS_INIT_UNKNOWN_TIMEOUT =
		HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_UNKNOWN_TIMEOUT;
		private static final int METRICS_INIT_UNKNOWN_NO_VALUE =
		HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_UNKNOWN_NO_VALUE;
		private static final int METRICS_INIT_UNKNOWN_OVER_MAX_CUSTOM_VALUE =
		HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_UNKNOWN_OVER_MAX_CUSTOM_VALUE;
		private static final int METRICS_INIT_CALLBACK_STATE_ERROR =
		HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_ERROR;
		private static final int METRICS_INIT_CALLBACK_STATE_SUCCESS =
		HOTWORD_DETECTION_SERVICE_INIT_RESULT_REPORTED__RESULT__CALLBACK_INIT_STATE_SUCCESS;

		private final Executor mAudioCopyExecutor = Executors.newCachedThreadPool();
		// TODO: This may need to be a Handler(looper)
		private final ScheduledExecutorService mScheduledExecutorService =
		@@ -107,17 +138,20 @@ final class HotwordDetectionConnection {
		private final IBinder.DeathRecipient mAudioServerDeathRecipient = this::audioServerDied;
		private final @NonNull ServiceConnectionFactory mServiceConnectionFactory;
		private final IHotwordRecognitionStatusCallback mCallback;
		private final int mDetectorType;

		final Object mLock;
		final int mVoiceInteractionServiceUid;
		final ComponentName mDetectionComponentName;
		final int mUser;
		final Context mContext;

		volatile HotwordDetectionServiceIdentity mIdentity;
		private IMicrophoneHotwordDetectionVoiceInteractionCallback mSoftwareCallback;
		private Instant mLastRestartInstant;

		private ScheduledFuture<?> mCancellationTaskFuture;
		private ScheduledFuture<?> mCancellationKeyPhraseDetectionFuture;
		private ScheduledFuture<?> mDebugHotwordLoggingTimeoutFuture = null;

		/** Identity used for attributing app ops when delivering data to the Interactor. */
		@@ -133,7 +167,6 @@ final class HotwordDetectionConnection {
		private @NonNull ServiceConnection mRemoteHotwordDetectionService;
		private IBinder mAudioFlinger;
		private boolean mDebugHotwordLogging = false;
		private final int mDetectorType;

		HotwordDetectionConnection(Object lock, Context context, int voiceInteractionServiceUid,
		Identity voiceInteractorIdentity, ComponentName serviceName, int userId,
		@@ -169,6 +202,8 @@ final class HotwordDetectionConnection {
		Slog.v(TAG, "Time to restart the process, TTL has passed");
		synchronized (mLock) {
		restartProcessLocked();
		HotwordMetricsLogger.writeServiceRestartEvent(mDetectorType,
		HOTWORD_DETECTION_SERVICE_RESTARTED__REASON__SCHEDULE);
		}
		}, 30, 30, TimeUnit.MINUTES);
		}
		@@ -201,6 +236,8 @@ final class HotwordDetectionConnection {
		// We restart the process instead of simply sending over the new binder, to avoid race
		// conditions with audio reading in the service.
		restartProcessLocked();
		HotwordMetricsLogger.writeServiceRestartEvent(mDetectorType,
		HOTWORD_DETECTION_SERVICE_RESTARTED__REASON__AUDIO_SERVICE_DIED);
		}
		}

		@@ -220,26 +257,32 @@ final class HotwordDetectionConnection {
		future.complete(null);
		if (mUpdateStateAfterStartFinished.getAndSet(true)) {
		Slog.w(TAG, "call callback after timeout");
		HotwordMetricsLogger.writeDetectorEvent(mDetectorType,
		HOTWORD_DETECTOR_EVENTS__EVENT__CALLBACK_UPDATE_STATE_AFTER_TIMEOUT,
		mVoiceInteractionServiceUid);
		return;
		}
		int status = bundle != null ? bundle.getInt(
		KEY_INITIALIZATION_STATUS,
		INITIALIZATION_STATUS_UNKNOWN)
		: INITIALIZATION_STATUS_UNKNOWN;
		// Add the protection to avoid unexpected status
		if (status > HotwordDetectionService.getMaxCustomInitializationStatus()
		&& status != INITIALIZATION_STATUS_UNKNOWN) {
		status = INITIALIZATION_STATUS_UNKNOWN;
		}
		Pair<Integer, Integer> statusResultPair = getInitStatusAndMetricsResult(bundle);
		int status = statusResultPair.first;
		int initResultMetricsResult = statusResultPair.second;
		try {
		mCallback.onStatusReported(status);
		HotwordMetricsLogger.writeServiceInitResultEvent(mDetectorType,
		initResultMetricsResult);
		} catch (RemoteException e) {
		// TODO: Add a new atom for RemoteException case, the error doesn't very
		// correct here
		Slog.w(TAG, "Failed to report initialization status: " + e);
		HotwordMetricsLogger.writeServiceInitResultEvent(mDetectorType,
		METRICS_INIT_CALLBACK_STATE_ERROR);
		}
		}
		};
		try {
		service.updateState(options, sharedMemory, statusCallback);
		HotwordMetricsLogger.writeDetectorEvent(mDetectorType,
		HOTWORD_DETECTOR_EVENTS__EVENT__REQUEST_UPDATE_STATE,
		mVoiceInteractionServiceUid);
		} catch (RemoteException e) {
		// TODO: (b/181842909) Report an error to voice interactor
		Slog.w(TAG, "Failed to updateState for HotwordDetectionService", e);
		@@ -254,8 +297,12 @@ final class HotwordDetectionConnection {
		}
		try {
		mCallback.onStatusReported(INITIALIZATION_STATUS_UNKNOWN);
		HotwordMetricsLogger.writeServiceInitResultEvent(mDetectorType,
		METRICS_INIT_UNKNOWN_TIMEOUT);
		} catch (RemoteException e) {
		Slog.w(TAG, "Failed to report initialization status UNKNOWN", e);
		HotwordMetricsLogger.writeServiceInitResultEvent(mDetectorType,
		METRICS_INIT_CALLBACK_STATE_ERROR);
		}
		} else if (err != null) {
		Slog.w(TAG, "Failed to update state: " + err);
		@@ -265,6 +312,23 @@ final class HotwordDetectionConnection {
		});
		}

		private static Pair<Integer, Integer> getInitStatusAndMetricsResult(Bundle bundle) {
		if (bundle == null) {
		return new Pair<>(INITIALIZATION_STATUS_UNKNOWN, METRICS_INIT_UNKNOWN_NO_VALUE);
		}
		int status = bundle.getInt(KEY_INITIALIZATION_STATUS, INITIALIZATION_STATUS_UNKNOWN);
		if (status > HotwordDetectionService.getMaxCustomInitializationStatus()
		&& status != INITIALIZATION_STATUS_UNKNOWN) {
		return new Pair<>(INITIALIZATION_STATUS_UNKNOWN,
		METRICS_INIT_UNKNOWN_OVER_MAX_CUSTOM_VALUE);
		}
		// TODO: should guard against negative here
		int metricsResult = status == INITIALIZATION_STATUS_UNKNOWN
		? METRICS_INIT_CALLBACK_STATE_ERROR
		: METRICS_INIT_CALLBACK_STATE_SUCCESS;
		return new Pair<>(status, metricsResult);
		}

		private boolean isBound() {
		synchronized (mLock) {
		return mRemoteHotwordDetectionService.isBound();
		@@ -481,12 +545,31 @@ final class HotwordDetectionConnection {
		Slog.d(TAG, "onDetected");
		}
		synchronized (mLock) {
		// TODO: If the dsp trigger comes in after the timeout, we will log both events.
		// Because we don't enforce the timeout yet. We should add some synchronizations
		// within the runnable to prevent the race condition to log both events.
		if (mCancellationKeyPhraseDetectionFuture != null) {
		mCancellationKeyPhraseDetectionFuture.cancel(true);
		}
		HotwordMetricsLogger.writeKeyphraseTriggerEvent(
		mDetectorType,
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__DETECTED);
		if (!mValidatingDspTrigger) {
		Slog.i(TAG, "Ignoring #onDetected due to a process restart");
		HotwordMetricsLogger.writeKeyphraseTriggerEvent(
		mDetectorType,
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__DETECT_EXCEPTION);
		return;
		}
		mValidatingDspTrigger = false;
		try {
		enforcePermissionsForDataDelivery();
		} catch (SecurityException e) {
		HotwordMetricsLogger.writeKeyphraseTriggerEvent(
		mDetectorType,
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__DETECT_EXCEPTION);
		throw e;
		}
		externalCallback.onKeyphraseDetected(recognitionEvent, result);
		if (result != null) {
		Slog.i(TAG, "Egressed " + HotwordDetectedResult.getUsageSize(result)
		@@ -504,8 +587,17 @@ final class HotwordDetectionConnection {
		Slog.d(TAG, "onRejected");
		}
		synchronized (mLock) {
		if (mCancellationKeyPhraseDetectionFuture != null) {
		mCancellationKeyPhraseDetectionFuture.cancel(true);
		}
		HotwordMetricsLogger.writeKeyphraseTriggerEvent(
		mDetectorType,
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__REJECTED);
		if (!mValidatingDspTrigger) {
		Slog.i(TAG, "Ignoring #onRejected due to a process restart");
		HotwordMetricsLogger.writeKeyphraseTriggerEvent(
		mDetectorType,
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__DETECT_EXCEPTION);
		return;
		}
		mValidatingDspTrigger = false;
		@@ -520,11 +612,20 @@ final class HotwordDetectionConnection {
		synchronized (mLock) {
		mValidatingDspTrigger = true;
		mRemoteHotwordDetectionService.run(
		service -> service.detectFromDspSource(
		service -> {
		// TODO: avoid allocate every time
		mCancellationKeyPhraseDetectionFuture = mScheduledExecutorService.schedule(
		() -> HotwordMetricsLogger
		.writeKeyphraseTriggerEvent(mDetectorType,
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__DETECT_TIMEOUT),
		VALIDATION_TIMEOUT_MILLIS,
		TimeUnit.MILLISECONDS);
		service.detectFromDspSource(
		recognitionEvent,
		recognitionEvent.getCaptureFormat(),
		VALIDATION_TIMEOUT_MILLIS,
		internalCallback));
		internalCallback);
		});
		}
		}

		@@ -625,10 +726,16 @@ final class HotwordDetectionConnection {
		}
		final boolean useHotwordDetectionService = mHotwordDetectionConnection != null;
		if (useHotwordDetectionService) {
		HotwordMetricsLogger.writeKeyphraseTriggerEvent(
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__DETECTOR_TYPE__TRUSTED_DETECTOR_DSP,
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__KEYPHRASE_TRIGGER);
		mRecognitionEvent = recognitionEvent;
		mHotwordDetectionConnection.detectFromDspSource(
		recognitionEvent, mExternalCallback);
		} else {
		HotwordMetricsLogger.writeKeyphraseTriggerEvent(
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__DETECTOR_TYPE__NORMAL_DETECTOR,
		HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__RESULT__KEYPHRASE_TRIGGER);
		mExternalCallback.onKeyphraseDetected(recognitionEvent, null);
		}
		}
		@@ -793,6 +900,7 @@ final class HotwordDetectionConnection {

		private boolean mRespectServiceConnectionStatusChanged = true;
		private boolean mIsBound = false;
		private boolean mIsLoggedFirstConnect = false;

		ServiceConnection(@NonNull Context context,
		@NonNull Intent intent, int bindingFlags, int userId,
		@@ -816,6 +924,12 @@ final class HotwordDetectionConnection {
		return;
		}
		mIsBound = connected;
		if (connected && !mIsLoggedFirstConnect) {
		mIsLoggedFirstConnect = true;
		HotwordMetricsLogger.writeDetectorEvent(mDetectorType,
		HOTWORD_DETECTOR_EVENTS__EVENT__ON_CONNECTED,
		mVoiceInteractionServiceUid);
		}
		}
		}

		@@ -846,13 +960,25 @@ final class HotwordDetectionConnection {
		protected boolean bindService(
		@NonNull android.content.ServiceConnection serviceConnection) {
		try {
		return mContext.bindIsolatedService(
		HotwordMetricsLogger.writeDetectorEvent(mDetectorType,
		HOTWORD_DETECTOR_EVENTS__EVENT__REQUEST_BIND_SERVICE,
		mVoiceInteractionServiceUid);
		boolean bindResult = mContext.bindIsolatedService(
		mIntent,
		Context.BIND_AUTO_CREATE \| Context.BIND_FOREGROUND_SERVICE \| mBindingFlags,
		"hotword_detector_" + mInstanceNumber,
		mExecutor,
		serviceConnection);
		if (!bindResult) {
		HotwordMetricsLogger.writeDetectorEvent(mDetectorType,
		HOTWORD_DETECTOR_EVENTS__EVENT__REQUEST_BIND_SERVICE_FAIL,
		mVoiceInteractionServiceUid);
		}
		return bindResult;
		} catch (IllegalArgumentException e) {
		HotwordMetricsLogger.writeDetectorEvent(mDetectorType,
		HOTWORD_DETECTOR_EVENTS__EVENT__REQUEST_BIND_SERVICE_FAIL,
		mVoiceInteractionServiceUid);
		Slog.wtf(TAG, "Can't bind to the hotword detection service!", e);
		return false;
		}

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

+91 −6

File changed.

Preview size limit exceeded, changes collapsed.

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

+24 −0

Original line number	Diff line number	Diff line
		@@ -462,24 +462,33 @@ class VoiceInteractionManagerServiceImpl implements VoiceInteractionSessionConne
		IHotwordRecognitionStatusCallback callback,
		int detectorType) {
		Slog.v(TAG, "updateStateLocked");
		int voiceInteractionServiceUid = mInfo.getServiceInfo().applicationInfo.uid;
		if (mHotwordDetectionComponentName == null) {
		Slog.w(TAG, "Hotword detection service name not found");
		logDetectorCreateEventIfNeeded(callback, detectorType, false,
		voiceInteractionServiceUid);
		throw new IllegalStateException("Hotword detection service name not found");
		}
		ServiceInfo hotwordDetectionServiceInfo = getServiceInfoLocked(
		mHotwordDetectionComponentName, mUser);
		if (hotwordDetectionServiceInfo == null) {
		Slog.w(TAG, "Hotword detection service info not found");
		logDetectorCreateEventIfNeeded(callback, detectorType, false,
		voiceInteractionServiceUid);
		throw new IllegalStateException("Hotword detection service info not found");
		}
		if (!isIsolatedProcessLocked(hotwordDetectionServiceInfo)) {
		Slog.w(TAG, "Hotword detection service not in isolated process");
		logDetectorCreateEventIfNeeded(callback, detectorType, false,
		voiceInteractionServiceUid);
		throw new IllegalStateException("Hotword detection service not in isolated process");
		}
		if (!Manifest.permission.BIND_HOTWORD_DETECTION_SERVICE.equals(
		hotwordDetectionServiceInfo.permission)) {
		Slog.w(TAG, "Hotword detection service does not require permission "
		+ Manifest.permission.BIND_HOTWORD_DETECTION_SERVICE);
		logDetectorCreateEventIfNeeded(callback, detectorType, false,
		voiceInteractionServiceUid);
		throw new SecurityException("Hotword detection service does not require permission "
		+ Manifest.permission.BIND_HOTWORD_DETECTION_SERVICE);
		}
		@@ -488,17 +497,23 @@ class VoiceInteractionManagerServiceImpl implements VoiceInteractionSessionConne
		mInfo.getServiceInfo().packageName) == PackageManager.PERMISSION_GRANTED) {
		Slog.w(TAG, "Voice interaction service should not hold permission "
		+ Manifest.permission.BIND_HOTWORD_DETECTION_SERVICE);
		logDetectorCreateEventIfNeeded(callback, detectorType, false,
		voiceInteractionServiceUid);
		throw new SecurityException("Voice interaction service should not hold permission "
		+ Manifest.permission.BIND_HOTWORD_DETECTION_SERVICE);
		}

		if (sharedMemory != null && !sharedMemory.setProtect(OsConstants.PROT_READ)) {
		Slog.w(TAG, "Can't set sharedMemory to be read-only");
		logDetectorCreateEventIfNeeded(callback, detectorType, false,
		voiceInteractionServiceUid);
		throw new IllegalStateException("Can't set sharedMemory to be read-only");
		}

		mDetectorType = detectorType;

		logDetectorCreateEventIfNeeded(callback, detectorType, true,
		voiceInteractionServiceUid);
		if (mHotwordDetectionConnection == null) {
		mHotwordDetectionConnection = new HotwordDetectionConnection(mServiceStub, mContext,
		mInfo.getServiceInfo().applicationInfo.uid, voiceInteractorIdentity,
		@@ -509,6 +524,15 @@ class VoiceInteractionManagerServiceImpl implements VoiceInteractionSessionConne
		}
		}

		private void logDetectorCreateEventIfNeeded(IHotwordRecognitionStatusCallback callback,
		int detectorType, boolean isCreated, int voiceInteractionServiceUid) {
		if (callback != null) {
		HotwordMetricsLogger.writeDetectorCreateEvent(detectorType, true,
		voiceInteractionServiceUid);
		}

		}

		public void shutdownHotwordDetectionServiceLocked() {
		if (DEBUG) {
		Slog.d(TAG, "shutdownHotwordDetectionServiceLocked");