Rightpoint/RZBluetooth

Unable to reconnect peripheral after Bluetooth reset

MrGoPoint opened this issue · 6 comments

MrGoPoint commented

If the Bluetooth radio resets during a connection, I am unable to reconnect to the peripheral. The only solution is to hard reset the phone.

CBCentralState 5 -> 1

[V][2017/05/24 11:55:16:268][AppDelegate -[AppDelegate application:didFinishLaunchingWithOptions:]_block_invoke][Line 57] peripheral:didUpdateValueForCharacteristic:error: - 4A571E85-188E-44CF-A03F-4DDDD152BA7E 914214C5-825C-4D8F-BD37-570F6BD532CD (null)
[V][2017/05/24 11:55:16:750][AppDelegate -[AppDelegate application:didFinishLaunchingWithOptions:]_block_invoke][Line 57] 4A571E85-188E-44CF-A03F-4DDDD152BA7E readValueForCharacteristic:914214C5-825C-4D8F-BD37-570F6BD532CD
[V][2017/05/24 11:55:17:774][AppDelegate -[AppDelegate application:didFinishLaunchingWithOptions:]_block_invoke][Line 57] centralManagerDidUpdateState: - <CBCentralManager: 0x170275640>
[V][2017/05/24 11:55:17:775][ViewController -[ViewController stateChange]][Line 352]
[V][2017/05/24 11:55:17:775][ViewController -[ViewController stateChange]][Line 353] centralManager.state = 1
[V][2017/05/24 11:55:17:775][ViewController -[ViewController stateChange]][Line 361] ERROR reset pause
[V][2017/05/24 11:55:17:797][ViewController -[ViewController stateChange]][Line 372] ERROR CBManagerStateResetting: The Bluetooth radio reset unexpectedly. btConnected = 1 scanning = 0
[V][2017/05/24 11:55:17:836][ViewController -[ViewController stateChange]_block_invoke][Line 384] cancelConnectionWithCompletion
[V][2017/05/24 11:55:21:251][AppDelegate -[AppDelegate application:didFinishLaunchingWithOptions:]_block_invoke][Line 57] centralManagerDidUpdateState: - <CBCentralManager: 0x170275640>
[V][2017/05/24 11:55:21:252][ViewController -[ViewController stateChange]][Line 352]
[V][2017/05/24 11:55:21:252][ViewController -[ViewController stateChange]][Line 353] centralManager.state = 5
[V][2017/05/24 11:55:21:267][AppDelegate -[AppDelegate application:didFinishLaunchingWithOptions:]_block_invoke][Line 57] connectPeripheral:4A571E85-188E-44CF-A03F-4DDDD152BA7E options:(null)

Attempt to connect fails

[V][2017/05/24 11:59:15:627][AppDelegate -[AppDelegate application:didFinishLaunchingWithOptions:]_block_invoke][Line 57] centralManager:didDiscoverPeripheral:advertisementData:RSSI: - <CBCentralManager: 0x170275640> 4A571E85-188E-44CF-A03F-4DDDD152BA7E
[V][2017/05/24 11:59:15:627][ViewController -[ViewController poweredOn]_block_invoke_2][Line 436] discovered Plug
[V][2017/05/24 11:59:15:628][ViewController -[ViewController poweredOn]_block_invoke_2][Line 456] peripheral = 4A571E85-188E-44CF-A03F-4DDDD152BA7E
[V][2017/05/24 11:59:15:628][ViewController -[ViewController poweredOn]_block_invoke_2][Line 457] services = (
)
[V][2017/05/24 11:59:15:628][ViewController -[ViewController poweredOn]_block_invoke_2][Line 458] readCharacteristicUUID:
[V][2017/05/24 11:59:15:628][ViewController -[ViewController readPowerReset]][Line 1326]
[V][2017/05/24 11:59:15:629][AppDelegate -[AppDelegate application:didFinishLaunchingWithOptions:]_block_invoke][Line 57] connectPeripheral:4A571E85-188E-44CF-A03F-4DDDD152BA7E options:(null)
...
[V][2017/05/24 11:59:46:491][ViewController -[ViewController poweredOn]_block_invoke_4][Line 464] Error Domain=com.raizlabs.bluetooth Code=7 "(null)"
[V][2017/05/24 11:59:46:491][ViewController -[ViewController readPowerReset]_block_invoke_2][Line 1332] Error Domain=com.raizlabs.bluetooth Code=7 "(null)"
[V][2017/05/24 11:59:46:492][ViewController -[ViewController readPowerReset]_block_invoke_2][Line 1332] Error Domain=com.raizlabs.bluetooth Code=7 "(null)"
[V][2017/05/24 11:59:46:492][ViewController -[ViewController poweredOn]_block_invoke_5][Line 473] cancelConnectionWithCompletion

KingOfBrian commented

