Audio service: no double message handling for A2DP device connection

  This change affects the implementation of the
setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent method:
when the computed delay before making the device available or not
available anymore is 0, perform the operation synchronously. The
AudioManager method is still asynchronous, but this prevent
yet another message to be processed on the AudioDeviceBroker queue.
  The previous implementation was causing the following message to
sometimes be observed in the logs:
"invalid null DeviceInfo in onBluetoothA2dpActiveDeviceChange" and
was due to the following sequence of calls when an A2DP device would
connect: (AM=AudioManager, AS=AudioService, ADI=AudioDeviceInventory,
ADB=AudioDeviceBroker)
BT service would call
 AM.setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent
 AM.handleBluetoothA2dpDeviceConfigChange
which was translating into the following:
AM.setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent
   AS.setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent
      > ADB.postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent -> MSG_L_A2DP_DEVICE_CONNECTION_CHANGE_EXT
AM.handleBluetoothA2dpDeviceConfigChange
   AS.handleBluetoothA2dpDeviceConfigChange
      > ADB.postBluetoothA2dpDeviceConfigChange ->MSG_L_A2DP_DEVICE_CONFIG_CHANGE

MSG_L_A2DP_DEVICE_CONNECTION_CHANGE_EXT
   > ADI.setBluetoothA2dpDeviceConnectionState
      > delay = checkSendBecomingNoisyIntentInt
      > ADB.postA2dpSinkConnection(delay)     -> MSG_IL_SET_A2DP_SINK_CONNECTION_STATE

MSG_L_A2DP_DEVICE_CONFIG_CHANGE
   > ADI.onBluetoothA2dpActiveDeviceChange
      AS.AudioDeviceInventory: invalid null DeviceInfo in onBluetoothA2dpActiveDeviceChange
      => doesn't call  AudioSystem.handleDeviceConfigChange
                      ADB.postSetVolumeIndexOnDevice(vol, A2DP)

MSG_IL_SET_A2DP_SINK_CONNECTION_STATE
   > ADI.onSetA2dpSinkConnectionState
      > ADB.postSetVolumeIndexOnDevice()
          > AS.postSetVolumeIndexOnDevice  -> MSG...
      > makeA2dpDeviceAvailable: mConnectedDevices.put(...)

with the new implementation we get:

AM.setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent
   AS.setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent
      > ADB.postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent -> MSG_L_A2DP_DEVICE_CONNECTION_CHANGE_EXT
AM.handleBluetoothA2dpDeviceConfigChange
   AS.handleBluetoothA2dpDeviceConfigChange
      > ADB.postBluetoothA2dpDeviceConfigChange ->MSG_L_A2DP_DEVICE_CONFIG_CHANGE

MSG_L_A2DP_DEVICE_CONNECTION_CHANGE_EXT
   > ADI.setBluetoothA2dpDeviceConnectionState
      > delay = checkSendBecomingNoisyIntentInt
      > if delay == 0 then ADI.onSetA2dpSinkConnection()
          > AS.postSetVolumeIndexOnDevice  -> MSG...
          > makeA2dpDeviceAvailable: mConnectedDevices.put(...)

MSG_L_A2DP_DEVICE_CONFIG_CHANGE
   > ADI.onBluetoothA2dpActiveDeviceChange
      > AudioSystem.handleDeviceConfigChange
      > ADB.postSetVolumeIndexOnDevice(vol, A2DP)

Bug: 132602437
Bug: 132416679
Test: connect/disconnect A2DP devices and verify "dumpsys audio" for
absence of "invalid null DeviceInfo" messages

Change-Id: If9afd6174f8e49273ce20912a60b2f64b19b6d94

4 files changed, 18 insertions, 6 deletions

diff --git a/services/core/java/com/android/server/audio/AudioDeviceBroker.java b/services/core/java/com/android/server/audio/AudioDeviceBroker.java
index fcd6a0aacd92..884ecbaac058 100644
--- a/services/core/java/com/android/server/audio/AudioDeviceBroker.java
+++ b/services/core/java/com/android/server/audio/AudioDeviceBroker.java
@@ -569,9 +569,8 @@ import com.android.internal.annotations.GuardedBy;
         return mBrokerHandler.hasMessages(MSG_IL_BTA2DP_DOCK_TIMEOUT);
     }
 
-    //###
     // must be called synchronized on mConnectedDevices
-    /*package*/  boolean hasScheduledA2dpSinkConnectionState(BluetoothDevice btDevice) {
+    /*package*/ boolean hasScheduledA2dpSinkConnectionState(BluetoothDevice btDevice) {
         return mBrokerHandler.hasMessages(MSG_IL_SET_A2DP_SINK_CONNECTION_STATE,
                 new BtHelper.BluetoothA2dpDeviceInfo(btDevice));
     }
diff --git a/services/core/java/com/android/server/audio/AudioDeviceInventory.java b/services/core/java/com/android/server/audio/AudioDeviceInventory.java
index 99b97cbf7dbc..a9a8ef2f7e12 100644
--- a/services/core/java/com/android/server/audio/AudioDeviceInventory.java
+++ b/services/core/java/com/android/server/audio/AudioDeviceInventory.java
@@ -146,6 +146,7 @@ public final class AudioDeviceInventory {
         }
     }
 
