Add a new countdown latch to ensure telephony unbinds

1) After each test, ensure that AOSP has unbound before continuing.
2) Enhance logging and fix some logging typos

Bug: 197991451

Test: atest CtsTelephonyTestCases:ImsServiceTest
Change-Id: I2ea68d615c38dae08fb30fff324aa1d2bbb0114c
Merged-In: I2ea68d615c38dae08fb30fff324aa1d2bbb0114c
diff --git a/tests/tests/telephony/current/TestExternalImsServiceApp/aidl/android/telephony/cts/externalimsservice/ITestExternalImsService.aidl b/tests/tests/telephony/current/TestExternalImsServiceApp/aidl/android/telephony/cts/externalimsservice/ITestExternalImsService.aidl
index 2529ada..71924a2 100644
--- a/tests/tests/telephony/current/TestExternalImsServiceApp/aidl/android/telephony/cts/externalimsservice/ITestExternalImsService.aidl
+++ b/tests/tests/telephony/current/TestExternalImsServiceApp/aidl/android/telephony/cts/externalimsservice/ITestExternalImsService.aidl
@@ -29,4 +29,5 @@
     boolean isRcsFeatureCreated();
     boolean isMmTelFeatureCreated();
     void resetState();
+    boolean isTelephonyBound();
 }
diff --git a/tests/tests/telephony/current/TestExternalImsServiceApp/src/android/telephony/cts/externalimsservice/TestExternalImsService.java b/tests/tests/telephony/current/TestExternalImsServiceApp/src/android/telephony/cts/externalimsservice/TestExternalImsService.java
index 9101ae5..eaeb6d1 100644
--- a/tests/tests/telephony/current/TestExternalImsServiceApp/src/android/telephony/cts/externalimsservice/TestExternalImsService.java
+++ b/tests/tests/telephony/current/TestExternalImsServiceApp/src/android/telephony/cts/externalimsservice/TestExternalImsService.java
@@ -29,7 +29,7 @@
  */
 
 public class TestExternalImsService extends TestImsService {
-    private static final String TAG = "GtsImsTestDeviceImsService";
+    private static final String TAG = "CtsImsTestDeviceImsService";
     // TODO: Use ImsService.SERVICE_INTERFACE definition when it becomes public.
     private static final String ACTION_BIND_IMS_SERVICE = "android.telephony.ims.ImsService";
 
@@ -56,19 +56,26 @@
         public void resetState() {
             TestExternalImsService.this.resetState();
         }
+
+        public boolean isTelephonyBound() {
+            return TestExternalImsService.this.isTelephonyBound();
+        }
     }
 
     @Override
     public IBinder onBind(Intent intent) {
-        if (ACTION_BIND_IMS_SERVICE.equals(intent.getAction())) {
-            if (ImsUtils.VDBG) {
-                Log.i(TAG, "onBind-Remote");
+        synchronized (mLock) {
+            if (ACTION_BIND_IMS_SERVICE.equals(intent.getAction())) {
+                if (ImsUtils.VDBG) {
+                    Log.i(TAG, "onBind-Remote");
+                }
+                mIsTelephonyBound = true;
+                return super.onBind(intent);
             }
-            return super.onBind(intent);
+            if (ImsUtils.VDBG) {
+                Log.i(TAG, "onBind-Local");
+            }
+            return mBinder;
         }
-        if (ImsUtils.VDBG) {
-            Log.i(TAG, "onBind-Local");
-        }
-        return mBinder;
     }
 }
diff --git a/tests/tests/telephony/current/src/android/telephony/ims/cts/ImsServiceConnector.java b/tests/tests/telephony/current/src/android/telephony/ims/cts/ImsServiceConnector.java
index 65bc7d3..a994d98 100644
--- a/tests/tests/telephony/current/src/android/telephony/ims/cts/ImsServiceConnector.java
+++ b/tests/tests/telephony/current/src/android/telephony/ims/cts/ImsServiceConnector.java
@@ -123,7 +123,7 @@
 
         @Override
         public void onServiceDisconnected(ComponentName name) {
-            mCarrierService = null;
+            mExternalService = null;
         }
     }
 