Hey @MrGoPoint , first off, if you have to restart the iPhone, I doubt that this is an RZBluetooth problem. It may be a compatibility issue between your device and iOS. Assuming that this issue resolves by restarting the app and not a hard reset, a few questions:

  • The logs you included are not the RZBluetooth logs, and don't have enough information. Can you configure RZBSetLogHandler and include that log with the bug report? This logs every command to Core Bluetooth and every delegate callback, and can show exactly what's happening.
  • Double check that you're using the latest version on CocoaPods. There was an issue with changing the bluetooth state a few versions back.
  • When you say 'bluetooth radio resets', are you referring to the device or the iPhone? If iOS is connecting to a device and the device goes out of range (or is reset) during the connection, you should get a CBErrorConnection[Timeout|Failed|LimitReached] error. This error should be passed to centralManager:didFailToConnectPeripheral:error:. If a connection related error occurs outside of connection, it is usually passed to centralManager:didDisconnectPeripheral:error:, but could be passed to any other delegate method. I can look at what's happening if you include the RZBSetLogHandler output.

My gut reaction is this isn't an RZBluetooth issue, but if there is an issue, I'd guess it's due to RZBluetooth attempting to automatically reconnect before the device is ready and causing a lot of connection errors which may aggravate an iOS issue. It might be an interesting data point to disable auto reconnect and see if this issue goes away. If this resolves the issue, you can use the connection delegate to implement a custom reconnect pattern that delays the connection a bit, and see if that resolves the issue.

Anyway, enough speculation! If you attach the RZBluetooth log, I'll gladly see if I can come up with a more accurate idea.

MrGoPoint commented

Using version 1.2 of RZBluetooth

While the peripheral is connected, the Bluetooth goes into CBManagerStateResetting before going back to CBManagerStatePoweredOn. I'm not sure what causes this, but it happens infrequently.

I don't explicitly set self.peripheral.maintainConnection, should I?

When this error happens, I delay any attempts to reconnect to the peripheral by 60-seconds. During this time, the peripheral resets and comes up in a fresh state.

I'm using Cocoalumberjack

    RZBSetLogHandler(^(RZBLogLevel logLevel, NSString *format, va_list args) {
        if (logLevel != RZBLogLevelWriteCommandData && logLevel != RZBLogLevelDelegateValue) {
            DDLogDebug(@"%@",  [[NSString alloc] initWithFormat:format arguments:args]);
        }
    });

Things I tried:

  • Bluetooth on/off [no effect]
  • Kill and restart app [no effect]
  • Power cycle peripheral [no effect]
  • Hard reset phone [works]

How's this:

CBCentralState 5 -> 1

[RZBluetooth] peripheral:didUpdateValueForCharacteristic:error: - 4A571E85-188E-44CF-A03F-4DDDD152BA7E 914214C5-825C-4D8F-BD37-570F6BD532CD (null)
[RZBluetooth] 4A571E85-188E-44CF-A03F-4DDDD152BA7E readValueForCharacteristic:914214C5-825C-4D8F-BD37-570F6BD532CD
[RZBluetooth] centralManagerDidUpdateState: - <CBCentralManager: 0x170275640>
[myApp] centralManager.state = 1
[myApp] ERROR reset pause
[myApp] ERROR CBManagerStateResetting: The Bluetooth radio reset unexpectedly. btConnected = 1 scanning = 0
[myApp] cancelConnectionWithCompletion
[RZBluetooth] centralManagerDidUpdateState: - <CBCentralManager: 0x170275640>
[myApp] centralManager.state = 5
[RZBluetooth] connectPeripheral:4A571E85-188E-44CF-A03F-4DDDD152BA7E options:(null)

After 60 seconds

[RZBluetooth] centralManager:didDiscoverPeripheral:advertisementData:RSSI: - <CBCentralManager: 0x170275640> 4A571E85-188E-44CF-A03F-4DDDD152BA7E
[myApp] discovered Plug
[myApp] peripheral = 4A571E85-188E-44CF-A03F-4DDDD152BA7E
[myApp] services = (
)
[myApp] readCharacteristicUUID:
[RZBluetooth] connectPeripheral:4A571E85-188E-44CF-A03F-4DDDD152BA7E options:(null)
...
[myApp] Error Domain=com.raizlabs.bluetooth Code=7 "(null)"
[myApp] cancelConnectionWithCompletion

KingOfBrian commented 
While the peripheral is connected, the Bluetooth goes into CBManagerStateResetting before going back to CBManagerStatePoweredOn. I'm not sure what causes this, but it happens infrequently.

Yea, core bluetooth does this randomly, and it's tough. RZBluetooth tries to handle this transparently by not holding transient state and tracking the overall user intent, but the number of ways this can happen is hard to exhaustively test. You may be hitting a corner case here, but this also shouldn't force a device reset to fix. From RZBluetooth perspective, it's just app state, but Core Bluetooth may be wedged. If you open the Device Explorer in Xcode and look at the device console, sometimes CoreBluetooth will log helpful error messages there. If you see something, I'd be interested in what it is.

Can you send the entire log with timestamps? I'm not sure what commands are pending when CBCentralState 5 -> 1 is reported, but it appears there's a command in the queue, since it automatically attempts re-connection. Also, given there's a connection attempt outstanding, the second readCharacteristicUUID shouldn't be initiating another connect attempt. Having the full log will help, and may give me enough data to write a test to reproduce this.

If you're more comfortable emailing them, send it to brian.king@raizlabs.com. If you could also include the RZBluetooth commands you're doing on discovery and connection that may help.

KingOfBrian commented

Hey @MrGoPoint -- any update to this issue?

MrGoPoint commented
KingOfBrian commented

Please re-open if this comes up again, even if it's not an RZBluetooth issue, but a Core Bluetooth reseting behavior.