Android startBluetoothSco not starting sco but isBluetoothScoOn returns true

swooby picture swooby · Oct 5, 2012 · Viewed 10.7k times · Source

I have created a GitHub repo with a sample project that shows the below problem I am asking about here:
https://github.com/paulpv/audio-loopback/tree/simplified/src/com/twistpair/wave/experimental/loopback
(please stick w/ the “simplified” branch and disregard the “master” branch)

The two main files are:

Disclaimer: I am currently only using a single Samsung Epic SPH-D700 running CyanogenMod 10 Jelly Bean to code and test this with. I have not tried this on other devices, but maybe that might help stop me from pulling my hair out and going crazy.

I have been fighting getting Android Bluetooth SCO to reliably start and stop and capture/playback audio FOR MONTHS!
Once I can get the phone in to SCO mode, capture and playback via AudioRecord and AudioTrack (respectively) works fine as documented.
The problem I am having is that I cannot reliably get the phone in to SCO mode!

The examples on “The Internets” to use startBluetoothSco() and setBluetoothScoOn(true) all seem simple and straight-forward, but when I use them on my device they almost never reliably work.
I created my own test app that does nothing but start and stop SCO, and I cannot even get this to reliably work!

My code listens for a BluetoothHeadset.ACTION_CONNECTION_STATE_CHANGED EXTRA_STATE==CONNECTED.
I can reliably detect when any headset is connected or disconnected.

When detecting a connection my handler immediately calls startBluetoothSco().
A could swear that at least once this has kicked SCO_AUDIO_STATE to CONNECTED, but 99% of the time it just results in a transition from DISCONNECTED->CONNECTING->DISCONNECTED.

Here is my annotated log output from my GitHub sample app:

10-03 17:00:13.970: I/dalvikvm(29487): Debugger is active
10-03 17:00:14.158: I/System.out(29487): Debugger has connected
10-03 17:00:15.779: I/System.out(29487): waiting for debugger to settle...
10-03 17:00:15.978: I/System.out(29487): debugger has settled (1325)

My app starts w/ Jawbone headset turned off and updates the UI...

10-03 17:00:16.568: D/MainActivity(29487): updateScreen()...
10-03 17:00:16.572: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=false

...UI update done
Sticky broadcast that tells me the current SCO_AUDIO_STATE...

10-03 17:00:16.689: D/AudioStateManager(29487): onReceive: intent=Intent { act=android.media.ACTION_SCO_AUDIO_STATE_UPDATED flg=0x10 (has extras) }
10-03 17:00:16.689: D/AudioStateManager(29487): extras={"android.media.extra.SCO_AUDIO_PREVIOUS_STATE"=2, "android.media.extra.SCO_AUDIO_STATE"=0}
10-03 17:00:16.689: D/AudioStateManager(29487): android.media.ACTION_SCO_AUDIO_STATE_UPDATED
10-03 17:00:16.693: D/AudioStateManager(29487): ==> scoAudioStatePrevious=SCO_AUDIO_STATE_CONNECTING(2)
10-03 17:00:16.693: D/AudioStateManager(29487): ==> scoAudioState=SCO_AUDIO_STATE_DISCONNECTED(0)
10-03 17:00:16.693: D/AudioStateManager(29487): android.media.ACTION_SCO_AUDIO_STATE_UPDATED: SCO_AUDIO_STATE_DISCONNECTED

...current SCO_AUDIO_STATE == DISCONNECTED; expected, since my headset is turned off.
My SCO Disconnected event listener is called and updates the UI w/ two sendMessages...

