search

twilio / audioswitch

An Android audio management library for real-time communication apps.
Apache License 2.0
160 stars 49 forks source link

Fail to connect to BluetoothHeadset #148

Closed michaelfpet closed 6 months ago

michaelfpet commented 1 year ago

Describe the bug Unable to use bluetooth headset.

To Reproduce Steps to reproduce the behavior:

  1. Start AudioSwitch
  2. Wait for the AudioSwitch to first connect followed by a disconnect to bluetooth headset.
  3. When it returns to using the speakerphone, manually set bluetooth headset as device by selecting it from the list of available devices.

Expected behavior The bluetooth headset should be used for the call.

Actual behavior Usage of the bluetooth headset fails. The speakerphone output route is used, despite the bluetooth headset being set as the current device.

Application Logs Logcat logs with logging enabled and AS/ logcat filter applied:

2023-03-23 11:50:19.286 17350-17350 AS/AudioSwitch D AudioSwitch(1.1.7) 2023-03-23 11:50:19.286 17350-17350 AS/AudioSwitch D Preferred device list = [BluetoothHeadset, WiredHeadset, Earpiece, Speakerphone] 2023-03-23 11:50:19.295 17350-17350 AS/AudioDeviceManager D Speakerphone available 2023-03-23 11:50:19.295 17350-17350 AS/AudioSwitch D Available AudioDevice list updated: [Speakerphone(name=Speakerphone)] 2023-03-23 11:50:19.295 17350-17350 AS/AudioSwitch D Current user selected AudioDevice = null 2023-03-23 11:50:19.449 17350-17350 AS/Bluetoo...setManager W Cannot deactivate when in the Disconnected state 2023-03-23 11:50:19.465 17350-17350 AS/Bluetoo...setManager D Bluetooth Poly Sync 20 connected 2023-03-23 11:50:19.469 17350-17350 AS/Bluetoo...setManager D Headset state changed to Connected 2023-03-23 11:50:19.472 17350-17350 AS/Bluetoo...setManager D Device size 1 with device name: Poly Sync 20 2023-03-23 11:50:19.473 17350-17350 AS/AudioDeviceManager D Speakerphone available 2023-03-23 11:50:19.473 17350-17350 AS/AudioSwitch D Available AudioDevice list updated: [BluetoothHeadset(name=Poly Sync 20), Speakerphone(name=Speakerphone)] 2023-03-23 11:50:19.473 17350-17350 AS/AudioSwitch D Current user selected AudioDevice = null 2023-03-23 11:50:19.551 17350-17350 AS/BluetoothScoJob D Scheduled bluetooth sco job 2023-03-23 11:50:19.557 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:19.765 17350-17350 AS/Bluetoo...setManager D Headset state changed to AudioActivating 2023-03-23 11:50:20.286 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:20.977 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:21.478 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:21.980 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:22.482 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:22.990 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:23.492 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:23.994 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:24.495 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:25.007 17350-17350 AS/Bluetoo...setManager D Attempting to enable bluetooth SCO 2023-03-23 11:50:25.512 17350-17350 AS/BluetoothScoJob E Bluetooth sco job timed out java.util.concurrent.TimeoutException at com.twilio.audioswitch.bluetooth.BluetoothScoJob$BluetoothScoRunnable.run(BluetoothScoJob.kt:56) at android.os.Handler.handleCallback(Handler.java:942) at android.os.Handler.dispatchMessage(Handler.java:99) at android.os.Looper.loopOnce(Looper.java:226) at android.os.Looper.loop(Looper.java:313) at android.app.ActivityThread.main(ActivityThread.java:8775) at java.lang.reflect.Method.invoke(Native Method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:571) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1067) 2023-03-23 11:50:25.512 17350-17350 AS/Bluetoo...setManager D Headset state changed to AudioActivationError 2023-03-23 11:50:25.519 17350-17350 AS/Bluetoo...setManager D Device size 1 with device name: Poly Sync 20 2023-03-23 11:50:25.526 17350-17350 AS/AudioDeviceManager D Speakerphone available 2023-03-23 11:50:25.526 17350-17350 AS/AudioSwitch D Available AudioDevice list updated: [BluetoothHeadset(name=Poly Sync 20), Speakerphone(name=Speakerphone)] 2023-03-23 11:50:25.526 17350-17350 AS/AudioSwitch D Current user selected AudioDevice = null 2023-03-23 11:50:25.529 17350-17350 AS/Bluetoo...setManager W Cannot deactivate when in the AudioActivationError state 2023-03-23 11:50:25.530 17350-17350 AS/AudioSwitch D Selected AudioDevice = BluetoothHeadset(name=Poly Sync 20) 2023-03-23 11:50:25.545 17350-17350 AS/Bluetoo...setManager D Device size 1 with device name: Poly Sync 20 2023-03-23 11:50:25.545 17350-17350 AS/AudioDeviceManager D Speakerphone available 2023-03-23 11:50:25.545 17350-17350 AS/AudioSwitch D Available AudioDevice list updated: [BluetoothHeadset(name=Poly Sync 20), Speakerphone(name=Speakerphone)] 2023-03-23 11:50:25.545 17350-17350 AS/AudioSwitch D Current user selected AudioDevice = BluetoothHeadset(name=Poly Sync 20) 2023-03-23 11:50:25.554 17350-17350 AS/BluetoothScoJob D Scheduled bluetooth sco job 2023-03-23 11:50:25.554 17350-17350 AS/BluetoothScoJob D Canceled bluetooth sco job

