Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 91701dd2 authored by Nicholas Ambur's avatar Nicholas Ambur
Browse files

only start latency measurement on successful phrase triggers 

Bug: 265850090
Test: atest SoundTriggerMiddlewareLoggingTest
Change-Id: Ifaba86daea8ab92551ed75a251cd3a6ca55ffaed
parent 71f29f31

services/tests/voiceinteractiontests/Android.bp

+1 −0
Original line number Diff line number Diff line
@@ -29,6 +29,7 @@ android_test { 


    srcs: [

        "src/**/*.java",

        ":FrameworksCoreTestDoubles-sources",

    ],



    static_libs: [

services/tests/voiceinteractiontests/src/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLoggingTest.java

0 → 100644
+181 −0
Original line number Diff line number Diff line 
/*

 * Copyright (C) 2023 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_middleware;



import static com.android.internal.util.LatencyTracker.ACTION_SHOW_VOICE_INTERACTION;



import static com.google.common.truth.Truth.assertThat;



import static org.mockito.ArgumentMatchers.anyInt;

import static org.mockito.Mockito.verify;



import android.Manifest;

import android.app.ActivityThread;

import android.media.permission.Identity;

import android.media.permission.IdentityContext;

import android.media.soundtrigger.PhraseRecognitionEvent;

import android.media.soundtrigger.PhraseRecognitionExtra;

import android.media.soundtrigger.RecognitionEvent;

import android.media.soundtrigger.RecognitionStatus;

import android.media.soundtrigger_middleware.ISoundTriggerCallback;

import android.media.soundtrigger_middleware.ISoundTriggerModule;

import android.os.BatteryStatsInternal;

import android.os.Process;

import android.os.RemoteException;



import androidx.test.platform.app.InstrumentationRegistry;



import com.android.internal.util.FakeLatencyTracker;



import org.junit.After;

import org.junit.Before;

import org.junit.Test;

import org.junit.runner.RunWith;

import org.junit.runners.JUnit4;

import org.mockito.ArgumentCaptor;

import org.mockito.Mock;

import org.mockito.MockitoAnnotations;



import java.util.Optional;



@RunWith(JUnit4.class)

public class SoundTriggerMiddlewareLoggingTest {

    private FakeLatencyTracker mLatencyTracker;

    @Mock

    private BatteryStatsInternal mBatteryStatsInternal;

    @Mock

    private ISoundTriggerMiddlewareInternal mDelegateMiddleware;

    @Mock

    private ISoundTriggerCallback mISoundTriggerCallback;

    @Mock

    private ISoundTriggerModule mSoundTriggerModule;

    private SoundTriggerMiddlewareLogging mSoundTriggerMiddlewareLogging;



    @Before

    public void setUp() throws Exception {

        MockitoAnnotations.initMocks(this);



        InstrumentationRegistry.getInstrumentation().getUiAutomation()

                .adoptShellPermissionIdentity(Manifest.permission.WRITE_DEVICE_CONFIG,

                        Manifest.permission.READ_DEVICE_CONFIG);



        Identity identity = new Identity();

        identity.uid = Process.myUid();

        identity.pid = Process.myPid();

        identity.packageName = ActivityThread.currentOpPackageName();

        IdentityContext.create(identity);



        mLatencyTracker = FakeLatencyTracker.create();

        mLatencyTracker.forceEnabled(ACTION_SHOW_VOICE_INTERACTION, -1);

        mSoundTriggerMiddlewareLogging = new SoundTriggerMiddlewareLogging(mLatencyTracker,

                () -> mBatteryStatsInternal,

                mDelegateMiddleware);

    }



    @After

    public void tearDown() {

        InstrumentationRegistry.getInstrumentation().getUiAutomation()

                .dropShellPermissionIdentity();

    }



    @Test

    public void testSetUpAndTearDown() {

    }



    @Test

    public void testOnPhraseRecognitionStartsLatencyTrackerWithSuccessfulPhraseIdTrigger()

            throws RemoteException {

        ArgumentCaptor<ISoundTriggerCallback> soundTriggerCallbackCaptor = ArgumentCaptor.forClass(

                ISoundTriggerCallback.class);

        mSoundTriggerMiddlewareLogging.attach(0, mISoundTriggerCallback);

        verify(mDelegateMiddleware).attach(anyInt(), soundTriggerCallbackCaptor.capture());



        triggerPhraseRecognitionEvent(soundTriggerCallbackCaptor.getValue(),

                RecognitionStatus.SUCCESS, Optional.of(100) /* keyphraseId */);



        assertThat(mLatencyTracker.getActiveActionStartTime(

                ACTION_SHOW_VOICE_INTERACTION)).isGreaterThan(-1);

    }



    @Test

    public void testOnPhraseRecognitionRestartsActiveSession() throws RemoteException {

        ArgumentCaptor<ISoundTriggerCallback> soundTriggerCallbackCaptor = ArgumentCaptor.forClass(

                ISoundTriggerCallback.class);

        mSoundTriggerMiddlewareLogging.attach(0, mISoundTriggerCallback);

        verify(mDelegateMiddleware).attach(anyInt(), soundTriggerCallbackCaptor.capture());



        triggerPhraseRecognitionEvent(soundTriggerCallbackCaptor.getValue(),

                RecognitionStatus.SUCCESS, Optional.of(100) /* keyphraseId */);

        long firstTriggerSessionStartTime = mLatencyTracker.getActiveActionStartTime(

                ACTION_SHOW_VOICE_INTERACTION);

        triggerPhraseRecognitionEvent(soundTriggerCallbackCaptor.getValue(),

                RecognitionStatus.SUCCESS, Optional.of(100) /* keyphraseId */);

        assertThat(mLatencyTracker.getActiveActionStartTime(

                ACTION_SHOW_VOICE_INTERACTION)).isGreaterThan(-1);

        assertThat(mLatencyTracker.getActiveActionStartTime(

                ACTION_SHOW_VOICE_INTERACTION)).isNotEqualTo(firstTriggerSessionStartTime);

    }



    @Test

    public void testOnPhraseRecognitionNeverStartsLatencyTrackerWithNonSuccessEvent()

            throws RemoteException {

        ArgumentCaptor<ISoundTriggerCallback> soundTriggerCallbackCaptor = ArgumentCaptor.forClass(

                ISoundTriggerCallback.class);

        mSoundTriggerMiddlewareLogging.attach(0, mISoundTriggerCallback);

        verify(mDelegateMiddleware).attach(anyInt(), soundTriggerCallbackCaptor.capture());



        triggerPhraseRecognitionEvent(soundTriggerCallbackCaptor.getValue(),

                RecognitionStatus.ABORTED, Optional.of(100) /* keyphraseId */);



        assertThat(

                mLatencyTracker.getActiveActionStartTime(ACTION_SHOW_VOICE_INTERACTION)).isEqualTo(

                -1);

    }



    @Test

    public void testOnPhraseRecognitionNeverStartsLatencyTrackerWithNoKeyphraseId()

            throws RemoteException {

        ArgumentCaptor<ISoundTriggerCallback> soundTriggerCallbackCaptor = ArgumentCaptor.forClass(

                ISoundTriggerCallback.class);

        mSoundTriggerMiddlewareLogging.attach(0, mISoundTriggerCallback);

        verify(mDelegateMiddleware).attach(anyInt(), soundTriggerCallbackCaptor.capture());



        triggerPhraseRecognitionEvent(soundTriggerCallbackCaptor.getValue(),

                RecognitionStatus.SUCCESS, Optional.empty() /* keyphraseId */);



        assertThat(

                mLatencyTracker.getActiveActionStartTime(ACTION_SHOW_VOICE_INTERACTION)).isEqualTo(

                -1);

    }



    private void triggerPhraseRecognitionEvent(ISoundTriggerCallback callback,

            @RecognitionStatus int triggerEventStatus, Optional<Integer> optionalKeyphraseId)

            throws RemoteException {

        // trigger a phrase recognition to start a latency tracker session

        PhraseRecognitionEvent successEventWithKeyphraseId = new PhraseRecognitionEvent();

        successEventWithKeyphraseId.common = new RecognitionEvent();

        successEventWithKeyphraseId.common.status = triggerEventStatus;

        if (optionalKeyphraseId.isPresent()) {

            PhraseRecognitionExtra recognitionExtra = new PhraseRecognitionExtra();

            recognitionExtra.id = optionalKeyphraseId.get();

            successEventWithKeyphraseId.phraseExtras =

                    new PhraseRecognitionExtra[]{recognitionExtra};

        }

        callback.onPhraseRecognition(0 /* modelHandle */, successEventWithKeyphraseId,

                0 /* captureSession */);

    }

}

