search

hbldh / bleak

A cross platform Bluetooth Low Energy Client for Python using asyncio
MIT License
1.8k stars 297 forks source link

WinRT backend should allow ADV_IND without SCAN_RESP #1211

Closed dlech closed 1 year ago

dlech commented 1 year ago

Discussed in https://github.com/hbldh/bleak/discussions/1210

Originally posted by **zapta** January 30, 2023 * bleak version: 0.19.5 * Python version: Python 3.10.7 * Operating System: Windows 10 * BlueZ version (`bluetoothctl -v`) in case of Linux: ### Description I have a BLE device which sends adv packets but for some reason doesn't send scan response packets and am resolving it with the vendor https://github.com/espressif/esp-idf/issues/10660 . My question here is regarding Bleak. If I use the Nordic nRF Connect app on my phone, I see the device in the scan list and can connect to it with no problem even though the device didn't respond to SCAN_REQ (verified with wireshark). However, when I use a python program with Bleak, it doesn't show in the Bleak scan list and if I try to connect directly by specifying the address it Bleak still doesn't connect. Is there a way to tell Bleak to not require a SCAN_RESP packet and list and connect to the device regardless? ### What I Did I ran a python script with a bleak scanner and captured the traffic with wireshark and a Nordic dongle. The computer with the Bleak scanner did sends a SCAN_REQ, but didn't get back a SCAN_RESP and ignored the device. The wireshark packet file and screen shot are included below. ### Logs C:\projects\esp32\repo\release\windows>set BLEAK_LOGGING=1 C:\projects\esp32\repo\release\windows>analyzer.exe --scan OS: Windows-10-10.0.19044-SP0 Platform:: uname_result(system='Windows', node='Ryzen', release='10', version='10.0.19044', machine='AMD64') Python 3.10.7 (tags/v3.10.7:6cc6b13, Sep 5 2022, 14:08:36) [MSC v.1933 64 bit (AMD64)] Scanning 5 secs for advertising BLE devices ... 2023-01-30 19:33:32,751 bleak.backends.winrt.scanner DEBUG: Received 30:E2:83:7C:F3:11: . 2023-01-30 19:33:32,752 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:32,752 bleak.backends.winrt.scanner DEBUG: Received 3A:35:F1:22:AE:BD: . 2023-01-30 19:33:32,849 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:32,849 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:32,983 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:32,984 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:33,568 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:33,569 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:33,797 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:33,797 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:33,799 bleak.backends.winrt.scanner DEBUG: Received 3A:35:F1:22:AE:BD: . 2023-01-30 19:33:34,394 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:34,395 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:34,516 bleak.backends.winrt.scanner DEBUG: Received 3A:35:F1:22:AE:BD: . 2023-01-30 19:33:34,624 bleak.backends.winrt.scanner DEBUG: Received 3A:35:F1:22:AE:BD: . 2023-01-30 19:33:34,887 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:34,887 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:34,984 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:34,985 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:35,568 bleak.backends.winrt.scanner DEBUG: Received 3A:35:F1:22:AE:BD: . 2023-01-30 19:33:35,573 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:35,573 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:36,162 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:36,163 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:36,514 bleak.backends.winrt.scanner DEBUG: Received 3A:35:F1:22:AE:BD: . 2023-01-30 19:33:36,527 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:36,527 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:36,750 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:36,751 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:37,111 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: ESP_GATTS_DEMO. 2023-01-30 19:33:37,112 bleak.backends.winrt.scanner DEBUG: skipping callback, waiting for scan response 2023-01-30 19:33:37,317 bleak.backends.winrt.scanner DEBUG: 1 devices found. Watcher status: 3. 1 device address: 3A:35:F1:22:AE:BD () Scanning done. C:\projects\esp32\repo\release\windows> ### Attachments ![2023-01-30_18-44-26](https://user-images.githubusercontent.com/2184769/215651452-4b1f3524-f2e0-4b61-bd22-4f853207bd02.jpg) [bleak_scan.zip](https://github.com/hbldh/bleak/files/10542243/bleak_scan.zip)
dlech commented 1 year ago

