diff --git a/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java b/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java index efe300951dc89..bee75dfe785f8 100644 --- a/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java +++ b/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerHelper.java @@ -16,6 +16,9 @@ package com.android.server.soundtrigger; +import static com.android.server.soundtrigger.SoundTriggerEvent.SessionEvent.Type; +import static com.android.server.utils.EventLogger.Event.ALOGW; + import android.annotation.NonNull; import android.annotation.Nullable; import android.content.BroadcastReceiver; @@ -51,6 +54,9 @@ import android.util.Slog; import com.android.internal.annotations.GuardedBy; import com.android.internal.logging.MetricsLogger; +import com.android.server.soundtrigger.SoundTriggerEvent.SessionEvent; +import com.android.server.utils.EventLogger.Event; +import com.android.server.utils.EventLogger; import java.io.FileDescriptor; import java.io.PrintWriter; @@ -76,7 +82,6 @@ import java.util.function.Supplier; */ public class SoundTriggerHelper implements SoundTrigger.StatusListener { static final String TAG = "SoundTriggerHelper"; - static final boolean DBG = false; // Module ID if there is no available module to connect to. public static final int INVALID_MODULE_ID = -1; @@ -129,11 +134,12 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { private final int mModuleId; private final Function mModuleProvider; private final Supplier> mModulePropertiesProvider; + private final EventLogger mEventLogger; @GuardedBy("mLock") private boolean mIsDetached = false; - SoundTriggerHelper(Context context, + SoundTriggerHelper(Context context, EventLogger eventLogger, @NonNull Function moduleProvider, int moduleId, @NonNull Supplier> modulePropertiesProvider) { @@ -144,6 +150,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { mModelDataMap = new HashMap(); mKeyphraseUuidMap = new HashMap(); mModuleProvider = moduleProvider; + mEventLogger = eventLogger; mModulePropertiesProvider = modulePropertiesProvider; if (moduleId == INVALID_MODULE_ID) { mModule = null; @@ -234,14 +241,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { throw new IllegalStateException("SoundTriggerHelper has been detached"); } - if (DBG) { - Slog.d(TAG, "startKeyphraseRecognition for keyphraseId=" + keyphraseId - + " soundModel=" + soundModel + ", callback=" + callback.asBinder() - + ", recognitionConfig=" + recognitionConfig - + ", runInBatterySaverMode=" + runInBatterySaverMode); - dumpModelStateLocked(); - } - ModelData model = getKeyphraseModelDataLocked(keyphraseId); if (model != null && !model.isKeyphraseModel()) { Slog.e(TAG, "Generic model with same UUID exists."); @@ -301,9 +300,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } modelData.setHandle(handle[0]); modelData.setLoaded(); - if (DBG) { - Slog.d(TAG, "prepareForRecognition: Sound model loaded with handle:" + handle[0]); - } } return STATUS_OK; } @@ -448,13 +444,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { return STATUS_ERROR; } - if (DBG) { - Slog.d(TAG, "stopRecognition for keyphraseId=" + keyphraseId + ", callback =" + - callback.asBinder()); - Slog.d(TAG, "current callback=" - + ((modelData == null || modelData.getCallback() == null) ? "null" : - modelData.getCallback().asBinder())); - } int status = stopRecognition(modelData, callback); if (status != SoundTrigger.STATUS_OK) { return status; @@ -635,7 +624,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { // Remove it from existence. mModelDataMap.remove(modelId); - if (DBG) dumpModelStateLocked(); return status; } } @@ -797,7 +785,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { return; } - if (DBG) Slog.d(TAG, "onRecognition: " + event); synchronized (mLock) { switch (event.status) { case SoundTrigger.RECOGNITION_STATUS_ABORT: @@ -845,12 +832,14 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } try { + mEventLogger.enqueue(new SessionEvent(Type.RECOGNITION, model.getModelId())); callback.onGenericSoundTriggerDetected((GenericRecognitionEvent) event); - } catch (DeadObjectException e) { + } catch (RemoteException e) { + mEventLogger.enqueue(new SessionEvent( + Type.RECOGNITION, model.getModelId(), "RemoteException") + .printLog(ALOGW, TAG)); forceStopAndUnloadModelLocked(model, e); return; - } catch (RemoteException e) { - Slog.w(TAG, "RemoteException in onGenericSoundTriggerDetected", e); } RecognitionConfig config = model.getRecognitionConfig(); @@ -869,7 +858,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { @Override public void onModelUnloaded(int modelHandle) { - if (DBG) Slog.d(TAG, "onModelUnloaded: " + modelHandle); synchronized (mLock) { MetricsLogger.count(mContext, "sth_sound_model_updated", 1); onModelUnloadedLocked(modelHandle); @@ -878,7 +866,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { @Override public void onResourcesAvailable() { - if (DBG) Slog.d(TAG, "onResourcesAvailable"); synchronized (mLock) { onResourcesAvailableLocked(); } @@ -920,6 +907,7 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } private void onResourcesAvailableLocked() { + mEventLogger.enqueue(new SessionEvent(Type.RESOURCES_AVAILABLE, null)); updateAllRecognitionsLocked(); } @@ -932,12 +920,14 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { try { IRecognitionStatusCallback callback = modelData.getCallback(); if (callback != null) { + mEventLogger.enqueue(new SessionEvent(Type.PAUSE, modelData.getModelId())); callback.onRecognitionPaused(); } - } catch (DeadObjectException e) { - forceStopAndUnloadModelLocked(modelData, e); } catch (RemoteException e) { - Slog.w(TAG, "RemoteException in onRecognitionPaused", e); + mEventLogger.enqueue(new SessionEvent( + Type.PAUSE, modelData.getModelId(), "RemoteException") + .printLog(ALOGW, TAG)); + forceStopAndUnloadModelLocked(modelData, e); } updateRecognitionLocked(modelData, true); } @@ -979,12 +969,14 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } try { + mEventLogger.enqueue(new SessionEvent(Type.RECOGNITION, modelData.getModelId())); modelData.getCallback().onKeyphraseDetected((KeyphraseRecognitionEvent) event); - } catch (DeadObjectException e) { + } catch (RemoteException e) { + mEventLogger.enqueue(new SessionEvent( + Type.RECOGNITION, modelData.getModelId(), "RemoteException") + .printLog(ALOGW, TAG)); forceStopAndUnloadModelLocked(modelData, e); return; - } catch (RemoteException e) { - Slog.w(TAG, "RemoteException in onKeyphraseDetected", e); } RecognitionConfig config = modelData.getRecognitionConfig(); @@ -1036,10 +1028,13 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { IRecognitionStatusCallback callback = modelData.getCallback(); if (callback != null) { try { + mEventLogger.enqueue(new SessionEvent(Type.MODULE_DIED, + modelData.getModelId()).printLog(ALOGW, TAG)); callback.onModuleDied(); } catch (RemoteException e) { - Slog.w(TAG, "RemoteException send moduleDied for model handle " + - modelData.getHandle(), e); + mEventLogger.enqueue(new SessionEvent(Type.MODULE_DIED, + modelData.getModelId(), "RemoteException") + .printLog(ALOGW, TAG)); } } } @@ -1085,7 +1080,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { @Override public void onCallStateChanged(int state, String arg1) { - if (DBG) Slog.d(TAG, "onCallStateChanged: " + state); if (mHandler != null) { synchronized (mLock) { @@ -1107,9 +1101,6 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { } @SoundTriggerPowerSaveMode int soundTriggerPowerSaveMode = mPowerManager.getSoundTriggerPowerSaveMode(); - if (DBG) { - Slog.d(TAG, "onPowerSaveModeChanged: " + soundTriggerPowerSaveMode); - } synchronized (mLock) { onPowerSaveModeChangedLocked(soundTriggerPowerSaveMode); } @@ -1151,13 +1142,13 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { public void detach() { synchronized (mLock) { if (mIsDetached) return; + mIsDetached = true; for (ModelData model : mModelDataMap.values()) { forceStopAndUnloadModelLocked(model, null); } mModelDataMap.clear(); internalClearGlobalStateLocked(); if (mModule != null) { - mIsDetached = true; mModule.detach(); mModule = null; } @@ -1361,11 +1352,16 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { // Notify of error if needed. if (notifyClientOnError) { try { + mEventLogger.enqueue(new SessionEvent(Type.RESUME_FAILED, + modelData.getModelId(), String.valueOf(status)) + .printLog(ALOGW, TAG)); callback.onResumeFailed(status); - } catch (DeadObjectException e) { - forceStopAndUnloadModelLocked(modelData, e); } catch (RemoteException e) { - Slog.w(TAG, "RemoteException in onResumeFailed", e); + mEventLogger.enqueue(new SessionEvent(Type.RESUME_FAILED, + modelData.getModelId(), + String.valueOf(status) + " - RemoteException") + .printLog(ALOGW, TAG)); + forceStopAndUnloadModelLocked(modelData, e); } } } else { @@ -1375,17 +1371,16 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { // Notify of resume if needed. if (notifyClientOnError) { try { + mEventLogger.enqueue(new SessionEvent(Type.RESUME, + modelData.getModelId())); callback.onRecognitionResumed(); - } catch (DeadObjectException e) { - forceStopAndUnloadModelLocked(modelData, e); } catch (RemoteException e) { - Slog.w(TAG, "RemoteException in onRecognitionResumed", e); + mEventLogger.enqueue(new SessionEvent(Type.RESUME, + modelData.getModelId(), "RemoteException").printLog(ALOGW, TAG)); + forceStopAndUnloadModelLocked(modelData, e); } } } - if (DBG) { - Slog.d(TAG, "Model being started :" + modelData.toString()); - } return status; } @@ -1405,11 +1400,16 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { MetricsLogger.count(mContext, "sth_stop_recognition_error", 1); if (notify) { try { + mEventLogger.enqueue(new SessionEvent(Type.PAUSE_FAILED, + modelData.getModelId(), String.valueOf(status)) + .printLog(ALOGW, TAG)); callback.onPauseFailed(status); - } catch (DeadObjectException e) { - forceStopAndUnloadModelLocked(modelData, e); } catch (RemoteException e) { - Slog.w(TAG, "RemoteException in onPauseFailed", e); + mEventLogger.enqueue(new SessionEvent(Type.PAUSE_FAILED, + modelData.getModelId(), + String.valueOf(status) + " - RemoteException") + .printLog(ALOGW, TAG)); + forceStopAndUnloadModelLocked(modelData, e); } } } else { @@ -1418,27 +1418,19 @@ public class SoundTriggerHelper implements SoundTrigger.StatusListener { // Notify of pause if needed. if (notify) { try { + mEventLogger.enqueue(new SessionEvent(Type.PAUSE, + modelData.getModelId())); callback.onRecognitionPaused(); - } catch (DeadObjectException e) { - forceStopAndUnloadModelLocked(modelData, e); } catch (RemoteException e) { - Slog.w(TAG, "RemoteException in onRecognitionPaused", e); + mEventLogger.enqueue(new SessionEvent(Type.PAUSE, + modelData.getModelId(), "RemoteException").printLog(ALOGW, TAG)); + forceStopAndUnloadModelLocked(modelData, e); } } } - if (DBG) { - Slog.d(TAG, "Model being stopped :" + modelData.toString()); - } return status; } - private void dumpModelStateLocked() { - for (UUID modelId : mModelDataMap.keySet()) { - ModelData modelData = mModelDataMap.get(modelId); - Slog.i(TAG, "Model :" + modelData.toString()); - } - } - // Computes whether we have any recognition running at all (voice or generic). Sets // the mRecognitionRequested variable with the result. private boolean computeRecognitionRequestedLocked() { diff --git a/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerService.java b/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerService.java index b6673ad1e3880..77e53177e6a81 100644 --- a/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerService.java +++ b/services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerService.java @@ -31,6 +31,9 @@ import static android.hardware.soundtrigger.SoundTrigger.STATUS_OK; import static android.provider.Settings.Global.MAX_SOUND_TRIGGER_DETECTION_SERVICE_OPS_PER_DAY; import static android.provider.Settings.Global.SOUND_TRIGGER_DETECTION_SERVICE_OP_TIMEOUT; +import static com.android.server.soundtrigger.SoundTriggerEvent.SessionEvent.Type; +import static com.android.server.utils.EventLogger.Event.ALOGW; + import static com.android.internal.util.function.pooled.PooledLambda.obtainMessage; import android.Manifest; @@ -83,6 +86,7 @@ import android.os.UserHandle; import android.provider.Settings; import android.util.ArrayMap; import android.util.ArraySet; +import android.util.SparseArray; import android.util.Slog; import com.android.internal.annotations.GuardedBy; @@ -90,6 +94,9 @@ import com.android.internal.app.ISoundTriggerService; import com.android.internal.app.ISoundTriggerSession; import com.android.server.SoundTriggerInternal; import com.android.server.SystemService; +import com.android.server.soundtrigger.SoundTriggerEvent.ServiceEvent; +import com.android.server.soundtrigger.SoundTriggerEvent.SessionEvent; +import com.android.server.utils.EventLogger.Event; import com.android.server.utils.EventLogger; import java.io.FileDescriptor; @@ -97,11 +104,16 @@ import java.io.PrintWriter; import java.util.ArrayList; import java.util.Arrays; import java.util.List; +import java.util.Set; +import java.util.Deque; import java.util.Map; import java.util.Objects; import java.util.TreeMap; import java.util.UUID; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.LinkedBlockingDeque; import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicInteger; import java.util.stream.Collectors; /** @@ -116,6 +128,7 @@ import java.util.stream.Collectors; public class SoundTriggerService extends SystemService { private static final String TAG = "SoundTriggerService"; private static final boolean DEBUG = true; + private static final int SESSION_MAX_EVENT_SIZE = 128; final Context mContext; private Object mLock; @@ -123,6 +136,12 @@ public class SoundTriggerService extends SystemService { private final LocalSoundTriggerService mLocalSoundTriggerService; private SoundTriggerDbHelper mDbHelper; + private final EventLogger mServiceEventLogger = new EventLogger(256, "Service"); + + private final Set mSessionEventLoggers = ConcurrentHashMap.newKeySet(4); + private final Deque mDetachedSessionEventLoggers = new LinkedBlockingDeque<>(4); + private AtomicInteger mSessionIdCounter = new AtomicInteger(0); + class SoundModelStatTracker { private class SoundModelStat { SoundModelStat() { @@ -164,7 +183,7 @@ public class SoundTriggerService extends SystemService { public synchronized void onStop(UUID id) { SoundModelStat stat = mModelStats.get(id); if (stat == null) { - Slog.w(TAG, "error onStop(): Model " + id + " has no stats available"); + Slog.i(TAG, "error onStop(): Model " + id + " has no stats available"); return; } @@ -241,7 +260,9 @@ public class SoundTriggerService extends SystemService { } } - private SoundTriggerHelper newSoundTriggerHelper(ModuleProperties moduleProperties) { + private SoundTriggerHelper newSoundTriggerHelper( + ModuleProperties moduleProperties, EventLogger eventLogger) { + Identity middlemanIdentity = new Identity(); middlemanIdentity.packageName = ActivityThread.currentOpPackageName(); Identity originatorIdentity = IdentityContext.getNonNull(); @@ -260,6 +281,7 @@ public class SoundTriggerService extends SystemService { return new SoundTriggerHelper( mContext, + eventLogger, (SoundTrigger.StatusListener statusListener) -> SoundTrigger.attachModuleAsMiddleman( moduleId, statusListener, null /* handler */, @@ -269,14 +291,33 @@ public class SoundTriggerService extends SystemService { ); } + // Helper to add session logger to the capacity limited detached list. + // If we are at capacity, remove the oldest, and retry + private void addDetachedSessionLogger(EventLogger logger) { + // Attempt to push to the top of the queue + while (!mDetachedSessionEventLoggers.offerFirst(logger)) { + // Remove the oldest element, if one still exists + mDetachedSessionEventLoggers.pollLast(); + } + } + class SoundTriggerServiceStub extends ISoundTriggerService.Stub { @Override public ISoundTriggerSession attachAsOriginator(@NonNull Identity originatorIdentity, @NonNull ModuleProperties moduleProperties, @NonNull IBinder client) { + + int sessionId = mSessionIdCounter.getAndIncrement(); + mServiceEventLogger.enqueue(new ServiceEvent( + ServiceEvent.Type.ATTACH, originatorIdentity.packageName + "#" + sessionId)); try (SafeCloseable ignored = PermissionUtil.establishIdentityDirect( originatorIdentity)) { - return new SoundTriggerSessionStub(client, newSoundTriggerHelper(moduleProperties)); + var eventLogger = new EventLogger(SESSION_MAX_EVENT_SIZE, + "SoundTriggerSessionLogs for package: " + + Objects.requireNonNull(originatorIdentity.packageName) + + "#" + sessionId); + return new SoundTriggerSessionStub(client, + newSoundTriggerHelper(moduleProperties, eventLogger), eventLogger); } } @@ -285,15 +326,26 @@ public class SoundTriggerService extends SystemService { @NonNull Identity middlemanIdentity, @NonNull ModuleProperties moduleProperties, @NonNull IBinder client) { + + int sessionId = mSessionIdCounter.getAndIncrement(); + mServiceEventLogger.enqueue(new ServiceEvent( + ServiceEvent.Type.ATTACH, originatorIdentity.packageName + "#" + sessionId)); try (SafeCloseable ignored = PermissionUtil.establishIdentityIndirect(mContext, SOUNDTRIGGER_DELEGATE_IDENTITY, middlemanIdentity, originatorIdentity)) { - return new SoundTriggerSessionStub(client, newSoundTriggerHelper(moduleProperties)); + var eventLogger = new EventLogger(SESSION_MAX_EVENT_SIZE, + "SoundTriggerSessionLogs for package: " + + Objects.requireNonNull(originatorIdentity.packageName) + "#" + + sessionId); + return new SoundTriggerSessionStub(client, + newSoundTriggerHelper(moduleProperties, eventLogger), eventLogger); } } @Override public List listModuleProperties(@NonNull Identity originatorIdentity) { + mServiceEventLogger.enqueue(new ServiceEvent( + ServiceEvent.Type.LIST_MODULE, originatorIdentity.packageName)); try (SafeCloseable ignored = PermissionUtil.establishIdentityDirect( originatorIdentity)) { return listUnderlyingModuleProperties(originatorIdentity); @@ -316,6 +368,31 @@ public class SoundTriggerService extends SystemService { throw e.rethrowFromSystemServer(); } } + + @Override + public void dump(FileDescriptor fd, PrintWriter pw, String[] args) { + // Event loggers + pw.println("##Service-Wide logs:"); + mServiceEventLogger.dump(pw, /* indent = */ " "); + + pw.println("\n##Active Session dumps:\n"); + for (var sessionLogger : mSessionEventLoggers) { + sessionLogger.dump(pw, /* indent= */ " "); + pw.println(""); + } + pw.println("##Detached Session dumps:\n"); + for (var sessionLogger : mDetachedSessionEventLoggers) { + sessionLogger.dump(pw, /* indent= */ " "); + pw.println(""); + } + // enrolled models + pw.println("##Enrolled db dump:\n"); + mDbHelper.dump(pw); + + // stats + pw.println("\n##Sound Model Stats dump:\n"); + mSoundModelStatTracker.dump(pw); + } } class SoundTriggerSessionStub extends ISoundTriggerSession.Stub { @@ -326,17 +403,20 @@ public class SoundTriggerService extends SystemService { private final TreeMap mLoadedModels = new TreeMap<>(); private final Object mCallbacksLock = new Object(); private final TreeMap mCallbacks = new TreeMap<>(); + private final EventLogger mEventLogger; - SoundTriggerSessionStub(@NonNull IBinder client, SoundTriggerHelper soundTriggerHelper) { + SoundTriggerSessionStub(@NonNull IBinder client, + SoundTriggerHelper soundTriggerHelper, EventLogger eventLogger) { mSoundTriggerHelper = soundTriggerHelper; mClient = client; mOriginatorIdentity = IdentityContext.getNonNull(); + mEventLogger = eventLogger; + mSessionEventLoggers.add(mEventLogger); + try { - mClient.linkToDeath(() -> { - clientDied(); - }, 0); + mClient.linkToDeath(() -> clientDied(), 0); } catch (RemoteException e) { - Slog.e(TAG, "Failed to register death listener.", e); + clientDied(); } } @@ -344,11 +424,14 @@ public class SoundTriggerService extends SystemService { public int startRecognition(GenericSoundModel soundModel, IRecognitionStatusCallback callback, RecognitionConfig config, boolean runInBatterySaverMode) { + mEventLogger.enqueue(new SessionEvent(Type.START_RECOGNITION, getUuid(soundModel))); + try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); if (soundModel == null) { - Slog.e(TAG, "Null model passed to startRecognition"); + mEventLogger.enqueue(new SessionEvent(Type.START_RECOGNITION, + getUuid(soundModel), "Invalid sound model").printLog(ALOGW, TAG)); return STATUS_ERROR; } @@ -356,13 +439,6 @@ public class SoundTriggerService extends SystemService { enforceCallingPermission(Manifest.permission.SOUND_TRIGGER_RUN_IN_BATTERY_SAVER); } - if (DEBUG) { - Slog.i(TAG, "startRecognition(): Uuid : " + soundModel.toString()); - } - - sEventLogger.enqueue(new EventLogger.StringEvent( - "startRecognition(): Uuid : " + soundModel.getUuid().toString())); - int ret = mSoundTriggerHelper.startGenericRecognition(soundModel.getUuid(), soundModel, callback, config, runInBatterySaverMode); @@ -375,15 +451,9 @@ public class SoundTriggerService extends SystemService { @Override public int stopRecognition(ParcelUuid parcelUuid, IRecognitionStatusCallback callback) { + mEventLogger.enqueue(new SessionEvent(Type.STOP_RECOGNITION, getUuid(parcelUuid))); try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.i(TAG, "stopRecognition(): Uuid : " + parcelUuid); - } - - sEventLogger.enqueue(new EventLogger.StringEvent("stopRecognition(): Uuid : " - + parcelUuid)); - int ret = mSoundTriggerHelper.stopGenericRecognition(parcelUuid.getUuid(), callback); if (ret == STATUS_OK) { @@ -397,13 +467,6 @@ public class SoundTriggerService extends SystemService { public SoundTrigger.GenericSoundModel getSoundModel(ParcelUuid soundModelId) { try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.i(TAG, "getSoundModel(): id = " + soundModelId); - } - - sEventLogger.enqueue(new EventLogger.StringEvent("getSoundModel(): id = " - + soundModelId)); - SoundTrigger.GenericSoundModel model = mDbHelper.getGenericSoundModel( soundModelId.getUuid()); return model; @@ -412,29 +475,18 @@ public class SoundTriggerService extends SystemService { @Override public void updateSoundModel(SoundTrigger.GenericSoundModel soundModel) { + mEventLogger.enqueue(new SessionEvent(Type.UPDATE_MODEL, getUuid(soundModel))); try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.i(TAG, "updateSoundModel(): model = " + soundModel); - } - - sEventLogger.enqueue(new EventLogger.StringEvent("updateSoundModel(): model = " - + soundModel)); - mDbHelper.updateGenericSoundModel(soundModel); + mDbHelper.updateGenericSoundModel(soundModel); } } @Override public void deleteSoundModel(ParcelUuid soundModelId) { + mEventLogger.enqueue(new SessionEvent(Type.DELETE_MODEL, getUuid(soundModelId))); try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.i(TAG, "deleteSoundModel(): id = " + soundModelId); - } - - sEventLogger.enqueue(new EventLogger.StringEvent("deleteSoundModel(): id = " - + soundModelId)); - // Unload the model if it is loaded. mSoundTriggerHelper.unloadGenericSoundModel(soundModelId.getUuid()); @@ -447,22 +499,14 @@ public class SoundTriggerService extends SystemService { @Override public int loadGenericSoundModel(GenericSoundModel soundModel) { + mEventLogger.enqueue(new SessionEvent(Type.LOAD_MODEL, getUuid(soundModel))); try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); if (soundModel == null || soundModel.getUuid() == null) { - Slog.w(TAG, "Invalid sound model"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "loadGenericSoundModel(): Invalid sound model")); - + mEventLogger.enqueue(new SessionEvent(Type.LOAD_MODEL, + getUuid(soundModel), "Invalid sound model").printLog(ALOGW, TAG)); return STATUS_ERROR; } - if (DEBUG) { - Slog.i(TAG, "loadGenericSoundModel(): id = " + soundModel.getUuid()); - } - - sEventLogger.enqueue(new EventLogger.StringEvent("loadGenericSoundModel(): id = " - + soundModel.getUuid())); synchronized (mLock) { SoundModel oldModel = mLoadedModels.get(soundModel.getUuid()); @@ -483,32 +527,22 @@ public class SoundTriggerService extends SystemService { @Override public int loadKeyphraseSoundModel(KeyphraseSoundModel soundModel) { + mEventLogger.enqueue(new SessionEvent(Type.LOAD_MODEL, getUuid(soundModel))); + try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); if (soundModel == null || soundModel.getUuid() == null) { - Slog.w(TAG, "Invalid sound model"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "loadKeyphraseSoundModel(): Invalid sound model")); + mEventLogger.enqueue(new SessionEvent(Type.LOAD_MODEL, getUuid(soundModel), + "Invalid sound model").printLog(ALOGW, TAG)); return STATUS_ERROR; } if (soundModel.getKeyphrases() == null || soundModel.getKeyphrases().length != 1) { - Slog.w(TAG, "Only one keyphrase per model is currently supported."); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "loadKeyphraseSoundModel(): Only one keyphrase per model" - + " is currently supported.")); - + mEventLogger.enqueue(new SessionEvent(Type.LOAD_MODEL, getUuid(soundModel), + "Only one keyphrase supported").printLog(ALOGW, TAG)); return STATUS_ERROR; } - if (DEBUG) { - Slog.i(TAG, "loadKeyphraseSoundModel(): id = " + soundModel.getUuid()); - } - sEventLogger.enqueue( - new EventLogger.StringEvent("loadKeyphraseSoundModel(): id = " - + soundModel.getUuid())); synchronized (mLock) { SoundModel oldModel = mLoadedModels.get(soundModel.getUuid()); @@ -530,23 +564,17 @@ public class SoundTriggerService extends SystemService { @Override public int startRecognitionForService(ParcelUuid soundModelId, Bundle params, - ComponentName detectionService, SoundTrigger.RecognitionConfig config) { + ComponentName detectionService, SoundTrigger.RecognitionConfig config) { + mEventLogger.enqueue(new SessionEvent(Type.START_RECOGNITION_SERVICE, + getUuid(soundModelId))); try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { Objects.requireNonNull(soundModelId); Objects.requireNonNull(detectionService); Objects.requireNonNull(config); enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - enforceDetectionPermissions(detectionService); - if (DEBUG) { - Slog.i(TAG, "startRecognition(): id = " + soundModelId); - } - - sEventLogger.enqueue(new EventLogger.StringEvent( - "startRecognitionForService(): id = " + soundModelId)); - IRecognitionStatusCallback callback = new RemoteSoundTriggerDetectionService(soundModelId.getUuid(), params, detectionService, Binder.getCallingUserHandle(), config); @@ -554,10 +582,10 @@ public class SoundTriggerService extends SystemService { synchronized (mLock) { SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid()); if (soundModel == null) { - Slog.w(TAG, soundModelId + " is not loaded"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "startRecognitionForService():" + soundModelId + " is not loaded")); + mEventLogger.enqueue(new SessionEvent( + Type.START_RECOGNITION_SERVICE, + getUuid(soundModelId), + "Model not loaded").printLog(ALOGW, TAG)); return STATUS_ERROR; } @@ -566,12 +594,10 @@ public class SoundTriggerService extends SystemService { existingCallback = mCallbacks.get(soundModelId.getUuid()); } if (existingCallback != null) { - Slog.w(TAG, soundModelId + " is already running"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "startRecognitionForService():" - + soundModelId + " is already running")); - + mEventLogger.enqueue(new SessionEvent( + Type.START_RECOGNITION_SERVICE, + getUuid(soundModelId), + "Model already running").printLog(ALOGW, TAG)); return STATUS_ERROR; } int ret; @@ -581,20 +607,18 @@ public class SoundTriggerService extends SystemService { (GenericSoundModel) soundModel, callback, config, false); break; default: - Slog.e(TAG, "Unknown model type"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "startRecognitionForService(): Unknown model type")); - + mEventLogger.enqueue(new SessionEvent( + Type.START_RECOGNITION_SERVICE, + getUuid(soundModelId), + "Unsupported model type").printLog(ALOGW, TAG)); return STATUS_ERROR; } if (ret != STATUS_OK) { - Slog.e(TAG, "Failed to start model: " + ret); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "startRecognitionForService(): Failed to start model:")); - + mEventLogger.enqueue(new SessionEvent( + Type.START_RECOGNITION_SERVICE, + getUuid(soundModelId), + "Model start fail").printLog(ALOGW, TAG)); return ret; } synchronized (mCallbacksLock) { @@ -609,23 +633,20 @@ public class SoundTriggerService extends SystemService { @Override public int stopRecognitionForService(ParcelUuid soundModelId) { + mEventLogger.enqueue(new SessionEvent(Type.STOP_RECOGNITION_SERVICE, + getUuid(soundModelId))); + try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.i(TAG, "stopRecognition(): id = " + soundModelId); - } - - sEventLogger.enqueue(new EventLogger.StringEvent( - "stopRecognitionForService(): id = " + soundModelId)); synchronized (mLock) { SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid()); if (soundModel == null) { - Slog.w(TAG, soundModelId + " is not loaded"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "stopRecognitionForService(): " + soundModelId - + " is not loaded")); + mEventLogger.enqueue(new SessionEvent( + Type.STOP_RECOGNITION_SERVICE, + getUuid(soundModelId), + "Model not loaded") + .printLog(ALOGW, TAG)); return STATUS_ERROR; } @@ -634,12 +655,11 @@ public class SoundTriggerService extends SystemService { callback = mCallbacks.get(soundModelId.getUuid()); } if (callback == null) { - Slog.w(TAG, soundModelId + " is not running"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "stopRecognitionForService(): " + soundModelId - + " is not running")); - + mEventLogger.enqueue(new SessionEvent( + Type.STOP_RECOGNITION_SERVICE, + getUuid(soundModelId), + "Model not running") + .printLog(ALOGW, TAG)); return STATUS_ERROR; } int ret; @@ -649,20 +669,21 @@ public class SoundTriggerService extends SystemService { soundModel.getUuid(), callback); break; default: - Slog.e(TAG, "Unknown model type"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "stopRecognitionForService(): Unknown model type")); + mEventLogger.enqueue(new SessionEvent( + Type.STOP_RECOGNITION_SERVICE, + getUuid(soundModelId), + "Unknown model type") + .printLog(ALOGW, TAG)); return STATUS_ERROR; } if (ret != STATUS_OK) { - Slog.e(TAG, "Failed to stop model: " + ret); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "stopRecognitionForService(): Failed to stop model: " + ret)); - + mEventLogger.enqueue(new SessionEvent( + Type.STOP_RECOGNITION_SERVICE, + getUuid(soundModelId), + "Failed to stop model") + .printLog(ALOGW, TAG)); return ret; } synchronized (mCallbacksLock) { @@ -677,23 +698,18 @@ public class SoundTriggerService extends SystemService { @Override public int unloadSoundModel(ParcelUuid soundModelId) { + mEventLogger.enqueue(new SessionEvent(Type.UNLOAD_MODEL, getUuid(soundModelId))); try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.i(TAG, "unloadSoundModel(): id = " + soundModelId); - } - - sEventLogger.enqueue(new EventLogger.StringEvent("unloadSoundModel(): id = " - + soundModelId)); synchronized (mLock) { SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid()); if (soundModel == null) { - Slog.w(TAG, soundModelId + " is not loaded"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "unloadSoundModel(): " + soundModelId + " is not loaded")); - + mEventLogger.enqueue(new SessionEvent( + Type.UNLOAD_MODEL, + getUuid(soundModelId), + "Model not loaded") + .printLog(ALOGW, TAG)); return STATUS_ERROR; } int ret; @@ -706,19 +722,19 @@ public class SoundTriggerService extends SystemService { ret = mSoundTriggerHelper.unloadGenericSoundModel(soundModel.getUuid()); break; default: - Slog.e(TAG, "Unknown model type"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "unloadSoundModel(): Unknown model type")); - + mEventLogger.enqueue(new SessionEvent( + Type.UNLOAD_MODEL, + getUuid(soundModelId), + "Unknown model type") + .printLog(ALOGW, TAG)); return STATUS_ERROR; } if (ret != STATUS_OK) { - Slog.e(TAG, "Failed to unload model"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "unloadSoundModel(): Failed to unload model")); - + mEventLogger.enqueue(new SessionEvent( + Type.UNLOAD_MODEL, + getUuid(soundModelId), + "Failed to unload model") + .printLog(ALOGW, TAG)); return ret; } mLoadedModels.remove(soundModelId.getUuid()); @@ -743,24 +759,19 @@ public class SoundTriggerService extends SystemService { @Override public int getModelState(ParcelUuid soundModelId) { + mEventLogger.enqueue(new SessionEvent(Type.GET_MODEL_STATE, getUuid(soundModelId))); try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); int ret = STATUS_ERROR; - if (DEBUG) { - Slog.i(TAG, "getModelState(): id = " + soundModelId); - } - - sEventLogger.enqueue(new EventLogger.StringEvent("getModelState(): id = " - + soundModelId)); synchronized (mLock) { SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid()); if (soundModel == null) { - Slog.w(TAG, soundModelId + " is not loaded"); - - sEventLogger.enqueue(new EventLogger.StringEvent("getModelState(): " - + soundModelId + " is not loaded")); - + mEventLogger.enqueue(new SessionEvent( + Type.GET_MODEL_STATE, + getUuid(soundModelId), + "Model is not loaded") + .printLog(ALOGW, TAG)); return ret; } switch (soundModel.getType()) { @@ -769,13 +780,13 @@ public class SoundTriggerService extends SystemService { break; default: // SoundModel.TYPE_KEYPHRASE is not supported to increase privacy. - Slog.e(TAG, "Unsupported model type, " + soundModel.getType()); - sEventLogger.enqueue(new EventLogger.StringEvent( - "getModelState(): Unsupported model type, " - + soundModel.getType())); + mEventLogger.enqueue(new SessionEvent( + Type.GET_MODEL_STATE, + getUuid(soundModelId), + "Unsupported model type") + .printLog(ALOGW, TAG)); break; } - return ret; } } @@ -784,16 +795,11 @@ public class SoundTriggerService extends SystemService { @Override @Nullable public ModuleProperties getModuleProperties() { + mEventLogger.enqueue(new SessionEvent(Type.GET_MODULE_PROPERTIES, null)); try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.i(TAG, "getModuleProperties()"); - } - synchronized (mLock) { ModuleProperties properties = mSoundTriggerHelper.getModuleProperties(); - sEventLogger.enqueue(new EventLogger.StringEvent( - "getModuleProperties(): " + properties)); return properties; } } @@ -802,33 +808,21 @@ public class SoundTriggerService extends SystemService { @Override public int setParameter(ParcelUuid soundModelId, @ModelParams int modelParam, int value) { + mEventLogger.enqueue(new SessionEvent(Type.SET_PARAMETER, getUuid(soundModelId))); try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.d(TAG, "setParameter(): id=" + soundModelId - + ", param=" + modelParam - + ", value=" + value); - } - - sEventLogger.enqueue(new EventLogger.StringEvent( - "setParameter(): id=" + soundModelId - + ", param=" + modelParam - + ", value=" + value)); - synchronized (mLock) { SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid()); if (soundModel == null) { - Slog.w(TAG, soundModelId + " is not loaded. Loaded models: " - + mLoadedModels.toString()); - - sEventLogger.enqueue(new EventLogger.StringEvent("setParameter(): " - + soundModelId + " is not loaded")); - + mEventLogger.enqueue(new SessionEvent( + Type.SET_PARAMETER, + getUuid(soundModelId), + "Model not loaded") + .printLog(ALOGW, TAG)); return STATUS_BAD_VALUE; } - - return mSoundTriggerHelper.setParameter(soundModel.getUuid(), modelParam, - value); + return mSoundTriggerHelper.setParameter( + soundModel.getUuid(), modelParam, value); } } } @@ -839,26 +833,11 @@ public class SoundTriggerService extends SystemService { throws UnsupportedOperationException, IllegalArgumentException { try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.d(TAG, "getParameter(): id=" + soundModelId - + ", param=" + modelParam); - } - - sEventLogger.enqueue(new EventLogger.StringEvent( - "getParameter(): id=" + soundModelId - + ", param=" + modelParam)); - synchronized (mLock) { SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid()); if (soundModel == null) { - Slog.w(TAG, soundModelId + " is not loaded"); - - sEventLogger.enqueue(new EventLogger.StringEvent("getParameter(): " - + soundModelId + " is not loaded")); - throw new IllegalArgumentException("sound model is not loaded"); } - return mSoundTriggerHelper.getParameter(soundModel.getUuid(), modelParam); } } @@ -870,37 +849,28 @@ public class SoundTriggerService extends SystemService { @ModelParams int modelParam) { try (SafeCloseable ignored = ClearCallingIdentityContext.create()) { enforceCallingPermission(Manifest.permission.MANAGE_SOUND_TRIGGER); - if (DEBUG) { - Slog.d(TAG, "queryParameter(): id=" + soundModelId - + ", param=" + modelParam); - } - - sEventLogger.enqueue(new EventLogger.StringEvent( - "queryParameter(): id=" + soundModelId - + ", param=" + modelParam)); - synchronized (mLock) { SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid()); if (soundModel == null) { - Slog.w(TAG, soundModelId + " is not loaded"); - - sEventLogger.enqueue(new EventLogger.StringEvent( - "queryParameter(): " - + soundModelId + " is not loaded")); - return null; } - return mSoundTriggerHelper.queryParameter(soundModel.getUuid(), modelParam); } } } private void clientDied() { - Slog.w(TAG, "Client died, cleaning up session."); - sEventLogger.enqueue(new EventLogger.StringEvent( - "Client died, cleaning up session.")); + mEventLogger.enqueue(new SessionEvent(Type.DETACH, null)); + mServiceEventLogger.enqueue(new ServiceEvent( + ServiceEvent.Type.DETACH, mOriginatorIdentity.packageName, "Client died") + .printLog(ALOGW, TAG)); + detach(); + } + + private void detach() { mSoundTriggerHelper.detach(); + mSessionEventLoggers.remove(mEventLogger); + addDetachedSessionLogger(mEventLogger); } private void enforceCallingPermission(String permission) { @@ -922,6 +892,14 @@ public class SoundTriggerService extends SystemService { } } + private UUID getUuid(ParcelUuid uuid) { + return (uuid != null) ? uuid.getUuid() : null; + } + + private UUID getUuid(SoundModel model) { + return (model != null) ? model.getUuid() : null; + } + /** * Local end for a {@link SoundTriggerDetectionService}. Operations are queued up and * executed when the service connects. @@ -1068,7 +1046,7 @@ public class SoundTriggerService extends SystemService { } catch (Exception e) { Slog.e(TAG, mPuuid + ": Cannot remove client", e); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": Cannot remove client")); } @@ -1091,9 +1069,7 @@ public class SoundTriggerService extends SystemService { * dropped. */ private void destroy() { - if (DEBUG) Slog.v(TAG, mPuuid + ": destroy"); - - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": destroy")); + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": destroy")); synchronized (mRemoteServiceLock) { disconnectLocked(); @@ -1127,7 +1103,7 @@ public class SoundTriggerService extends SystemService { Slog.e(TAG, mPuuid + ": Could not stop operation " + mRunningOpIds.valueAt(i), e); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": Could not stop operation " + mRunningOpIds.valueAt( i))); @@ -1157,7 +1133,7 @@ public class SoundTriggerService extends SystemService { if (ri == null) { Slog.w(TAG, mPuuid + ": " + mServiceName + " not found"); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": " + mServiceName + " not found")); return; @@ -1168,7 +1144,7 @@ public class SoundTriggerService extends SystemService { Slog.w(TAG, mPuuid + ": " + mServiceName + " does not require " + BIND_SOUND_TRIGGER_DETECTION_SERVICE); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": " + mServiceName + " does not require " + BIND_SOUND_TRIGGER_DETECTION_SERVICE)); @@ -1184,7 +1160,7 @@ public class SoundTriggerService extends SystemService { } else { Slog.w(TAG, mPuuid + ": Could not bind to " + mServiceName); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": Could not bind to " + mServiceName)); } @@ -1206,7 +1182,7 @@ public class SoundTriggerService extends SystemService { mPuuid + ": Dropped operation as already destroyed or marked for " + "destruction"); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ":Dropped operation as already destroyed or marked for " + "destruction")); @@ -1238,7 +1214,7 @@ public class SoundTriggerService extends SystemService { mPuuid + ": Dropped operation as too many operations " + "were run in last 24 hours"); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": Dropped operation as too many operations " + "were run in last 24 hours")); @@ -1248,7 +1224,7 @@ public class SoundTriggerService extends SystemService { } catch (Exception e) { Slog.e(TAG, mPuuid + ": Could not drop operation", e); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": Could not drop operation")); } @@ -1265,7 +1241,7 @@ public class SoundTriggerService extends SystemService { try { if (DEBUG) Slog.v(TAG, mPuuid + ": runOp " + opId); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": runOp " + opId)); op.run(opId, mService); @@ -1273,7 +1249,7 @@ public class SoundTriggerService extends SystemService { } catch (Exception e) { Slog.e(TAG, mPuuid + ": Could not run operation " + opId, e); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": Could not run operation " + opId)); } @@ -1303,11 +1279,6 @@ public class SoundTriggerService extends SystemService { @Override public void onKeyphraseDetected(SoundTrigger.KeyphraseRecognitionEvent event) { - Slog.w(TAG, mPuuid + "->" + mServiceName + ": IGNORED onKeyphraseDetected(" + event - + ")"); - - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + "->" + mServiceName - + ": IGNORED onKeyphraseDetected(" + event + ")")); } /** @@ -1325,7 +1296,7 @@ public class SoundTriggerService extends SystemService { AudioFormat originalFormat = event.getCaptureFormat(); - sEventLogger.enqueue(new EventLogger.StringEvent("createAudioRecordForEvent")); + mEventLogger.enqueue(new EventLogger.StringEvent("createAudioRecordForEvent")); return (new AudioRecord.Builder()) .setAudioAttributes(attributes) @@ -1340,11 +1311,6 @@ public class SoundTriggerService extends SystemService { @Override public void onGenericSoundTriggerDetected(SoundTrigger.GenericRecognitionEvent event) { - if (DEBUG) Slog.v(TAG, mPuuid + ": Generic sound trigger event: " + event); - - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid - + ": Generic sound trigger event: " + event)); - runOrAddOperation(new Operation( // always execute: () -> { @@ -1376,7 +1342,7 @@ public class SoundTriggerService extends SystemService { private void onError(int status) { if (DEBUG) Slog.v(TAG, mPuuid + ": onError: " + status); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": onError: " + status)); runOrAddOperation( @@ -1421,27 +1387,17 @@ public class SoundTriggerService extends SystemService { @Override public void onRecognitionPaused() { - Slog.i(TAG, mPuuid + "->" + mServiceName + ": IGNORED onRecognitionPaused"); - - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid - + "->" + mServiceName + ": IGNORED onRecognitionPaused")); - } @Override public void onRecognitionResumed() { - Slog.i(TAG, mPuuid + "->" + mServiceName + ": IGNORED onRecognitionResumed"); - - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid - + "->" + mServiceName + ": IGNORED onRecognitionResumed")); - } @Override public void onServiceConnected(ComponentName name, IBinder service) { if (DEBUG) Slog.v(TAG, mPuuid + ": onServiceConnected(" + service + ")"); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": onServiceConnected(" + service + ")")); synchronized (mRemoteServiceLock) { @@ -1464,7 +1420,7 @@ public class SoundTriggerService extends SystemService { public void onServiceDisconnected(ComponentName name) { if (DEBUG) Slog.v(TAG, mPuuid + ": onServiceDisconnected"); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": onServiceDisconnected")); synchronized (mRemoteServiceLock) { @@ -1476,7 +1432,7 @@ public class SoundTriggerService extends SystemService { public void onBindingDied(ComponentName name) { if (DEBUG) Slog.v(TAG, mPuuid + ": onBindingDied"); - sEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + mEventLogger.enqueue(new EventLogger.StringEvent(mPuuid + ": onBindingDied")); synchronized (mRemoteServiceLock) { @@ -1488,7 +1444,7 @@ public class SoundTriggerService extends SystemService { public void onNullBinding(ComponentName name) { Slog.w(TAG, name + " for model " + mPuuid + " returned a null binding"); - sEventLogger.enqueue(new EventLogger.StringEvent(name + " for model " + mEventLogger.enqueue(new EventLogger.StringEvent(name + " for model " + mPuuid + " returned a null binding")); synchronized (mRemoteServiceLock) { @@ -1613,17 +1569,25 @@ public class SoundTriggerService extends SystemService { private class SessionImpl implements Session { private final @NonNull SoundTriggerHelper mSoundTriggerHelper; private final @NonNull IBinder mClient; + private final EventLogger mEventLogger; + private final Identity mOriginatorIdentity; + + private final SparseArray mModelUuid = new SparseArray<>(1); + + private SessionImpl(@NonNull SoundTriggerHelper soundTriggerHelper, + @NonNull IBinder client, + @NonNull EventLogger eventLogger, @NonNull Identity originatorIdentity) { - private SessionImpl( - @NonNull SoundTriggerHelper soundTriggerHelper, @NonNull IBinder client) { mSoundTriggerHelper = soundTriggerHelper; mClient = client; + mOriginatorIdentity = originatorIdentity; + mEventLogger = eventLogger; + + mSessionEventLoggers.add(mEventLogger); try { - mClient.linkToDeath(() -> { - clientDied(); - }, 0); + mClient.linkToDeath(() -> clientDied(), 0); } catch (RemoteException e) { - Slog.e(TAG, "Failed to register death listener.", e); + clientDied(); } } @@ -1631,6 +1595,9 @@ public class SoundTriggerService extends SystemService { public int startRecognition(int keyphraseId, KeyphraseSoundModel soundModel, IRecognitionStatusCallback listener, RecognitionConfig recognitionConfig, boolean runInBatterySaverMode) { + mModelUuid.put(keyphraseId, soundModel.getUuid()); + mEventLogger.enqueue(new SessionEvent(Type.START_RECOGNITION, + soundModel.getUuid())); return mSoundTriggerHelper.startKeyphraseRecognition(keyphraseId, soundModel, listener, recognitionConfig, runInBatterySaverMode); } @@ -1638,16 +1605,21 @@ public class SoundTriggerService extends SystemService { @Override public synchronized int stopRecognition(int keyphraseId, IRecognitionStatusCallback listener) { + var uuid = mModelUuid.get(keyphraseId); + mEventLogger.enqueue(new SessionEvent(Type.STOP_RECOGNITION, uuid)); return mSoundTriggerHelper.stopKeyphraseRecognition(keyphraseId, listener); } @Override public ModuleProperties getModuleProperties() { + mEventLogger.enqueue(new SessionEvent(Type.GET_MODULE_PROPERTIES, null)); return mSoundTriggerHelper.getModuleProperties(); } @Override public int setParameter(int keyphraseId, @ModelParams int modelParam, int value) { + var uuid = mModelUuid.get(keyphraseId); + mEventLogger.enqueue(new SessionEvent(Type.SET_PARAMETER, uuid)); return mSoundTriggerHelper.setKeyphraseParameter(keyphraseId, modelParam, value); } @@ -1664,40 +1636,54 @@ public class SoundTriggerService extends SystemService { @Override public void detach() { - mSoundTriggerHelper.detach(); + detachInternal(); } @Override public int unloadKeyphraseModel(int keyphraseId) { + var uuid = mModelUuid.get(keyphraseId); + mEventLogger.enqueue(new SessionEvent(Type.UNLOAD_MODEL, uuid)); return mSoundTriggerHelper.unloadKeyphraseSoundModel(keyphraseId); } private void clientDied() { - Slog.w(TAG, "Client died, cleaning up session."); - sEventLogger.enqueue(new EventLogger.StringEvent( - "Client died, cleaning up session.")); + mServiceEventLogger.enqueue(new ServiceEvent( + ServiceEvent.Type.DETACH, mOriginatorIdentity.packageName, + "Client died") + .printLog(ALOGW, TAG)); + detachInternal(); + } + + private void detachInternal() { + mEventLogger.enqueue(new SessionEvent(Type.DETACH, null)); + mSessionEventLoggers.remove(mEventLogger); + addDetachedSessionLogger(mEventLogger); mSoundTriggerHelper.detach(); } } @Override public Session attach(@NonNull IBinder client, ModuleProperties underlyingModule) { - return new SessionImpl(newSoundTriggerHelper(underlyingModule), client); + var identity = IdentityContext.getNonNull(); + int sessionId = mSessionIdCounter.getAndIncrement(); + mServiceEventLogger.enqueue(new ServiceEvent( + ServiceEvent.Type.ATTACH, identity.packageName + "#" + sessionId)); + var eventLogger = new EventLogger(SESSION_MAX_EVENT_SIZE, + "LocalSoundTriggerEventLogger for package: " + + identity.packageName + "#" + sessionId); + + return new SessionImpl(newSoundTriggerHelper(underlyingModule, eventLogger), + client, eventLogger, identity); } @Override public List listModuleProperties(Identity originatorIdentity) { + mServiceEventLogger.enqueue(new ServiceEvent( + ServiceEvent.Type.LIST_MODULE, originatorIdentity.packageName)); try (SafeCloseable ignored = PermissionUtil.establishIdentityDirect( originatorIdentity)) { return listUnderlyingModuleProperties(originatorIdentity); } } } - - //================================================================= - // For logging - - private static final EventLogger sEventLogger = new EventLogger(200, - "SoundTrigger activity"); - }