services/voiceinteraction/java/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLogging.java

+42 −24
Original line number Diff line number Diff line
@@ -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;
@@ -36,6 +37,8 @@ import android.os.RemoteException; 
import android.os.SystemClock;

import android.util.Log;



import com.android.internal.annotations.VisibleForTesting;

import com.android.internal.util.ArrayUtils;

import com.android.internal.util.LatencyTracker;

import com.android.server.LocalServices;
@@ -44,6 +47,7 @@ import java.text.SimpleDateFormat; 
import java.util.Date;

import java.util.LinkedList;

import java.util.Objects;

import java.util.function.Supplier;



/**

 * An ISoundTriggerMiddlewareService decorator, which adds logging of all API calls (and
@@ -71,12 +75,23 @@ import java.util.Objects; 
public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInternal, Dumpable {

    private static final String TAG = "SoundTriggerMiddlewareLogging";

    private final @NonNull ISoundTriggerMiddlewareInternal mDelegate;

    private final @NonNull Context mContext;

    private final @NonNull LatencyTracker mLatencyTracker;

    private final @NonNull Supplier<BatteryStatsInternal> mBatteryStatsInternalSupplier;



    public SoundTriggerMiddlewareLogging(@NonNull Context context,

            @NonNull ISoundTriggerMiddlewareInternal delegate) {

        this(LatencyTracker.getInstance(context),

                () -> BatteryStatsHolder.INSTANCE,

                delegate);

    }



    @VisibleForTesting

    public SoundTriggerMiddlewareLogging(@NonNull LatencyTracker latencyTracker,

            @NonNull Supplier<BatteryStatsInternal> batteryStatsInternalSupplier,

            @NonNull ISoundTriggerMiddlewareInternal delegate) {

        mDelegate = delegate;

        mContext = context;

        mLatencyTracker = latencyTracker;

        mBatteryStatsInternalSupplier = batteryStatsInternalSupplier;

    }



    @Override
@@ -294,7 +309,7 @@ public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInt 
            public void onRecognition(int modelHandle, RecognitionEvent event, int captureSession)

                    throws RemoteException {

                try {

                    BatteryStatsHolder.INSTANCE.noteWakingSoundTrigger(

                    mBatteryStatsInternalSupplier.get().noteWakingSoundTrigger(

                            SystemClock.elapsedRealtime(), mOriginatorIdentity.uid);

                    mCallbackDelegate.onRecognition(modelHandle, event, captureSession);

                    logVoidReturn("onRecognition", modelHandle, event);
@@ -309,7 +324,7 @@ public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInt 
                    int captureSession)

                    throws RemoteException {

                try {

                    BatteryStatsHolder.INSTANCE.noteWakingSoundTrigger(

                    mBatteryStatsInternalSupplier.get().noteWakingSoundTrigger(

                            SystemClock.elapsedRealtime(), mOriginatorIdentity.uid);

                    startKeyphraseEventLatencyTracking(event);

                    mCallbackDelegate.onPhraseRecognition(modelHandle, event, captureSession);
@@ -361,26 +376,6 @@ public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInt 
                logVoidReturnWithObject(this, mOriginatorIdentity, methodName, args);

            }



            /**

             * 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.

             */

            private void startKeyphraseEventLatencyTracking(PhraseRecognitionEvent event) {

                String latencyTrackerTag = null;

                if (event.phraseExtras.length > 0) {

                    latencyTrackerTag = "KeyphraseId=" + event.phraseExtras[0].id;

                }

                LatencyTracker latencyTracker = LatencyTracker.getInstance(mContext);

                // To avoid adding cancel to all of 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.

                latencyTracker.onActionCancel(LatencyTracker.ACTION_SHOW_VOICE_INTERACTION);

                latencyTracker.onActionStart(LatencyTracker.ACTION_SHOW_VOICE_INTERACTION,

                        latencyTrackerTag);

            }



            @Override

            public IBinder asBinder() {

                return mCallbackDelegate.asBinder();
@@ -399,6 +394,29 @@ public class SoundTriggerMiddlewareLogging implements ISoundTriggerMiddlewareInt 
                LocalServices.getService(BatteryStatsInternal.class);

    }



    /**

     * 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) {

        if (event.common.status != RecognitionStatus.SUCCESS

                || ArrayUtils.isEmpty(event.phraseExtras)) {

            return;

        }



        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.

        mLatencyTracker.onActionCancel(LatencyTracker.ACTION_SHOW_VOICE_INTERACTION);

        mLatencyTracker.onActionStart(LatencyTracker.ACTION_SHOW_VOICE_INTERACTION,

                latencyTrackerTag);

    }



    ////////////////////////////////////////////////////////////////////////////////////////////////

    // Actual logging logic below.