Voip call streaming operations cleanup.

1. Log all call transaction operations in sessions.
2. Avoid multiple times invoke of Call#destroy
3. Fix incorrect MessageArgs for CallAudioModeStateMachine to not treat
   disconnected streaming call as ongoing streaming call.

Bug: 279937547
Test: atest CallStreamingTest
Change-Id: I830534adff6526535b39f89d01a845964005a349
diff --git a/src/com/android/server/telecom/Call.java b/src/com/android/server/telecom/Call.java
index 42f02fb..7b0b697 100644
--- a/src/com/android/server/telecom/Call.java
+++ b/src/com/android/server/telecom/Call.java
@@ -534,6 +534,7 @@
     private boolean mWasHighDefAudio = false;
     private boolean mWasWifi = false;
     private boolean mWasVolte = false;
+    private boolean mDestroyed = false;
 
     // For conferences which support merge/swap at their level, we retain a notion of an active
     // call. This is used for BluetoothPhoneService.  In order to support hold/merge, it must have
@@ -929,6 +930,9 @@
     }
 
     public void destroy() {
+        if (mDestroyed) {
+            return;
+        }
         // We should not keep these bitmaps around because the Call objects may be held for logging
         // purposes.
         // TODO: Make a container object that only stores the information we care about for Logging.
@@ -939,6 +943,7 @@
         closeRttStreams();
 
         Log.addEvent(this, LogUtils.Events.DESTROYED);
+        mDestroyed = true;
     }
 
     private void closeRttStreams() {
diff --git a/src/com/android/server/telecom/CallAudioManager.java b/src/com/android/server/telecom/CallAudioManager.java
index 38e6b00..f52a966 100644
--- a/src/com/android/server/telecom/CallAudioManager.java
+++ b/src/com/android/server/telecom/CallAudioManager.java
@@ -795,7 +795,7 @@
                 .setHasHoldingCalls(mHoldingCalls.size() > 0)
                 .setHasAudioProcessingCalls(mAudioProcessingCalls.size() > 0)
                 .setIsTonePlaying(mIsTonePlaying)
-                .setIsStreaming(mStreamingCall != null)
+                .setIsStreaming((mStreamingCall != null) && (!mStreamingCall.isDisconnected()))
                 .setForegroundCallIsVoip(
                         mForegroundCall != null && isCallVoip(mForegroundCall))
                 .setSession(Log.createSubsession()).build();
diff --git a/src/com/android/server/telecom/LogUtils.java b/src/com/android/server/telecom/LogUtils.java
index 4e7546f..0d6acd5 100644
--- a/src/com/android/server/telecom/LogUtils.java
+++ b/src/com/android/server/telecom/LogUtils.java
@@ -224,6 +224,7 @@
         public static final String FLASH_NOTIFICATION_START = "FLASH_NOTIFICATION_START";
         public static final String FLASH_NOTIFICATION_STOP = "FLASH_NOTIFICATION_STOP";
         public static final String GAINED_FGS_DELEGATION = "GAINED_FGS_DELEGATION";
+        public static final String GAIN_FGS_DELEGATION_FAILED = "GAIN_FGS_DELEGATION_FAILED";
         public static final String LOST_FGS_DELEGATION = "LOST_FGS_DELEGATION";
         public static final String START_STREAMING = "START_STREAMING";
         public static final String STOP_STREAMING = "STOP_STREAMING";
diff --git a/src/com/android/server/telecom/voip/ParallelTransaction.java b/src/com/android/server/telecom/voip/ParallelTransaction.java
index 2762949..6176087 100644
--- a/src/com/android/server/telecom/voip/ParallelTransaction.java
+++ b/src/com/android/server/telecom/voip/ParallelTransaction.java
@@ -16,9 +16,11 @@
 
 package com.android.server.telecom.voip;
 
+import com.android.server.telecom.LoggedHandlerExecutor;
 import com.android.server.telecom.TelecomSystem;
 
 import java.util.List;
+import java.util.concurrent.CompletableFuture;
 import java.util.concurrent.atomic.AtomicInteger;
 
 /**
@@ -33,15 +35,19 @@
     @Override
     public void start() {
         // post timeout work
-        mHandler.postDelayed(() -> {
+        CompletableFuture<Void> future = new CompletableFuture<>();
+        mHandler.postDelayed(() -> future.complete(null), TIMEOUT_LIMIT);
+        future.thenApplyAsync((x) -> {
             if (mCompleted.getAndSet(true)) {
-                return;
+                return null;
             }
             if (mCompleteListener != null) {
                 mCompleteListener.onTransactionTimeout(mTransactionName);
             }
             finish();
-        }, TIMEOUT_LIMIT);
+            return null;
+        }, new LoggedHandlerExecutor(mHandler, mTransactionName + "@" + hashCode()
+                + ".s", mLock));
 
         if (mSubTransactions != null && mSubTransactions.size() > 0) {
             TransactionManager.TransactionCompleteListener subTransactionListener =
@@ -52,16 +58,21 @@
                         public void onTransactionCompleted(VoipCallTransactionResult result,
                                 String transactionName) {
                             if (result.getResult() != VoipCallTransactionResult.RESULT_SUCCEED) {
-                                mHandler.post(() -> {
-                                    VoipCallTransactionResult mainResult =
-                                            new VoipCallTransactionResult(
-                                                    VoipCallTransactionResult.RESULT_FAILED,
-                                                    String.format("sub transaction %s failed",
-                                                            transactionName));
-                                    mCompleteListener.onTransactionCompleted(mainResult,
-                                            mTransactionName);
-                                    finish();
-                                });
+                                CompletableFuture.completedFuture(null).thenApplyAsync(
+                                        (x) -> {
+                                            VoipCallTransactionResult mainResult =
+                                                    new VoipCallTransactionResult(
+                                                            VoipCallTransactionResult.RESULT_FAILED,
+                                                            String.format(
+                                                                    "sub transaction %s failed",
+                                                                    transactionName));
+                                            mCompleteListener.onTransactionCompleted(mainResult,
+                                                    mTransactionName);
+                                            finish();
+                                            return null;
+                                        }, new LoggedHandlerExecutor(mHandler,
+                                                mTransactionName + "@" + hashCode()
+                                                        + ".oTC", mLock));
                             } else {
                                 if (mCount.decrementAndGet() == 0) {
                                     scheduleTransaction();
@@ -71,15 +82,20 @@
 
                         @Override
                         public void onTransactionTimeout(String transactionName) {
-                            mHandler.post(() -> {
-                                VoipCallTransactionResult mainResult = new VoipCallTransactionResult(
-                                        VoipCallTransactionResult.RESULT_FAILED,
-                                        String.format("sub transaction %s timed out",
-                                                transactionName));
-                                mCompleteListener.onTransactionCompleted(mainResult,
-                                        mTransactionName);
-                                finish();
-                            });
+                            CompletableFuture.completedFuture(null).thenApplyAsync(
+                                    (x) -> {
+                                        VoipCallTransactionResult mainResult =
+                                                new VoipCallTransactionResult(
+                                                VoipCallTransactionResult.RESULT_FAILED,
+                                                String.format("sub transaction %s timed out",
+                                                        transactionName));
+                                        mCompleteListener.onTransactionCompleted(mainResult,
+                                                mTransactionName);
+                                        finish();
+                                        return null;
+                                    }, new LoggedHandlerExecutor(mHandler,
+                                            mTransactionName + "@" + hashCode()
+                                                    + ".oTT", mLock));
                         }
                     };
             for (VoipCallTransaction transaction : mSubTransactions) {
diff --git a/src/com/android/server/telecom/voip/SerialTransaction.java b/src/com/android/server/telecom/voip/SerialTransaction.java
index 4c6d02e..5d5d1f3 100644
--- a/src/com/android/server/telecom/voip/SerialTransaction.java
+++ b/src/com/android/server/telecom/voip/SerialTransaction.java
@@ -16,9 +16,11 @@
 
 package com.android.server.telecom.voip;
 
+import com.android.server.telecom.LoggedHandlerExecutor;
 import com.android.server.telecom.TelecomSystem;
 
 import java.util.List;
+import java.util.concurrent.CompletableFuture;
 
 /**
  * A VoipCallTransaction implementation that its sub transactions will be executed in serial
@@ -36,15 +38,19 @@
     @Override
     public void start() {
         // post timeout work
-        mHandler.postDelayed(() -> {
+        CompletableFuture<Void> future = new CompletableFuture<>();
+        mHandler.postDelayed(() -> future.complete(null), TIMEOUT_LIMIT);
+        future.thenApplyAsync((x) -> {
             if (mCompleted.getAndSet(true)) {
-                return;
+                return null;
             }
             if (mCompleteListener != null) {
                 mCompleteListener.onTransactionTimeout(mTransactionName);
             }
             finish();
-        }, TIMEOUT_LIMIT);
+            return null;
+        }, new LoggedHandlerExecutor(mHandler, mTransactionName + "@" + hashCode()
+                + ".s", mLock));
 
         if (mSubTransactions != null && mSubTransactions.size() > 0) {
             TransactionManager.TransactionCompleteListener subTransactionListener =
@@ -54,16 +60,21 @@
                         public void onTransactionCompleted(VoipCallTransactionResult result,
                                 String transactionName) {
                             if (result.getResult() != VoipCallTransactionResult.RESULT_SUCCEED) {
-                                mHandler.post(() -> {
-                                    VoipCallTransactionResult mainResult =
-                                            new VoipCallTransactionResult(
-                                                    VoipCallTransactionResult.RESULT_FAILED,
-                                                    String.format("sub transaction %s failed",
-                                                            transactionName));
-                                    mCompleteListener.onTransactionCompleted(mainResult,
-                                            mTransactionName);
-                                    finish();
-                                });
+                                CompletableFuture.completedFuture(null).thenApplyAsync(
+                                        (x) -> {
+                                            VoipCallTransactionResult mainResult =
+                                                    new VoipCallTransactionResult(
+                                                            VoipCallTransactionResult.RESULT_FAILED,
+                                                            String.format(
+                                                                    "sub transaction %s failed",
+                                                                    transactionName));
+                                            mCompleteListener.onTransactionCompleted(mainResult,
+                                                    mTransactionName);
+                                            finish();
+                                            return null;
+                                        }, new LoggedHandlerExecutor(mHandler,
+                                                mTransactionName + "@" + hashCode()
+                                                        + ".oTC", mLock));
                             } else {
                                 if (mSubTransactions.size() > 0) {
                                     VoipCallTransaction transaction = mSubTransactions.remove(0);
@@ -77,15 +88,20 @@
 
                         @Override
                         public void onTransactionTimeout(String transactionName) {
-                            mHandler.post(() -> {
-                                VoipCallTransactionResult mainResult = new VoipCallTransactionResult(
-                                        VoipCallTransactionResult.RESULT_FAILED,
-                                        String.format("sub transaction %s timed out",
-                                                transactionName));
-                                mCompleteListener.onTransactionCompleted(mainResult,
-                                        mTransactionName);
-                                finish();
-                            });
+                            CompletableFuture.completedFuture(null).thenApplyAsync(
+                                    (x) -> {
+                                        VoipCallTransactionResult mainResult =
+                                                new VoipCallTransactionResult(
+                                                VoipCallTransactionResult.RESULT_FAILED,
+                                                String.format("sub transaction %s timed out",
+                                                        transactionName));
+                                        mCompleteListener.onTransactionCompleted(mainResult,
+                                                mTransactionName);
+                                        finish();
+                                        return null;
+                                    }, new LoggedHandlerExecutor(mHandler,
+                                            mTransactionName + "@" + hashCode()
+                                                    + ".oTT", mLock));
                         }
                     };
             VoipCallTransaction transaction = mSubTransactions.remove(0);
diff --git a/src/com/android/server/telecom/voip/TransactionManager.java b/src/com/android/server/telecom/voip/TransactionManager.java
index 773dfb8..228bdde 100644
--- a/src/com/android/server/telecom/voip/TransactionManager.java
+++ b/src/com/android/server/telecom/voip/TransactionManager.java
@@ -70,8 +70,8 @@
             @Override
             public void onTransactionCompleted(VoipCallTransactionResult result,
                     String transactionName){
-                Log.i(TAG, String.format("transaction completed: with result=[%d]",
-                        result.getResult()));
+                Log.i(TAG, String.format("transaction %s completed: with result=[%d]",
+                        transactionName, result.getResult()));
                 if (result.getResult() == TelecomManager.TELECOM_TRANSACTION_SUCCESS) {
                     receiver.onResult(result);
                 } else {
@@ -84,6 +84,7 @@
 
             @Override
             public void onTransactionTimeout(String transactionName){
+                Log.i(TAG, String.format("transaction %s timeout", transactionName));
                 receiver.onError(new CallException(transactionName + " timeout",
                         CODE_OPERATION_TIMED_OUT));
                 finishTransaction();
diff --git a/src/com/android/server/telecom/voip/VoipCallMonitor.java b/src/com/android/server/telecom/voip/VoipCallMonitor.java
index 2a81051..58650f5 100644
--- a/src/com/android/server/telecom/voip/VoipCallMonitor.java
+++ b/src/com/android/server/telecom/voip/VoipCallMonitor.java
@@ -31,6 +31,7 @@
 import android.service.notification.NotificationListenerService;
 import android.service.notification.StatusBarNotification;
 import android.telecom.Log;
+import android.telecom.PhoneAccount;
 import android.telecom.PhoneAccountHandle;
 
 import com.android.internal.annotations.VisibleForTesting;
@@ -38,6 +39,7 @@
 import com.android.server.telecom.Call;
 import com.android.server.telecom.CallsManagerListenerBase;
 import com.android.server.telecom.LogUtils;
+import com.android.server.telecom.LoggedHandlerExecutor;
 import com.android.server.telecom.TelecomSystem;
 
 import java.util.ArrayList;
@@ -46,6 +48,7 @@
 import java.util.List;
 import java.util.Map;
 import java.util.Set;
+import java.util.concurrent.CompletableFuture;
 
 public class VoipCallMonitor extends CallsManagerListenerBase {
 
@@ -62,8 +65,10 @@
     private final Handler mHandler;
     private final Context mContext;
     private List<StatusBarNotification> mPendingSBN;
+    private TelecomSystem.SyncRoot mSyncRoot;
 
     public VoipCallMonitor(Context context, TelecomSystem.SyncRoot lock) {
+        mSyncRoot = lock;
         mContext = context;
         mHandlerThread = new HandlerThread(this.getClass().getSimpleName());
         mHandlerThread.start();
@@ -108,7 +113,7 @@
                     Call call = mNotifications.getOrDefault(sbn.toString(), null);
                     if (call != null) {
                         mNotifications.remove(sbn.toString(), call);
-                        stopFGSDelegation(call.getTargetPhoneAccount());
+                        stopFGSDelegation(call);
                     }
                 }
             }
@@ -146,9 +151,12 @@
                     k -> new HashSet<>());
             callList.add(call);
 
-            mHandler.post(
-                    () -> startFGSDelegation(call.getCallingPackageIdentity().mCallingPackagePid,
-                            call.getCallingPackageIdentity().mCallingPackageUid, call));
+            CompletableFuture.completedFuture(null).thenComposeAsync(
+                    (x) -> {
+                        startFGSDelegation(call.getCallingPackageIdentity().mCallingPackagePid,
+                                call.getCallingPackageIdentity().mCallingPackageUid, call);
+                        return null;
+                    }, new LoggedHandlerExecutor(mHandler, "VCM.oCA", mSyncRoot));
         }
     }
 
@@ -166,7 +174,7 @@
             callList.remove(call);
 
             if (callList.isEmpty()) {
-                stopFGSDelegation(phoneAccountHandle);
+                stopFGSDelegation(call);
             }
         }
     }
@@ -183,19 +191,22 @@
             ServiceConnection fgsConnection = new ServiceConnection() {
                 @Override
                 public void onServiceConnected(ComponentName name, IBinder service) {
-                    Log.addEvent(call, LogUtils.Events.GAINED_FGS_DELEGATION);
                     mServices.put(handle, this);
                     startMonitorWorks(call);
                 }
 
                 @Override
                 public void onServiceDisconnected(ComponentName name) {
-                    Log.addEvent(call, LogUtils.Events.LOST_FGS_DELEGATION);
                     mServices.remove(handle);
                 }
             };
             try {
-                mActivityManagerInternal.startForegroundServiceDelegate(options, fgsConnection);
+                if (mActivityManagerInternal
+                        .startForegroundServiceDelegate(options, fgsConnection)) {
+                    Log.addEvent(call, LogUtils.Events.GAINED_FGS_DELEGATION);
+                } else {
+                    Log.addEvent(call, LogUtils.Events.GAIN_FGS_DELEGATION_FAILED);
+                }
             } catch (Exception e) {
                 Log.i(this, "startForegroundServiceDelegate failed due to: " + e);
             }
@@ -203,13 +214,14 @@
     }
 
     @VisibleForTesting
-    public void stopFGSDelegation(PhoneAccountHandle handle) {
+    public void stopFGSDelegation(Call call) {
         synchronized (mLock) {
-            Log.i(this, "stopFGSDelegation of handle %s", handle);
+            Log.i(this, "stopFGSDelegation of call %s", call);
+            PhoneAccountHandle handle = call.getTargetPhoneAccount();
             Set<Call> calls = mPhoneAccountHandleListMap.get(handle);
             if (calls != null) {
-                for (Call call : calls) {
-                    stopMonitorWorks(call);
+                for (Call c : calls) {
+                    stopMonitorWorks(c);
                 }
             }
             mPhoneAccountHandleListMap.remove(handle);
@@ -218,6 +230,7 @@
                 ServiceConnection fgsConnection = mServices.get(handle);
                 if (fgsConnection != null) {
                     mActivityManagerInternal.stopForegroundServiceDelegate(fgsConnection);
+                    Log.addEvent(call, LogUtils.Events.LOST_FGS_DELEGATION);
                 }
             }
         }
@@ -245,16 +258,19 @@
             if (!sbnMatched) {
                 // Only continue to
                 mPendingCalls.add(call);
-                mHandler.postDelayed(() -> {
-                    synchronized (mLock) {
-                        if (mPendingCalls.contains(call)) {
-                            Log.i(this, "Notification for voip-call %s haven't "
-                                    + "posted in time, stop delegation.", call.getId());
-                            stopFGSDelegation(call.getTargetPhoneAccount());
-                            mPendingCalls.remove(call);
-                        }
-                    }
-                }, 5000L);
+                CompletableFuture<Void> future = new CompletableFuture<>();
+                mHandler.postDelayed(() -> future.complete(null), 5000L);
+                future.thenComposeAsync(
+                        (x) -> {
+                            if (mPendingCalls.contains(call)) {
+                                Log.i(this, "Notification for voip-call %s haven't "
+                                        + "posted in time, stop delegation.", call.getId());
+                                stopFGSDelegation(call);
+                                mPendingCalls.remove(call);
+                                return null;
+                            }
+                            return null;
+                        }, new LoggedHandlerExecutor(mHandler, "VCM.sMN", mSyncRoot));
             }
         }
     }
diff --git a/src/com/android/server/telecom/voip/VoipCallTransaction.java b/src/com/android/server/telecom/voip/VoipCallTransaction.java
index 38f1d54..a952eb1 100644
--- a/src/com/android/server/telecom/voip/VoipCallTransaction.java
+++ b/src/com/android/server/telecom/voip/VoipCallTransaction.java
@@ -38,7 +38,7 @@
     protected Handler mHandler;
     protected TransactionManager.TransactionCompleteListener mCompleteListener;
     protected List<VoipCallTransaction> mSubTransactions;
-    private TelecomSystem.SyncRoot mLock;
+    protected TelecomSystem.SyncRoot mLock;
 
     public VoipCallTransaction(
             List<VoipCallTransaction> subTransactions, TelecomSystem.SyncRoot lock) {
@@ -55,37 +55,40 @@
 
     public void start() {
         // post timeout work
-        mHandler.postDelayed(() -> {
+        CompletableFuture<Void> future = new CompletableFuture<>();
+        mHandler.postDelayed(() -> future.complete(null), TIMEOUT_LIMIT);
+        future.thenApplyAsync((x) -> {
             if (mCompleted.getAndSet(true)) {
-                return;
+                return null;
             }
             if (mCompleteListener != null) {
                 mCompleteListener.onTransactionTimeout(mTransactionName);
             }
             finish();
-        }, TIMEOUT_LIMIT);
+            return null;
+        }, new LoggedHandlerExecutor(mHandler, mTransactionName + "@" + hashCode()
+                + ".s", mLock));
 
         scheduleTransaction();
     }
 
     protected void scheduleTransaction() {
+        LoggedHandlerExecutor executor = new LoggedHandlerExecutor(mHandler,
+                mTransactionName + "@" + hashCode() + ".pT", mLock);
         CompletableFuture<Void> future = CompletableFuture.completedFuture(null);
-        future.thenComposeAsync(this::processTransaction,
-                        new LoggedHandlerExecutor(mHandler, mTransactionName + "@"
-                                + hashCode() + ".pT", mLock))
-                .thenApplyAsync(
-                        (Function<VoipCallTransactionResult, Void>) result -> {
-                            mCompleted.set(true);
-                            if (mCompleteListener != null) {
-                                mCompleteListener.onTransactionCompleted(result, mTransactionName);
-                            }
-                            finish();
-                            return null;
-                        })
-                .exceptionally((throwable) -> {
+        future.thenComposeAsync(this::processTransaction, executor)
+                .thenApplyAsync((Function<VoipCallTransactionResult, Void>) result -> {
+                    mCompleted.set(true);
+                    if (mCompleteListener != null) {
+                        mCompleteListener.onTransactionCompleted(result, mTransactionName);
+                    }
+                    finish();
+                    return null;
+                    }, executor)
+                .exceptionallyAsync((throwable -> {
                     Log.e(this, throwable, "Error while executing transaction.");
                     return null;
-                });;
+                }), executor);
     }
 
     public CompletionStage<VoipCallTransactionResult> processTransaction(Void v) {
diff --git a/tests/src/com/android/server/telecom/tests/CallAudioModeStateMachineTest.java b/tests/src/com/android/server/telecom/tests/CallAudioModeStateMachineTest.java
index d0a1d8b..d7854a5 100644
--- a/tests/src/com/android/server/telecom/tests/CallAudioModeStateMachineTest.java
+++ b/tests/src/com/android/server/telecom/tests/CallAudioModeStateMachineTest.java
@@ -117,7 +117,7 @@
         when(mCallAudioManager.startRinging()).thenReturn(false);
 
         sm.sendMessage(CallAudioModeStateMachine.START_CALL_STREAMING, new Builder()
-                .setHasActiveOrDialingCalls(false)
+                .setHasActiveOrDialingCalls(true)
                 .setHasRingingCalls(false)
                 .setHasHoldingCalls(false)
                 .setIsTonePlaying(false)
diff --git a/tests/src/com/android/server/telecom/tests/VoipCallMonitorTest.java b/tests/src/com/android/server/telecom/tests/VoipCallMonitorTest.java
index 346b3d8..c9ea34f 100644
--- a/tests/src/com/android/server/telecom/tests/VoipCallMonitorTest.java
+++ b/tests/src/com/android/server/telecom/tests/VoipCallMonitorTest.java
@@ -197,7 +197,7 @@
         ServiceConnection conn2 = captor2.getValue();
         conn2.onServiceConnected(mHandle1User1.getComponentName(), service);
 
-        mMonitor.stopFGSDelegation(mHandle1User1);
+        mMonitor.stopFGSDelegation(call1);
         verify(mActivityManagerInternal, timeout(TIMEOUT).times(1))
                 .stopForegroundServiceDelegate(eq(conn2));
         conn2.onServiceDisconnected(mHandle1User1.getComponentName());
diff --git a/tests/src/com/android/server/telecom/tests/VoipCallTransactionTest.java b/tests/src/com/android/server/telecom/tests/VoipCallTransactionTest.java
index e2c7b7b..0a7e27d 100644
--- a/tests/src/com/android/server/telecom/tests/VoipCallTransactionTest.java
+++ b/tests/src/com/android/server/telecom/tests/VoipCallTransactionTest.java
@@ -62,7 +62,7 @@
         private int mType;
 
         public TestVoipCallTransaction(String name, long sleepTime, int type) {
-            super(mLock);
+            super(VoipCallTransactionTest.this.mLock);
             mName = name;
             mSleepTime = sleepTime;
             mType = type;