@@ -149,11 +149,13 @@
             mIsServiceOverridden = true;
             switch (mConnectionType) {
                 case CONNECTION_TYPE_IMS_SERVICE_CARRIER: {
-                    setCarrierImsService("none");
+                    boolean unbindSent = setCarrierImsService("none");
+                    if (unbindSent) waitForCarrierPackageUnbind();
                     break;
                 }
                 case CONNECTION_TYPE_IMS_SERVICE_DEVICE: {
-                    setDeviceImsService("");
+                    boolean unbindSent = setDeviceImsService("");
+                    if (unbindSent) waitForDevicePackageUnbind();
                     break;
                 }
                 case CONNECTION_TYPE_DEFAULT_SMS_APP: {
@@ -163,6 +165,35 @@
             }
         }
 
+        void waitForCarrierPackageUnbind() {
+            TestImsService carrierService = getCarrierService();
+            if (carrierService == null) return;
+            // First unbind the local services
+            removeLocalCarrierServiceConnection();
+            // Then wait for AOSP to unbind if there is still an active binding.
+            boolean isBound = carrierService.isTelephonyBound();
+            if (ImsUtils.VDBG) Log.i(TAG, "waitForCarrierPackageUnbind: isBound=" + isBound);
+            if (isBound) {
+                // Wait for telephony to unbind to local ImsService
+                carrierService.waitForLatchCountdown(TestImsService.LATCH_ON_UNBIND);
+            }
+        }
+
+        void waitForDevicePackageUnbind() throws Exception {
+            // Wait until the ImsService unbinds
+            ITestExternalImsService externalService = getExternalService();
+            if (externalService == null) return;
+            // First unbind the local services
+            removeLocalExternalServiceConnection();
+            // Then wait for AOSP to unbind if there is still an active binding.
+            boolean isBound = externalService.isTelephonyBound();
+            if (ImsUtils.VDBG) Log.i(TAG, "waitForDevicePackageUnbind: isBound=" + isBound);
+            if (isBound) {
+                // Wait for telephony to unbind to external ImsService
+                externalService.waitForLatchCountdown(TestImsService.LATCH_ON_UNBIND);
+            }
+        }
+
         boolean overrideService(ImsFeatureConfiguration config) throws Exception {
             mIsServiceOverridden = true;
             switch (mConnectionType) {
@@ -570,17 +601,27 @@
         }
     }
 