+    @GuardedBy("AudioDeviceBroker.mDeviceStateLock")
     /*package*/ void onSetA2dpSinkConnectionState(@NonNull BtHelper.BluetoothA2dpDeviceInfo btInfo,
             @AudioService.BtProfileConnectionState int state) {
         final BluetoothDevice btDevice = btInfo.getBtDevice();
@@ -259,6 +260,7 @@ public final class AudioDeviceInventory {
         }
     }
 
+    @GuardedBy("AudioDeviceBroker.mDeviceStateLock")
     /*package*/ void onBluetoothA2dpActiveDeviceChange(
             @NonNull BtHelper.BluetoothA2dpDeviceInfo btInfo, int event) {
         final BluetoothDevice btDevice = btInfo.getBtDevice();
@@ -532,6 +534,7 @@ public final class AudioDeviceInventory {
         return mCurAudioRoutes;
     }
 
+    @GuardedBy("AudioDeviceBroker.mDeviceStateLock")
     /*package*/ void setBluetoothA2dpDeviceConnectionState(
             @NonNull BluetoothDevice device, @AudioService.BtProfileConnectionState int state,
             int profile, boolean suppressNoisyIntent, int musicDevice, int a2dpVolume) {
@@ -559,9 +562,13 @@ public final class AudioDeviceInventory {
             final BtHelper.BluetoothA2dpDeviceInfo a2dpDeviceInfo =
                     new BtHelper.BluetoothA2dpDeviceInfo(device, a2dpVolume, a2dpCodec);
             if (profile == BluetoothProfile.A2DP) {
-                mDeviceBroker.postA2dpSinkConnection(state,
-                        a2dpDeviceInfo,
-                        delay);
+                if (delay == 0) {
+                    onSetA2dpSinkConnectionState(a2dpDeviceInfo, state);
+                } else {
+                    mDeviceBroker.postA2dpSinkConnection(state,
+                            a2dpDeviceInfo,
+                            delay);
+                }
             } else { //profile == BluetoothProfile.A2DP_SINK
                 mDeviceBroker.postA2dpSourceConnection(state,
                         a2dpDeviceInfo,
diff --git a/services/core/java/com/android/server/audio/AudioService.java b/services/core/java/com/android/server/audio/AudioService.java
index 30035c8c365b..7fde0ae8d445 100644
--- a/services/core/java/com/android/server/audio/AudioService.java
+++ b/services/core/java/com/android/server/audio/AudioService.java
@@ -5508,6 +5508,8 @@ public class AudioService extends IAudioService.Stub
 
     public void avrcpSupportsAbsoluteVolume(String address, boolean support) {
         // address is not used for now, but may be used when multiple a2dp devices are supported
+        sVolumeLogger.log(new AudioEventLogger.StringEvent("avrcpSupportsAbsoluteVolume addr="
+                + address + " support=" + support));
         mDeviceBroker.setAvrcpAbsoluteVolumeSupported(support);
         sendMsg(mAudioHandler, MSG_SET_DEVICE_VOLUME, SENDMSG_QUEUE,
                     AudioSystem.DEVICE_OUT_BLUETOOTH_A2DP, 0,
diff --git a/services/core/java/com/android/server/audio/BtHelper.java b/services/core/java/com/android/server/audio/BtHelper.java
index 934c7bfe3392..1a63f8f51ee3 100644
--- a/services/core/java/com/android/server/audio/BtHelper.java
+++ b/services/core/java/com/android/server/audio/BtHelper.java
@@ -200,16 +200,20 @@ public class BtHelper {
 
     /*package*/ synchronized void setAvrcpAbsoluteVolumeSupported(boolean supported) {
         mAvrcpAbsVolSupported = supported;
+        Log.i(TAG, "setAvrcpAbsoluteVolumeSupported supported=" + supported);
     }
 
     /*package*/ synchronized void setAvrcpAbsoluteVolumeIndex(int index) {
         if (mA2dp == null) {
             if (AudioService.DEBUG_VOL) {
-                Log.d(TAG, "setAvrcpAbsoluteVolumeIndex: bailing due to null mA2dp");
+                AudioService.sVolumeLogger.log(new AudioEventLogger.StringEvent(
+                        "setAvrcpAbsoluteVolumeIndex: bailing due to null mA2dp").printLog(TAG));
                 return;
             }
         }
         if (!mAvrcpAbsVolSupported) {
+            AudioService.sVolumeLogger.log(new AudioEventLogger.StringEvent(
+                    "setAvrcpAbsoluteVolumeIndex: abs vol not supported ").printLog(TAG));
             return;
         }
         if (AudioService.DEBUG_VOL) {