AudioSwitch Version

Android Device (please complete the following information):

Additional context After it disconnects from the bluetooth headset, I manually select the bluetooth headset from the list of available devices. it doesn't fail in the log the second time, but it keeps using the built in speakerphone.

ocarevs commented 1 year ago

Hi @michaelfpet I managed to get the exact scenario a few times, however I am not reproducing the issue. One thing in the logs, after selecting bluetooth device there were no logs between or after last two log entries? Also there's a race condition issue with the latest available version that was fixed and pushed to master branch, however the changes are not yet released. Though it's unclear if that could be the cause. Back to my logging question, if there's any more logs you could provide that would be nice.

michaelfpet commented 1 year ago

HI @ocarevs I just tested on version 1.1.8-SNAPSHOT, and the problem is unfortunately still present. If I understand it correctly, it should contain the changes you mentioned?

I get a callback in my AudioDeviceChangeListener where found devices are :

And the selected one is:

But nothing else unfortunately.

ocarevs commented 1 year ago

@michaelfpet Unfortunately we haven't been able to reproduce the issue so far. We will post an update if there's any development on this issue.

michaelfpet commented 1 year ago

Hi @ocarevs, Any news? I got a bit extra time for testing. I am able to replicate the problem using your demo application (https://github.com/twilio/twilio-video-app-android) without any modifications. I have attached a full application log: log.txt

Below is only AS/ logs. 2023-04-28 08:57:43.091 is when I join the room.

2023-04-28 08:57:27.056 18646-18646 AS/AudioSwitch com...lio.video.app.community.debug D AudioSwitch(1.1.7) 2023-04-28 08:57:27.056 18646-18646 AS/AudioSwitch com...lio.video.app.community.debug D Preferred device list = [BluetoothHeadset, WiredHeadset, Speakerphone, Earpiece] 2023-04-28 08:57:27.084 18646-18646 AS/AudioDeviceManager com...lio.video.app.community.debug D Speakerphone available 2023-04-28 08:57:27.085 18646-18646 AS/AudioSwitch com...lio.video.app.community.debug D Available AudioDevice list updated: [Speakerphone(name=Speakerphone)] 2023-04-28 08:57:27.085 18646-18646 AS/AudioSwitch com...lio.video.app.community.debug D Current user selected AudioDevice = null 2023-04-28 08:57:27.373 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Bluetooth Poly Sync 20 connected 2023-04-28 08:57:27.379 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Headset state changed to Connected 2023-04-28 08:57:27.388 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Device size 1 with device name: Poly Sync 20 2023-04-28 08:57:27.389 18646-18646 AS/AudioDeviceManager com...lio.video.app.community.debug D Speakerphone available 2023-04-28 08:57:27.389 18646-18646 AS/AudioSwitch com...lio.video.app.community.debug D Available AudioDevice list updated: [BluetoothHeadset(name=Poly Sync 20), Speakerphone(name=Speakerphone)] 2023-04-28 08:57:27.389 18646-18646 AS/AudioSwitch com...lio.video.app.community.debug D Current user selected AudioDevice = null 2023-04-28 08:57:43.091 18646-18646 AS/BluetoothScoJob com...lio.video.app.community.debug D Scheduled bluetooth sco job 2023-04-28 08:57:43.165 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:43.167 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Headset state changed to AudioActivating 2023-04-28 08:57:43.667 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:44.169 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:44.683 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:45.238 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:45.747 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:46.249 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:46.751 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:47.252 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:47.754 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:48.263 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Attempting to enable bluetooth SCO 2023-04-28 08:57:48.775 18646-18646 AS/BluetoothScoJob com...lio.video.app.community.debug E Bluetooth sco job timed out java.util.concurrent.TimeoutException at com.twilio.audioswitch.bluetooth.BluetoothScoJob$BluetoothScoRunnable.run(BluetoothScoJob.kt:56) at android.os.Handler.handleCallback(Handler.java:942) at android.os.Handler.dispatchMessage(Handler.java:99) at android.os.Looper.loopOnce(Looper.java:226) at android.os.Looper.loop(Looper.java:313) at android.app.ActivityThread.main(ActivityThread.java:8757) at java.lang.reflect.Method.invoke(Native Method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:571) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1067) 2023-04-28 08:57:48.775 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Headset state changed to AudioActivationError 2023-04-28 08:57:48.779 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug D Device size 1 with device name: Poly Sync 20 2023-04-28 08:57:48.784 18646-18646 AS/AudioDeviceManager com...lio.video.app.community.debug D Speakerphone available 2023-04-28 08:57:48.784 18646-18646 AS/AudioSwitch com...lio.video.app.community.debug D Available AudioDevice list updated: [BluetoothHeadset(name=Poly Sync 20), Speakerphone(name=Speakerphone)] 2023-04-28 08:57:48.784 18646-18646 AS/AudioSwitch com...lio.video.app.community.debug D Current user selected AudioDevice = null 2023-04-28 08:57:48.786 18646-18646 AS/Bluetoo...setManager com...lio.video.app.community.debug W Cannot deactivate when in the AudioActivationError state 2023-04-28 08:57:48.786 18646-18646 AS/BluetoothScoJob com...lio.video.app.community.debug D Canceled bluetooth sco job

