Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Client.disconnect() hangs with Windows 10 #1648

Open
kins3i opened this issue Oct 1, 2024 · 8 comments
Open

Client.disconnect() hangs with Windows 10 #1648

kins3i opened this issue Oct 1, 2024 · 8 comments
Labels
Backend: WinRT Issues or PRs relating to the WinRT backend more info required Issues does not have a reproducible test case, has insufficent logs or otherwise needs more feedback

Comments

@kins3i
Copy link

kins3i commented Oct 1, 2024

  • bleak version: 0.22.2
  • Python version: 3.12.4
  • Operating System: Windows 10

Description

After invoking client.disconnect() it hangs on function. It does reconnect (I have LED status on my device for connection status) and with debugging every variable show device does indeed disconnect. Nevertheless the function doesn't end correctly, it always reaches async timeout. I cannot use winrt library as I have too new Python version. I'm reluctant to downgrade Python version.

What I Did

Here is main code for disconnecting. The code never reaches beyond single_client.disconnect(). It caches Exception, it doesn't print exception cause, but raises Timeout Exception.

class A
    async def single_disconnect(self, address):
        single_client = None
        device_class = None
        for client in self.client_list:
            if client.address == address:
                single_client = client
        if single_client is not None:
            try:
                if single_client.is_connected:
                    for device in self.client_device_list:
                        device_address = device.MAC_ST
                        if device_address == single_client.address:
                            device_class = device
                    if device_class is not None:
                        device_class.stop_all_notifies()
                        print("Disconnecting device, ", datetime.now())
                        for x in self.client_list:
                            if x == single_client:
                                self.client_list.remove(x)
                        for device in self.client_device_list:
                            if device.MAC_ST == single_client.address:
                                self.client_device_list.remove(device)
                        bool_var = await single_client.disconnect()
                        while single_client.is_connected:
                            continue
                        print("disconnected")

                        print('Disconnecting single client: ' + str(address))
                else:
                    for x in self.client_list:
                        if x == single_client:
                            self.client_list.remove(x)
                    for device in self.client_device_list:
                        if device.MAC_ST == single_client.address:
                            self.client_device_list.remove(device)
                    print("Already disconnected: ", address)
            except (ValueError, Exception) as e:
                print('Error disconnecting to device, ', e)
                raise Exception(e)

class B (tkinter based, main class)
    def one_disconnect(self, address):
        loop = asyncio.new_event_loop()
        loop.run_until_complete(self.ble.single_disconnect(address))

class C (tkinter based)
    def checkbox_event(self, btn):
        name_address = btn.cget("text")
        var = btn.cget("variable")
        address = name_address.split()[1]
        if var.get() == 1:
            thr_connect = threading.Thread(target=self.master.one_connect, args=(address,), daemon=True)
            thr_connect.start()
        elif var.get() == 0:
            thr_disconnect = threading.Thread(target=self.master.one_disconnect, args=(address,), daemon=True)
            thr_disconnect.start()

Beside this I did debugging of winrt/client.py and self._requester property and self.is_connected shows device is disconnected after about 30 seconds. I tried adding asyncio.sleep before self._requester.close(), but it didn't help. I tried doing this: https://stackoverflow.com/questions/71557849/listing-connected-ble-devices-from-cpython-in-windows but it doesn't work (first function always gives empty list).

Logs

Here is info about my BLE driver:
image
and below are logs from debug:

