Issues enumerating Descriptors with a device with lots of characteristics.

[txf-]

• bleak version:
  0.10.0
• Python version:
  3.7.3 (raspbian), 3.8 (Windows 10).
• Operating System:
  Windows 10 and Rasbian Buster
• BlueZ version (bluetoothctl -v) in case of Linux:
  5.50

Description

I am having issues enumerating services and characteristics using bleak connecting to an ESP32, it has no issues when there is a small number of services and characteristics but when there are more, it doesn't enumerate correctly on a Raspberry Pi and it crashes on windows.

The issue seems to primarily concern Descriptors. Using an Android phone with nRF Connect, everything seems to enumerate correctly.

What I Did

Using service_explorer.py as a base I tried to enumerate everything from services to descriptors.

So on a raspberry pi I get this:

Executing <Task pending coro=<run() running at get_services.py:25> wait_for=<Future pending cb=[Deferred.asFuture.<locals>.checkCancel() at /usr/local/lib/python3.7/dist-packages/twisted/internet/defer.py:786, <TaskWakeupMethWrapper object at 0x75a27db0>()] created at /usr/lib/python3.7/asyncio/base_events.py:396> cb=[_run_until_complete_cb() at /usr/lib/python3.7/asyncio/base_events.py:158] created at /usr/lib/python3.7/asyncio/base_events.py:563> took 0.122 seconds
Connected: True

[Service] 6e400001-b5a3-f393-e0a9-e50e24dcca9e: Nordic UART Service
        [Characteristic] 6e400002-b5a3-f393-e0a9-e50e24dcca9e: (Handle: 83) (write) | Name: Nordic UART RX, Value: None
        [Characteristic] 6e400003-b5a3-f393-e0a9-e50e24dcca9e: (Handle: 81) (notify) | Name: Nordic UART TX, Value: None
[Service] c8659210-af91-4ad3-a995-a58d6fd26145: Unknown
        [Characteristic] c8659211-af91-4ad3-a995-a58d6fd26145: (Handle: 63) (write,notify) | Name: Unknown, Value: None
        [Characteristic] c8659212-af91-4ad3-a995-a58d6fd26145: (Handle: 61) (read) | Name: Unknown, Value: b'\x02\x04\x00\x01\x00'
[Service] 11111111-1fb5-459e-8fcc-c5c9c331914b: Unknown
        [Characteristic] 11111111-36e1-4688-b7f5-ea07361b26a8: (Handle: 56) (read) | Name: Unknown, Value: b'fcf5c47ffa96\x00f10e261b556d735b902c049716307df356fdddcd\x00'
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 58) | Value: b'\x00\x00'
        [Characteristic] 44444444-36e1-4688-b7f5-ea07361b26a8: (Handle: 53) (read,notify) | Name: Unknown, Value: b''
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 55) | Value: b'\x00\x00'
        [Characteristic] 88888888-36e1-4688-b7f5-ea07361b26a8: (Handle: 50) (read,notify) | Name: Unknown, Value: b'\x01\x00\x00\x00\xe8\x03\x00\x0033\x82B3\x13zD\xcd\x0c\xfaD\x00\x88;E\x9a\tzE\x9a\x85\xbbEf\xc6\xdaE?x'
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 52) | Value: b'\x00\x00'
        [Characteristic] 99999999-36e1-4688-b7f5-ea07361b26a8: (Handle: 47) (read,write,notify) | Name: Unknown, Value: b''
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 49) | Value: b'\x00\x00'
        [Characteristic] 77777777-36e1-4688-b7f5-ea07361b26a8: (Handle: 44) (read,write,notify) | Name: Unknown, Value: b''
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 46) | Value: b'\x00\x00'
        [Characteristic] 55555555-36e1-4688-b7f5-ea07361b26a8: (Handle: 41) (read,write) | Name: Unknown, Value: b'\x00\x00\x00\x00'
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 43) | Value: b'\x00\x00'
[Service] 00001801-0000-1000-8000-00805f9b34fb: Generic Attribute Profile
        [Characteristic] 00002a05-0000-1000-8000-00805f9b34fb: (Handle: 2) (indicate) | Name: Service Changed, Value: None
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 4) | Value: b'\x02\x00'

Nordic UART TX characteristic should have a 0x2902 (00002902-0000-1000-8000-00805f9b34fb) descriptor as should c8659211-af91-4ad3-a995-a58d6fd26145.

On windows the .net service crashes when attempting the same (oddly with a different order of services):

 python .\get_services.py

