Kotlin-BLE-Library icon indicating copy to clipboard operation
Kotlin-BLE-Library copied to clipboard

Published 20 hours ago • verified publisher icon NordicSemiconductor

Notification channel left open after disconnecting device

Open jpd236 opened this issue 1 year ago • 0 comments

Testing with 1.0.10. The following snippet scans, connects to, and monitors notifications for a couple of services on a fitness watch:

val job = launch {
  val device = scanner.scan(
              filters = listOf(
                  BleScanFilter(serviceUuid = FilteredServiceUuid(ParcelUuid(HR_SERVICE_UUID))),
              ),
              settings = BleScannerSettings(
                  includeStoredBondedDevices = false,
              )
          ).first().device
  val watch = ClientBleGatt.Companion.connect(applicationContext, device, lifecycleScope)
  val services = watch!!.discoverServices()
  val hrService = services.findService(HR_SERVICE_UUID)!!
  val hrCharacteristic = hrService.findCharacteristic(HR_CHARACTERISTIC_UUID)!!
  launch {
      hrCharacteristic.getNotifications().collect {
          // act on data
      }
  }
  val rscService = services.findService(RSC_SERVICE_UUID)!!
  val rscCharacteristic = rscService.findCharacteristic(RSC_CHARACTERISTIC_UUID)!!
  launch {
      rscCharacteristic.getNotifications().collect {
          // act on data
      }
    }
  }
}

Later on, I call job.cancelAndJoin() , watch.disconnect(), and watch.close() to stop monitoring.

I am reliably observing that only the first notification observer of the two above is getting canceled. While the app stops getting events, the second observer remains connected - the watch still shows that it is connected for those fields (but not the other), and if I open the nRF Connect app and reconnect to the device and click the corresponding service, the property shows up as being actively monitored already.

If I reverse the two snippets (RSC before Heart Rate), the opposite happens - RSC is closed but HR is not.

Here's a snippet of logcat. I can see logs that seem to indicate that notifications are disabled on both characteristics, but evidently they're not actually being disabled properly for one of them.

