From 64c62ca506e104885518a9bb7f48aaa9670ccfd5 Mon Sep 17 00:00:00 2001 From: Ytai Ben-Tsvi Date: Wed, 6 Apr 2022 11:29:40 -0700 Subject: [PATCH 1/2] Revert "Wait for an abort event when stopping a model" This reverts commit 6e2eb81ac4687ac5340673ff996c0591154def7f. The original commit fixed b/223922855, which resulted from fixing b/191935600, but created another. Blocking the stop() call until the event confirming the stop arrives is a bad idea, since: - We have to give up the lock when waiting for the event, and thus lose the atomicity of some of the operations. b/226926627 is an example of this. - It turns out some of the forward calls happen from the main thread's looper, which is also used for callbacks, and we risk deadlocks. A follow-up commit will address the fix in a better way. Bug: 191935600 Bug: 226926627 Bug: 223922855 Test: See next commit in the chain. Change-Id: I2b9987ae93803d3b4f72a1df56c88e284bed43c5 --- .../soundtrigger/SoundTriggerHelper.java | 82 +++++++------------ 1 file changed, 29 insertions(+), 53 deletions(-) diff --git a/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java b/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java index ee2d235580102..3aa0ddd26e2d3 100644 --- a/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java +++ b/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java @@ -84,9 +84,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { private static final int INVALID_VALUE = Integer.MIN_VALUE; - /** Maximum time to wait for a model stop confirmation before giving up. */ - private static final long STOP_TIMEOUT_MS = 5000; - /** The {@link ModuleProperties} for the system, or null if none exists. */ final ModuleProperties mModuleProperties; @@ -834,7 +831,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } if (!event.recognitionStillActive) { - model.setStoppedLocked(); + model.setStopped(); } try { @@ -921,7 +918,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { MetricsLogger.count(mContext, "sth_recognition_aborted", 1); ModelData modelData = getModelDataForLocked(event.soundModelHandle); if (modelData != null && modelData.isModelStarted()) { - modelData.setStoppedLocked(); + modelData.setStopped(); try { IRecognitionStatusCallback callback = modelData.getCallback(); if (callback != null) { @@ -978,7 +975,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } if (!event.recognitionStillActive) { - modelData.setStoppedLocked(); + modelData.setStopped(); } try { @@ -1206,7 +1203,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { if (modelData.isModelStarted()) { Slog.d(TAG, "Stopping previously started dangling model " + modelData.getHandle()); if (mModule.stopRecognition(modelData.getHandle()) == STATUS_OK) { - modelData.setStoppedLocked(); + modelData.setStopped(); modelData.setRequested(false); } else { Slog.e(TAG, "Failed to stop model " + modelData.getHandle()); @@ -1255,7 +1252,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { private ModelData getOrCreateGenericModelDataLocked(UUID modelId) { ModelData modelData = mModelDataMap.get(modelId); if (modelData == null) { - modelData = createGenericModelData(modelId); + modelData = ModelData.createGenericModelData(modelId); mModelDataMap.put(modelId, modelData); } else if (!modelData.isGenericModel()) { Slog.e(TAG, "UUID already used for non-generic model."); @@ -1287,7 +1284,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { mKeyphraseUuidMap.remove(keyphraseId); mModelDataMap.remove(modelId); mKeyphraseUuidMap.put(keyphraseId, modelId); - ModelData modelData = createKeyphraseModelData(modelId); + ModelData modelData = ModelData.createKeyphraseModelData(modelId); mModelDataMap.put(modelId, modelData); return modelData; } @@ -1419,26 +1416,18 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { Slog.w(TAG, "RemoteException in onError", e); } } - return status; - } - - // Wait for model to be stopped. - try { - modelData.waitStoppedLocked(STOP_TIMEOUT_MS); - } catch (InterruptedException e) { - Slog.e(TAG, "Didn't receive model stop callback"); - return SoundTrigger.STATUS_ERROR; - } - - MetricsLogger.count(mContext, "sth_stop_recognition_success", 1); - // Notify of pause if needed. - if (notify) { - try { - callback.onRecognitionPaused(); - } catch (DeadObjectException e) { - forceStopAndUnloadModelLocked(modelData, e); - } catch (RemoteException e) { - Slog.w(TAG, "RemoteException in onRecognitionPaused", e); + } else { + modelData.setStopped(); + MetricsLogger.count(mContext, "sth_stop_recognition_success", 1); + // Notify of pause if needed. + if (notify) { + try { + callback.onRecognitionPaused(); + } catch (DeadObjectException e) { + forceStopAndUnloadModelLocked(modelData, e); + } catch (RemoteException e) { + Slog.w(TAG, "RemoteException in onRecognitionPaused", e); + } } } if (DBG) { @@ -1473,7 +1462,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { // This class encapsulates the callbacks, state, handles and any other information that // represents a model. - private class ModelData { + private static class ModelData { // Model not loaded (and hence not started). static final int MODEL_NOTLOADED = 0; @@ -1530,9 +1519,17 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { mModelType = modelType; } + static ModelData createKeyphraseModelData(UUID modelId) { + return new ModelData(modelId, SoundModel.TYPE_KEYPHRASE); + } + + static ModelData createGenericModelData(UUID modelId) { + return new ModelData(modelId, SoundModel.TYPE_GENERIC_SOUND); + } + // Note that most of the functionality in this Java class will not work for // SoundModel.TYPE_UNKNOWN nevertheless we have it since lower layers support it. - ModelData createModelDataOfUnknownType(UUID modelId) { + static ModelData createModelDataOfUnknownType(UUID modelId) { return new ModelData(modelId, SoundModel.TYPE_UNKNOWN); } @@ -1556,20 +1553,8 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { mModelState = MODEL_STARTED; } - synchronized void setStoppedLocked() { + synchronized void setStopped() { mModelState = MODEL_LOADED; - mLock.notifyAll(); - } - - void waitStoppedLocked(long timeoutMs) throws InterruptedException { - long deadline = System.currentTimeMillis() + timeoutMs; - while (mModelState == MODEL_STARTED) { - long waitTime = deadline - System.currentTimeMillis(); - if (waitTime <= 0) { - throw new InterruptedException(); - } - mLock.wait(waitTime); - } } synchronized void setLoaded() { @@ -1589,7 +1574,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { mRecognitionConfig = null; mRequested = false; mCallback = null; - notifyAll(); } synchronized void clearCallback() { @@ -1694,12 +1678,4 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { return "Model type: " + type + "\n"; } } - - ModelData createKeyphraseModelData(UUID modelId) { - return new ModelData(modelId, SoundModel.TYPE_KEYPHRASE); - } - - ModelData createGenericModelData(UUID modelId) { - return new ModelData(modelId, SoundModel.TYPE_GENERIC_SOUND); - } } From f3e7be00588ea67dfaeb8be3847802d238a9a974 Mon Sep 17 00:00:00 2001 From: Ytai Ben-Tsvi Date: Wed, 6 Apr 2022 15:53:38 -0700 Subject: [PATCH 2/2] Wait for an abort event when stopping a model Because the client callbacks from SoundTriggerMiddleware service are async, if a client quickly stops and starts a model, then receives a detection event for that model, it is impossible for it to tell whether the event corresponding to the previous or current session, and thus is unable to reason about the resulting state of the model. To mitigate that, we will always wait for an abort event when a model is stopped before any other operation is attempted. This way the model state stays synchronized. Bug: 191935600 Fixes: 226926627 Test: Manual verification of soundtrigger use-cases. Specifically, quick toggling of Assitant and Now Playing via Settings. Change-Id: Ia1b91e78aa6981a7b3612ae9213af1b37a333d00 --- .../soundtrigger/SoundTriggerHelper.java | 47 +++++++++++-------- 1 file changed, 28 insertions(+), 19 deletions(-) diff --git a/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java b/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java index 3aa0ddd26e2d3..b71669046ee9e 100644 --- a/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java +++ b/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java @@ -395,20 +395,8 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { return STATUS_OK; } - int status = prepareForRecognition(modelData); - if (status != STATUS_OK) { - Slog.w(TAG, "startRecognition failed to prepare model for recognition"); - return status; - } - status = startRecognitionLocked(modelData, + return updateRecognitionLocked(modelData, false /* Don't notify for synchronous calls */); - - // Initialize power save, call active state monitoring logic. - if (status == STATUS_OK) { - initializeDeviceStateListeners(); - } - - return status; } } @@ -557,7 +545,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } } - if (unloadModel && modelData.isModelLoaded()) { + if (unloadModel && (modelData.isModelLoaded() || modelData.isStopPending())) { Slog.d(TAG, "Unloading previously loaded stale model."); if (mModule == null) { return STATUS_ERROR; @@ -917,7 +905,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { Slog.w(TAG, "Recognition aborted"); MetricsLogger.count(mContext, "sth_recognition_aborted", 1); ModelData modelData = getModelDataForLocked(event.soundModelHandle); - if (modelData != null && modelData.isModelStarted()) { + if (modelData != null && (modelData.isModelStarted() || modelData.isStopPending())) { modelData.setStopped(); try { IRecognitionStatusCallback callback = modelData.getCallback(); @@ -929,6 +917,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } catch (RemoteException e) { Slog.w(TAG, "RemoteException in onRecognitionPaused", e); } + updateRecognitionLocked(modelData, true); } } @@ -1008,16 +997,22 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { private int updateRecognitionLocked(ModelData model, boolean notifyClientOnError) { boolean shouldStartModel = model.isRequested() && isRecognitionAllowedByDeviceState(model); - if (shouldStartModel == model.isModelStarted()) { + if (shouldStartModel == model.isModelStarted() || model.isStopPending()) { // No-op. return STATUS_OK; } if (shouldStartModel) { int status = prepareForRecognition(model); if (status != STATUS_OK) { + Slog.w(TAG, "startRecognition failed to prepare model for recognition"); return status; } - return startRecognitionLocked(model, notifyClientOnError); + status = startRecognitionLocked(model, notifyClientOnError); + // Initialize power save, call active state monitoring logic. + if (status == STATUS_OK) { + initializeDeviceStateListeners(); + } + return status; } else { return stopRecognitionLocked(model, notifyClientOnError); } @@ -1200,7 +1195,10 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { if (mModule == null) { return; } - if (modelData.isModelStarted()) { + if (modelData.isStopPending()) { + // No need to wait for the stop to be confirmed. + modelData.setStopped(); + } else if (modelData.isModelStarted()) { Slog.d(TAG, "Stopping previously started dangling model " + modelData.getHandle()); if (mModule.stopRecognition(modelData.getHandle()) == STATUS_OK) { modelData.setStopped(); @@ -1417,7 +1415,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } } } else { - modelData.setStopped(); + modelData.setStopPending(); MetricsLogger.count(mContext, "sth_stop_recognition_success", 1); // Notify of pause if needed. if (notify) { @@ -1472,6 +1470,9 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { // Started implies model was successfully loaded and start was called. static final int MODEL_STARTED = 2; + // Model stop request has been sent. Waiting for an event to signal model being stopped. + static final int MODEL_STOP_PENDING = 3; + // One of MODEL_NOTLOADED, MODEL_LOADED, MODEL_STARTED (which implies loaded). private int mModelState; private UUID mModelId; @@ -1549,6 +1550,10 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { return mModelState == MODEL_NOTLOADED; } + synchronized boolean isStopPending() { + return mModelState == MODEL_STOP_PENDING; + } + synchronized void setStarted() { mModelState = MODEL_STARTED; } @@ -1557,6 +1562,10 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { mModelState = MODEL_LOADED; } + synchronized void setStopPending() { + mModelState = MODEL_STOP_PENDING; + } + synchronized void setLoaded() { mModelState = MODEL_LOADED; }