Connected: True
[Service] 00001801-0000-1000-8000-00805f9b34fb: Generic Attribute Profile
        [Characteristic] 00002a05-0000-1000-8000-00805f9b34fb: (Handle: 2) (indicate) | Name: Service Changed, Value: None 
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 4) | Value: b'\x00\x00' 
[Service] 00001800-0000-1000-8000-00805f9b34fb: Generic Access Profile
        [Characteristic] 00002a00-0000-1000-8000-00805f9b34fb: (Handle: 21) (read) | Name: Device Name, Value: b'Device-FA96' 
        [Characteristic] 00002a01-0000-1000-8000-00805f9b34fb: (Handle: 23) (read) | Name: Appearance, Value: b'\x00\x00' 
        [Characteristic] 00002aa6-0000-1000-8000-00805f9b34fb: (Handle: 25) (read) | Name: Central Address Resolution, Value: b'\x00' 
[Service] 11111111-1fb5-459e-8fcc-c5c9c331914b: Unknown
        [Characteristic] 55555555-36e1-4688-b7f5-ea07361b26a8: (Handle: 41) (read,write) | Name: Unknown, Value: b'\x00\x00\x00\x00' 
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 43) | Value: b'\x00\x00' 
        [Characteristic] 77777777-36e1-4688-b7f5-ea07361b26a8: (Handle: 44) (read,write,notify) | Name: Unknown, Value: b'' 
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 46) | Value: b'\x00\x00' 
        [Characteristic] 99999999-36e1-4688-b7f5-ea07361b26a8: (Handle: 47) (read,write,notify) | Name: Unknown, Value: b'' 
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 49) | Value: b'\x00\x00' 
        [Characteristic] 88888888-36e1-4688-b7f5-ea07361b26a8: (Handle: 50) (read,notify) | Name: Unknown, Value: b'\x01\x00\x00\x00\xe8\x03\x00\x0033\x82B3\x13zD\xcd\x0c\xfaD\x00\x88;E\x9a\tzE\x9a\x85\xbbEf\xc6\xdaE?x'
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 52) | Value: b'\x00\x00' 
        [Characteristic] 44444444-36e1-4688-b7f5-ea07361b26a8: (Handle: 53) (read,notify) | Name: Unknown, Value: b'' 
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 55) | Value: b'\x00\x00' 
        [Characteristic] 11111111-36e1-4688-b7f5-ea07361b26a8: (Handle: 56) (read) | Name: Unknown, Value: b'fcf5c47ffa96\x00f10e261b556d735b902c049716307df356fdddcd\x00' 
                [Descriptor] 00002902-0000-1000-8000-00805f9b34fb: (Handle: 58) | Value: b'\x00\x00' 
[Service] c8659210-af91-4ad3-a995-a58d6fd26145: Unknown
        [Characteristic] c8659212-af91-4ad3-a995-a58d6fd26145: (Handle: 61) (read) | Name: Unknown, Value: b'\x02\x04\x00\x01\x00' 
        [Characteristic] c8659211-af91-4ad3-a995-a58d6fd26145: (Handle: 63) (write,notify) | Name: Unknown, Value: None 
[Service] 6e400001-b5a3-f393-e0a9-e50e24dcca9e: Nordic UART Service
        [Characteristic] 6e400003-b5a3-f393-e0a9-e50e24dcca9e: (Handle: 66) (notify) | Name: Nordic UART TX, Value: None 
Executing <Handle <TaskWakeupMethWrapper object at 0x00000179DE6BA8B0>(<Future finis...events.py:418>) created at C:\Python38\lib\asyncio\locks.py:288> took 0.140 seconds
Traceback (most recent call last):
  File ".\get_services.py", line 62, in <module>
    loop.run_until_complete(run(mac_addr, True))
  File "C:\Python38\lib\asyncio\base_events.py", line 608, in run_until_complete
    return future.result()
  File ".\get_services.py", line 49, in run
    value = await client.read_gatt_descriptor(descriptor.handle)
  File "C:\Python38\lib\site-packages\bleak\backends\dotnet\client.py", line 620, in read_gatt_descriptor
    raise BleakDotNetTaskError(
bleak.exc.BleakDotNetTaskError: Could not get GATT characteristics for 00002902-0000-1000-8000-00805f9b34fb: ProtocolError (Error: 0x01: Unknown HCI Command)

Notably when Isolating when isolating the problem services/chars on the esp32 firmware, yields a correct enumeration.

[dlech]

I would first suspect that the error message is correct and there is some sort of protocol error on the part of the ESP32. I would inspect the Bluetooth traffic with Wireshark to see what is really going on. https://bleak.readthedocs.io/en/latest/troubleshooting.html#capture-bluetooth-traffic

[txf-]

Actually it turned out that for some reason it was attempting to get cached data. I was under the impression that by default that this was off. Making a new bond the device from windows settings seems to have fixed it.

[dlech]

I think there was some work on caching on windows recently, but I don't think it has been released yet.

[hbldh]

No, it hasn't been released yet, but it is available on the develop branch (See #431 and documentation for the Windows client and the new use_cached keywords is here).