100% cpu load from bluepy-helper

[DefCon-CC]

Describe the bug
After some after starting bt-mqtt-gateway I experience a huge cpu load from bluepy-helper. I bumped into it as I saw that the power consumption from my server increased from 10W to 26W. I'm using bluez version 5.63.

To Reproduce
Steps to reproduce the behavior:

1. Start bt-mqtt-gateway by calling ./gateway.py
2. After some time I experience a huge cpu load from bluepy-helper. (a few hours)

Expected behavior
Not such a high cpu load

Config

• normal MQTT configuration
• command_timeout: 45
• command_retries: 0
• update_retries: 0
• workers: 5x lywsd03mmc devices (passive: false, scan_timeout:20, update_interval: 120)

Debug gateway logs
I will try to reproduce and print debug output here.

Server (please complete the following information):

• OS: Linux
• Distro: Redhat Enterprise Linux
• Version 8.7

Additional context

[DefCon-CC]

Debug-Output:

2023-01-26 17:41:24,892 DEBUG bt-mqtt-gw.workers.lywsd03mmc lywsd03mmc.py:67:connected - A4:C1:38:36:76:C8 - connected
2023-01-26 17:41:36,589 ERROR bt-mqtt-gw.workers_manager logger.py:50:log_exception - Execution of command Lywsd03MmcWorker.status_update timed out after 60 seconds, sending only partial update
Traceback (most recent call last):
File "/home/webmaster/server/bt-mqtt-gateway/workers_manager.py", line 45, in execute
for message in self._callback(*self._args):
File "/home/webmaster/server/bt-mqtt-gateway/workers/lywsd03mmc.py", line 44, in status_update
ret = lywsd03mmc.readAll()
File "/home/webmaster/server/bt-mqtt-gateway/workers/lywsd03mmc.py", line 80, in readAll
with self.connected() as device:
File "/usr/lib64/python3.6/contextlib.py", line 81, in enter
return next(self.gen)
File "/home/webmaster/server/bt-mqtt-gateway/workers/lywsd03mmc.py", line 69, in connected
device.connect(self.mac)
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 445, in connect
self._connect(addr, addrType, iface)
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 436, in _connect
rsp = self._getResp('stat')
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 407, in _getResp
resp = self._waitResp(wantType + ['ntfy', 'ind'], timeout)
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 347, in _waitResp
rv = self._helper.stdout.readline()
File "/usr/local/lib/python3.6/site-packages/interruptingcow/init.py", line 74, in handler
raise exception
exceptions.WorkerTimeoutError: Execution of command Lywsd03MmcWorker.status_update timed out after 60 seconds
2023-01-26 17:41:36,590 DEBUG bt-mqtt-gw.workers_manager workers_manager.py:57:execute - Execution result of command Lywsd03MmcWorker.status_update: [{'topic': 'xiaomiTempHumSensor/livingRoom', 'payload': '{"temperature": 18.2, "humidity": 66, "battery": 2.96}'}]
2023-01-26 17:42:36,591 DEBUG bt-mqtt-gw.workers.lywsd03mmc lywsd03mmc.py:67:connected - A4:C1:38:25:0C:F7 - connected
2023-01-26 17:42:39,788 DEBUG bt-mqtt-gw.workers.lywsd03mmc lywsd03mmc.py:87:readAll - A4:C1:38:25:0C:F7 - found values 18.200000, 66, 2
2023-01-26 17:42:39,789 DEBUG bt-mqtt-gw.workers.lywsd03mmc lywsd03mmc.py:67:connected - A4:C1:38:BF:EC:8F - connected
2023-01-26 17:43:23,676 ERROR bt-mqtt-gw.workers.lywsd03mmc logger.py:50:log_exception - Failed connect from lywsd03mmc to device 'bath': BTLEDisconnectError
Traceback (most recent call last):
File "/home/webmaster/server/bt-mqtt-gateway/workers/lywsd03mmc.py", line 44, in status_update
ret = lywsd03mmc.readAll()
File "/home/webmaster/server/bt-mqtt-gateway/workers/lywsd03mmc.py", line 80, in readAll
with self.connected() as device:
File "/usr/lib64/python3.6/contextlib.py", line 81, in enter
return next(self.gen)
File "/home/webmaster/server/bt-mqtt-gateway/workers/lywsd03mmc.py", line 69, in connected
device.connect(self.mac)
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 445, in connect
self._connect(addr, addrType, iface)
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 439, in _connect
raise BTLEDisconnectError("Failed to connect to peripheral %s, addr type: %s" % (addr, addrType), rsp)
bluepy.btle.BTLEDisconnectError: Failed to connect to peripheral A4:C1:38:BF:EC:8F, addr type: public
2023-01-26 17:43:23,677 DEBUG bt-mqtt-gw.workers.lywsd03mmc lywsd03mmc.py:67:connected - A4:C1:38:36:76:C8 - connected
2023-01-26 17:43:36,591 ERROR bt-mqtt-gw.workers_manager logger.py:50:log_exception - Execution of command Lywsd03MmcWorker.status_update timed out after 60 seconds, sending only partial update
Traceback (most recent call last):
File "/home/webmaster/server/bt-mqtt-gateway/workers_manager.py", line 45, in execute
for message in self._callback(*self._args):
File "/home/webmaster/server/bt-mqtt-gateway/workers/lywsd03mmc.py", line 44, in status_update
ret = lywsd03mmc.readAll()
File "/home/webmaster/server/bt-mqtt-gateway/workers/lywsd03mmc.py", line 80, in readAll
with self.connected() as device:
File "/usr/lib64/python3.6/contextlib.py", line 81, in enter
return next(self.gen)
File "/home/webmaster/server/bt-mqtt-gateway/workers/lywsd03mmc.py", line 69, in connected
device.connect(self.mac)
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 445, in connect
self._connect(addr, addrType, iface)
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 436, in _connect
rsp = self._getResp('stat')
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 407, in _getResp
resp = self._waitResp(wantType + ['ntfy', 'ind'], timeout)
File "/usr/local/lib/python3.6/site-packages/bluepy/btle.py", line 347, in _waitResp
rv = self._helper.stdout.readline()
File "/usr/local/lib/python3.6/site-packages/interruptingcow/init.py", line 74, in handler
raise exception
exceptions.WorkerTimeoutError: Execution of command Lywsd03MmcWorker.status_update timed out after 60 seconds
2023-01-26 17:43:36,592 DEBUG bt-mqtt-gw.workers_manager workers_manager.py:57:execute - Execution result of command Lywsd03MmcWorker.status_update: [{'topic': 'xiaomiTempHumSensor/livingRoom', 'payload': '{"temperature": 18.2, "humidity": 66, "battery": 2.961}'}]
2023-01-26 17:44:36,594 DEBUG bt-mqtt-gw.workers.lywsd03mmc lywsd03mmc.py:67:connected - A4:C1:38:25:0C:F7 - connected
2023-01-26 17:44:42,895 DEBUG bt-mqtt-gw.workers.lywsd03mmc lywsd03mmc.py:87:readAll - A4:C1:38:25:0C:F7 - found values 18.100000, 66, 2
2023-01-26 17:44:42,897 DEBUG bt-mqtt-gw.workers.lywsd03mmc lywsd03mmc.py:67:connected - A4:C1:38:BF:EC:8F - connected

[DefCon-CC]

I observed also the following in the output "dmesg -wH":

[Jan31 10:59] Bluetooth: hci0: Controller not accepting commands anymore: ncmd = 0
[ +0.000011] Bluetooth: hci0: Injecting HCI hardware error event
[ +0.000018] Bluetooth: hci0: hardware error 0x00