2024-10-01 08:43:00,524 bleak.backends.winrt.scanner MainThread DEBUG: Received 1F:66:DC:7D:A0:6F: .
2024-10-01 08:43:00,532 bleak.backends.winrt.scanner MainThread DEBUG: Received 1F:66:DC:7D:A0:6F: .
2024-10-01 08:43:01,846 bleak.backends.winrt.scanner MainThread DEBUG: Received 1F:66:DC:7D:A0:6F: .
2024-10-01 08:43:01,854 bleak.backends.winrt.scanner MainThread DEBUG: Received 1F:66:DC:7D:A0:6F: .
2024-10-01 08:43:01,952 bleak.backends.winrt.scanner MainThread DEBUG: Received 01:0D:85:F3:F8:D3: .
2024-10-01 08:43:02,187 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: XXX.
2024-10-01 08:43:02,198 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: .
2024-10-01 08:43:02,565 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: XXX.
2024-10-01 08:43:02,575 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: .
2024-10-01 08:43:02,904 bleak.backends.winrt.scanner MainThread DEBUG: Received 01:0D:85:F3:F8:D3: .
2024-10-01 08:43:02,917 bleak.backends.winrt.scanner MainThread DEBUG: Received 1F:66:DC:7D:A0:6F: .
2024-10-01 08:43:02,926 bleak.backends.winrt.scanner MainThread DEBUG: Received 1F:66:DC:7D:A0:6F: .
2024-10-01 08:43:03,147 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: XXX.
2024-10-01 08:43:03,157 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: .
2024-10-01 08:43:03,983 bleak.backends.winrt.scanner MainThread DEBUG: Received 1F:66:DC:7D:A0:6F: .
2024-10-01 08:43:03,991 bleak.backends.winrt.scanner MainThread DEBUG: Received 1F:66:DC:7D:A0:6F: .
2024-10-01 08:43:04,106 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: XXX.
2024-10-01 08:43:04,116 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: .
2024-10-01 08:43:04,576 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: XXX.
2024-10-01 08:43:04,585 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: .
2024-10-01 08:43:04,673 bleak.backends.winrt.scanner MainThread DEBUG: Received C5:4B:72:21:D6:04: .
2024-10-01 08:43:04,677 bleak.backends.winrt.scanner MainThread DEBUG: Received C5:4B:72:21:D6:04: Mi Smart Band 5.
2024-10-01 08:43:04,805 bleak.backends.winrt.scanner MainThread DEBUG: Received 01:0D:85:F3:F8:D3: .
2024-10-01 08:43:05,042 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: XXX.
2024-10-01 08:43:05,050 bleak.backends.winrt.scanner MainThread DEBUG: Received 00:80:E1:26:BB:DA: .
2024-10-01 08:43:05,523 bleak.backends.winrt.scanner MainThread DEBUG: 4 devices found. Watcher status: <BluetoothLEAdvertisementWatcherStatus.STOPPED: 3>.
2024-10-01 08:43:09,090 bleak.backends.winrt.scanner Thread-2 (one_connect) DEBUG: Received 00:80:E1:26:BB:DA: XXX.
2024-10-01 08:43:09,099 bleak.backends.winrt.scanner Thread-2 (one_connect) DEBUG: Received 00:80:E1:26:BB:DA: .
2024-10-01 08:43:09,108 bleak.backends.winrt.scanner Thread-2 (one_connect) DEBUG: 1 devices found. Watcher status: <BluetoothLEAdvertisementWatcherStatus.STOPPED: 3>.
2024-10-01 08:43:09,110 bleak.backends.winrt.client Thread-2 (one_connect) DEBUG: Connecting to BLE device @ 00:80:E1:26:BB:DA
2024-10-01 08:43:09,158 bleak.backends.winrt.client Thread-2 (one_connect) DEBUG: getting services (service_cache_mode=None, cache_mode=None)...
2024-10-01 08:43:09,286 bleak.backends.winrt.client Dummy-3 DEBUG: session_status_changed_event_handler: id: BluetoothLE#BluetoothLE04:7f:0e:4b:7d:69-00:80:e1:26:bb:da, error: <BluetoothError.SUCCESS: 0>, status: <GattSessionStatus.ACTIVE: 1>
2024-10-01 08:43:09,352 bleak.backends.winrt.client Dummy-4 DEBUG: max_pdu_size_changed_handler: 512
2024-10-01 08:43:10,705 bleak.backends.winrt.client Dummy-4 DEBUG: 00:80:E1:26:BB:DA: services changed
2024-10-01 08:43:10,781 bleak.backends.winrt.client Dummy-4 DEBUG: 00:80:E1:26:BB:DA: services changed
2024-10-01 08:43:10,860 bleak.backends.winrt.client Dummy-4 DEBUG: 00:80:E1:26:BB:DA: services changed
2024-10-01 08:43:10,938 bleak.backends.winrt.client Dummy-4 DEBUG: 00:80:E1:26:BB:DA: services changed
2024-10-01 08:43:11,018 bleak.backends.winrt.client Dummy-4 DEBUG: 00:80:E1:26:BB:DA: services changed
2024-10-01 08:43:11,093 bleak.backends.winrt.client Dummy-4 DEBUG: 00:80:E1:26:BB:DA: services changed
2024-10-01 08:43:11,161 bleak.backends.winrt.client Dummy-4 DEBUG: 00:80:E1:26:BB:DA: services changed
Single connected to: 00:80:E1:26:BB:DA, type: <class 'bleak.BleakClient'>
>> here is some printing and invoking functions opening notifies I hidden for privacy <<
Disconnecting device,  2024-10-01 08:43:18.027125
2024-10-01 08:43:18,027 bleak.backends.winrt.client Thread-8 (one_disconnect) DEBUG: Disconnecting from BLE device...
2024-10-01 08:43:21,233 bleak.backends.winrt.client Dummy-3 DEBUG: max_pdu_size_changed_handler: 23
2024-10-01 08:43:21,233 bleak.backends.winrt.client Dummy-9 DEBUG: session_status_changed_event_handler: id: BluetoothLE#BluetoothLE04:7f:0e:4b:7d:69-00:80:e1:26:bb:da, error: <BluetoothError.SUCCESS: 0>, status: <GattSessionStatus.CLOSED: 0>
>> here function stopped for 2 minutes and device disconnected as indicated by LED and internal debug <<
Error disconnecting to device, >>here should be Exception cause, but it's empty<<
 
Exception in thread Thread-8 (one_disconnect):
Traceback (most recent call last):
  File "my_path", line 550, in disconnect
    await event.wait()
  File "C:\Python312\Lib\asyncio\locks.py", line 212, in wait
    await fut
