bleak icon indicating copy to clipboard operation
bleak copied to clipboard
verified publisher icon hbldh

TimeoutError on connect in Windows

Open maxentric-gnylund opened this issue 1 year ago • 1 comments

  • bleak version: 0.22.3
  • Python version: 3.13.0
  • Operating System: Windows 11 Pro (10.0.26100 N/A Build 26100)

Description

Hello, I am trying to connect to a BLE peripheral (VTM 20F pulse oximeter) using bleak. My script works on MacOS (15.0 Build 24A335), but on Windows I get a TimeoutError. Note that I am able to connect to other BLE peripherals on my Windows setup, but this particular device is not cooperating. I have included debug output for both Windows (not working) and MacOS (working). Let me know if any other information could be helpful.

What I Did

Minimum workable example:

import asyncio

from bleak import BleakClient, BleakScanner


async def main():

    MYPERIPHERAL = "VTM 20F"

    print(f"Scanning for {MYPERIPHERAL}...")

    device = await BleakScanner.find_device_by_name(MYPERIPHERAL)

    if device is None:
        print(f"Could not find {MYPERIPHERAL}")
        return

    print(f"Found device: {device.name} ({device.address})")

    async with BleakClient(device, timeout=30) as client:
        print(f"Connected to {client}!")
        await asyncio.sleep(3)

    print("Disconnected!")


if __name__ == "__main__":
    asyncio.run(main())

Output on Windows:

Traceback (most recent call last):
  File "C:\mybleakapp\.venv\Lib\site-packages\bleak\backends\winrt\client.py", line 487, in connect
    self.services = await self.get_services(
                    ^^^^^^^^^^^^^^^^^^^^^^^^
    ...<2 lines>...
    )
    ^
  File "C:\mybleakapp\.venv\Lib\site-packages\bleak\backends\winrt\client.py", line 720, in get_services
    await FutureLike(self._requester.get_gatt_services_async(*srv_args)),
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\mybleakapp\.venv\Lib\site-packages\bleak\backends\winrt\client.py", line 1129, in __await__
    yield self  # This tells Task to wait for completion.
    ^^^^^^^^^^
  File "C:\mybleakapp\.venv\Lib\site-packages\bleak\backends\winrt\client.py", line 1072, in result
    raise asyncio.CancelledError
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "c:\mybleakapp\mybleakapp.py", line 30, in <module>
    asyncio.run(main())
    ~~~~~~~~~~~^^^^^^^^
  File "C:\Users\myuser\.pyenv\pyenv-win\versions\3.13.0\Lib\asyncio\runners.py", line 194, in run
    return runner.run(main)
           ~~~~~~~~~~^^^^^^
  File "C:\Users\myuser\.pyenv\pyenv-win\versions\3.13.0\Lib\asyncio\runners.py", line 118, in run
    return self._loop.run_until_complete(task)
           ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
  File "C:\Users\myuser\.pyenv\pyenv-win\versions\3.13.0\Lib\asyncio\base_events.py", line 721, in run_until_complete
    return future.result()
           ~~~~~~~~~~~~~^^
  File "c:\mybleakapp\mybleakapp.py", line 22, in main
    async with BleakClient(device) as client:
               ~~~~~~~~~~~^^^^^^^^
  File "C:\mybleakapp\.venv\Lib\site-packages\bleak\__init__.py", line 570, in __aenter__
    await self.connect()
  File "C:\mybleakapp\.venv\Lib\site-packages\bleak\__init__.py", line 615, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\mybleakapp\.venv\Lib\site-packages\bleak\backends\winrt\client.py", line 443, in connect
    async with async_timeout(timeout):
               ~~~~~~~~~~~~~^^^^^^^^^
  File "C:\Users\myuser\.pyenv\pyenv-win\versions\3.13.0\Lib\asyncio\timeouts.py", line 116, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

Logs

Debug log for Windows:

Scanning for VTM 20F...
2024-11-21 18:42:36,708 bleak.backends.winrt.scanner MainThread DEBUG: Received 21:09:03:1E:A3:1B: .
2024-11-21 18:42:36,837 bleak.backends.winrt.scanner MainThread DEBUG: Received BE:FF:20:00:09:A5: ELK-BLEDOM .
2024-11-21 18:42:36,945 bleak.backends.winrt.scanner MainThread DEBUG: Received 41:2D:DB:B5:28:96: .
2024-11-21 18:42:37,079 bleak.backends.winrt.scanner MainThread DEBUG: Received BE:FF:20:00:09:A5: ELK-BLEDOM .
2024-11-21 18:42:37,085 bleak.backends.winrt.scanner MainThread DEBUG: Received C0:4E:30:F2:89:A6: .
2024-11-21 18:42:37,088 bleak.backends.winrt.scanner MainThread DEBUG: Received 69:7C:81:0A:C1:FA: .
2024-11-21 18:42:37,090 bleak.backends.winrt.scanner MainThread DEBUG: Received 69:7C:81:0A:C1:FA: .
2024-11-21 18:42:37,200 bleak.backends.winrt.scanner MainThread DEBUG: Received E0:5A:1B:E1:FB:8E: .
2024-11-21 18:42:37,206 bleak.backends.winrt.scanner MainThread DEBUG: Received E0:5A:1B:E1:FB:8E: 110092_FB8C.
2024-11-21 18:42:37,210 bleak.backends.winrt.scanner MainThread DEBUG: Received 41:2D:DB:B5:28:96: .
2024-11-21 18:42:37,213 bleak.backends.winrt.scanner MainThread DEBUG: Received 41:2D:DB:B5:28:96: .
2024-11-21 18:42:37,217 bleak.backends.winrt.scanner MainThread DEBUG: Received 21:09:03:1E:A3:1B: .
2024-11-21 18:42:37,220 bleak.backends.winrt.scanner MainThread DEBUG: Received 21:09:03:1E:A3:1B: VTM 20F.
2024-11-21 18:42:37,222 bleak.backends.winrt.scanner MainThread DEBUG: 6 devices found. Watcher status: <BluetoothLEAdvertisementWatcherStatus.STOPPED: 3>.
Found device: VTM 20F (21:09:03:1E:A3:1B)
2024-11-21 18:42:37,233 bleak.backends.winrt.client MainThread DEBUG: Connecting to BLE device @ 21:09:03:1E:A3:1B
2024-11-21 18:42:37,272 bleak.backends.winrt.client MainThread DEBUG: getting services (service_cache_mode=None, cache_mode=None)...
2024-11-21 18:42:37,400 bleak.backends.winrt.client Dummy-1 DEBUG: session_status_changed_event_handler: id: BluetoothLE#BluetoothLE04:ed:33:69:45:f0-21:09:03:1e:a3:1b, error: <BluetoothError.SUCCESS: 0>, status: <GattSessionStatus.ACTIVE: 1>
2024-11-21 18:42:37,439 bleak.backends.winrt.client Dummy-2 DEBUG: session_status_changed_event_handler: id: BluetoothLE#BluetoothLE04:ed:33:69:45:f0-21:09:03:1e:a3:1b, error: <BluetoothError.SUCCESS: 0>, status: <GattSessionStatus.CLOSED: 0>
2024-11-21 18:42:37,632 bleak.backends.winrt.client Dummy-3 DEBUG: session_status_changed_event_handler: id: BluetoothLE#BluetoothLE04:ed:33:69:45:f0-21:09:03:1e:a3:1b, error: <BluetoothError.SUCCESS: 0>, status: <GattSessionStatus.ACTIVE: 1>
2024-11-21 18:42:37,648 bleak.backends.winrt.client Dummy-4 DEBUG: max_pdu_size_changed_handler: 131
2024-11-21 18:42:37,724 bleak.backends.winrt.client Dummy-5 DEBUG: 21:09:03:1E:A3:1B: services changed
2024-11-21 18:42:47,280 bleak.backends.winrt.client MainThread DEBUG: closing requester
2024-11-21 18:42:47,283 bleak.backends.winrt.client MainThread DEBUG: closing session