-    // Detect and disconnect all active services.
-    void disconnectServices() throws Exception {
-        // Remove local connection
+    void removeLocalCarrierServiceConnection() {
         if (mCarrierServiceConn != null) {
             mInstrumentation.getContext().unbindService(mCarrierServiceConn);
+            mCarrierServiceConn = null;
             mCarrierService = null;
         }
+    }
+
+    void removeLocalExternalServiceConnection() {
         if (mExternalServiceConn != null) {
             mInstrumentation.getContext().unbindService(mExternalServiceConn);
+            mExternalServiceConn = null;
             mExternalService = null;
         }
+    }
+
+    // Detect and disconnect all active services.
+    void disconnectServices() throws Exception {
+        // Remove local connections
+        removeLocalCarrierServiceConnection();
+        removeLocalExternalServiceConnection();
         mDeviceServiceConnection.restoreOriginalPackage();
         mCarrierServiceConnection.restoreOriginalPackage();
         mDefaultSmsAppConnection.restoreOriginalPackage();
diff --git a/tests/tests/telephony/current/src/android/telephony/ims/cts/ImsServiceTest.java b/tests/tests/telephony/current/src/android/telephony/ims/cts/ImsServiceTest.java
index de09863..ac79f41 100644
--- a/tests/tests/telephony/current/src/android/telephony/ims/cts/ImsServiceTest.java
+++ b/tests/tests/telephony/current/src/android/telephony/ims/cts/ImsServiceTest.java
@@ -364,7 +364,7 @@
         if (!ImsUtils.shouldTestImsService()) {
             return;
         }
-        // Unbind the GTS ImsService after the test completes.
+        // Unbind the ImsService after the test completes.
         if (sServiceConnector != null) {
             sServiceConnector.setSingleRegistrationTestModeEnabled(false);
             sServiceConnector.disconnectCarrierImsService();
diff --git a/tests/tests/telephony/current/src/android/telephony/ims/cts/TestImsService.java b/tests/tests/telephony/current/src/android/telephony/ims/cts/TestImsService.java
index 4f29b89..82df301 100644
--- a/tests/tests/telephony/current/src/android/telephony/ims/cts/TestImsService.java
+++ b/tests/tests/telephony/current/src/android/telephony/ims/cts/TestImsService.java
@@ -46,7 +46,7 @@
  */
 public class TestImsService extends Service {
 
-    private static final String TAG = "GtsImsTestImsService";
+    private static final String TAG = "CtsImsTestImsService";
     private static MessageExecutor sMessageExecutor = null;
 
     private TestImsRegistration mImsRegistrationImplBase;
@@ -62,7 +62,8 @@
     private boolean mIsTestTypeExecutor = false;
     private long mCapabilities = 0;
     private ImsFeatureConfiguration mFeatureConfig;
-    private final Object mLock = new Object();
+    protected boolean mIsTelephonyBound = false;
+    protected final Object mLock = new Object();
 
     public static final int LATCH_FEATURES_READY = 0;
     public static final int LATCH_ENABLE_IMS = 1;
@@ -77,7 +78,8 @@
     public static final int LATCH_RCS_CAP_SET = 10;
     public static final int LATCH_UCE_LISTENER_SET = 11;
     public static final int LATCH_UCE_REQUEST_PUBLISH = 12;
-    private static final int LATCH_MAX = 13;
+    public static final int LATCH_ON_UNBIND = 13;
+    private static final int LATCH_MAX = 14;
     protected static final CountDownLatch[] sLatches = new CountDownLatch[LATCH_MAX];
     static {
         for (int i = 0; i < LATCH_MAX; i++) {
@@ -343,16 +345,34 @@
 
     @Override
     public IBinder onBind(Intent intent) {
-        if ("android.telephony.ims.ImsService".equals(intent.getAction())) {
-            if (ImsUtils.VDBG) {
-                Log.d(TAG, "onBind-Remote");
+        synchronized (mLock) {
+            if ("android.telephony.ims.ImsService".equals(intent.getAction())) {
+                if (ImsUtils.VDBG) {
+                    Log.i(TAG, "onBind-Remote");
+                }
+                mIsTelephonyBound = true;
+                return getImsService().onBind(intent);
             }
-            return getImsService().onBind(intent);
+            if (ImsUtils.VDBG) {
+                Log.i(TAG, "onBind-Local");
+            }
+            return mBinder;
         }
-        if (ImsUtils.VDBG) {
-            Log.i(TAG, "onBind-Local");
+    }
+
+    @Override
+    public boolean onUnbind(Intent intent) {
+        synchronized (mLock) {
+            if ("android.telephony.ims.ImsService".equals(intent.getAction())) {
+                if (ImsUtils.VDBG)  Log.i(TAG, "onUnbind-Remote");
+                mIsTelephonyBound = false;
+                countDownLatch(LATCH_ON_UNBIND);
+            } else {
+                if (ImsUtils.VDBG)  Log.i(TAG, "onUnbind-Local");
+            }
+            // return false so that onBind is called next time.
+            return false;
         }
-        return mBinder;
     }
 
     public void resetState() {
@@ -375,11 +395,15 @@
         }
     }
 
+    public boolean isTelephonyBound() {
+        return mIsTelephonyBound;
+    }
+
     public void setExecutorTestType(boolean type) {
         mIsTestTypeExecutor = type;
         if (mIsTestTypeExecutor) {
             if (sMessageExecutor == null) {
-                sMessageExecutor = new MessageExecutor("TestImSService");
+                sMessageExecutor = new MessageExecutor("TestImsService");
             }
             mExecutor = sMessageExecutor;
         }
@@ -430,20 +454,7 @@
     }
 
     public boolean waitForLatchCountdown(int latchIndex) {
-        boolean complete = false;
-        try {
-            CountDownLatch latch;
-            synchronized (mLock) {
-                latch = sLatches[latchIndex];
-            }
-            complete = latch.await(ImsUtils.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS);
-        } catch (InterruptedException e) {
-            // complete == false
-        }
-        synchronized (mLock) {
-            sLatches[latchIndex] = new CountDownLatch(1);
-        }
-        return complete;
+        return waitForLatchCountdown(latchIndex, ImsUtils.TEST_TIMEOUT_MS);
     }
 
     public boolean waitForLatchCountdown(int latchIndex, long waitMs) {
@@ -453,7 +464,12 @@
             synchronized (mLock) {
                 latch = sLatches[latchIndex];
             }
+            long startTime = System.currentTimeMillis();
             complete = latch.await(waitMs, TimeUnit.MILLISECONDS);
+            if (ImsUtils.VDBG) {
+                Log.i(TAG, "Latch " + latchIndex + " took "
+                        + (System.currentTimeMillis() - startTime) + " ms to count down.");
+            }
         } catch (InterruptedException e) {
             // complete == false
         }