10-03 17:00:16.693: I/MainActivity(29487): onAudioManagerScoAudioDisconnected()
10-03 17:00:16.755: D/libEGL(29487): loaded /vendor/lib/egl/libEGL_POWERVR_SGX540_120.so
10-03 17:00:16.787: D/libEGL(29487): loaded /vendor/lib/egl/libGLESv1_CM_POWERVR_SGX540_120.so
10-03 17:00:16.791: D/libEGL(29487): loaded /vendor/lib/egl/libGLESv2_POWERVR_SGX540_120.so
10-03 17:00:16.888: D/OpenGLRenderer(29487): Enabling debug mode 0
10-03 17:00:16.912: D/MainActivity(29487): MSG_UPDATE_BLUETOOTH_INDICATION
10-03 17:00:16.912: D/MainActivity(29487): updateScreen()...
10-03 17:00:16.912: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=false
10-03 17:00:16.927: D/MainActivity(29487): MSG_UPDATE_AUDIO_OUTPUT_STREAM_TYPE
10-03 17:00:16.927: D/MainActivity(29487): updateScreen()...
10-03 17:00:16.931: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=false

...UI update done

After ~20 seconds I turn on my Jawbone headset...

10-03 17:00:37.572: D/AudioStateManager(29487): onReceive: intent=Intent { act=android.bluetooth.headset.profile.action.CONNECTION_STATE_CHANGED flg=0x10 (has extras) }
10-03 17:00:37.583: D/AudioStateManager(29487): extras={"android.bluetooth.device.extra.DEVICE"=00:21:3C:00:3E:02, "android.bluetooth.profile.extra.PREVIOUS_STATE"=0, "android.bluetooth.profile.extra.STATE"=1}
10-03 17:00:37.587: D/AudioStateManager(29487): mReceiver: BluetoothHeadset.ACTION_CONNECTION_STATE_CHANGED
10-03 17:00:37.587: D/AudioStateManager(29487): ==> bluetoothDevice=00:21:3C:00:3E:02
10-03 17:00:37.587: D/AudioStateManager(29487): ==> bluetoothHeadsetStatePrevious=STATE_DISCONNECTED(0)
10-03 17:00:37.587: D/AudioStateManager(29487): ==> bluetoothHeadsetState=STATE_CONNECTING(1)
10-03 17:00:37.619: D/AudioStateManager(29487): onReceive: intent=Intent { act=android.bluetooth.headset.profile.action.CONNECTION_STATE_CHANGED flg=0x10 (has extras) }
10-03 17:00:37.623: D/AudioStateManager(29487): extras={"android.bluetooth.device.extra.DEVICE"=00:21:3C:00:3E:02, "android.bluetooth.profile.extra.PREVIOUS_STATE"=1, "android.bluetooth.profile.extra.STATE"=2}
10-03 17:00:37.623: D/AudioStateManager(29487): mReceiver: BluetoothHeadset.ACTION_CONNECTION_STATE_CHANGED
10-03 17:00:37.623: D/AudioStateManager(29487): ==> bluetoothDevice=00:21:3C:00:3E:02
10-03 17:00:37.626: D/AudioStateManager(29487): ==> bluetoothHeadsetStatePrevious=STATE_CONNECTING(1)
10-03 17:00:37.626: D/AudioStateManager(29487): ==> bluetoothHeadsetState=STATE_CONNECTED(2)

Jawbone connected; My event listener is called...

10-03 17:00:37.626: I/MainActivity(29487): onBluetoothHeadsetConnected()

...sees that we can SCO...

10-03 17:00:37.626: D/AudioStateManager(29487): mAudioManager.isBluetoothScoAvailableOffCall()=true

...and auto-calls startBluetoothSco()
HERE IS WHERE THE PROBLEM IS! Why does this call to startBluetoothSco not result in SCO_AUDIO_STATE == CONNECTED?!?!

10-03 17:00:37.626: D/AudioStateManager(29487): startBluetoothSco()
10-03 17:00:37.626: I/AudioStateManager(29487): mAudioManager.startBluetoothSco();

My event listener finishes up w/ a sendMessage to update the UI w/ the current BT state...

10-03 17:00:37.646: D/MainActivity(29487): MSG_UPDATE_BLUETOOTH_INDICATION
10-03 17:00:37.650: D/MainActivity(29487): updateScreen()...
10-03 17:00:37.650: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=false

