fix flaky behavior in FakeLatencyTracker

LatencyTrackerTest exposed a race condition leading to deadlock in
FakeLatencyTracker.

This also fixes users of FakeLatencyTracker like
SoundTriggerMiddlewareLoggingTest

Bug: 275113847
Test: atest LatencyTrackerTest --iterations 20
Test: atest FakeLatencyTrackerTest --iterations 20
Test: atest SoundTriggerMiddlewareLoggingTest --iterations 20
Change-Id: I5e4a4e489711fff05c2fceffbe76c258a54cd49f

4 files changed, 143 insertions, 132 deletions

diff --git a/core/java/com/android/internal/util/LatencyTracker.java b/core/java/com/android/internal/util/LatencyTracker.java
index c1445035ca33..f2776353fd1b 100644
--- a/core/java/com/android/internal/util/LatencyTracker.java
+++ b/core/java/com/android/internal/util/LatencyTracker.java
@@ -305,10 +305,17 @@ public class LatencyTracker {
     private final SparseArray<ActionProperties> mActionPropertiesMap = new SparseArray<>();
     @GuardedBy("mLock")
     private boolean mEnabled;
+    private final DeviceConfig.OnPropertiesChangedListener mOnPropertiesChangedListener =
+            this::updateProperties;
 
     // Wrapping this in a holder class achieves lazy loading behavior
     private static final class SLatencyTrackerHolder {
-        private static final LatencyTracker sLatencyTracker = new LatencyTracker();
+        private static final LatencyTracker sLatencyTracker;
+
+        static {
+            sLatencyTracker = new LatencyTracker();
+            sLatencyTracker.startListeningForLatencyTrackerConfigChanges();
+        }
     }
 
     public static LatencyTracker getInstance(Context context) {
@@ -319,31 +326,16 @@ public class LatencyTracker {
      * Constructor for LatencyTracker
      *
      * <p>This constructor is only visible for test classes to inject their own consumer callbacks
+     *
+     * @param startListeningForPropertyChanges If set, constructor will register for device config
+     *                      property updates prior to returning. If not set,
+     *                      {@link #startListeningForLatencyTrackerConfigChanges} must be called
+     *                      to start listening.
      */
     @RequiresPermission(Manifest.permission.READ_DEVICE_CONFIG)
     @VisibleForTesting
     public LatencyTracker() {
         mEnabled = DEFAULT_ENABLED;
-
-        final Context context = ActivityThread.currentApplication();
-        if (context != null
-                && context.checkCallingOrSelfPermission(READ_DEVICE_CONFIG) == PERMISSION_GRANTED) {
-            // Post initialization to the background in case we're running on the main thread.
-            BackgroundThread.getHandler().post(() -> this.updateProperties(
-                    DeviceConfig.getProperties(NAMESPACE_LATENCY_TRACKER)));
-            DeviceConfig.addOnPropertiesChangedListener(NAMESPACE_LATENCY_TRACKER,
-                    BackgroundThread.getExecutor(), this::updateProperties);
-        } else {
-            if (DEBUG) {
-                if (context == null) {
-                    Log.d(TAG, "No application for " + ActivityThread.currentActivityThread());
-                } else {
-                    Log.d(TAG, "Initialized the LatencyTracker."
-                            + " (No READ_DEVICE_CONFIG permission to change configs)"
-                            + " enabled=" + mEnabled + ", package=" + context.getPackageName());
-                }
-            }
-        }
     }
 
     private void updateProperties(DeviceConfig.Properties properties) {
@@ -366,6 +358,54 @@ public class LatencyTracker {
     }
 
     /**
+     * Test method to start listening to {@link DeviceConfig} properties changes.
+     *
+     * <p>During testing, a {@link LatencyTracker} it is desired to stop and start listening for
+     * config updates.
+     *
+     * <p>This is not used for production usages of this class outside of testing as we are
+     * using a single static object.
+     */
+    @VisibleForTesting
+    public void startListeningForLatencyTrackerConfigChanges() {
+        final Context context = ActivityThread.currentApplication();
+        if (context != null
+                && context.checkCallingOrSelfPermission(READ_DEVICE_CONFIG) == PERMISSION_GRANTED) {
+            // Post initialization to the background in case we're running on the main thread.
+            BackgroundThread.getHandler().post(() -> this.updateProperties(
+                    DeviceConfig.getProperties(NAMESPACE_LATENCY_TRACKER)));
+            DeviceConfig.addOnPropertiesChangedListener(NAMESPACE_LATENCY_TRACKER,
+                    BackgroundThread.getExecutor(), mOnPropertiesChangedListener);
+        } else {
+            if (DEBUG) {
+                if (context == null) {
+                    Log.d(TAG, "No application for " + ActivityThread.currentActivityThread());
+                } else {
+                    synchronized (mLock) {
+                        Log.d(TAG, "Initialized the LatencyTracker."
+                                + " (No READ_DEVICE_CONFIG permission to change configs)"
+                                + " enabled=" + mEnabled + ", package=" + context.getPackageName());
+                    }
+                }
+            }
+        }
+    }
+
+    /**
+     * Test method to stop listening to {@link DeviceConfig} properties changes.
+     *
+     * <p>During testing, a {@link LatencyTracker} it is desired to stop and start listening for
+     * config updates.
+     *
+     * <p>This is not used for production usages of this class outside of testing as we are
+     * using a single static object.
+     */
+    @VisibleForTesting
+    public void stopListeningForLatencyTrackerConfigChanges() {
+        DeviceConfig.removeOnPropertiesChangedListener(mOnPropertiesChangedListener);
+    }
+
+    /**
      * A helper method to translate action type to name.
      *
      * @param atomsProtoAction the action type defined in AtomsProto.java
diff --git a/core/tests/coretests/src/com/android/internal/util/LatencyTrackerTest.java b/core/tests/coretests/src/com/android/internal/util/LatencyTrackerTest.java
index 645324d57ea9..584ad205a55d 100644
--- a/core/tests/coretests/src/com/android/internal/util/LatencyTrackerTest.java
+++ b/core/tests/coretests/src/com/android/internal/util/LatencyTrackerTest.java
@@ -28,12 +28,12 @@ import static com.google.common.truth.Truth.assertWithMessage;
 import android.provider.DeviceConfig;
 
 import androidx.test.ext.junit.runners.AndroidJUnit4;
-import androidx.test.filters.SmallTest;
 
 import com.android.internal.util.LatencyTracker.ActionProperties;
 
 import com.google.common.truth.Expect;
 
+import org.junit.After;
 import org.junit.Before;
 import org.junit.Rule;
 import org.junit.Test;
@@ -48,7 +48,6 @@ import java.util.List;
 import java.util.Map;
 import java.util.stream.Collectors;
 
-@SmallTest
 @RunWith(AndroidJUnit4.class)
 public class LatencyTrackerTest {
     private static final String ENUM_NAME_PREFIX = "UIACTION_LATENCY_REPORTED__ACTION__";
@@ -65,6 +64,11 @@ public class LatencyTrackerTest {
         mLatencyTracker = FakeLatencyTracker.create();
     }
 
+    @After
+    public void tearDown() {
+        mLatencyTracker.stopListeningForLatencyTrackerConfigChanges();
+    }
+
     @Test
     public void testCujsMapToEnumsCorrectly() {
         List<Field> actions = getAllActionFields();
diff --git a/core/tests/coretests/testdoubles/src/com/android/internal/util/FakeLatencyTracker.java b/core/tests/coretests/testdoubles/src/com/android/internal/util/FakeLatencyTracker.java
index 61e976bee35e..76e69bf35aaf 100644
--- a/core/tests/coretests/testdoubles/src/com/android/internal/util/FakeLatencyTracker.java
+++ b/core/tests/coretests/testdoubles/src/com/android/internal/util/FakeLatencyTracker.java
@@ -25,8 +25,6 @@ import android.provider.DeviceConfig;
 import android.util.Log;
 import android.util.SparseArray;
 
-import androidx.annotation.Nullable;
-
 import com.android.internal.annotations.GuardedBy;
 
 import com.google.common.collect.ImmutableMap;
@@ -51,15 +49,17 @@ public final class FakeLatencyTracker extends LatencyTracker {
     private final List<String> mPerfettoTraceNamesTriggered;
     private final AtomicReference<SparseArray<ActionProperties>> mLastPropertiesUpdate =
             new AtomicReference<>();
-    @Nullable
-    @GuardedBy("mLock")
-    private Callable<Boolean> mShouldClosePropertiesUpdatedCallable = null;
+    private final AtomicReference<Callable<Boolean>> mShouldClosePropertiesUpdatedCallable =
+            new AtomicReference<>();
     private final ConditionVariable mDeviceConfigPropertiesUpdated = new ConditionVariable();
 
     public static FakeLatencyTracker create() throws Exception {
         Log.i(TAG, "create");
         disableForAllActions();
+        Log.i(TAG, "done disabling all actions");
         FakeLatencyTracker fakeLatencyTracker = new FakeLatencyTracker();
+        Log.i(TAG, "done creating tracker object");
+        fakeLatencyTracker.startListeningForLatencyTrackerConfigChanges();
         // always return the fake in the disabled state and let the client control the desired state
         fakeLatencyTracker.waitForGlobalEnabledState(false);
         fakeLatencyTracker.waitForAllPropertiesEnableState(false);
@@ -131,27 +131,25 @@ public final class FakeLatencyTracker extends LatencyTracker {
     @Override
     public void onDeviceConfigPropertiesUpdated(SparseArray<ActionProperties> actionProperties) {
         Log.d(TAG, "onDeviceConfigPropertiesUpdated: " + actionProperties);
+
         mLastPropertiesUpdate.set(actionProperties);
-        synchronized (mLock) {
-            if (mShouldClosePropertiesUpdatedCallable != null) {
-                try {
-                    boolean shouldClosePropertiesUpdated =
-                            mShouldClosePropertiesUpdatedCallable.call();
-                    Log.i(TAG, "shouldClosePropertiesUpdatedCallable callable result="
-                            + shouldClosePropertiesUpdated);
-                    if (shouldClosePropertiesUpdated) {
-                        Log.i(TAG, "shouldClosePropertiesUpdatedCallable=true, opening condition");
-                        mShouldClosePropertiesUpdatedCallable = null;
-                        mDeviceConfigPropertiesUpdated.open();
-                    }
-                } catch (Exception e) {
-                    Log.e(TAG, "exception when calling callable", e);
-                    throw new RuntimeException(e);
+        Callable<Boolean> shouldClosePropertiesUpdated =
+                mShouldClosePropertiesUpdatedCallable.get();
+        if (shouldClosePropertiesUpdated != null) {
+            try {
+                boolean result = shouldClosePropertiesUpdated.call();
+                Log.i(TAG, "shouldClosePropertiesUpdatedCallable callable result=" + result);
+                if (result) {
+                    mShouldClosePropertiesUpdatedCallable.set(null);
+                    mDeviceConfigPropertiesUpdated.open();
                 }
-            } else {
-                Log.i(TAG, "no conditional callable set, opening condition");
-                mDeviceConfigPropertiesUpdated.open();
+            } catch (Exception e) {
+                Log.e(TAG, "exception when calling callable", e);
+                throw new RuntimeException(e);
             }
+        } else {
+            Log.i(TAG, "no conditional callable set, opening condition");
+            mDeviceConfigPropertiesUpdated.open();
         }
     }
 
@@ -175,107 +173,82 @@ public final class FakeLatencyTracker extends LatencyTracker {
 
     public void waitForAllPropertiesEnableState(boolean enabledState) throws Exception {
         Log.i(TAG, "waitForAllPropertiesEnableState: enabledState=" + enabledState);
-        synchronized (mLock) {
-            Log.i(TAG, "closing condition");
-            mDeviceConfigPropertiesUpdated.close();
-            // Update the callable to only close the properties updated condition when all the
-            // desired properties have been updated. The DeviceConfig callbacks may happen multiple
-            // times so testing the resulting updates is required.
-            mShouldClosePropertiesUpdatedCallable = () -> {
-                Log.i(TAG, "verifying if last properties update has all properties enable="
-                        + enabledState);
-                SparseArray<ActionProperties> newProperties = mLastPropertiesUpdate.get();
-                if (newProperties != null) {
-                    for (int i = 0; i < newProperties.size(); i++) {
-                        if (newProperties.get(i).isEnabled() != enabledState) {
-                            return false;
-                        }
+        // Update the callable to only close the properties updated condition when all the
+        // desired properties have been updated. The DeviceConfig callbacks may happen multiple
+        // times so testing the resulting updates is required.
+        waitForPropertiesCondition(() -> {
+            Log.i(TAG, "verifying if last properties update has all properties enable="
+                    + enabledState);
+            SparseArray<ActionProperties> newProperties = mLastPropertiesUpdate.get();
+            if (newProperties != null) {
+                for (int i = 0; i < newProperties.size(); i++) {
+                    if (newProperties.get(i).isEnabled() != enabledState) {
+                        return false;
                     }
                 }
-                return true;
-            };
-            if (mShouldClosePropertiesUpdatedCallable.call()) {
-                return;
             }
-        }
-        Log.i(TAG, "waiting for condition");
-        mDeviceConfigPropertiesUpdated.block();
+            return true;
+        });
     }
 
     public void waitForMatchingActionProperties(ActionProperties actionProperties)
             throws Exception {
         Log.i(TAG, "waitForMatchingActionProperties: actionProperties=" + actionProperties);
-        synchronized (mLock) {
-            Log.i(TAG, "closing condition");
-            mDeviceConfigPropertiesUpdated.close();
-            // Update the callable to only close the properties updated condition when all the
-            // desired properties have been updated. The DeviceConfig callbacks may happen multiple
-            // times so testing the resulting updates is required.
-            mShouldClosePropertiesUpdatedCallable = () -> {
-                Log.i(TAG, "verifying if last properties update contains matching property ="
-                        + actionProperties);
-                SparseArray<ActionProperties> newProperties = mLastPropertiesUpdate.get();
-                if (newProperties != null) {
-                    if (newProperties.size() > 0) {
-                        return newProperties.get(actionProperties.getAction()).equals(
-                                actionProperties);
-                    }
+        // Update the callable to only close the properties updated condition when all the
+        // desired properties have been updated. The DeviceConfig callbacks may happen multiple
+        // times so testing the resulting updates is required.
+        waitForPropertiesCondition(() -> {
+            Log.i(TAG, "verifying if last properties update contains matching property ="
+                    + actionProperties);
+            SparseArray<ActionProperties> newProperties = mLastPropertiesUpdate.get();
+            if (newProperties != null) {
+                if (newProperties.size() > 0) {
+                    return newProperties.get(actionProperties.getAction()).equals(
+                            actionProperties);
                 }
-                return false;
-            };
-            if (mShouldClosePropertiesUpdatedCallable.call()) {
-                return;
             }
-        }
-        Log.i(TAG, "waiting for condition");
-        mDeviceConfigPropertiesUpdated.block();
+            return false;
+        });
     }
 
     public void waitForActionEnabledState(int action, boolean enabledState) throws Exception {
         Log.i(TAG, "waitForActionEnabledState:"
                 + " action=" + action + ", enabledState=" + enabledState);
-        synchronized (mLock) {
-            Log.i(TAG, "closing condition");
-            mDeviceConfigPropertiesUpdated.close();
-            // Update the callable to only close the properties updated condition when all the
-            // desired properties have been updated. The DeviceConfig callbacks may happen multiple
-            // times so testing the resulting updates is required.
-            mShouldClosePropertiesUpdatedCallable = () -> {
-                Log.i(TAG, "verifying if last properties update contains action=" + action
-                        + ", enabledState=" + enabledState);
-                SparseArray<ActionProperties> newProperties = mLastPropertiesUpdate.get();
-                if (newProperties != null) {
-                    if (newProperties.size() > 0) {
-                        return newProperties.get(action).isEnabled() == enabledState;
-                    }
+        // Update the callable to only close the properties updated condition when all the
+        // desired properties have been updated. The DeviceConfig callbacks may happen multiple
+        // times so testing the resulting updates is required.
+        waitForPropertiesCondition(() -> {
+            Log.i(TAG, "verifying if last properties update contains action=" + action
+                    + ", enabledState=" + enabledState);
+            SparseArray<ActionProperties> newProperties = mLastPropertiesUpdate.get();
+            if (newProperties != null) {
+                if (newProperties.size() > 0) {
+                    return newProperties.get(action).isEnabled() == enabledState;
                 }
-                return false;
-            };
-            if (mShouldClosePropertiesUpdatedCallable.call()) {
-                return;
             }
-        }
-        Log.i(TAG, "waiting for condition");
-        mDeviceConfigPropertiesUpdated.block();
+            return false;
+        });
     }
 
     public void waitForGlobalEnabledState(boolean enabledState) throws Exception {
         Log.i(TAG, "waitForGlobalEnabledState: enabledState=" + enabledState);
-        synchronized (mLock) {
-            Log.i(TAG, "closing condition");
-            mDeviceConfigPropertiesUpdated.close();
-            // Update the callable to only close the properties updated condition when all the
-            // desired properties have been updated. The DeviceConfig callbacks may happen multiple
-            // times so testing the resulting updates is required.
-            mShouldClosePropertiesUpdatedCallable = () -> {
-                //noinspection deprecation
-                return isEnabled() == enabledState;
-            };
-            if (mShouldClosePropertiesUpdatedCallable.call()) {
-                return;
-            }
+        // Update the callable to only close the properties updated condition when all the
+        // desired properties have been updated. The DeviceConfig callbacks may happen multiple
+        // times so testing the resulting updates is required.
+        waitForPropertiesCondition(() -> {
+            //noinspection deprecation
+            return isEnabled() == enabledState;
+        });
+    }
+
+    public void waitForPropertiesCondition(Callable<Boolean> shouldClosePropertiesUpdatedCallable)
+            throws Exception {
+        mShouldClosePropertiesUpdatedCallable.set(shouldClosePropertiesUpdatedCallable);
+        mDeviceConfigPropertiesUpdated.close();
+        if (!shouldClosePropertiesUpdatedCallable.call()) {
+            Log.i(TAG, "waiting for mDeviceConfigPropertiesUpdated condition");
+            mDeviceConfigPropertiesUpdated.block();
         }
-        Log.i(TAG, "waiting for condition");
-        mDeviceConfigPropertiesUpdated.block();
+        Log.i(TAG, "waitForPropertiesCondition: returning");
     }
 }
diff --git a/services/tests/voiceinteractiontests/src/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLoggingLatencyTest.java b/services/tests/voiceinteractiontests/src/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLoggingLatencyTest.java
index cc357d76cb4a..7bcd60b067b5 100644
--- a/services/tests/voiceinteractiontests/src/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLoggingLatencyTest.java
+++ b/services/tests/voiceinteractiontests/src/com/android/server/soundtrigger_middleware/SoundTriggerMiddlewareLoggingLatencyTest.java
@@ -37,7 +37,6 @@ import android.os.BatteryStatsInternal;
 import android.os.Process;
 import android.os.RemoteException;
 
-import androidx.test.filters.FlakyTest;
 import androidx.test.platform.app.InstrumentationRegistry;
 
 import com.android.internal.util.FakeLatencyTracker;
@@ -91,12 +90,10 @@ public class SoundTriggerMiddlewareLoggingLatencyTest {
     }
 
     @Test
-    @FlakyTest(bugId = 275113847)
     public void testSetUpAndTearDown() {
     }
 
     @Test
-    @FlakyTest(bugId = 275113847)
     public void testOnPhraseRecognitionStartsLatencyTrackerWithSuccessfulPhraseIdTrigger()
             throws RemoteException {
         ArgumentCaptor<ISoundTriggerCallback> soundTriggerCallbackCaptor = ArgumentCaptor.forClass(
@@ -112,7 +109,6 @@ public class SoundTriggerMiddlewareLoggingLatencyTest {
     }
 
     @Test
-    @FlakyTest(bugId = 275113847)
     public void testOnPhraseRecognitionRestartsActiveSession() throws RemoteException {
         ArgumentCaptor<ISoundTriggerCallback> soundTriggerCallbackCaptor = ArgumentCaptor.forClass(
                 ISoundTriggerCallback.class);
@@ -132,7 +128,6 @@ public class SoundTriggerMiddlewareLoggingLatencyTest {
     }
 
     @Test
-    @FlakyTest(bugId = 275113847)
     public void testOnPhraseRecognitionNeverStartsLatencyTrackerWithNonSuccessEvent()
             throws RemoteException {
         ArgumentCaptor<ISoundTriggerCallback> soundTriggerCallbackCaptor = ArgumentCaptor.forClass(
@@ -149,7 +144,6 @@ public class SoundTriggerMiddlewareLoggingLatencyTest {
     }
 
     @Test
-    @FlakyTest(bugId = 275113847)
     public void testOnPhraseRecognitionNeverStartsLatencyTrackerWithNoKeyphraseId()
             throws RemoteException {
         ArgumentCaptor<ISoundTriggerCallback> soundTriggerCallbackCaptor = ArgumentCaptor.forClass(