twilio / audioswitch

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

java.lang.IllegalArgumentException: Receiver not registered: com.twilio.audioswitch.bluetooth.BluetoothHeadsetManager #108

Closed mykola-tarchanyn closed 2 years ago

mykola-tarchanyn commented 2 years ago

Describe the bug Recently in 1.1.3 you added support for Android 12, which is great although I'm getting a crash when trying to stop() the AudioManager if the BLUETOOTH_CONNECT permission was granted while on a call.

Also, it's worth mentioning that in 1.1.3 version AudioDeviceChangeListener is inconsistently firing off unexpected events with an incorrectly selected audio device.

To Reproduce Steps to reproduce the behavior:

  1. Start AudioManager.
  2. Grant BLUETOOTH_CONNECT permission.
  3. Stop Audio Manager.
  4. Crash

Expected behavior The app shouldn't crash.

Actual behavior The app crashes.

Application Logs

Caused by: java.lang.IllegalArgumentException: Receiver not registered: com.twilio.audioswitch.bluetooth.BluetoothHeadsetManager@bb582b7
        at android.app.LoadedApk.forgetReceiverDispatcher(LoadedApk.java:1555)
        at android.app.ContextImpl.unregisterReceiver(ContextImpl.java:1789)
        at android.content.ContextWrapper.unregisterReceiver(ContextWrapper.java:769)
        at com.twilio.audioswitch.bluetooth.BluetoothHeadsetManager.stop(BluetoothHeadsetManager.kt:173)
        at com.twilio.audioswitch.AudioSwitch.closeListeners(AudioSwitch.kt:356)
        at com.twilio.audioswitch.AudioSwitch.stop(AudioSwitch.kt:179)

AudioSwitch Version

afalls-twilio commented 2 years ago

Thanks for the report, we have a fix coming for the IllegalArgumentException issue but as for the inconsistent events with incorrect device information, can you give me more info on that?

1) Does this happen only when the Bluetooth permissions are granted after AudioSwitch is started? 2) Is this android 12 or older devices (pre-Android 12)?

Thanks!

mykola-tarchanyn commented 2 years ago

Thanks for getting back to me so quickly. When do you think you can have a release with the IllegalArgumentException fix?

As for inconsistent events, it's pretty hard to give you the steps to reproduce the issue as it's not consistent. Here's what I think is the most likely scenario to reproduce it: it happens on Android 12 device (Pixel 6 Pro), and it was happening when Bluetooth permissions were granted before AudioSwitch started, then whenever I turn BL on (with auto connected BL headphones) -> turn off -> turn back on the audioDeviceChangeListener is firing off with incorrect currently selected device, I believe it defaults to Earpiece (which by your docs it means that it will happen when there's an error connecting to BL device, although other apps have no problem connecting to it). The worst part about this is selectedAudioDevice will have a different value than audioDeviceChangeListener which is pretty strange. Hope it helps!

afalls-twilio commented 2 years ago

Thank you for the steps. I was able to receive redundant events (multiple audioDeviceChangeListener events), I was not able to reproduce the issue where the incorrect device is listed as the selected audio device. I tested this on both a Pixel 4a and a Pixel 6. The steps i followed were as presented above.. (run app with BL permissions on android 12)->(turn off BL from settings)->(Turn on BL from settings)->Review audioDeviceChangeListener events.

What I received was as follows..

D/AS/AudioSwitch: Preferred device list = [BluetoothHeadset, WiredHeadset, Speakerphone, Earpiece]
D/AS/AudioSwitch: Available AudioDevice list updated: [Speakerphone(name=Speakerphone), Earpiece(name=Earpiece)]
D/AS/AudioSwitch: Current user selected AudioDevice = null
D/AS/AudioSwitch: *** Device List Update ***
        list:
            Speakerphone
            Earpiece
        selected device: Speakerphone

Then, I enabled bluetooth from the setting menu

D/AS/BluetoothHeadsetManager: Bluetooth headset BluetoothDeviceWrapperImpl(device=EA:0A:EF:26:5A:91, name=LC-B41, deviceClass=1028) connected
D/AS/BluetoothHeadsetManager: Headset state changed to Connected
D/AS/AudioSwitch: Available AudioDevice list updated: [BluetoothHeadset(name=LC-B41), Speakerphone(name=Speakerphone), Earpiece(name=Earpiece)]
D/AS/AudioSwitch: Current user selected AudioDevice = null
D/AS/AudioSwitch: *** Device List Update ***
        list:
            LC-B41
            Speakerphone
            Earpiece
        selected device: LC-B41

