search

polarofficial / polar-ble-sdk

Repository includes SDK and code examples. More info https://polar.com/en/developers
Other
447 stars 147 forks source link

BLE error "Peer removed pairing information" not handled properly (lost BT pairing keys?) #389

Closed orestesgaolin closed 10 months ago

orestesgaolin commented 11 months ago

Platform on which you observed the bug:

Device on which you observed the bug:

Describe the bug We don't know the reason but sometimes Verity Sense looses BLE pairing keys. We received multiple reports from our users that when this happens then the only way to resolve it is to forget the device via system settings. See more about this particular error here.

After first occurrence of the Peer removed pairing information the SDK tries to continuously reconnect with the device.

Logs are shown below.

Seems like the didFailToConnect is not exposed anywhere else beside the log and then passed to handleDisconnected which in turn tries to connect with the device again, repeating the cycle.

How to Reproduce

We don't really have a way of reproducing this issue. If you have any ideas we'd be happy to validate them.

Expected behavior

I would expect the SDK to inform the consumer about the failure, maybe along with the failure reason. I think that adding failure flag to deviceDisconnected or exposing another method in the PolarBleApiObserver protocol would be sufficient.

Screenshots and logs

Logs from iOS

``` 2023-07-28T07:42:05.449Z BFS: Starting service for device ABCDEFGH. Restored: true 2023-07-28T07:42:05.605Z PC: Setting heart rate listener 2023-07-28T07:42:05.605Z BFS: Received device battery update {"value": -1, "timestamp": "1690530125605", "deviceId": "" } 2023-07-28T07:42:05.606Z Polar SDK log: [BLE] willRestoreState called with dict: ["kCBRestoredScanOptions": { kCBScanOptionAllowDuplicates = 1; }, "kCBRestoredPeripherals": <__NSArrayM 0x28221cc30>( ) , "kCBRestoredScanServices": <__NSArrayM 0x2822113e0>( Heart Rate, FEEE ) ] 2023-07-28T07:42:05.606Z Polar SDK log: [BLE] willRestoreState found devices: Optional(<__NSArrayM 0x28221cc30>( ) ) 2023-07-28T07:42:05.606Z Polar SDK log: [BLE] willRestoreState found device: 2023-07-28T07:42:05.608Z PC: Device battery updated: {"value": -1, "timestamp": "1690530125605", "deviceId": "" } 2023-07-28T07:42:05.608Z PC: Setting device synchronization listener 2023-07-28T07:42:05.608Z PC: Setting device version listener 2023-07-28T07:42:05.608Z BFS: Received device version update {"deviceId": "", "softwareVersion": "" } 2023-07-28T07:42:05.608Z PC: Device version updated: {"deviceId": "", "softwareVersion": "" } 2023-07-28T07:42:05.609Z PC: Setting device contact listener 2023-07-28T07:42:05.609Z BFS: Received device contact update {"deviceId": "ABCDEFGH", "timestamp": "1690467570242" } 2023-07-28T07:42:05.609Z PC: Device contact updated: {"deviceId": "ABCDEFGH", "timestamp": "1690467570242" } 2023-07-28T07:42:05.609Z PC: Connecting to device ABCDEFGH 2023-07-28T07:42:05.609Z BFS: Received connection update {"connection": 0, "deviceId": "ABCDEFGH", "name": "Polar Sense ABCDEFGH" } 2023-07-28T07:42:05.609Z PC: Device connection updated: {"connection": 0, "deviceId": "ABCDEFGH", "name": "Polar Sense ABCDEFGH" } 2023-07-28T07:42:05.611Z Polar SDK log: [BLE] commandState state:IDLE action: CLIENT_START_SCAN 2023-07-28T07:42:05.611Z Polar SDK log: [BLE] commandState state:IDLE action: EXIT 2023-07-28T07:42:05.611Z Polar SDK log: [BLE] commandState state:SCANNING action: ENTRY 2023-07-28T07:42:05.611Z Polar SDK log: [BLE] start scan services: nil 2023-07-28T07:42:05.612Z Polar SDK log: [BLE] Automatically enable characteristic notification 2A37 on connect. Disable on disconnect: true 2023-07-28T07:42:05.616Z Polar SDK log: [BLE] Automatically enable characteristic notification 2A19 on connect. Disable on disconnect: false 2023-07-28T07:42:05.616Z Polar SDK log: [BLE] Automatically enable characteristic notification FB005C81-02E7-F387-1CAD-8ACD2D8DF0C8 on connect. Disable on disconnect: false 2023-07-28T07:42:05.616Z Polar SDK log: [BLE] Automatically enable characteristic notification FB005C82-02E7-F387-1CAD-8ACD2D8DF0C8 on connect. Disable on disconnect: false 2023-07-28T07:42:05.616Z Polar SDK log: [BLE] Automatically enable characteristic notification FB005C51-02E7-F387-1CAD-8ACD2D8DF0C8 on connect. Disable on disconnect: false 2023-07-28T07:42:05.616Z Polar SDK log: [BLE] Automatically enable characteristic notification FB005C52-02E7-F387-1CAD-8ACD2D8DF0C8 on connect. Disable on disconnect: false 2023-07-28T07:42:05.616Z Polar SDK log: [BLE] new peripheral discovered: 2023-07-28T07:42:05.638Z BFS: Setting connected_device_id to ABCDEFGH 2023-07-28T07:42:05.638Z BFS: Setting connected_device_name to Polar Sense ABCDEFGH 2023-07-28T07:42:05.638Z BFS: Requested to connect to device ABCDEFGH 2023-07-28T07:42:05.739Z HeartRateFetcher: Central manager restored with 1 devices 2023-07-28T07:42:05.740Z HeartRateFetcher: Restore complete with disconnected peripheral 2023-07-28T07:42:05.740Z PC: Bluetooth turned on 2023-07-28T07:42:05.740Z Polar SDK log: [BLE] state update to: PoweredOn 2023-07-28T07:42:05.740Z Polar SDK log: [BLE] commandState state:SCANNING action: BLE_POWER_ON 2023-07-28T07:42:05.742Z Polar SDK log: [BLE] default session state update from: sessionClosed to: sessionOpening 2023-07-28T07:42:05.742Z Polar SDK log: connect search complete 2023-07-28T07:42:05.742Z Polar SDK log: [BLE] commandState state:SCANNING action: CLIENT_REMOVED 2023-07-28T07:42:05.742Z Polar SDK log: [BLE] commandState state:SCANNING action: EXIT 2023-07-28T07:42:05.743Z Polar SDK log: [BLE] commandState state:IDLE action: ENTRY 2023-07-28T07:42:05.747Z HeartRateFetcher: Central manager did update state: 5 2023-07-28T07:42:06.130Z Polar SDK log: [BLE] didFailToConnect: error: Peer removed pairing information 2023-07-28T07:42:06.248Z Polar SDK log: [BLE] default session state update from: sessionOpening to: sessionOpenPark 2023-07-28T07:42:06.249Z Polar SDK log: [BLE] commandState state:IDLE action: ENTRY 2023-07-28T07:42:06.249Z Polar SDK log: [BLE] commandState state:IDLE action: EXIT 2023-07-28T07:42:06.249Z Polar SDK log: [BLE] commandState state:SCANNING action: ENTRY 2023-07-28T07:42:06.249Z Polar SDK log: [BLE] start scan services: nil 2023-07-28T08:28:08.671Z Polar SDK log: foreground 2023-07-28T08:28:08.673Z Polar SDK log: [BLE] commandState state:SCANNING action: ADMIN_STOP_SCAN 2023-07-28T08:28:08.674Z Polar SDK log: [BLE] commandState state:SCANNING action: EXIT 2023-07-28T08:28:08.677Z Polar SDK log: [BLE] commandState state:STOPPED action: ENTRY 2023-07-28T08:28:08.677Z Polar SDK log: [BLE] commandState state:STOPPED action: ADMIN_START_SCAN 2023-07-28T08:28:08.678Z Polar SDK log: [BLE] commandState state:STOPPED action: EXIT 2023-07-28T08:28:08.678Z Polar SDK log: [BLE] commandState state:IDLE action: ENTRY 2023-07-28T08:28:08.678Z Polar SDK log: [BLE] commandState state:IDLE action: EXIT 2023-07-28T08:28:08.678Z Polar SDK log: [BLE] commandState state:SCANNING action: ENTRY 2023-07-28T08:28:08.678Z Polar SDK log: [BLE] start scan services: nil 2023-07-28T08:28:08.685Z AppDelegate: applicationDidReceiveMemoryWarning 2023-07-28T08:28:08.760Z Polar SDK log: [BLE] default session state update from: sessionOpenPark to: sessionOpening 2023-07-28T08:28:08.761Z Polar SDK log: [BLE] commandState state:SCANNING action: CLIENT_REMOVED 2023-07-28T08:28:08.761Z Polar SDK log: [BLE] commandState state:SCANNING action: EXIT 2023-07-28T08:28:08.762Z Polar SDK log: [BLE] commandState state:IDLE action: ENTRY 2023-07-28T08:28:09.156Z Polar SDK log: [BLE] didFailToConnect: error: Peer removed pairing information 2023-07-28T08:28:09.163Z Polar SDK log: [BLE] default session state update from: sessionOpening to: sessionOpenPark 2023-07-28T08:28:09.163Z Polar SDK log: [BLE] commandState state:IDLE action: ENTRY 2023-07-28T08:28:09.163Z Polar SDK log: [BLE] commandState state:IDLE action: EXIT 2023-07-28T08:28:09.163Z Polar SDK log: [BLE] commandState state:SCANNING action: ENTRY 2023-07-28T08:28:09.163Z Polar SDK log: [BLE] start scan services: nil 2023-07-28T08:28:09.228Z Polar SDK log: [BLE] default session state update from: sessionOpenPark to: sessionOpening 2023-07-28T08:28:09.228Z Polar SDK log: [BLE] commandState state:SCANNING action: CLIENT_REMOVED 2023-07-28T08:28:09.228Z Polar SDK log: [BLE] commandState state:SCANNING action: EXIT 2023-07-28T08:28:09.228Z Polar SDK log: [BLE] commandState state:IDLE action: ENTRY 2023-07-28T08:28:09.608Z Polar SDK log: [BLE] didFailToConnect: error: Peer removed pairing information 2023-07-28T08:28:09.609Z Polar SDK log: [BLE] default session state update from: sessionOpening to: sessionOpenPark 2023-07-28T08:28:09.609Z Polar SDK log: [BLE] commandState state:IDLE action: ENTRY 2023-07-28T08:28:09.609Z Polar SDK log: [BLE] commandState state:IDLE action: EXIT 2023-07-28T08:28:09.609Z Polar SDK log: [BLE] commandState state:SCANNING action: ENTRY 2023-07-28T08:28:09.610Z Polar SDK log: [BLE] start scan services: nil 2023-07-28T08:28:09.681Z Polar SDK log: [BLE] default session state update from: sessionOpenPark to: sessionOpening ```