...UI update done
First result from startBluetoothSco comes in...

10-03 17:00:37.681: D/AudioStateManager(29487): onReceive: intent=Intent { act=android.media.ACTION_SCO_AUDIO_STATE_UPDATED flg=0x10 (has extras) }
10-03 17:00:37.681: D/AudioStateManager(29487): extras={"android.media.extra.SCO_AUDIO_STATE"=2, "android.media.extra.SCO_AUDIO_PREVIOUS_STATE"=0}
10-03 17:00:37.681: D/AudioStateManager(29487): android.media.ACTION_SCO_AUDIO_STATE_UPDATED
10-03 17:00:37.685: D/AudioStateManager(29487): ==> scoAudioStatePrevious=SCO_AUDIO_STATE_DISCONNECTED(0)
10-03 17:00:37.685: D/AudioStateManager(29487): ==> scoAudioState=SCO_AUDIO_STATE_CONNECTING(2)

...moved from DISCONNECTED to CONNECTING
Second result from startBluetoothSco comes in...

10-03 17:00:37.759: D/AudioStateManager(29487): onReceive: intent=Intent { act=android.media.ACTION_SCO_AUDIO_STATE_UPDATED flg=0x10 (has extras) }
10-03 17:00:37.763: D/AudioStateManager(29487): extras={"android.media.extra.SCO_AUDIO_STATE"=0, "android.media.extra.SCO_AUDIO_PREVIOUS_STATE"=2}
10-03 17:00:37.763: D/AudioStateManager(29487): android.media.ACTION_SCO_AUDIO_STATE_UPDATED
10-03 17:00:37.763: D/AudioStateManager(29487): ==> scoAudioStatePrevious=SCO_AUDIO_STATE_CONNECTING(2)
10-03 17:00:37.763: D/AudioStateManager(29487): ==> scoAudioState=SCO_AUDIO_STATE_DISCONNECTED(0)
10-03 17:00:37.763: D/AudioStateManager(29487): android.media.ACTION_SCO_AUDIO_STATE_UPDATED: SCO_AUDIO_STATE_DISCONNECTED

...moved from CONNECTING to DISCONNECTED
I would have expected SCO to go from CONNECTING to CONNECTED!
My event listener is called and updates the UI w/ two sendMessages...

10-03 17:00:37.763: I/MainActivity(29487): onAudioManagerScoAudioDisconnected()
10-03 17:00:37.767: D/MainActivity(29487): MSG_UPDATE_BLUETOOTH_INDICATION
10-03 17:00:37.767: D/MainActivity(29487): updateScreen()...
10-03 17:00:37.767: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=false
10-03 17:00:37.783: D/MainActivity(29487): MSG_UPDATE_AUDIO_OUTPUT_STREAM_TYPE
10-03 17:00:37.783: D/MainActivity(29487): updateScreen()...
10-03 17:00:37.783: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=false

...UI update done

I wait ~20 seconds for SCO connected but it never comes.
I press my app's "startBluetoothSco" button.
NOTE THAT THIS RESULTS IN THE EXACT SAME CALL TO startBluetoothSco() AT 17:00:37.626

10-03 17:01:01.689: D/AudioStateManager(29487): startBluetoothSco()
10-03 17:01:01.689: I/AudioStateManager(29487): mAudioManager.startBluetoothSco();

First result from startBluetoothSco comes in...

10-03 17:01:01.708: D/AudioStateManager(29487): onReceive: intent=Intent { act=android.media.ACTION_SCO_AUDIO_STATE_UPDATED flg=0x10 (has extras) }
10-03 17:01:01.712: D/AudioStateManager(29487): extras={"android.media.extra.SCO_AUDIO_STATE"=2, "android.media.extra.SCO_AUDIO_PREVIOUS_STATE"=0}
10-03 17:01:01.712: D/AudioStateManager(29487): android.media.ACTION_SCO_AUDIO_STATE_UPDATED
10-03 17:01:01.712: D/AudioStateManager(29487): ==> scoAudioStatePrevious=SCO_AUDIO_STATE_DISCONNECTED(0)
10-03 17:01:01.712: D/AudioStateManager(29487): ==> scoAudioState=SCO_AUDIO_STATE_CONNECTING(2)