Then I turned off bluetooth from the settings menu and received two (one spurious) audio change events.

D/AS/BluetoothHeadsetManager: Bluetooth disconnected
D/AS/AudioSwitch: Available AudioDevice list updated: [Speakerphone(name=Speakerphone), Earpiece(name=Earpiece)]
D/AS/AudioSwitch: Current user selected AudioDevice = null
D/AS/AudioSwitch: *** Device List Update ***
        list:
            Speakerphone
            Earpiece
        selected device: Speakerphone

In all cases, while the event was fired more than once, the data presented in the event was correct and reflected the selected audio device.

Also, in terms of what audio device it defaults the connection to, and the order, that can be specified by the user and is not only due to the BL failing. Its specified via preferredDeviceList which is passed in. The order specifies the priority of which audiodevices should be fell back upon. The desired selected audio device can be selected with SelectDevice(..) but if the selected device is not available, then it defaults to what is available in the order described in the preferredDeviceList.

In order to generate the above logcat messages I added the following lines of code to AudioSwitch.kt:295


        // debug. 
        var log_message : StringBuffer = StringBuffer("\n*** Device List Update ***\n\tlist:\n"). 
        for (device in mutableAudioDevices) {. 
            log_message.append("\t\t" + device.name + "\n"). 
        }. 
        log_message.append("\tselected device: "). 
        selectedAudioDevice?.name?.let { log_message.append(it) }. 
        logger.d(TAG, log_message.toString());  
        // end debug  ```
fergusonm commented 2 years ago

I hate adding me too comments but I'm going to to help highlight this isn't just a one-off issue.

I'm running into a very similar, if not identical issue. I too got the same crash and I'm also experiencing the same incorrect selected audio device. I've been trying to find a solid set of steps to reproduce it but it's inconsistent. In my case I'm not turning off bluetooth on the phone but rather turning off the bluetooth connection on my headset.

If I start with BLUETOOTH_CONNECT permissions granted and the headset connected sometimes the headset isn't picked up in the list of available audio devices when calling audioSwith.start. Turning off the headset and then back on triggers the callbacks and it shows up in the list.

I'll do some digging to see if I can find a better set of steps to reproduce it.

fergusonm commented 2 years ago

I was able to reproduce it, but again not consistently. I added some logs to AudioSwitch#addAvailableAudioDevices to record when the list of available devices was being updated.

D/AS/BluetoothHeadsetManager: Bluetooth service connected
D/AS/BluetoothHeadsetManager: Bluetooth PLT_BBFIT connected
D/AS/BluetoothHeadsetManager: Device size 1 with device name: PLT_BBFIT
D/AS/AudioSwitch: ********START Adding available audio devices called with bluetoothHeadSetName PLT_BBFIT
D/AS/AudioSwitch: Mutable audio devices before clear:
D/AS/AudioSwitch: ***: Speakerphone
D/AS/AudioSwitch: ***: Earpiece
D/AS/AudioSwitch: Adding bluetooth failed getHeadset(PLT_BBFIT) returned null
D/AS/AudioSwitch: Adding speakerphone to mutableAudioDevices
D/AS/AudioSwitch: Adding ear piece to mutableAudioDevices
D/AS/AudioSwitch: Mutable audio devices after walking preferred device list:
D/AS/AudioSwitch:       ***: Speakerphone
D/AS/AudioSwitch:       ***: Earpiece
D/AS/AudioSwitch: ********END Available AudioDevice list updated: [Speakerphone(name=Speakerphone), Earpiece(name=Earpiece)]

Note the bluetooth headset being connected but getHeadset call returning null so it isn't being added to the list of available devices.

afalls-twilio commented 2 years ago

@fergusonm Thank you for the additional information, and no, don't worry about dog piling on an issue, the more information, the better. We'll continue investigating this issue, and get back to all of you.

afriedmanGlacier commented 2 years ago

It looks like there was a commit for this issue f1de0fe, does that seem to do the trick and any idea when this might be released? Thanks!

afalls-twilio commented 2 years ago

There are two issues raised in this issue thread. The first issue has been fixed and the second one will be fixed in the near future. If a release is urgently needed, one can be made, otherwise we will hold off until both issues are fixed to do a release, whatever is better for all of you, please let us know.

afriedmanGlacier commented 2 years ago

The issue that we are seeing on Android 12 is that the bluetooth device is not showing up under available audio devices. I'm guessing that means the crash is resolved but the missing bluetooth audio device issue is not? We are not currently seeing a crash. If the (inconsistent) incorrectly selected audio device and missing bluetooth device issue is the one that is resolved, a release as soon as possible would be great!