samulimaa commented 11 months ago

Hello,

Explanation and possible fix: iOS applications are not permitted to remove Bluetooth pairings, so user has to remove the pairing manually from the settings.

To detect when this is happening, you could try monitoring the device connection state with PolarBleApiObserver and attempt to detect when the device gets stuck in the device connecting state. Then, for example, a popup could be shown to the user, guiding them to remove the pairing from the Bluetooth settings and re-pair the device. For usage of PolarBleApiObserver, please see example implementation from iOS example app: https://github.com/polarofficial/polar-ble-sdk/blob/master/examples/example-ios/iosBleSdkTestApp/iosBleSdkTestApp/PolarBleSdkManager.swift#L1164

orestesgaolin commented 11 months ago

We are already using PolarBleApiObserver in our implementation and it reports that the device is connected, the deviceConnected is being called in an infinite loop. The deviceDisconnected is not being called.

samulimaa commented 10 months ago

The SDK indeed had a bug where PolarBleApiObserver.deviceDisconnected() was not called in the case of 'Peer removed pairing information.' This has now been fixed in SDK version 5.2.0. Also deviceDisconnected() now has a pairingError parameter, which indicates that the device was disconnected due to an error in pairing. Your application can then detect this and guide the end user to remove pairing from the system settings.

I was able to reproduce this issue with Verity Sense by pairing the sensor with a phone and then performing a factory reset on the sensor. This should cause the pairing keys to be lost. Here's how to perform a factory reset: https://support.polar.com/en/how-can-i-reset-my-sensor

orestesgaolin commented 10 months ago

Thank you so much for addressing the issue, we appreciate it a lot!

Wondering if you ever encountered this issue when the pairing keys would be lost "spontaneously" with no explicit factory reset?

samulimaa commented 10 months ago

No problem.

No, strange, it doesn't seem to be widely reported issue.

orestesgaolin commented 9 months ago

Hey there, I noticed you added new ability to do the factory reset remotely in 5.4.0. Is it necessary to pair with the device first to perform the factory reset? We were wondering if this might be possible workaround for pairing/connection issues that we're experiencing sometimes, but if we cannot connect to the device in the first place (even via Polar Flow), then this will kot work anyway, right?

samulimaa commented 9 months ago

Hey, it's unfortunately not possible to do factory reset if device is not connected.