2023-11-18 10:22:23.652 31489-31489 BluetoothAdapter	D  isLeEnabled(): ON
2023-11-18 10:22:23.656 31489-31504 BluetoothLeScanner	D  onScannerRegistered() - status=0 scannerId=6 mScannerId=0
2023-11-18 10:22:26.935 31489-31614 ProfileInstaller	D  Installing profile for <redacted>
2023-11-18 10:22:28.713 31489-31489 BluetoothAdapter	D  isLeEnabled(): ON
2023-11-18 10:22:28.764 31489-31489 BLEK-LOG	I  Connecting to <redacted>:70:14
2023-11-18 10:22:28.799 31489-31489 BluetoothGatt	D  connect() - device: XX:XX:XX:XX:70:14, auto: false
2023-11-18 10:22:28.799 31489-31489 BluetoothGatt	D  registerApp()
2023-11-18 10:22:28.801 31489-31489 BluetoothGatt	D  registerApp() - UUID=69612120-cf25-457b-856d-49b23638194d
2023-11-18 10:22:28.806 31489-31504 BluetoothGatt	D  onClientRegistered() - status=0 clientIf=15
2023-11-18 10:22:28.817 31489-31504 BluetoothGatt	D  onClientConnectionState() - status=0 clientIf=15 device=<redacted>:70:14
2023-11-18 10:22:28.819 31489-31599 BLEK-LOG	V  On gatt event: ConnectionStateChanged(status=SUCCESS, newState=STATE_CONNECTED)
2023-11-18 10:22:28.819 31489-31599 BLEK-LOG	D  On connection state changed: STATE_CONNECTED, status: SUCCESS
2023-11-18 10:22:28.819 31489-31599 BLEK-LOG	I  Device connected
2023-11-18 10:22:28.821 31489-31489 BluetoothGatt	D  discoverServices() - device: XX:XX:XX:XX:70:14
2023-11-18 10:22:28.834 31489-31504 BluetoothGatt	D  onSearchComplete() = Device=<redacted>:70:14 Status=0
2023-11-18 10:22:28.871 31489-31599 BLEK-LOG	V  On gatt event: ServicesDiscovered(services=[{ uuid: 00001800-0000-1000-8000-00805f9b34fb, type: 0, characteristics: [ { uuid : 00002a00-0000-1000-8000-00805f9b34fb, instanceId : 3, permissions : 0, properties : 2, writeType : 2, value : (0x) , descriptors : [] },  { uuid : 00002a01-0000-1000-8000-00805f9b34fb, instanceId : 5, permissions : 0, properties : 2, writeType : 2, value : (0x) , descriptors : [] },  { uuid : 00002a04-0000-1000-8000-00805f9b34fb, instanceId : 7, permissions : 0, properties : 2, writeType : 2, value : (0x) , descriptors : [] },  { uuid : 00002aa6-0000-1000-8000-00805f9b34fb, instanceId : 9, permissions : 0, properties : 2, writeType : 2, value : (0x) , descriptors : [] }] }, { uuid: 00001801-0000-1000-8000-00805f9b34fb, type: 0, characteristics: [ { uuid : 00002a05-0000-1000-8000-00805f9b34fb, instanceId : 12, permissions : 0, properties : 32, writeType : 2, value : (0x) , descriptors : [{ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }] }] }, { uuid: 6a4e8022-667b-11e3-949a-0800200c9a66, type: 0, characteristics: [ { uuid : 6a4e4c80-667b-11e3-949a-0800200c9a66, instanceId : 16, permissions : 0, properties : 4, writeType : 1, value : (0x) , descriptors : [] },  { uuid : 6a4ecd28-667b-11e3-949a-0800200c9a66, instanceId : 18, permissions : 0, properties : 18, writeType : 2, value : (0x) , descriptors : [{ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }] }] }, { uuid: 6a4e2800-667b-11e3-949a-0800200c9a66, type: 0, characteristics: [ { uuid : 6a4e2803-667b-11e3-949a-0800200c9a66, instanceId : 22, permissions : 0, properties : 14, writeType : 1, value : (0x) , descriptors : [] },  { uuid : 6a4e2810-667b-11e3-949a-0800200c9a66, instanceId : 24, permissions : 0, properties : 30, writeType : 1, value : (0x) , descriptors : [{ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }] },  { uuid : 6a4e2820-667b-11e3-949a-0800200c9a66, instanceId : 27, permissions : 0, properties : 12, writeType : 1, value : (0x) , descriptors : [] },  { uuid : 6a4e2811-667b-11e3-949a-0800200c9a66, instanceId : 29, permissions : 0, properties : 30, writeType : 1, value : (0x) , descriptors : [{ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }] },  { uuid : 6a4e2821-667b-11e3-949a-0800200c9a66, instanceId : 32, permissions : 0, properties : 12, writeType : 1, value : (0x) , descriptors : [] },  { uuid : 6a4e2812-667b-11e3-949a-0800200c9a66, instanceId : 34, permissions : 0, properties : 30, writeType : 1, value : (0x) , descriptors : [{ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }] },  { uuid : 6a4e2822-667b-11e3-949a-0800200c9a66, instanceId : 37, permissions : 0, properties : 12, writeType : 1, value : (0x) , descriptors : [] }] }, { uuid: 0000180d-0000-1000-8000-00805f9b34fb, type: 0, characteristics: [ { uuid : 00002a37-0000-1000-8000-00805f9b34fb, instanceId : 40, permissions : 0, properties : 16, writeType : 2, value : (0x) , descriptors : [{ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }] }] }, { uuid: 00001814-0000-1000-8000-00805f9b34fb, type: 0, characteristics: [ { uuid : 00002a54-0000-1000-8000-00805f9b34fb, instanceId : 44, permissions : 0, properties : 2, writeType : 2, value : (0x) , descriptors : [] },  { uuid : 00002a53-0000-1000-8000-00805f9b34fb, instanceId : 46, permissions : 0, properties : 16, writeType : 2, value : (0x) , descriptors : [{ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }] }] }], status=GATT_SUCCESS)
2023-11-18 10:22:28.871 31489-31599 BLEK-LOG	I  Services discovered
2023-11-18 10:22:28.874 31489-31599 BLEK-LOG	D  Discovered services: [00001800-0000-1000-8000-00805f9b34fb, 00001801-0000-1000-8000-00805f9b34fb, 6a4e8022-667b-11e3-949a-0800200c9a66, 6a4e2800-667b-11e3-949a-0800200c9a66, 0000180d-0000-1000-8000-00805f9b34fb, 00001814-0000-1000-8000-00805f9b34fb], status: GATT_SUCCESS
2023-11-18 10:22:28.890 31489-31489 BLEK-LOG	D  Enable notifications on characteristic - start, uuid: 00002a37-0000-1000-8000-00805f9b34fb
2023-11-18 10:22:28.892 31489-31489 BluetoothGatt	D  setCharacteristicNotification() - uuid: 00002a37-0000-1000-8000-00805f9b34fb enable: true
2023-11-18 10:22:28.905 31489-31489 BLEK-LOG	D  Write to descriptor - start, uuid: 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01:00
2023-11-18 10:22:28.915 31489-31489 BLEK-LOG	D  Enable notifications on characteristic - start, uuid: 00002a53-0000-1000-8000-00805f9b34fb
2023-11-18 10:22:28.915 31489-31489 BluetoothGatt	D  setCharacteristicNotification() - uuid: 00002a53-0000-1000-8000-00805f9b34fb enable: true
2023-11-18 10:22:29.350 31489-31599 BLEK-LOG	V  On gatt event: DescriptorWrite(descriptor={ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }, status=GATT_SUCCESS)
2023-11-18 10:22:29.351 31489-31489 BLEK-LOG	D  Write to descriptor - start, uuid: 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01:00
2023-11-18 10:22:29.351 31489-31599 BLEK-LOG	D  Write to descriptor - end, uuid: 00002902-0000-1000-8000-00805f9b34fb, value: GATT_SUCCESS
2023-11-18 10:22:29.354 31489-31489 BLEK-LOG	I  Notifications enabled: 00002a37-0000-1000-8000-00805f9b34fb
2023-11-18 10:22:29.717 31489-31599 BLEK-LOG	V  On gatt event: DescriptorWrite(descriptor={ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }, status=GATT_SUCCESS)
2023-11-18 10:22:29.718 31489-31599 BLEK-LOG	D  Write to descriptor - end, uuid: 00002902-0000-1000-8000-00805f9b34fb, value: GATT_SUCCESS
2023-11-18 10:22:29.720 31489-31489 BLEK-LOG	I  Notifications enabled: 00002a53-0000-1000-8000-00805f9b34fb
2023-11-18 10:22:39.102 31489-31599 BLEK-LOG	V  On gatt event: CharacteristicChanged(characteristic= { uuid : 00002a53-0000-1000-8000-00805f9b34fb, instanceId : 46, permissions : 0, properties : 16, writeType : 2, value : (0x) 00:00:00:00, descriptors : [{ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }] }, value=(0x) 00:00:00:00)
2023-11-18 10:22:39.110 31489-31489 BLEK-LOG	V  On notification received: (0x) 00:00:00:00
2023-11-18 10:22:39.264 31489-31599 BLEK-LOG	V  On gatt event: CharacteristicChanged(characteristic= { uuid : 00002a37-0000-1000-8000-00805f9b34fb, instanceId : 40, permissions : 0, properties : 16, writeType : 2, value : (0x) 06:3E, descriptors : [{ uuid : 00002902-0000-1000-8000-00805f9b34fb, permissions : 0, value : (0x) , }] }, value=(0x) 06:3E)
2023-11-18 10:22:39.269 31489-31489 BLEK-LOG	V  On notification received: (0x) 06:3E
... (more events)
2023-11-18 10:22:39.445 31489-31489 BLEK-LOG	D  Disable notifications on characteristic - start, uuid: 00002a37-0000-1000-8000-00805f9b34fb
2023-11-18 10:22:39.445 31489-31489 BluetoothGatt	D  setCharacteristicNotification() - uuid: 00002a37-0000-1000-8000-00805f9b34fb enable: false
2023-11-18 10:22:39.450 31489-31489 BLEK-LOG	D  Write to descriptor - start, uuid: 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 00:00
2023-11-18 10:22:39.457 31489-31489 BLEK-LOG	D  Disable notifications on characteristic - start, uuid: 00002a53-0000-1000-8000-00805f9b34fb
2023-11-18 10:22:39.457 31489-31489 BluetoothGatt	D  setCharacteristicNotification() - uuid: 00002a53-0000-1000-8000-00805f9b34fb enable: false
2023-11-18 10:22:39.462 31489-31599 BLEK-LOG	I  Disconnecting...
2023-11-18 10:22:39.462 31489-31599 BluetoothGatt	D  cancelOpen() - device: XX:XX:XX:XX:70:14
2023-11-18 10:22:39.464 31489-31599 BluetoothGatt	D  close()
2023-11-18 10:22:39.464 31489-31599 BluetoothGatt	D  unregisterApp() - mClientIf=15
2023-11-18 10:22:39.464 31489-31504 BluetoothGatt	D  onClientConnectionState() - status=0 clientIf=15 device=<redacted>:70:14

jpd236 avatar Nov 18 '23 18:11 jpd236