afalls-twilio commented 2 years ago

@afriedmanGlacier The issue you seem to be describing seems different that the other issues described in this thread. Several questions.. 1) Are you not seeing any available bluetooth devices with the current release (1.1.3) on android 12 or with the most recent commit? 2) Are you prompting the user for bluetooth permissions before activating audioswitch? As of Android 12, Bluetooth permissions require user approval and as of audioswitch 1.1.3, if bluetooth permissions are not granted, the feature is disabled instead of crashing. (https://developer.android.com/guide/topics/connectivity/bluetooth/permissions#declare-android12-or-higher).

afriedmanGlacier commented 2 years ago

Oh my goodness, I bet that's it! I'll have to verify the user permissions, but that's probably the issue. Thanks!

FYI, I am using the current release (1.1.3) on android 12.

fergusonm commented 2 years ago

@afriedmanGlacier for what it's worth you can get the list of bluetooth headsets using just audio manager. (No bluetooth permission required on android 12 so no messing with the bluetooth manager and thus no possible crash.) I was running into the same issue as you and that's how I worked-around it.

audioManager.getDevices(AudioManager.GET_DEVICES_OUTPUTS)

And filter by the AudioDeviceInfo type.

4brunu commented 2 years ago

@afalls-twilio do you have any idea of how long the second bug fix with take to land on master? One week, two weeks, one month? Because having an idea of how long it will take, helps to decide if we should have an intermediate release. If it will take 1 or 2 weeks, I think we don't need an intermediate release, but if it takes 1 or 2 months, maybe an intermediate release would be nice. By the way, thanks for your help and for being open to create an intermediate release in case it's necessary 🙂

afalls-twilio commented 2 years ago

@4brunu We are targeting to have the release before the end of the month, but considering we are headed into the holidays, there is the potential that may happen right after the new year. If you need it sooner, then we'll have to make a release next week (without the second bug fix).

4brunu commented 2 years ago

@afalls-twilio thanks for the feedback 👍 At least for me, I can wait for that and have only one release

zalyssas commented 2 years ago

Hi @afalls-twilio, just wanted to give you a heads up that this also caused a crash in a recent app release for one of our teams here at Zillow. We have a temporary fix to stop the crash, but looking forward to the fix! 😄

afalls-twilio commented 2 years ago

@fergusonm I am still struggling to repo the issue you reported regarding BluetoothHeadsetManager.getHeadset(..) returning null upon successful connection, I suspect there is some timing or state management issue where AudioSwitch 'thinks' it's still disconnected. If you could please try to reproduce it with these specific changes to help me better debug... In particular, if you could change the getHeadset method to include the following log messages and then please post the log (and video of you reproducing it if possible). Thank you so much.

BTW how fast are you turning on and off the bluetooth device?


    fun getHeadset(bluetoothHeadsetName: String?): AudioDevice.BluetoothHeadset? {
        return if (hasPermissions()) {
            if (headsetState != Disconnected) {
                val headsetName = bluetoothHeadsetName ?: getHeadsetName()
                val ret = headsetName?.let { AudioDevice.BluetoothHeadset(it) }
                    ?: AudioDevice.BluetoothHeadset()
                logger.w(TAG, "getHeadset(...) 1 : $headsetName : $ret")
                ret
            } else {
                logger.w(TAG, "getHeadset(...) 2 : got here")
                null
            }
        } else {
            logger.w(TAG, PERMISSION_ERROR_MESSAGE)
            null
        }
    }```
fergusonm commented 2 years ago

With some quick light testing I'm not able to reproduce it again.

However, with respect to how my app references and selects audio output devices, things have changed dramatically. Regrettably, I stopped using AudioSwitch and started referencing and activating the audio output devices, including bluetooth headsets, from Android's AudioManager directly instead.

So it's possible that I'm simply no longer able to set up the conditions that caused that bug. It feels like a threading issue with enumerateDevices and multiple threads modifying the mutableAudioDevices map but I can't see anywhere in the source that map is access off the main thread.

Sorry I can't be of more help. It's a gnarly bug.

afalls-twilio commented 2 years ago

@fergusonm no problem, thank you for trying to help. Yeah, AudioSwitch is single threaded, everything runs off the main thread... I'll make a release next week with the existing changes.

afalls-twilio commented 2 years ago

Release made with crash fixes @4brunu @zalyssas @mykola-tarchanyn