Performance regression with bleak 0.21 #109
Description
Describe the bug
Sending is horribly slow with ~100 ms delay per packet now:
Completed read 1437 bytes in 6.581 s
Rate 218.36 byte/s = 1747 bit/s = 2184 baud
Or randomly even slower:
Completed read 1437 bytes in 33.600 s
Rate 42.77 byte/s = 342 bit/s = 428 baud
That is actually the same test as on the initial 2.0 release, where it was at least 10x faster: https://blog.ja-ke.tech/2021/04/22/ble-serial-2.html#performance
Started experimenting with different bleak (ble library) versions, since I could not find a reason in ble-serial itself. The results above are from latest bleak 0.22.3 and same with 0.21. Downgrading to 0.20 did the trick and gives the expected speed:
Completed read 1437 bytes in 0.717 s
Rate 2003.36 byte/s = 16027 bit/s = 20034 baud
{'valid': True, 'loss_percent': 0.0, 'rx_bits': 16026, 'rx_baud': 20033, 'dir': 'BLE >> UART', 'rated_baud': 115200, 'packet_size': 128, 'delay': 0}
Log messages
With latest bleak
03:23:40.556 | DEBUG | ble_interface.py: Sending b'a aliquyam erat, sed'
03:23:40.670 | DEBUG | ble_interface.py: Sending b' diam voluptua. At v'
03:23:40.743 | DEBUG | ble_interface.py: Sending b'ero eos et accusam e'
03:23:40.820 | DEBUG | ble_interface.py: Sending b't justo duo dolores '
03:23:40.926 | DEBUG | ble_interface.py: Sending b'et ea rebum. Stet cl'
03:23:41.003 | DEBUG | ble_interface.py: Sending b'ita kasd gubergren, '
03:23:41.080 | DEBUG | ble_interface.py: Sending b'no sea takimata sanc'
03:23:41.156 | DEBUG | ble_interface.py: Sending b'tus est Lorem ipsum '
03:23:41.226 | DEBUG | ble_interface.py: Sending b'dolor sit amet. Lore'
03:23:41.303 | DEBUG | ble_interface.py: Sending b'm ipsum dolor sit am'
03:23:41.376 | DEBUG | ble_interface.py: Sending b'et, consetetur sadip'
03:23:41.453 | DEBUG | ble_interface.py: Sending b'scing elitr, sed dia'
03:23:41.563 | DEBUG | ble_interface.py: Sending b'm nonumy eirmod temp'
03:23:41.640 | DEBUG | ble_interface.py: Sending b'or invidunt ut labor'
...
Setup (please complete the following information):
- OS: Arch
- Bluetooth Hardware: HM-10
- BlueZ Version: 5.79
- Python Version: 3.12.7
- ble-serial and dependency versions:
- ble-serial 2.8.0
- bleak 0.21.0a1
Additional Context
Bisect confirms:
401e71ae661a3b50abbb81ae380a8f34841bf7e4 is the first bad commit
commit 401e71ae661a3b50abbb81ae380a8f34841bf7e4 (HEAD)
Author: David Lechner david@lechnology.com
Date: Sat Feb 18 19:35:48 2023 -0600
BleakClient.write_gatt_char: change handling of default response
Previously, some backends would select the "best" response type based
on the reported characteristics while some did not. For the ones that
didn't, it was a commonly reported issue for the write to not work.
This adds a recommendation to the docs to always be explicit about
the requested response type and moves the common logic for picking
the "best" type in the default case to the BleakClient class to avoid
duplicated code.
The logic is simplified to prefer a write with response if available
and no longer reports a warning for devices that don't properly specify
properties (since it would create much noise with many writes).
Fixes: hbldh/bleak#909
Figured out already here:
#89 (comment)