asyncio.exceptions.CancelledError

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

Traceback (most recent call last):
  File "my_path", line 165, in single_disconnect
    bool_var = await single_client.disconnect()
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "my_path\.venv\Lib\site-packages\bleak\__init__.py", line 624, in disconnect
    return await self._backend.disconnect()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "my_path\.venv\Lib\site-packages\bleak\backends\winrt\client.py", line 549, in disconnect
    async with async_timeout(120):
  File "C:\Python312\Lib\asyncio\timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\Python312\Lib\threading.py", line 1073, in _bootstrap_inner
    self.run()
  File "C:\Python312\Lib\threading.py", line 1010, in run
    self._target(*self._args, **self._kwargs)
  File "my_path", line 119, in one_disconnect
    loop.run_until_complete(self.ble.single_disconnect(address))
  File "C:\Python312\Lib\asyncio\base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "my_path", line 181, in single_disconnect
    raise Exception(e)
Exception


For safety reasons I changed correct paths to "my_path", as the error is not depending on path.

Because of the error my app hangs and I need to forcefully kill it (which is bad, as I should invoke disconnect devices on closing app). If I close my app without prior device disconnecting library does correct closing connection.

Is it the problem in your library and you can fix it or is it in winrt one and I do need to downgrade Python version?

@dlech
Copy link
Collaborator

dlech commented Oct 2, 2024

I had a Windows computer that took a very long time to disconnect. I ended up reinstalling Windows and it fixed the problem.

@dlech dlech added the Backend: WinRT Issues or PRs relating to the WinRT backend label Oct 2, 2024
@kins3i
Copy link
Author

kins3i commented Oct 2, 2024

Unfortunately, the problem is existing on Windows 11 too, but my main project is based on Windows 10. Secondly, the device do disconnect. Debug shows device loses connection, my device indicates disconnecting with LED and device's serial port shows BLE commands for disconnect handle. Everything shows device is disconnected, but your library's event is never set. I can make disconnect timeout longer, but it won't help, as your library variables shows device is disconencted, as I mentioned in my post.

I cannot do reinstaling of operating system, because problem concerns multiple PCs, at least one with Windows 11 (but I didn't want to make different post, as the solution for windows 11 is probably same as for windows 10). I would block work of many colleagues just to arrive at the same point that it's something in library.

If you can, please write where (which file and line) you do event.set() for disconnect() and I will try debugging more. Unfortunately I'm not very familiar with async functions, so I cannot back-engineer where event.set() should be called

@dlech
Copy link
Collaborator

dlech commented Oct 2, 2024

Tkinter doesn't integrate well with asyncio, so it could be that tkinter is blocking the disconnect event.

You could try this example code to see if you see the same problem: https://github.com/hbldh/bleak/blob/develop/examples/disconnect_callback.py

@dlech dlech added the more info required Issues does not have a reproducible test case, has insufficent logs or otherwise needs more feedback label Oct 5, 2024
@windsunsjtu
Copy link

windsunsjtu commented Oct 8, 2024

I tried https://github.com/hbldh/bleak/blob/develop/examples/disconnect_callback.py, and it freezes when disconnecting. In fact, the same code was working fine a few weeks ago. I strongly suspect that some update has been made to Windows during this time. I tried both on Windows 10 and Windows 11

However, if I use https://github.com/hbldh/bleak/blob/develop/examples/enable_notifications.py, the disconnection works normally.

@idotta
Copy link

idotta commented Oct 25, 2024

Are there any news on this issue? I'm also having this problem on latest Win11 version.

I perform a loopback test, in which I continuously send packages to the device and it sends them back to me. I use asyncio.Queues to buffer the data from read and write, like some of the examples.

The disconnect call can take a few seconds, to more than 10 minutes. I have no idea how to fix this issue. Any clues?

@dlech
Copy link
Collaborator

dlech commented Oct 25, 2024

Are there any news on this issue?

It is lacking a reproducible test case or sufficient logs to be able to tell what the different is between working and not working cases.

Logging Bluetooth packets with Wireshark as describe in the troubleshooting guide is always the best way to see what is going on at a low level.

@idotta
Copy link

idotta commented Oct 25, 2024

In my case, I found that the packages were piling up on the lower levels of the stack. Even after terminating the application, Windows would still keep sending the enqueued packages until they were all sent. The only way to stop it is by turning the bluetooth off.

I solved it by controlling the amount of enqueued packages, only writing more when some amount was already sent back by the device. By doing that, disconnect now takes roughly the same time as if no data was sent.

Hope this helps. Thanks.

@dlech
Copy link
Collaborator

dlech commented Oct 25, 2024

That is useful information to know, thanks for following up.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Backend: WinRT Issues or PRs relating to the WinRT backend more info required Issues does not have a reproducible test case, has insufficent logs or otherwise needs more feedback
Projects
None yet
Development

No branches or pull requests

4 participants