berger89 commented 1 year ago

we can also reproduce the problem.

Only when AudioSwitch is already started and then the Bluetooth headset is switched on and then connects to the Bluetooth headset from the list of available AudioDevices does the connection fail. If AudioSwitch has not yet been started and the Bluetooth headset is switched on first and then AudioSwitch is started and connects to the Bluetooth headset from the list of available AudioDevices, everything works without problems.

michaelfpet commented 1 year ago

Hi @berger89

Great news! Do you known when a fix will be available?

berger89 commented 1 year ago

@michaelfpet I am not a contributor. I am also a user of this lib ...

michaelfpet commented 1 year ago

Arh i am sry @berger89.
But I am glad we aren't the only one 🙂

ocarevs commented 1 year ago

Hi @berger89 @michaelfpet are you using latest version 1.1.7 or code form repository. We've pushed some fixes to master branch a while back but haven't made a release yet. If you are using 1.1.7, could you check with local build of the library with latest changes on master branch and see if the issue is still there?

michaelfpet commented 1 year ago

Hi @ocarevs,

I apologize for the delay, as I have been on an extended holiday. I am now back. I noticed that you have released version 1.1.8 in the meantime. Unfortunately, the new version still encounters the same issue.

ocarevs commented 11 months ago

Hi @michaelfpet sorry for the late reply. We've been unable to reproduce the issue so far. I have couple of questions that might help me to get to the bottom of this. Is this specific to the device mentioned, or can be reproduce with other devices? Goes for both the Android and the Bluetooth headset. I assume your headset works perfectly fine with other apps; but I wanted to know, in a scenario where you encounter the issue if you background video app and open something like youtube (anything that plays audio), does it route audio through speaker or bluetooth headset? Does restarting the bluetooth headset (off/on) help with the issue or it still fails to connect and route audio through headset, or disconnecting and connecting bluetooth device on the android device?

afalls-twilio commented 6 months ago

closing due to customer inactivity