...moved from DISCONNECTED to CONNECTING
Here is where things differ from the auto-call of startBluetoothSco() at 17:00:37.626
We get a BluetoothHeadset.ACTION_AUDIO_STATE_CHANGED event...

10-03 17:01:01.716: D/AudioStateManager(29487): onReceive: intent=Intent { act=android.bluetooth.headset.profile.action.AUDIO_STATE_CHANGED flg=0x10 (has extras) }
10-03 17:01:01.720: D/AudioStateManager(29487): extras={"android.bluetooth.device.extra.DEVICE"=00:21:3C:00:3E:02, "android.bluetooth.profile.extra.PREVIOUS_STATE"=10, "android.bluetooth.profile.extra.STATE"=11}
10-03 17:01:01.720: D/AudioStateManager(29487): mReceiver: BluetoothHeadset.ACTION_AUDIO_STATE_CHANGED
10-03 17:01:01.720: D/AudioStateManager(29487): ==> bluetoothDevice=00:21:3C:00:3E:02
10-03 17:01:01.720: D/AudioStateManager(29487): ==> bluetoothHeadsetAudioStatePrevious=STATE_AUDIO_DISCONNECTED(10)
10-03 17:01:01.720: D/AudioStateManager(29487): ==> bluetoothHeadsetAudioState=STATE_AUDIO_CONNECTING(11)

...moved from DISCONNECTED to CONNECTING
We get another BluetoothHeadset.ACTION_AUDIO_STATE_CHANGED event...

10-03 17:01:02.572: D/AudioStateManager(29487): onReceive: intent=Intent { act=android.bluetooth.headset.profile.action.AUDIO_STATE_CHANGED flg=0x10 (has extras) }
10-03 17:01:02.576: D/AudioStateManager(29487): extras={"android.bluetooth.device.extra.DEVICE"=00:21:3C:00:3E:02, "android.bluetooth.profile.extra.PREVIOUS_STATE"=11, "android.bluetooth.profile.extra.STATE"=12}
10-03 17:01:02.576: D/AudioStateManager(29487): mReceiver: BluetoothHeadset.ACTION_AUDIO_STATE_CHANGED
10-03 17:01:02.576: D/AudioStateManager(29487): ==> bluetoothDevice=00:21:3C:00:3E:02
10-03 17:01:02.576: D/AudioStateManager(29487): ==> bluetoothHeadsetAudioStatePrevious=STATE_AUDIO_CONNECTING(11)
10-03 17:01:02.580: D/AudioStateManager(29487): ==> bluetoothHeadsetAudioState=STATE_AUDIO_CONNECTED(12)

...moved from CONNECTING to CONNECTED
Event updates the UI w/ one sendMessage

10-03 17:01:02.580: I/MainActivity(29487): onBluetoothHeadsetAudioConnected()
10-03 17:01:02.580: D/MainActivity(29487): MSG_UPDATE_BLUETOOTH_INDICATION
10-03 17:01:02.580: D/MainActivity(29487): updateScreen()...
10-03 17:01:02.583: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=true

...UI update done (To be honest, I am not sure what is calling isBluetoothScoOn a second time)

10-03 17:01:02.603: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=true

Second result from startBluetoothSco comes in...

