Merge changes from topic "latencytracker-vi-fix" into tm-qpr-dev

* changes:
  cancel VI latency tracking for non ST triggers
  only start latency measurement on successful phrase triggers
  fix enable checks to check use action in LatencyTracker
  add LatencyTracker tracing cancel / timeout events
This commit is contained in:
Nicholas Ambur
2023-03-23 19:44:00 +00:00
committed by Android (Google) Code Review
4 changed files with 85 additions and 13 deletions

View File

@@ -471,7 +471,7 @@ public class LatencyTracker {
*/
public void onActionStart(@Action int action, String tag) {
synchronized (mLock) {
if (!isEnabled()) {
if (!isEnabled(action)) {
return;
}
// skip if the action is already instrumenting.
@@ -495,7 +495,7 @@ public class LatencyTracker {
*/
public void onActionEnd(@Action int action) {
synchronized (mLock) {
if (!isEnabled()) {
if (!isEnabled(action)) {
return;
}
Session session = mSessions.get(action);
@@ -605,23 +605,27 @@ public class LatencyTracker {
void begin(@NonNull Runnable timeoutAction) {
mStartRtc = SystemClock.elapsedRealtime();
Trace.asyncTraceBegin(TRACE_TAG_APP, traceName(), 0);
Trace.asyncTraceForTrackBegin(TRACE_TAG_APP, traceName(), traceName(), 0);
// start counting timeout.
mTimeoutRunnable = timeoutAction;
mTimeoutRunnable = () -> {
Trace.instantForTrack(TRACE_TAG_APP, traceName(), "timeout");
timeoutAction.run();
};
BackgroundThread.getHandler()
.postDelayed(mTimeoutRunnable, TimeUnit.SECONDS.toMillis(15));
}
void end() {
mEndRtc = SystemClock.elapsedRealtime();
Trace.asyncTraceEnd(TRACE_TAG_APP, traceName(), 0);
Trace.asyncTraceForTrackEnd(TRACE_TAG_APP, traceName(), "end", 0);
BackgroundThread.getHandler().removeCallbacks(mTimeoutRunnable);
mTimeoutRunnable = null;
}
void cancel() {
Trace.asyncTraceEnd(TRACE_TAG_APP, traceName(), 0);
Trace.instantForTrack(TRACE_TAG_APP, traceName(), "cancel");
Trace.asyncTraceForTrackEnd(TRACE_TAG_APP, traceName(), "cancel", 0);
BackgroundThread.getHandler().removeCallbacks(mTimeoutRunnable);
mTimeoutRunnable = null;
}

View File

@@ -26,6 +26,7 @@ import android.media.soundtrigger.PhraseRecognitionEvent;
import android.media.soundtrigger.PhraseSoundModel;
import android.media.soundtrigger.RecognitionConfig;
import android.media.soundtrigger.RecognitionEvent;
import android.media.soundtrigger.RecognitionStatus;
import android.media.soundtrigger.SoundModel;
import android.media.soundtrigger_middleware.ISoundTriggerCallback;
import android.media.soundtrigger_middleware.ISoundTriggerModule;
@@ -34,6 +35,7 @@ import android.os.IBinder;
import android.os.RemoteException;
import android.util.Log;
import com.android.internal.util.ArrayUtils;
import com.android.internal.util.LatencyTracker;
import java.io.PrintWriter;
@@ -358,14 +360,19 @@ public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInt
* Starts the latency tracking log for keyphrase hotword invocation.
* The measurement covers from when the SoundTrigger HAL emits an event to when the
* {@link android.service.voice.VoiceInteractionSession} system UI view is shown.
*
* <p>The session is only started if the {@link PhraseRecognitionEvent} has a status of
* {@link RecognitionStatus#SUCCESS}
*/
private void startKeyphraseEventLatencyTracking(PhraseRecognitionEvent event) {
String latencyTrackerTag = null;
if (event.phraseExtras.length > 0) {
latencyTrackerTag = "KeyphraseId=" + event.phraseExtras[0].id;
if (event.common.status != RecognitionStatus.SUCCESS
|| ArrayUtils.isEmpty(event.phraseExtras)) {
return;
}
LatencyTracker latencyTracker = LatencyTracker.getInstance(mContext);
// To avoid adding cancel to all of the different failure modes between here and
String latencyTrackerTag = "KeyphraseId=" + event.phraseExtras[0].id;
// To avoid adding cancel to all the different failure modes between here and
// showing the system UI, we defensively cancel once.
// Either we hit the LatencyTracker timeout of 15 seconds or we defensively cancel
// here if any error occurs.

View File

@@ -34,10 +34,13 @@ import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_EVENT
import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__DETECTOR_TYPE__NORMAL_DETECTOR;
import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__DETECTOR_TYPE__TRUSTED_DETECTOR_DSP;
import static com.android.internal.util.FrameworkStatsLog.HOTWORD_DETECTOR_KEYPHRASE_TRIGGERED__DETECTOR_TYPE__TRUSTED_DETECTOR_SOFTWARE;
import static com.android.internal.util.LatencyTracker.ACTION_SHOW_VOICE_INTERACTION;
import android.content.Context;
import android.service.voice.HotwordDetector;
import com.android.internal.util.FrameworkStatsLog;
import com.android.internal.util.LatencyTracker;
/**
* A utility class for logging hotword statistics event.
@@ -116,6 +119,46 @@ public final class HotwordMetricsLogger {
metricsDetectorType, event, uid, streamSizeBytes, bundleSizeBytes, streamCount);
}
/**
* Starts a {@link LatencyTracker} log for the time it takes to show the
* {@link android.service.voice.VoiceInteractionSession} system UI after a voice trigger.
*
* @see LatencyTracker
*
* @param tag Extra tag to separate different sessions from each other.
*/
public static void startHotwordTriggerToUiLatencySession(Context context, String tag) {
LatencyTracker.getInstance(context).onActionStart(ACTION_SHOW_VOICE_INTERACTION, tag);
}
/**
* Completes a {@link LatencyTracker} log for the time it takes to show the
* {@link android.service.voice.VoiceInteractionSession} system UI after a voice trigger.
*
* <p>Completing this session will result in logging metric data.</p>
*
* @see LatencyTracker
*/
public static void stopHotwordTriggerToUiLatencySession(Context context) {
LatencyTracker.getInstance(context).onActionEnd(ACTION_SHOW_VOICE_INTERACTION);
}
/**
* Cancels a {@link LatencyTracker} log for the time it takes to show the
* {@link android.service.voice.VoiceInteractionSession} system UI after a voice trigger.
*
* <p>Cancels typically occur when the VoiceInteraction session UI is shown for reasons outside
* of a {@link android.hardware.soundtrigger.SoundTrigger.RecognitionEvent} such as an
* invocation from an external source or service.</p>
*
* <p>Canceling this session will not result in logging metric data.
*
* @see LatencyTracker
*/
public static void cancelHotwordTriggerToUiLatencySession(Context context) {
LatencyTracker.getInstance(context).onActionCancel(ACTION_SHOW_VOICE_INTERACTION);
}
private static int getCreateMetricsDetectorType(int detectorType) {
switch (detectorType) {
case HotwordDetector.DETECTOR_TYPE_TRUSTED_HOTWORD_SOFTWARE:

View File

@@ -95,7 +95,6 @@ import com.android.internal.app.IVoiceInteractor;
import com.android.internal.content.PackageMonitor;
import com.android.internal.os.BackgroundThread;
import com.android.internal.util.DumpUtils;
import com.android.internal.util.LatencyTracker;
import com.android.server.FgThread;
import com.android.server.LocalServices;
import com.android.server.SystemService;
@@ -404,6 +403,10 @@ public class VoiceInteractionManagerService extends SystemService {
final int callingUid = Binder.getCallingUid();
final long caller = Binder.clearCallingIdentity();
try {
// HotwordDetector trigger uses VoiceInteractionService#showSession
// We need to cancel here because UI is not being shown due to a SoundTrigger
// HAL event.
HotwordMetricsLogger.cancelHotwordTriggerToUiLatencySession(mContext);
mImpl.showSessionLocked(options,
VoiceInteractionSession.SHOW_SOURCE_ACTIVITY,
new IVoiceInteractionSessionShowCallback.Stub() {
@@ -954,6 +957,13 @@ public class VoiceInteractionManagerService extends SystemService {
Slog.w(TAG, "showSessionFromSession without running voice interaction service");
return false;
}
// If the token is null, then the request to show the session is not coming from
// the active VoiceInteractionService session.
// We need to cancel here because UI is not being shown due to a SoundTrigger
// HAL event.
if (token == null) {
HotwordMetricsLogger.cancelHotwordTriggerToUiLatencySession(mContext);
}
final long caller = Binder.clearCallingIdentity();
try {
return mImpl.showSessionLocked(sessionArgs, flags, null, null);
@@ -1718,6 +1728,11 @@ public class VoiceInteractionManagerService extends SystemService {
final long caller = Binder.clearCallingIdentity();
try {
// HotwordDetector trigger uses VoiceInteractionService#showSession
// We need to cancel here because UI is not being shown due to a SoundTrigger
// HAL event.
HotwordMetricsLogger.cancelHotwordTriggerToUiLatencySession(mContext);
return mImpl.showSessionLocked(args,
sourceFlags
| VoiceInteractionSession.SHOW_WITH_ASSIST
@@ -2361,8 +2376,11 @@ public class VoiceInteractionManagerService extends SystemService {
public void onVoiceSessionWindowVisibilityChanged(boolean visible)
throws RemoteException {
if (visible) {
LatencyTracker.getInstance(mContext)
.onActionEnd(LatencyTracker.ACTION_SHOW_VOICE_INTERACTION);
// The AlwaysOnHotwordDetector trigger latency is always completed here even
// if the reason the window was shown was not due to a SoundTrigger HAL
// event. It is expected that the latency will be canceled if shown for
// other invocation reasons, and this call becomes a noop.
HotwordMetricsLogger.stopHotwordTriggerToUiLatencySession(mContext);
}
}