Sorry for the noise, I prematurely converted this to a discussion and there is no undo for that.

I did some digging into the Bluetooth spec and it looks like ADV_IND without SCAN_RSP should be allowed so we need to fix that.

dlech commented 1 year ago

https://github.com/hbldh/bleak/blob/648dc2e672dfc4369e438d8f13adde19712a48a9/bleak/backends/winrt/scanner.py#L130-L140

We could either remove this check entirely or only skip the first receive packet instead of all.

zapta commented 1 year ago

I changed the conditions to 

        #if (raw_data.adv is None or raw_data.scan is None) and (
        if (raw_data.adv is None) and (
            event_args.advertisement_type
            in [
                BluetoothLEAdvertisementType.CONNECTABLE_UNDIRECTED,
                BluetoothLEAdvertisementType.SCANNABLE_UNDIRECTED,
                BluetoothLEAdvertisementType.SCAN_RESPONSE,
            ]
        ):
            logger.debug("skipping callback, waiting for scan response")
            return

And now the scanning works (good):

/c/projects/esp32/repo/analyzer/src$ ./analyzer.py --scan
OS: Windows-10-10.0.19044-SP0
Platform:: uname_result(system='Windows', node='Ryzen', release='10', version='10.0.19044', machine='AMD64')
Python 3.10.7 (tags/v3.10.7:6cc6b13, Sep  5 2022, 14:08:36) [MSC v.1933 64 bit (AMD64)]
Scanning 5 secs for advertising BLE devices ...

1 device address: 24:D7:EB:15:27:8E  (STP-24D7EB15278E)
2 device address: 2F:EB:75:37:1F:CE  ()
3 device address: 30:E2:83:7C:F3:11  ()

Scanning done.

But still can't connect by address:

/c/projects/esp32/repo/analyzer/src$ ./analyzer.py -d 24:D7:EB:15:27:8E
OS: Windows-10-10.0.19044-SP0
Platform:: uname_result(system='Windows', node='Ryzen', release='10', version='10.0.19044', machine='AMD64')
Python 3.10.7 (tags/v3.10.7:6cc6b13, Sep  5 2022, 14:08:36) [MSC v.1933 64 bit (AMD64)]
User specified device: [24:D7:EB:15:27:8E]
Device address: [24:D7:EB:15:27:8E]
Units: steps
Steps per unit: 1.0
Trying to connect to device [24:D7:EB:15:27:8E]...
INFO:probe:Found device: [24:D7:EB:15:27:8E]
Traceback (most recent call last):
  File "C:\projects\esp32\repo\analyzer\src\analyzer.py", line 214, in <module>
    probe = main_event_loop.run_until_complete(connect_to_probe())
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\asyncio\base_events.py", line 646, in run_until_complete
    return future.result()
  File "C:\projects\esp32\repo\analyzer\src\analyzer.py", line 200, in connect_to_probe
    if not await probe.connect():
  File "C:\projects\esp32\repo\analyzer\src\probe.py", line 105, in connect
    await self.__client.connect(timeout=timeout)
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\site-packages\bleak\__init__.py", line 471, in connect
    return await self._backend.connect(**kwargs)
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\site-packages\bleak\backends\winrt\client.py", line 413, in connect
    self.services = get_services_task.result()
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\site-packages\bleak\backends\winrt\client.py", line 643, in get_services
    services: Sequence[GattDeviceService] = _ensure_success(
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\site-packages\bleak\backends\winrt\client.py", line 120, in _ensure_success
    raise BleakError(f"{fail_msg}: Unreachable")
bleak.exc.BleakError: Could not get GATT services: Unreachable

If you need additional information please let me know.

dlech commented 1 year ago

For OS errors we need OS logs, e.g. wireshark packet capture.

zapta commented 1 year ago

Below are a screenshot, debug log snapshot, and a zipped wireshark file with the connection attempt using the the patched bleak.

image

C:\projects\esp32\repo\analyzer\src>set BLEAK_LOGGING=1

C:\projects\esp32\repo\analyzer\src>python analyzer.py -d 24:D7:EB:15:27:8E
OS: Windows-10-10.0.19044-SP0
Platform:: uname_result(system='Windows', node='Ryzen', release='10', version='10.0.19044', machine='AMD64')
Python 3.10.7 (tags/v3.10.7:6cc6b13, Sep  5 2022, 14:08:36) [MSC v.1933 64 bit (AMD64)]
User specified device: [24:D7:EB:15:27:8E]
Device address: [24:D7:EB:15:27:8E]
Units: steps
Steps per unit: 1.0
Trying to connect to device [24:D7:EB:15:27:8E]...
2023-01-31 17:48:53,573 bleak.backends.winrt.scanner DEBUG: Received 20:29:16:37:88:37: .
DEBUG:bleak.backends.winrt.scanner:Received 20:29:16:37:88:37: .
2023-01-31 17:48:53,705 bleak.backends.winrt.scanner DEBUG: Received 24:D7:EB:15:27:8E: STP-24D7EB15278E.
DEBUG:bleak.backends.winrt.scanner:Received 24:D7:EB:15:27:8E: STP-24D7EB15278E.
2023-01-31 17:48:53,708 bleak.backends.winrt.scanner DEBUG: 2 devices found. Watcher status: 3.
DEBUG:bleak.backends.winrt.scanner:2 devices found. Watcher status: 3.
INFO:probe:Found device: [24:D7:EB:15:27:8E]
2023-01-31 17:48:53,716 bleak.backends.winrt.client DEBUG: Connecting to BLE device @ 24:D7:EB:15:27:8E
DEBUG:bleak.backends.winrt.client:Connecting to BLE device @ 24:D7:EB:15:27:8E
2023-01-31 17:48:53,752 bleak.backends.winrt.client DEBUG: getting services (service_cache_mode=None, cache_mode=None)...
DEBUG:bleak.backends.winrt.client:getting services (service_cache_mode=None, cache_mode=None)...
2023-01-31 17:48:53,986 bleak.backends.winrt.client DEBUG: session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3C70>, error: BluetoothError.SUCCESS, status: GattSessionStatus.ACTIVE
DEBUG:bleak.backends.winrt.client:session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3C70>, error: BluetoothError.SUCCESS, status: GattSessionStatus.ACTIVE
2023-01-31 17:48:54,153 bleak.backends.winrt.client DEBUG: session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3C90>, error: BluetoothError.SUCCESS, status: GattSessionStatus.CLOSED
DEBUG:bleak.backends.winrt.client:session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3C90>, error: BluetoothError.SUCCESS, status: GattSessionStatus.CLOSED
2023-01-31 17:48:54,155 bleak.backends.winrt.client DEBUG: closing requester
DEBUG:bleak.backends.winrt.client:closing requester
2023-01-31 17:48:54,714 bleak.backends.winrt.client DEBUG: session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3910>, error: BluetoothError.SUCCESS, status: GattSessionStatus.CLOSED
DEBUG:bleak.backends.winrt.client:session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3910>, error: BluetoothError.SUCCESS, status: GattSessionStatus.CLOSED
2023-01-31 17:48:54,714 bleak.backends.winrt.client DEBUG: session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3DF0>, error: BluetoothError.SUCCESS, status: GattSessionStatus.ACTIVE
DEBUG:bleak.backends.winrt.client:session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3DF0>, error: BluetoothError.SUCCESS, status: GattSessionStatus.ACTIVE
2023-01-31 17:48:54,714 bleak.backends.winrt.client DEBUG: session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3F50>, error: BluetoothError.SUCCESS, status: GattSessionStatus.CLOSED
DEBUG:bleak.backends.winrt.client:session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B5A3F50>, error: BluetoothError.SUCCESS, status: GattSessionStatus.CLOSED
2023-01-31 17:48:54,714 bleak.backends.winrt.client DEBUG: closing session
DEBUG:bleak.backends.winrt.client:closing session
2023-01-31 17:48:54,714 bleak.backends.winrt.client DEBUG: session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B65C1D0>, error: BluetoothError.SUCCESS, status: GattSessionStatus.ACTIVE
DEBUG:bleak.backends.winrt.client:session_status_changed_event_handler: id: <_bleak_winrt_Windows_Devices_Bluetooth.BluetoothDeviceId object at 0x000001C72B65C1D0>, error: BluetoothError.SUCCESS, status: GattSessionStatus.ACTIVE
Traceback (most recent call last):
  File "C:\projects\esp32\repo\analyzer\src\analyzer.py", line 214, in <module>
    probe = main_event_loop.run_until_complete(connect_to_probe())
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\asyncio\base_events.py", line 646, in run_until_complete
    return future.result()
  File "C:\projects\esp32\repo\analyzer\src\analyzer.py", line 200, in connect_to_probe
    if not await probe.connect():
  File "C:\projects\esp32\repo\analyzer\src\probe.py", line 105, in connect
    await self.__client.connect(timeout=timeout)
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\site-packages\bleak\__init__.py", line 471, in connect
    return await self._backend.connect(**kwargs)
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\site-packages\bleak\backends\winrt\client.py", line 413, in connect
    self.services = get_services_task.result()
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\site-packages\bleak\backends\winrt\client.py", line 643, in get_services
    services: Sequence[GattDeviceService] = _ensure_success(
  File "C:\Users\user\AppData\Local\Programs\Python\Python310\lib\site-packages\bleak\backends\winrt\client.py", line 120, in _ensure_success
    raise BleakError(f"{fail_msg}: Unreachable")
bleak.exc.BleakError: Could not get GATT services: Unreachable

C:\projects\esp32\repo\analyzer\src>

wrieshark_bleak_patch_connect.zip

dlech commented 1 year ago

Windows is never initiating the connection (we should CONNECT_REQ in the logs). I would suggest playing around with Windows-specific service caching options or try a different Bluetooth adapter.

It would be helpful if you could share the adapter info as well in case this turns out to be one of the many problematic adapters on Windows. Run the following in PowerShell:

wget https://github.com/Microsoft/busiotools/raw/master/bluetooth/tracing/GetBluetoothRadioInfo.ps1 -UseBasicParsing | iex
zapta commented 1 year ago 
PS C:\WINDOWS\system32> wget https://github.com/Microsoft/busiotools/raw/master/bluetooth/tracing/GetBluetoothRadioInfo.ps1 -UseBasicParsing | iex                                                                                              

InstanceId        : USB\VID_8087&PID_0029\6&195F3125&0&2
MAC               : DC41A9D9332E
DriverDescription : Intel(R) Wireless Bluetooth(R)
DriverVersion     : 21.50.1.1
ErrorRecovery     : None
ScoType           : Unknown

InstanceId        : USB\VID_8087&PID_0A2A\6&195F3125&0&2
MAC               : 70CF499EC392
DriverDescription : Intel(R) Wireless Bluetooth(R)
DriverVersion     : 20.100.10.7
ErrorRecovery     : None
ScoType           : Unknown
zapta commented 1 year ago

@dlech, anything that can be done regarding the connection part? I tried to debug it but got into calls to code with no python source code.

If it's OK, I can mail you a couple of devices that don't respond to SCAN REQ.

dlech commented 1 year ago

The connecting issue is most likely due to the Bluetooth chip/driver.

Happy to try it locally if you want to send me something. You can find my email in my github profile.

zapta commented 1 year ago

Thanks @dlech, I ordered new identical boards and they don't reproduce the issue. I will try to identify the differences (efuses?) and then mail you the one that doesn't respond to SPAN_REQ.