Add event-log logging for TTS requests.

Change-Id: I5023194c469a602b85259088a2e59373c96a941e
This commit is contained in:
Narayan Kamath
2011-07-08 12:13:03 +01:00
parent 221bfab842
commit 6dabb63307
7 changed files with 226 additions and 13 deletions

View File

@@ -36,6 +36,7 @@ LOCAL_SRC_FILES := $(call find-other-java-files,$(FRAMEWORKS_BASE_SUBDIRS))
# EventLogTags files.
LOCAL_SRC_FILES += \
core/java/android/content/EventLogTags.logtags \
core/java/android/speech/tts/EventLogTags.logtags \
core/java/android/webkit/EventLogTags.logtags \
telephony/java/com/android/internal/telephony/EventLogTags.logtags \

View File

@@ -384,11 +384,16 @@ class AudioPlaybackHandler {
}
count += written;
}
param.mLogger.onPlaybackStart();
}
private void handleSynthesisDone(MessageParams msg) {
final SynthesisMessageParams params = (SynthesisMessageParams) msg;
handleSynthesisDone(params);
// This call is delayed more than it should be, but we are
// certain at this point that we have all the data we want.
params.mLogger.onWriteData();
}
// Flush all remaining data to the audio track, stop it and release
@@ -416,6 +421,8 @@ class AudioPlaybackHandler {
final SynthesisMessageParams params = (SynthesisMessageParams) msg;
if (DBG) Log.d(TAG, "completeAudioAvailable(" + params + ")");
params.mLogger.onPlaybackStart();
// Channel config and bytes per frame are checked before
// this message is sent.
int channelConfig = AudioPlaybackHandler.getChannelConfig(params.mChannelCount);

View File

@@ -0,0 +1,6 @@
# See system/core/logcat/event.logtags for a description of the format of this file.
option java_package android.speech.tts;
76001 tts_speak_success (engine|3),(caller|3),(length|1),(locale|3),(rate|1),(pitch|1),(engine_latency|2|3),(engine_total|2|3),(audio_latency|2|3)
76002 tts_speak_failure (engine|3),(caller|3),(length|1),(locale|3),(rate|1),(pitch|1)

View File

@@ -0,0 +1,175 @@
/*
* Copyright (C) 2011 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 android.speech.tts;
import android.os.SystemClock;
import android.text.TextUtils;
/**
* Writes data about a given speech synthesis request to the event logs.
* The data that is logged includes the calling app, length of the utterance,
* speech rate / pitch and the latency and overall time taken.
*
* Note that {@link EventLogger#onStopped()} and {@link EventLogger#onError()}
* might be called from any thread, but on {@link EventLogger#onPlaybackStart()} and
* {@link EventLogger#onComplete()} must be called from a single thread
* (usually the audio playback thread}
*/
class EventLogger {
private final SynthesisRequest mRequest;
private final String mCallingApp;
private final String mServiceApp;
private final long mReceivedTime;
private long mPlaybackStartTime = -1;
private volatile long mRequestProcessingStartTime = -1;
private volatile long mEngineStartTime = -1;
private volatile long mEngineCompleteTime = -1;
private volatile boolean mError = false;
private volatile boolean mStopped = false;
private boolean mLogWritten = false;
EventLogger(SynthesisRequest request, String callingApp,
String serviceApp) {
mRequest = request;
mCallingApp = callingApp;
mServiceApp = serviceApp;
mReceivedTime = SystemClock.elapsedRealtime();
}
/**
* Notifies the logger that this request has been selected from
* the processing queue for processing. Engine latency / total time
* is measured from this baseline.
*/
public void onRequestProcessingStart() {
mRequestProcessingStartTime = SystemClock.elapsedRealtime();
}
/**
* Notifies the logger that a chunk of data has been received from
* the engine. Might be called multiple times.
*/
public void onEngineDataReceived() {
if (mEngineStartTime == -1) {
mEngineStartTime = SystemClock.elapsedRealtime();
}
}
/**
* Notifies the logger that the engine has finished processing data.
* Will be called exactly once.
*/
public void onEngineComplete() {
mEngineCompleteTime = SystemClock.elapsedRealtime();
}
/**
* Notifies the logger that audio playback has started for some section
* of the synthesis. This is normally some amount of time after the engine
* has synthesized data and varides depending on utterances and
* other audio currently in the queue.
*/
public void onPlaybackStart() {
// For now, keep track of only the first chunk of audio
// that was played.
if (mPlaybackStartTime == -1) {
mPlaybackStartTime = SystemClock.elapsedRealtime();
}
}
/**
* Notifies the logger that the current synthesis was stopped.
* Latency numbers are not reported for stopped syntheses.
*/
public void onStopped() {
mStopped = false;
}
/**
* Notifies the logger that the current synthesis resulted in
* an error. This is logged using {@link EventLogTags#writeTtsSpeakFailure}.
*/
public void onError() {
mError = true;
}
/**
* Notifies the logger that the current synthesis has completed.
* All available data is not logged.
*/
public void onWriteData() {
if (mLogWritten) {
return;
} else {
mLogWritten = true;
}
long completionTime = SystemClock.elapsedRealtime();
// onPlaybackStart() should normally always be called if an
// error does not occur.
if (mError || mPlaybackStartTime == -1 || mEngineCompleteTime == -1) {
EventLogTags.writeTtsSpeakFailure(mServiceApp, mCallingApp,
getUtteranceLength(), getLocaleString(),
mRequest.getSpeechRate(), mRequest.getPitch());
return;
}
// We don't report stopped syntheses because their overall
// total time spent will be innacurate (will not correlate with
// the length of the utterance).
if (mStopped) {
return;
}
final long audioLatency = mPlaybackStartTime - mReceivedTime;
final long engineLatency = mEngineStartTime - mRequestProcessingStartTime;
final long engineTotal = mEngineCompleteTime - mRequestProcessingStartTime;
EventLogTags.writeTtsSpeakSuccess(mServiceApp, mCallingApp,
getUtteranceLength(), getLocaleString(),
mRequest.getSpeechRate(), mRequest.getPitch(),
engineLatency, engineTotal, audioLatency);
}
/**
* @return the length of the utterance for the given synthesis, 0
* if the utterance was {@code null}.
*/
private int getUtteranceLength() {
final String utterance = mRequest.getText();
return utterance == null ? 0 : utterance.length();
}
/**
* Returns a formatted locale string from the synthesis params of the
* form lang-country-variant.
*/
private String getLocaleString() {
StringBuilder sb = new StringBuilder(mRequest.getLanguage());
if (!TextUtils.isEmpty(mRequest.getCountry())) {
sb.append('-');
sb.append(mRequest.getCountry());
if (!TextUtils.isEmpty(mRequest.getVariant())) {
sb.append('-');
sb.append(mRequest.getVariant());
}
}
return sb.toString();
}
}

View File

@@ -65,29 +65,42 @@ class PlaybackSynthesisCallback extends AbstractSynthesisCallback {
private final UtteranceCompletedDispatcher mDispatcher;
private final String mCallingApp;
private final EventLogger mLogger;
PlaybackSynthesisCallback(int streamType, float volume, float pan,
AudioPlaybackHandler audioTrackHandler, UtteranceCompletedDispatcher dispatcher,
String callingApp) {
String callingApp, EventLogger logger) {
mStreamType = streamType;
mVolume = volume;
mPan = pan;
mAudioTrackHandler = audioTrackHandler;
mDispatcher = dispatcher;
mCallingApp = callingApp;
mLogger = logger;
}
@Override
void stop() {
if (DBG) Log.d(TAG, "stop()");
// Note that mLogger.mError might be true too at this point.
mLogger.onStopped();
synchronized (mStateLock) {
if (mToken == null || mStopped) {
Log.w(TAG, "stop() called twice, before start(), or after done()");
if (mStopped) {
Log.w(TAG, "stop() called twice");
return;
}
mAudioTrackHandler.stop(mToken);
mToken = null;
// mToken will be null if the engine encounters
// an error before it called start().
if (mToken != null) {
mAudioTrackHandler.stop(mToken);
mToken = null;
} else {
// In all other cases, mAudioTrackHandler.stop() will
// result in onComplete being called.
mLogger.onWriteData();
}
mStopped = true;
}
}
@@ -124,7 +137,7 @@ class PlaybackSynthesisCallback extends AbstractSynthesisCallback {
}
SynthesisMessageParams params = new SynthesisMessageParams(
mStreamType, sampleRateInHz, audioFormat, channelCount, mVolume, mPan,
mDispatcher, mCallingApp);
mDispatcher, mCallingApp, mLogger);
mAudioTrackHandler.enqueueSynthesisStart(params);
mToken = params;
@@ -157,6 +170,8 @@ class PlaybackSynthesisCallback extends AbstractSynthesisCallback {
mAudioTrackHandler.enqueueSynthesisDataAvailable(mToken);
}
mLogger.onEngineDataReceived();
return TextToSpeech.SUCCESS;
}
@@ -177,6 +192,7 @@ class PlaybackSynthesisCallback extends AbstractSynthesisCallback {
}
mAudioTrackHandler.enqueueSynthesisDone(mToken);
mLogger.onEngineComplete();
}
return TextToSpeech.SUCCESS;
}
@@ -184,6 +200,9 @@ class PlaybackSynthesisCallback extends AbstractSynthesisCallback {
@Override
public void error() {
if (DBG) Log.d(TAG, "error() [will call stop]");
// Currently, this call will not be logged if error( ) is called
// before start.
mLogger.onError();
stop();
}
@@ -208,7 +227,7 @@ class PlaybackSynthesisCallback extends AbstractSynthesisCallback {
}
SynthesisMessageParams params = new SynthesisMessageParams(
mStreamType, sampleRateInHz, audioFormat, channelCount, mVolume, mPan,
mDispatcher, mCallingApp);
mDispatcher, mCallingApp, mLogger);
params.addBuffer(buffer, offset, length);
mAudioTrackHandler.enqueueSynthesisCompleteDataAvailable(params);