10-03 17:01:02.603: D/AudioStateManager(29487): onReceive: intent=Intent { act=android.media.ACTION_SCO_AUDIO_STATE_UPDATED flg=0x10 (has extras) }
10-03 17:01:02.607: D/AudioStateManager(29487): extras={"android.media.extra.SCO_AUDIO_STATE"=1, "android.media.extra.SCO_AUDIO_PREVIOUS_STATE"=2}
10-03 17:01:02.607: D/AudioStateManager(29487): android.media.ACTION_SCO_AUDIO_STATE_UPDATED
10-03 17:01:02.607: D/AudioStateManager(29487): ==> scoAudioStatePrevious=SCO_AUDIO_STATE_CONNECTING(2)
10-03 17:01:02.607: D/AudioStateManager(29487): ==> scoAudioState=.SCO_AUDIO_STATE_CONNECTED(1)
10-03 17:01:02.607: D/AudioStateManager(29487): android.media.ACTION_SCO_AUDIO_STATE_UPDATED: SCO_AUDIO_STATE_CONNECTED

...moved from CONNECTING to CONNECTED

FINALLY!
My event listener is called and updates the UI w/ two sendMessages...

10-03 17:01:02.611: I/MainActivity(29487): onAudioManagerScoAudioConnected()
10-03 17:01:02.630: D/MainActivity(29487): MSG_UPDATE_BLUETOOTH_INDICATION
10-03 17:01:02.630: D/MainActivity(29487): updateScreen()...
10-03 17:01:02.634: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=true
10-03 17:01:02.650: D/MainActivity(29487): MSG_UPDATE_AUDIO_OUTPUT_STREAM_TYPE
10-03 17:01:02.650: D/MainActivity(29487): updateScreen()...
10-03 17:01:02.650: D/AudioStateManager(29487): mAudioManager.isBluetoothScoOn()=true

...UI update done

Everything (this time) works when I "manually" start SCO after some time, but not if I automatically start SCO immediately after a headset is connected.

To make things worse, when things aren't working as expected I see strange behavior in the SCO states:

  • Delaying the startBluetoothSco() for a resonable 3-5 seconds seems to make no difference. I haven't tried delaying it any more than 5 seconds. Waiting more than 5 seconds for audio to start flowing to your BT headset is ridiculous.
  • Sometimes calling isBluetoothScoOn() returns true, even when I have never received a broadcast event since the last DISCONNECTED state saying that state changed to CONNECTED.
  • Sometimes "manually" calling startBluetoothSco() from the UI does nothing, as if SCO is already on, yet I never received any broadcast event since the last DISCONNECTED state saying that state changed to CONNECTED.
  • Trying to open AudioTrack or AudioRecord results in no sound (this same code works fine when SCO isn't misbehaving. ie: the problem is the SCO state, not the AudioTrack/AudioRecord calls).
  • Calling stopBluetoothSco() does not result in any event reporting state DISCONNECTED.
  • setBluetoothScoOn(false/true) makes no difference. To be honest I don't understand the difference in the seemingly redundant "startBluetoothSco()/stopBluetoothSco()" and "setBluetoothScoOn(boolean)". When things work, my calling startBluetoothSco() results in isBluetoothScoOn() returning true making me think that I don't need to call setBluetoothScoOn(true).
  • Rebooting the phone makes no difference.
  • Rebooting the headset makes no difference.
  • Changing to another headset makes no difference.
  • Sometimes the headset loses its pairing and has to be re-paired.

Given Google's/Android's track record on Bluetooth support, very little of this surprises me.

Can someone please put me out of my misery and definitely explain how to reliably start and stop bluetooth SCO in Android?

PS: Is there an official channel to escalate issues like this [w/ Google? Samsung?]? Or, is StackOverflow my best chance of finding an actual answer?

Answer

Saurav picture Saurav · Mar 6, 2015

There are many things missing in the Android documentation, however, if you call startBluetoothSco() and stopBluetoothSco() each time during audio routing there should be no problem routing the audio properly. Even I have seen when the connection is kept idle for long and we start StartBluetoothSco() we directly get disconnection. To solve this I wrote a workaround which is here: https://github.com/kodered/Bluetooth-Refresh-Logic

Hope this helps.