Debug log for MacOS:

Scanning for VTM 20F...
2024-11-21 18:45:46,262 bleak.backends.corebluetooth.CentralManagerDelegate Dummy-1 DEBUG: centralManagerDidUpdateState_
2024-11-21 18:45:46,262 bleak.backends.corebluetooth.CentralManagerDelegate Dummy-1 DEBUG: Bluetooth powered on
2024-11-21 18:45:46,263 bleak.backends.corebluetooth.CentralManagerDelegate MainThread DEBUG: 'isScanning' changed
2024-11-21 18:45:46,307 bleak.backends.corebluetooth.CentralManagerDelegate Dummy-2 DEBUG: centralManager_didDiscoverPeripheral_advertisementData_RSSI_
2024-11-21 18:45:46,308 bleak.backends.corebluetooth.CentralManagerDelegate MainThread DEBUG: Discovered device F27156C9-567F-90F1-4BA2-0DD907CD7593: ELK-BLEDOM  @ RSSI: -75 (kCBAdvData <nsdict_keys(['kCBAdvDataLocalName', 'kCBAdvDataRxPrimaryPHY', 'kCBAdvDataRxSecondaryPHY', 'kCBAdvDataTimestamp', 'kCBAdvDataIsConnectable'])>) and Central: <CBCentralManager: 0x12a827850>
2024-11-21 18:45:46,322 bleak.backends.corebluetooth.CentralManagerDelegate Dummy-3 DEBUG: centralManager_didDiscoverPeripheral_advertisementData_RSSI_
2024-11-21 18:45:46,323 bleak.backends.corebluetooth.CentralManagerDelegate Dummy-4 DEBUG: centralManager_didDiscoverPeripheral_advertisementData_RSSI_
2024-11-21 18:45:46,323 bleak.backends.corebluetooth.CentralManagerDelegate Dummy-5 DEBUG: centralManager_didDiscoverPeripheral_advertisementData_RSSI_
2024-11-21 18:45:46,323 bleak.backends.corebluetooth.CentralManagerDelegate MainThread DEBUG: Discovered device 4C3C2BA1-628A-DA70-6799-7281E654B78A: VTM 20F @ RSSI: -49 (kCBAdvData <nsdict_keys(['kCBAdvDataIsConnectable', 'kCBAdvDataManufacturerData', 'kCBAdvDataServiceUUIDs', 'kCBAdvDataRxSecondaryPHY', 'kCBAdvDataTimestamp', 'kCBAdvDataRxPrimaryPHY'])>) and Central: <CBCentralManager: 0x12a827850>
2024-11-21 18:45:46,324 bleak.backends.corebluetooth.CentralManagerDelegate MainThread DEBUG: Discovered device 4C3C2BA1-628A-DA70-6799-7281E654B78A: VTM 20F @ RSSI: -49 (kCBAdvData <nsdict_keys(['kCBAdvDataManufacturerData', 'kCBAdvDataTimestamp', 'kCBAdvDataIsConnectable', 'kCBAdvDataRxPrimaryPHY', 'kCBAdvDataRxSecondaryPHY', 'kCBAdvDataLocalName', 'kCBAdvDataServiceUUIDs'])>) and Central: <CBCentralManager: 0x12a827850>
2024-11-21 18:45:46,324 bleak.backends.corebluetooth.CentralManagerDelegate MainThread DEBUG: 'isScanning' changed
Found device: VTM 20F (4C3C2BA1-628A-DA70-6799-7281E654B78A)
2024-11-21 18:45:46,333 bleak.backends.corebluetooth.client MainThread DEBUG: CentralManagerDelegate  at <CentralManagerDelegate: 0x148e924f0>
2024-11-21 18:45:46,333 bleak.backends.corebluetooth.client MainThread DEBUG: Connecting to BLE device @ 4C3C2BA1-628A-DA70-6799-7281E654B78A
2024-11-21 18:45:46,333 bleak.backends.corebluetooth.CentralManagerDelegate MainThread DEBUG: Discovered device F27156C9-567F-90F1-4BA2-0DD907CD7593: ELK-BLEDOM  @ RSSI: -75 (kCBAdvData <nsdict_keys(['kCBAdvDataLocalName', 'kCBAdvDataRxPrimaryPHY', 'kCBAdvDataRxSecondaryPHY', 'kCBAdvDataTimestamp', 'kCBAdvDataIsConnectable'])>) and Central: <CBCentralManager: 0x12a827850>
2024-11-21 18:45:46,509 bleak.backends.corebluetooth.CentralManagerDelegate Dummy-6 DEBUG: centralManager_didConnectPeripheral_
2024-11-21 18:45:46,510 bleak.backends.corebluetooth.client MainThread DEBUG: Retrieving services...
2024-11-21 18:45:46,598 bleak.backends.corebluetooth.PeripheralDelegate Dummy-7 DEBUG: peripheral_didDiscoverServices_
2024-11-21 18:45:46,600 bleak.backends.corebluetooth.PeripheralDelegate MainThread DEBUG: Services discovered
2024-11-21 18:45:46,600 bleak.backends.corebluetooth.client MainThread DEBUG: Retrieving characteristics for service FFE0
2024-11-21 18:45:46,601 bleak.backends.corebluetooth.PeripheralDelegate Dummy-8 DEBUG: peripheral_didDiscoverCharacteristicsForService_error_
2024-11-21 18:45:46,602 bleak.backends.corebluetooth.PeripheralDelegate MainThread DEBUG: Characteristics discovered
2024-11-21 18:45:46,602 bleak.backends.corebluetooth.client MainThread DEBUG: Retrieving descriptors for characteristic FFE4
2024-11-21 18:45:46,603 bleak.backends.corebluetooth.PeripheralDelegate Dummy-9 DEBUG: peripheral_didDiscoverDescriptorsForCharacteristic_error_
2024-11-21 18:45:46,603 bleak.backends.corebluetooth.PeripheralDelegate MainThread DEBUG: Descriptor discovered 12
2024-11-21 18:45:46,604 bleak.backends.corebluetooth.client MainThread DEBUG: Retrieving descriptors for characteristic FFF2
2024-11-21 18:45:46,604 bleak.backends.corebluetooth.PeripheralDelegate Dummy-10 DEBUG: peripheral_didDiscoverDescriptorsForCharacteristic_error_
2024-11-21 18:45:46,604 bleak.backends.corebluetooth.PeripheralDelegate MainThread DEBUG: Descriptor discovered 16
2024-11-21 18:45:46,605 bleak.backends.corebluetooth.client MainThread DEBUG: Services resolved for BleakClientCoreBluetooth (4C3C2BA1-628A-DA70-6799-7281E654B78A)
Connected to BleakClient, 4C3C2BA1-628A-DA70-6799-7281E654B78A!
2024-11-21 18:45:48,608 bleak.backends.corebluetooth.CentralManagerDelegate Dummy-11 DEBUG: centralManager_didDisconnectPeripheral_error_
2024-11-21 18:45:48,609 bleak.backends.corebluetooth.CentralManagerDelegate MainThread DEBUG: Peripheral Device disconnected!
Disconnected!

maxentric-gnylund avatar Nov 22 '24 03:11 maxentric-gnylund

The best way to resolve issues like this is to log Bluetooth packets on both the working and not working system and see what the difference is. See https://bleak.readthedocs.io/en/latest/troubleshooting.html#capture-bluetooth-traffic for instructions.

dlech avatar Apr 20 '25 15:04 dlech