Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "SoundTrigger Event logging" into qt-dev

Browse Source
This commit is contained in:
Jason CH Hsu
2019-04-30 02:34:25 +00:00
committed by Android (Google) Code Review
parent efc346677b 1363f581dc
commit 9741940810
2 changed files with 334 additions and 0 deletions
Download Patch File Download Diff File Expand all files Collapse all files

136
services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerLogger.java Normal file
View File

@@ -0,0 +1,136 @@
/*
* Copyright (C) 2019 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.android.server.soundtrigger;
import android.util.Log;
import java.io.PrintWriter;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.LinkedList;
/**
* Constructor SoundTriggerLogger class
*/
public class SoundTriggerLogger {
// ring buffer of events to log.
private final LinkedList<Event> mEvents;
private final String mTitle;
// the maximum number of events to keep in log
private final int mMemSize;
/**
* Constructor for Event class.
*/
public abstract static class Event {
// formatter for timestamps
private static final SimpleDateFormat sFormat = new SimpleDateFormat("MM-dd HH:mm:ss:SSS");
private final long mTimestamp;
Event() {
mTimestamp = System.currentTimeMillis();
}
/**
* Convert event to String
* @return StringBuilder
*/
public String toString() {
return (new StringBuilder(sFormat.format(new Date(mTimestamp))))
.append(" ").append(eventToString()).toString();
}
/**
* Causes the string message for the event to appear in the logcat.
* Here is an example of how to create a new event (a StringEvent), adding it to the logger
* (an instance of SoundTriggerLogger) while also making it show in the logcat:
* <pre>
* myLogger.log(
* (new StringEvent("something for logcat and logger")).printLog(MyClass.TAG) );
* </pre>
* @param tag the tag for the android.util.Log.v
* @return the same instance of the event
*/
public Event printLog(String tag) {
Log.i(tag, eventToString());
return this;
}
/**
* Convert event to String.
* This method is only called when the logger history is about to the dumped,
* so this method is where expensive String conversions should be made, not when the Event
* subclass is created.
* Timestamp information will be automatically added, do not include it.
* @return a string representation of the event that occurred.
*/
public abstract String eventToString();
}
/**
* Constructor StringEvent class
*/
public static class StringEvent extends Event {
private final String mMsg;
public StringEvent(String msg) {
mMsg = msg;
}
@Override
public String eventToString() {
return mMsg;
}
}
/**
* Constructor for logger.
* @param size the maximum number of events to keep in log
* @param title the string displayed before the recorded log
*/
public SoundTriggerLogger(int size, String title) {
mEvents = new LinkedList<Event>();
mMemSize = size;
mTitle = title;
}
/**
* Constructor for logger.
* @param evt the maximum number of events to keep in log
*/
public synchronized void log(Event evt) {
if (mEvents.size() >= mMemSize) {
mEvents.removeFirst();
}
mEvents.add(evt);
}
/**
* Constructor for logger.
* @param pw the maximum number of events to keep in log
*/
public synchronized void dump(PrintWriter pw) {
pw.println("ST Event log: " + mTitle);
for (Event evt : mEvents) {
pw.println(evt.toString());
}
}
}

198
services/voiceinteraction/java/com/android/server/soundtrigger/SoundTriggerService.java
View File