View File

@@ -30,6 +30,7 @@ final class SynthesisMessageParams extends MessageParams {
final int mChannelCount;
final float mVolume;
final float mPan;
final EventLogger mLogger;
public volatile AudioTrack mAudioTrack;
@@ -38,7 +39,7 @@ final class SynthesisMessageParams extends MessageParams {
SynthesisMessageParams(int streamType, int sampleRate,
int audioFormat, int channelCount,
float volume, float pan, UtteranceCompletedDispatcher dispatcher,
String callingApp) {
String callingApp, EventLogger logger) {
super(dispatcher, callingApp);
mStreamType = streamType;
@@ -47,6 +48,7 @@ final class SynthesisMessageParams extends MessageParams {
mChannelCount = channelCount;
mVolume = volume;
mPan = pan;
mLogger = logger;
// initially null.
mAudioTrack = null;

View File

@@ -82,8 +82,7 @@ public abstract class TextToSpeechService extends Service {
private AudioPlaybackHandler mAudioPlaybackHandler;
private CallbackMap mCallbacks;
private int mDefaultAvailability = TextToSpeech.LANG_NOT_SUPPORTED;
private String mPackageName;
@Override
public void onCreate() {
@@ -99,9 +98,10 @@ public abstract class TextToSpeechService extends Service {
mCallbacks = new CallbackMap();
mPackageName = getApplicationInfo().packageName;
// Load default language
mDefaultAvailability = onLoadLanguage(getDefaultLanguage(),
getDefaultCountry(), getDefaultVariant());
onLoadLanguage(getDefaultLanguage(), getDefaultCountry(), getDefaultVariant());
}
@Override
@@ -457,12 +457,14 @@ public abstract class TextToSpeechService extends Service {
// Non null after synthesis has started, and all accesses
// guarded by 'this'.
private AbstractSynthesisCallback mSynthesisCallback;
private final EventLogger mEventLogger;
public SynthesisSpeechItem(String callingApp, Bundle params, String text) {
super(callingApp, params);
mText = text;
mSynthesisRequest = new SynthesisRequest(mText, mParams);
setRequestParams(mSynthesisRequest);
mEventLogger = new EventLogger(mSynthesisRequest, getCallingApp(), mPackageName);
}
public String getText() {
@@ -485,6 +487,7 @@ public abstract class TextToSpeechService extends Service {
@Override
protected int playImpl() {
AbstractSynthesisCallback synthesisCallback;
mEventLogger.onRequestProcessingStart();
synchronized (this) {
mSynthesisCallback = createSynthesisCallback();
synthesisCallback = mSynthesisCallback;
@@ -495,7 +498,7 @@ public abstract class TextToSpeechService extends Service {
protected AbstractSynthesisCallback createSynthesisCallback() {
return new PlaybackSynthesisCallback(getStreamType(), getVolume(), getPan(),
mAudioPlaybackHandler, this, getCallingApp());
mAudioPlaybackHandler, this, getCallingApp(), mEventLogger);
}
private void setRequestParams(SynthesisRequest request) {