@@ -180,9 +180,16 @@ public class SoundTriggerService extends SystemService {
Slog.i(TAG, "startRecognition(): Uuid : " + parcelUuid);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent("startRecognition(): Uuid : "
+ parcelUuid));
GenericSoundModel model = getSoundModel(parcelUuid);
if (model == null) {
Slog.e(TAG, "Null model in database for id: " + parcelUuid);
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"startRecognition(): Null model in database for id: " + parcelUuid));
return STATUS_ERROR;
}
@@ -196,6 +203,10 @@ public class SoundTriggerService extends SystemService {
if (DEBUG) {
Slog.i(TAG, "stopRecognition(): Uuid : " + parcelUuid);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent("stopRecognition(): Uuid : "
+ parcelUuid));
if (!isInitialized()) return STATUS_ERROR;
return mSoundTriggerHelper.stopGenericRecognition(parcelUuid.getUuid(), callback);
}
@@ -206,6 +217,10 @@ public class SoundTriggerService extends SystemService {
if (DEBUG) {
Slog.i(TAG, "getSoundModel(): id = " + soundModelId);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent("getSoundModel(): id = "
+ soundModelId));
SoundTrigger.GenericSoundModel model = mDbHelper.getGenericSoundModel(
soundModelId.getUuid());
return model;
@@ -217,6 +232,10 @@ public class SoundTriggerService extends SystemService {
if (DEBUG) {
Slog.i(TAG, "updateSoundModel(): model = " + soundModel);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent("updateSoundModel(): model = "
+ soundModel));
mDbHelper.updateGenericSoundModel(soundModel);
}
@@ -226,6 +245,10 @@ public class SoundTriggerService extends SystemService {
if (DEBUG) {
Slog.i(TAG, "deleteSoundModel(): id = " + soundModelId);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent("deleteSoundModel(): id = "
+ soundModelId));
// Unload the model if it is loaded.
mSoundTriggerHelper.unloadGenericSoundModel(soundModelId.getUuid());
mDbHelper.deleteGenericSoundModel(soundModelId.getUuid());
@@ -237,11 +260,19 @@ public class SoundTriggerService extends SystemService {
if (!isInitialized()) return STATUS_ERROR;
if (soundModel == null || soundModel.uuid == null) {
Slog.e(TAG, "Invalid sound model");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"loadGenericSoundModel(): Invalid sound model"));
return STATUS_ERROR;
}
if (DEBUG) {
Slog.i(TAG, "loadGenericSoundModel(): id = " + soundModel.uuid);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent("loadGenericSoundModel(): id = "
+ soundModel.uuid));
synchronized (mLock) {
SoundModel oldModel = mLoadedModels.get(soundModel.uuid);
// If the model we're loading is actually different than what we had loaded, we
@@ -264,15 +295,28 @@ public class SoundTriggerService extends SystemService {
if (!isInitialized()) return STATUS_ERROR;
if (soundModel == null || soundModel.uuid == null) {
Slog.e(TAG, "Invalid sound model");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"loadKeyphraseSoundModel(): Invalid sound model"));
return STATUS_ERROR;
}
if (soundModel.keyphrases == null || soundModel.keyphrases.length != 1) {
Slog.e(TAG, "Only one keyphrase per model is currently supported.");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"loadKeyphraseSoundModel(): Only one keyphrase per model"
+ " is currently supported."));
return STATUS_ERROR;
}
if (DEBUG) {
Slog.i(TAG, "loadKeyphraseSoundModel(): id = " + soundModel.uuid);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent("loadKeyphraseSoundModel(): id = "
+ soundModel.uuid));
synchronized (mLock) {
SoundModel oldModel = mLoadedModels.get(soundModel.uuid);
// If the model we're loading is actually different than what we had loaded, we
@@ -303,6 +347,9 @@ public class SoundTriggerService extends SystemService {
Slog.i(TAG, "startRecognition(): id = " + soundModelId);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"startRecognitionForService(): id = " + soundModelId));
IRecognitionStatusCallback callback =
new RemoteSoundTriggerDetectionService(soundModelId.getUuid(), params,
detectionService, Binder.getCallingUserHandle(), config);
@@ -311,6 +358,10 @@ public class SoundTriggerService extends SystemService {
SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid());
if (soundModel == null) {
Slog.e(TAG, soundModelId + " is not loaded");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"startRecognitionForService():" + soundModelId + " is not loaded"));
return STATUS_ERROR;
}
IRecognitionStatusCallback existingCallback = null;
@@ -319,6 +370,11 @@ public class SoundTriggerService extends SystemService {
}
if (existingCallback != null) {
Slog.e(TAG, soundModelId + " is already running");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"startRecognitionForService():"
+ soundModelId + " is already running"));
return STATUS_ERROR;
}
int ret;
@@ -329,11 +385,19 @@ public class SoundTriggerService extends SystemService {
break;
default:
Slog.e(TAG, "Unknown model type");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"startRecognitionForService(): Unknown model type"));
return STATUS_ERROR;
}
if (ret != STATUS_OK) {
Slog.e(TAG, "Failed to start model: " + ret);
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"startRecognitionForService(): Failed to start model:"));
return ret;
}
synchronized (mCallbacksLock) {
@@ -351,10 +415,18 @@ public class SoundTriggerService extends SystemService {
Slog.i(TAG, "stopRecognition(): id = " + soundModelId);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"stopRecognitionForService(): id = " + soundModelId));
synchronized (mLock) {
SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid());
if (soundModel == null) {
Slog.e(TAG, soundModelId + " is not loaded");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"stopRecognitionForService(): " + soundModelId
+ " is not loaded"));
return STATUS_ERROR;
}
IRecognitionStatusCallback callback = null;
@@ -363,6 +435,11 @@ public class SoundTriggerService extends SystemService {
}
if (callback == null) {
Slog.e(TAG, soundModelId + " is not running");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"stopRecognitionForService(): " + soundModelId
+ " is not running"));
return STATUS_ERROR;
}
int ret;
@@ -372,11 +449,19 @@ public class SoundTriggerService extends SystemService {
break;
default:
Slog.e(TAG, "Unknown model type");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"stopRecognitionForService(): Unknown model type"));
return STATUS_ERROR;
}
if (ret != STATUS_OK) {
Slog.e(TAG, "Failed to stop model: " + ret);
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"stopRecognitionForService(): Failed to stop model: " + ret));
return ret;
}
synchronized (mCallbacksLock) {
@@ -394,10 +479,17 @@ public class SoundTriggerService extends SystemService {
Slog.i(TAG, "unloadSoundModel(): id = " + soundModelId);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent("unloadSoundModel(): id = "
+ soundModelId));
synchronized (mLock) {
SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid());
if (soundModel == null) {
Slog.e(TAG, soundModelId + " is not loaded");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"unloadSoundModel(): " + soundModelId + " is not loaded"));
return STATUS_ERROR;
}
int ret;
@@ -411,10 +503,18 @@ public class SoundTriggerService extends SystemService {
break;
default:
Slog.e(TAG, "Unknown model type");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"unloadSoundModel(): Unknown model type"));
return STATUS_ERROR;
}
if (ret != STATUS_OK) {
Slog.e(TAG, "Failed to unload model");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"unloadSoundModel(): Failed to unload model"));
return ret;
}
mLoadedModels.remove(soundModelId.getUuid());
@@ -444,10 +544,17 @@ public class SoundTriggerService extends SystemService {
Slog.i(TAG, "getModelState(): id = " + soundModelId);
}
sEventLogger.log(new SoundTriggerLogger.StringEvent("getModelState(): id = "
+ soundModelId));
synchronized (mLock) {
SoundModel soundModel = mLoadedModels.get(soundModelId.getUuid());
if (soundModel == null) {
Slog.e(TAG, soundModelId + " is not loaded");
sEventLogger.log(new SoundTriggerLogger.StringEvent("getModelState(): "
+ soundModelId + " is not loaded"));
return ret;
}
switch (soundModel.type) {
@@ -459,6 +566,10 @@ public class SoundTriggerService extends SystemService {
break;
default:
Slog.e(TAG, "Unknown model type");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"getModelState(): Unknown model type"));
break;
}
@@ -708,6 +819,10 @@ public class SoundTriggerService extends SystemService {
mService.removeClient(mPuuid);
} catch (Exception e) {
Slog.e(TAG, mPuuid + ": Cannot remove client", e);
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": Cannot remove client"));
}
mService = null;
@@ -730,6 +845,8 @@ public class SoundTriggerService extends SystemService {
private void destroy() {
if (DEBUG) Slog.v(TAG, mPuuid + ": destroy");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid + ": destroy"));
synchronized (mRemoteServiceLock) {
disconnectLocked();
@@ -761,6 +878,10 @@ public class SoundTriggerService extends SystemService {
} catch (Exception e) {
Slog.e(TAG, mPuuid + ": Could not stop operation "
+ mRunningOpIds.valueAt(i), e);
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": Could not stop operation " + mRunningOpIds.valueAt(i)));
}
}
@@ -786,6 +907,10 @@ public class SoundTriggerService extends SystemService {
if (ri == null) {
Slog.w(TAG, mPuuid + ": " + mServiceName + " not found");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": " + mServiceName + " not found"));
return;
}
@@ -793,6 +918,11 @@ public class SoundTriggerService extends SystemService {
.equals(ri.serviceInfo.permission)) {
Slog.w(TAG, mPuuid + ": " + mServiceName + " does not require "
+ BIND_SOUND_TRIGGER_DETECTION_SERVICE);
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": " + mServiceName + " does not require "
+ BIND_SOUND_TRIGGER_DETECTION_SERVICE));
return;
}
@@ -803,6 +933,10 @@ public class SoundTriggerService extends SystemService {
mRemoteServiceWakeLock.acquire();
} else {
Slog.w(TAG, mPuuid + ": Could not bind to " + mServiceName);
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": Could not bind to " + mServiceName));
}
} finally {
Binder.restoreCallingIdentity(token);
@@ -821,6 +955,9 @@ public class SoundTriggerService extends SystemService {
Slog.w(TAG, mPuuid + ": Dropped operation as already destroyed or marked for "
+ "destruction");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ":Dropped operation as already destroyed or marked for destruction"));
op.drop();
return;
}
@@ -847,11 +984,20 @@ public class SoundTriggerService extends SystemService {
if (DEBUG || opsAllowed + 10 > opsAdded) {
Slog.w(TAG, mPuuid + ": Dropped operation as too many operations "
+ "were run in last 24 hours");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": Dropped operation as too many operations "
+ "were run in last 24 hours"));
}
op.drop();
} catch (Exception e) {
Slog.e(TAG, mPuuid + ": Could not drop operation", e);
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": Could not drop operation"));
}
} else {
mNumOps.addOp(currentTime);
@@ -866,10 +1012,17 @@ public class SoundTriggerService extends SystemService {
try {
if (DEBUG) Slog.v(TAG, mPuuid + ": runOp " + opId);
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": runOp " + opId));
op.run(opId, mService);
mRunningOpIds.add(opId);
} catch (Exception e) {
Slog.e(TAG, mPuuid + ": Could not run operation " + opId, e);
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": Could not run operation " + opId));
}
}
@@ -897,6 +1050,10 @@ public class SoundTriggerService extends SystemService {
public void onKeyphraseDetected(SoundTrigger.KeyphraseRecognitionEvent event) {
Slog.w(TAG, mPuuid + "->" + mServiceName + ": IGNORED onKeyphraseDetected(" + event
+ ")");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid + "->" + mServiceName
+ ": IGNORED onKeyphraseDetected(" + event + ")"));
}
/**
@@ -928,6 +1085,8 @@ public class SoundTriggerService extends SystemService {
: AudioFormat.CHANNEL_IN_MONO,
captureFormat.getEncoding());
sEventLogger.log(new SoundTriggerLogger.StringEvent("createAudioRecordForEvent"));
return new AudioRecord(attributes, captureFormat, bufferSize,
event.getCaptureSession());
}
@@ -936,6 +1095,9 @@ public class SoundTriggerService extends SystemService {
public void onGenericSoundTriggerDetected(SoundTrigger.GenericRecognitionEvent event) {
if (DEBUG) Slog.v(TAG, mPuuid + ": Generic sound trigger event: " + event);
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": Generic sound trigger event: " + event));
runOrAddOperation(new Operation(
// always execute:
() -> {
@@ -966,6 +1128,9 @@ public class SoundTriggerService extends SystemService {
public void onError(int status) {
if (DEBUG) Slog.v(TAG, mPuuid + ": onError: " + status);
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": onError: " + status));
runOrAddOperation(
new Operation(
// always execute:
@@ -985,17 +1150,28 @@ public class SoundTriggerService extends SystemService {
@Override
public void onRecognitionPaused() {
Slog.i(TAG, mPuuid + "->" + mServiceName + ": IGNORED onRecognitionPaused");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ "->" + mServiceName + ": IGNORED onRecognitionPaused"));
}
@Override
public void onRecognitionResumed() {
Slog.i(TAG, mPuuid + "->" + mServiceName + ": IGNORED onRecognitionResumed");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ "->" + mServiceName + ": IGNORED onRecognitionResumed"));
}
@Override
public void onServiceConnected(ComponentName name, IBinder service) {
if (DEBUG) Slog.v(TAG, mPuuid + ": onServiceConnected(" + service + ")");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": onServiceConnected(" + service + ")"));
synchronized (mRemoteServiceLock) {
mService = ISoundTriggerDetectionService.Stub.asInterface(service);
@@ -1016,6 +1192,9 @@ public class SoundTriggerService extends SystemService {
public void onServiceDisconnected(ComponentName name) {
if (DEBUG) Slog.v(TAG, mPuuid + ": onServiceDisconnected");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": onServiceDisconnected"));
synchronized (mRemoteServiceLock) {
mService = null;
}
@@ -1025,6 +1204,9 @@ public class SoundTriggerService extends SystemService {
public void onBindingDied(ComponentName name) {
if (DEBUG) Slog.v(TAG, mPuuid + ": onBindingDied");
sEventLogger.log(new SoundTriggerLogger.StringEvent(mPuuid
+ ": onBindingDied"));
synchronized (mRemoteServiceLock) {
destroy();
}
@@ -1034,6 +1216,9 @@ public class SoundTriggerService extends SystemService {
public void onNullBinding(ComponentName name) {
Slog.w(TAG, name + " for model " + mPuuid + " returned a null binding");
sEventLogger.log(new SoundTriggerLogger.StringEvent(name + " for model "
+ mPuuid + " returned a null binding"));
synchronized (mRemoteServiceLock) {
disconnectLocked();
}
@@ -1082,11 +1267,17 @@ public class SoundTriggerService extends SystemService {
public void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
if (!isInitialized()) return;
mSoundTriggerHelper.dump(fd, pw, args);
// log
sEventLogger.dump(pw);
}
private synchronized boolean isInitialized() {
if (mSoundTriggerHelper == null ) {
Slog.e(TAG, "SoundTriggerHelper not initialized.");
sEventLogger.log(new SoundTriggerLogger.StringEvent(
"SoundTriggerHelper not initialized."));
return false;
}
return true;
@@ -1099,4 +1290,11 @@ public class SoundTriggerService extends SystemService {
throw new SecurityException("Caller does not hold the permission " + permission);
}
}
//=================================================================
// For logging
private static final SoundTriggerLogger sEventLogger = new SoundTriggerLogger(200,
"SoundTrigger activity");
}