search

zewelor / bt-mqtt-gateway

A simple Python script which provides a Bluetooth to MQTT gateway, easily extensible via custom workers. See https://github.com/zewelor/bt-mqtt-gateway/wiki for more information.
MIT License
549 stars 116 forks source link

BTLEDisconnectError & BluetoothBackEndExeption #64

Open robrec opened 5 years ago

robrec commented 5 years ago

Hi

i have used bt-mqtt-gateway for some month, no problems there but since 1 or 2 weeks i receive some errors.

Today i updated to the new version + update bluez to 5.50

Config:

mqtt: host: 192.168.178.2 port: 1883 username: bt-mqtt password: ***** client_id: bt-mqtt-gateway

manager: workers: thermostat: args: devices: schlafzimmer: 00:1A:22:10:FC:3D badezimmer: 00:1A:22:11:1D:75 wohnzimmer1: 00:1A:22:11:15:3F wohnzimmer2: 00:1A:22:10:DE:29 wohnzimmer3: 00:1A:22:11:02:76 hobbyraum: 00:1A:22:11:1D:CA topic_prefix: heizung topic_subscription: heizung/+/+/set update_interval: 60 miflora: args: devices: ebene2: C4:7C:8D:67:40:89 ebene1: C4:7C:8D:67:5A:51 topic_prefix: miflora update_interval: 60

pi@rpi:~/bt-mqtt-gateway $ sudo ./gateway.py 20:34:53 Starting 20:34:53 Adding 6 thermostat devices 20:34:54 Adding 2 miflora devices 20:34:54 Updating 6 thermostat devices 20:34:54 Error during update of thermostat device 'schlafzimmer' (00:1A:22:10:FC:3D): BTLEDisconnectError 20:34:54 Error during update of thermostat device 'hobbyraum' (00:1A:22:11:1D:CA): BTLEDisconnectError 20:34:54 Error during update of thermostat device 'wohnzimmer1' (00:1A:22:11:15:3F): BTLEDisconnectError 20:34:54 Error during update of thermostat device 'badezimmer' (00:1A:22:11:1D:75): BTLEDisconnectError 20:34:54 Error during update of thermostat device 'wohnzimmer2' (00:1A:22:10:DE:29): BTLEDisconnectError 20:34:54 Error during update of thermostat device 'wohnzimmer3' (00:1A:22:11:02:76): BTLEDisconnectError 20:34:54 Updating 2 miflora devices 20:34:55 Error during update of miflora device 'ebene1' (C4:7C:8D:67:5A:51): BluetoothBackendException 20:34:55 Error during update of miflora device 'ebene2' (C4:7C:8D:67:40:89): BluetoothBackendException 20:34:55 Setting target_temperature to 22.0 on thermostat device 'wohnzimmer2' (00:1A:22:10:DE:29) 20:34:55 Error setting target_temperature to 22.0 on thermostat device 'wohnzimmer2' (00:1A:22:10:DE:29): BTLEDisconnectError 20:34:55 Setting target_temperature to 22.0 on thermostat device 'wohnzimmer3' (00:1A:22:11:02:76) 20:34:55 Error setting target_temperature to 22.0 on thermostat device 'wohnzimmer3' (00:1A:22:11:02:76): BTLEDisconnectError 20:34:55 Setting target_temperature to 23.0 on thermostat device 'badezimmer' (00:1A:22:11:1D:75) 20:34:56 Error setting target_temperature to 23.0 on thermostat device 'badezimmer' (00:1A:22:11:1D:75): BTLEDisconnectError 20:34:56 Setting target_temperature to 22.0 on thermostat device 'wohnzimmer1' (00:1A:22:11:15:3F) 20:34:56 Error setting target_temperature to 22.0 on thermostat device 'wohnzimmer1' (00:1A:22:11:15:3F): BTLEDisconnectError 20:34:56 Setting target_temperature to 22.0 on thermostat device 'hobbyraum' (00:1A:22:11:1D:CA) 20:34:56 Error setting target_temperature to 22.0 on thermostat device 'hobbyraum' (00:1A:22:11:1D:CA): BTLEDisconnectError 20:34:56 Setting target_temperature to 4.5 on thermostat device 'schlafzimmer' (00:1A:22:10:FC:3D) 20:34:56 Error setting target_temperature to 4.5 on thermostat device 'schlafzimmer' (00:1A:22:10:FC:3D): BTLEDisconnectError

zewelor commented 5 years ago

So you didn't change anything at it started to appear ? Using phone app for thermostats ? Are thermostats runnign latest firmware ? You could also try to pair them, with the computer https://wiki.archlinux.org/index.php/bluetooth#Pairing

Maczuga commented 5 years ago

Same error for me, but with Xiaomi temperature and humidity sensors. Reboot helps for 5min - 12h. Also on Bluez 5.50. Even with pairing.

2019-06-04 14:27:02,680 ERROR bt-mqtt-gw.workers.mithermometer logger.py:48:log_exception - Error during update of mithermometer device 'gabinet' (4C:65:A8:D5:F8:99): BluetoothBackendException
Traceback (most recent call last):
  File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 26, in _func_wrapper
    return func(*args, **kwargs)
  File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 84, in write_handle
    return self._peripheral.writeCharacteristic(handle, value, True)
  File "/usr/local/lib/python3.5/dist-packages/bluepy/btle.py", line 542, in writeCharacteristic
    self._writeCmd("%s %X %s\n" % (cmd, handle, binascii.b2a_hex(val).decode('utf-8')))
  File "/usr/local/lib/python3.5/dist-packages/bluepy/btle.py", line 302, in _writeCmd
    raise BTLEInternalError("Helper not started (did you call connect()?)")
bluepy.btle.BTLEInternalError: Helper not started (did you call connect()?)

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

Traceback (most recent call last):
  File "/root/bt-mqtt-gateway/workers/mithermometer.py", line 30, in status_update
    ret += self.update_device_state(name, poller)
  File "/root/bt-mqtt-gateway/workers/mithermometer.py", line 39, in update_device_state
    ret.append(MqttMessage(topic=self.format_topic(name, attr), payload=poller.parameter_value(attr)))
  File "/usr/local/lib/python3.5/dist-packages/mithermometer/mithermometer_poller.py", line 136, in parameter_value
    self.fill_cache()
  File "/usr/local/lib/python3.5/dist-packages/mithermometer/mithermometer_poller.py", line 78, in fill_cache
    connection.wait_for_notification(_HANDLE_READ_SENSOR_DATA, Cache, self.ble_timeout)
  File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 26, in _func_wrapper
    return func(*args, **kwargs)
  File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 90, in wait_for_notification
    self.write_handle(handle, self._DATA_MODE_LISTEN)
  File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 32, in _func_wrapper
    raise BluetoothBackendException() from last_error
btlewrap.base.BluetoothBackendException
hobbypunk90 commented 5 years ago

Hey ho,

i have the same problem but i'm a little bit further 😁 the problem ist, that the bluepy-helper dies and ends up as zombie. if i have to guess, i would say, that interruptcow kills it by interrupting at a specific point of execution 🤔🤷 but i don't have any idea how to fix that...

bistory commented 5 years ago

Same problem here... Data are not sent to HA, only the topics... Here are the errors :

pi@raspberrypi:~/bt-mqtt-gateway $ sudo ./gateway.py -d
2019-06-26 20:17:44,867 INFO bt-mqtt-gw gateway.py:39:<module> - Starting
2019-06-26 20:17:44,873 DEBUG bt-mqtt-gw.mqtt mqtt.py:23:__init__ - Setting LWT to: lwt_topic
2019-06-26 20:17:48,695 INFO bt-mqtt-gw.workers.mithermometer mithermometer.py:18:_setup - Adding 1 mithermometer devices
2019-06-26 20:17:48,698 DEBUG bt-mqtt-gw.workers.mithermometer mithermometer.py:20:_setup - Adding mithermometer device 'living_room' (58:2D:34:10:40:D0)
2019-06-26 20:17:48,701 DEBUG bt-mqtt-gw.workers_manager workers_manager.py:60:register_workers - Added mithermometer config with a 2 seconds timeout
2019-06-26 20:17:48,703 DEBUG bt-mqtt-gw.workers_manager workers_manager.py:65:register_workers - Added mithermometer worker with 300 seconds interval and a 35 seconds timeout
2019-06-26 20:17:48,732 DEBUG bt-mqtt-gw.mqtt mqtt.py:77:callbacks_subscription - Subscribing to: mithermometer/update_interval
2019-06-26 20:17:48,737 DEBUG bt-mqtt-gw.mqtt mqtt.py:77:callbacks_subscription - Subscribing to: homeassistant/status
2019-06-26 20:17:48,747 DEBUG bt-mqtt-gw.workers_manager workers_manager.py:36:execute - Execution result of command MithermometerWorker.config: [{'topic': 'sensor/mithermometer_living_room_temperature/config', 'payload': '{"unique_id": "bt-mqtt-gateway_mithermometer_living_room_temperature", "state_topic": "mithermometer/living_room/temperature", "device_class": "temperature", "device": {"identifiers": ["58:2D:34:10:40:D0", "bt-mqtt-gateway_mithermometer_living_room"], "manufacturer": "Xiaomi", "model": "LYWSD(CGQ/01ZM)", "name": "Mithermometer Living_Room"}, "name": "mithermometer_living_room_temperature"}'}, {'topic': 'sensor/mithermometer_living_room_humidity/config', 'payload': '{"unique_id": "bt-mqtt-gateway_mithermometer_living_room_humidity", "state_topic": "mithermometer/living_room/humidity", "device_class": "humidity", "device": {"identifiers": ["58:2D:34:10:40:D0", "bt-mqtt-gateway_mithermometer_living_room"], "manufacturer": "Xiaomi", "model": "LYWSD(CGQ/01ZM)", "name": "Mithermometer Living_Room"}, "name": "mithermometer_living_room_humidity"}'}, {'topic': 'sensor/mithermometer_living_room_battery/config', 'payload': '{"unique_id": "bt-mqtt-gateway_mithermometer_living_room_battery", "state_topic": "mithermometer/living_room/battery", "device_class": "battery", "device": {"identifiers": ["58:2D:34:10:40:D0", "bt-mqtt-gateway_mithermometer_living_room"], "manufacturer": "Xiaomi", "model": "LYWSD(CGQ/01ZM)", "name": "Mithermometer Living_Room"}, "name": "mithermometer_living_room_battery"}'}]
2019-06-26 20:17:48,776 DEBUG bt-mqtt-gw.workers_manager workers_manager.py:116:update_all - Updating all workers
2019-06-26 20:17:48,781 INFO bt-mqtt-gw.workers.mithermometer mithermometer.py:39:status_update - Updating 1 mithermometer devices
2019-06-26 20:17:48,784 DEBUG bt-mqtt-gw.workers.mithermometer mithermometer.py:42:status_update - Updating mithermometer device 'living_room' (58:2D:34:10:40:D0)
2019-06-26 20:17:55,718 ERROR bt-mqtt-gw.workers.mithermometer logger.py:48:log_exception - Error during update of mithermometer device 'living_room' (58:2D:34:10:40:D0): BluetoothBackendException
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/btlewrap/bluepy.py", line 26, in _func_wrapper
    return func(*args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/btlewrap/bluepy.py", line 84, in write_handle
    return self._peripheral.writeCharacteristic(handle, value, True)
  File "/usr/local/lib/python3.7/dist-packages/bluepy/btle.py", line 543, in writeCharacteristic
    return self._getResp('wr')
  File "/usr/local/lib/python3.7/dist-packages/bluepy/btle.py", line 407, in _getResp
    resp = self._waitResp(wantType + ['ntfy', 'ind'], timeout)
  File "/usr/local/lib/python3.7/dist-packages/bluepy/btle.py", line 368, in _waitResp
    raise BTLEGattError("Bluetooth command failed", resp)
bluepy.btle.BTLEGattError: Bluetooth command failed (code: 253, error: Unexpected error code)

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

Traceback (most recent call last):
  File "/home/pi/bt-mqtt-gateway/workers/mithermometer.py", line 45, in status_update
    ret += self.update_device_state(name, data["poller"])
  File "/home/pi/bt-mqtt-gateway/workers/mithermometer.py", line 54, in update_device_state
    ret.append(MqttMessage(topic=self.format_topic(name, attr), payload=poller.parameter_value(attr)))
  File "/usr/local/lib/python3.7/dist-packages/mithermometer/mithermometer_poller.py", line 136, in parameter_value
    self.fill_cache()
  File "/usr/local/lib/python3.7/dist-packages/mithermometer/mithermometer_poller.py", line 78, in fill_cache
    connection.wait_for_notification(_HANDLE_READ_SENSOR_DATA, Cache, self.ble_timeout)
  File "/usr/local/lib/python3.7/dist-packages/btlewrap/bluepy.py", line 26, in _func_wrapper
    return func(*args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/btlewrap/bluepy.py", line 90, in wait_for_notification
    self.write_handle(handle, self._DATA_MODE_LISTEN)
  File "/usr/local/lib/python3.7/dist-packages/btlewrap/bluepy.py", line 32, in _func_wrapper
    raise BluetoothBackendException() from last_error
btlewrap.base.BluetoothBackendException
2019-06-26 20:17:55,752 DEBUG bt-mqtt-gw.workers_manager workers_manager.py:36:execute - Execution result of command MithermometerWorker.status_update: []
Maczuga commented 5 years ago

So far rebooting RPI every hour seems to work just fine. At least I am not getting stuck with empty responses.

bistory commented 5 years ago

By double-checking, I saw the problem is not the same... I'll have to investigate :s

hobbypunk90 commented 5 years ago

@Maczuga can you please check the next time if there is a zombie bluepy-helper?

i have a workaround, which works for me 🙈 i'm running the gateway as docker container on a raspberry pi3. and i check the health status via a check if there is a zombie process. if it is i restart the container. this seams to work for the last 2 oder 3 days 🤔

docker run -d -l autoheal=true --health-cmd "! top -bn1 | grep -v top | grep bluepy-helper | grep Z" --health-retries 5 --health-interval 10s --restart unless-stopped --name bt-mqtt --network=host -v <config_dir>:/config -e DEBUG=true bt-mqtt-gateway and docker run -d --name autoheal --restart=always -v /var/run/docker.sock:/var/run/docker.sock willfarrell/autoheal

i know it only hides the problem, but at this moment, its enough for me😅

StefanoMarchesi commented 5 years ago

Same problem here, but even more frequently, I can't get data most of the time, the only way to get it is to put the thermometer in pairing mode and it works for some seconds

2019-06-27 14:13:02,509 INFO bt-mqtt-gw.workers.mithermometer mithermometer.py:39:status_update - Updating 1 mithermometer devices 2019-06-27 14:13:02,515 DEBUG bt-mqtt-gw.workers.mithermometer mithermometer.py:42:status_update - Updating mithermometer device 'bed_room' (4C:65:A8:DD:37:C7) 2019-06-27 14:13:26,259 ERROR bt-mqtt-gw.workers.mithermometer logger.py:48:log_exception - Error during update of mithermometer device 'bed_room' (4C:65:A8:DD:37:C7): BluetoothBackendException Traceback (most recent call last): File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 26, in _func_wrapper return func(*args, **kwargs) File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 55, in connect self._peripheral = Peripheral(mac, iface=iface) File "/usr/local/lib/python3.5/dist-packages/bluepy/btle.py", line 391, in init self._connect(deviceAddr, addrType, iface) File "/usr/local/lib/python3.5/dist-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 4C:65:A8:DD:37:C7, addr type: public

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

Traceback (most recent call last): File "/home/osmc/bt-mqtt-gateway/workers/mithermometer.py", line 45, in status_update ret += self.update_device_state(name, data["poller"]) File "/home/osmc/bt-mqtt-gateway/workers/mithermometer.py", line 54, in update_device_state ret.append(MqttMessage(topic=self.format_topic(name, attr), payload=poller.parameter_value(attr))) File "/usr/local/lib/python3.5/dist-packages/mithermometer/mithermometer_poller.py", line 136, in parameter_value self.fill_cache() File "/usr/local/lib/python3.5/dist-packages/mithermometer/mithermometer_poller.py", line 60, in fill_cache self.firmware_version() File "/usr/local/lib/python3.5/dist-packages/mithermometer/mithermometer_poller.py", line 109, in firmware_version with self._bt_interface.connect(self._mac) as connection: File "/usr/local/lib/python3.5/dist-packages/btlewrap/base.py", line 44, in enter self._backend.connect(self._mac) File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 32, in _func_wrapper raise BluetoothBackendException() from last_error btlewrap.base.BluetoothBackendException 2019-06-27 14:13:26,321 DEBUG bt-mqtt-gw.workers_manager workers_manager.py:36:execute - Execution result of command MithermometerWorker.status_update: [] 2019-06-27 14:18:02,387 INFO bt-mqtt-gw.workers.mithermometer mithermometer.py:39:status_update - Updating 1 mithermometer devices 2019-06-27 14:18:02,394 DEBUG bt-mqtt-gw.workers.mithermometer mithermometer.py:42:status_update - Updating mithermometer device 'bed_room' (4C:65:A8:DD:37:C7) 2019-06-27 14:18:18,986 ERROR bt-mqtt-gw.workers.mithermometer logger.py:48:log_exception - Error during update of mithermometer device 'bed_room' (4C:65:A8:DD:37:C7): BluetoothBackendException Traceback (most recent call last): File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 26, in _func_wrapper return func(*args, **kwargs) File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 55, in connect self._peripheral = Peripheral(mac, iface=iface) File "/usr/local/lib/python3.5/dist-packages/bluepy/btle.py", line 391, in init self._connect(deviceAddr, addrType, iface) File "/usr/local/lib/python3.5/dist-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 4C:65:A8:DD:37:C7, addr type: public

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

Traceback (most recent call last): File "/home/osmc/bt-mqtt-gateway/workers/mithermometer.py", line 45, in status_update ret += self.update_device_state(name, data["poller"]) File "/home/osmc/bt-mqtt-gateway/workers/mithermometer.py", line 54, in update_device_state ret.append(MqttMessage(topic=self.format_topic(name, attr), payload=poller.parameter_value(attr))) File "/usr/local/lib/python3.5/dist-packages/mithermometer/mithermometer_poller.py", line 136, in parameter_value self.fill_cache() File "/usr/local/lib/python3.5/dist-packages/mithermometer/mithermometer_poller.py", line 60, in fill_cache self.firmware_version() File "/usr/local/lib/python3.5/dist-packages/mithermometer/mithermometer_poller.py", line 109, in firmware_version with self._bt_interface.connect(self._mac) as connection: File "/usr/local/lib/python3.5/dist-packages/btlewrap/base.py", line 44, in enter self._backend.connect(self._mac) File "/usr/local/lib/python3.5/dist-packages/btlewrap/bluepy.py", line 32, in _func_wrapper raise BluetoothBackendException() from last_error btlewrap.base.BluetoothBackendException 2019-06-27 14:18:19,020 DEBUG bt-mqtt-gw.workers_manager workers_manager.py:36:execute - Execution result of command MithermometerWorker.status_update: []

ozczecho commented 5 years ago

I had the same error as @StefanoMarchesi. After trying a few things the following worked for me.

Running sudo hcitool lescan a few times rediscovered the miflora devices and then the bt-mqtt-gateway started working again...

ronytomen commented 5 years ago

I'm wondering if an update occurred to a bluetooth related system package or even the kernel. I didn't have these issues and now I have them. Unfortunately I can't seem to pin point the time of the update nor the suspect package and version.

joselito11 commented 5 years ago

@zewelor gateway is stopping every day! It wont even last 24 hours. When it stops, then only help is restart NUC. Command sudo systemctl restart bt-mqtt-gatewaycause is to restart every few seconds: 

-- Unit bt-mqtt-gateway.service has finished shutting down.
Aug 06 14:07:12 w systemd[1]: Started Bluetooth MQTT gateway.
-- Subject: Unit bt-mqtt-gateway.service has finished start-up
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- Unit bt-mqtt-gateway.service has finished starting up.
-- 
-- The start-up result is RESULT.
Aug 06 14:07:13 w gateway.py[16522]: 14:07:13 Starting
Aug 06 14:07:14 w gateway.py[16522]: 02:07:14 PM Adding 2 miflora devices
Aug 06 14:07:14 w gateway.py[16522]: 02:07:14 PM Fatal error while executing worker command: BTLEManagementError
Aug 06 14:07:14 w gateway.py[16522]: Traceback (most recent call last):
Aug 06 14:07:14 w gateway.py[16522]:   File "/home/w/bt-mqtt-gateway/gateway.py", line 59, in <module>
Aug 06 14:07:14 w gateway.py[16522]:     raise e
Aug 06 14:07:14 w gateway.py[16522]:   File "/home/w/bt-mqtt-gateway/gateway.py", line 49, in <module>
Aug 06 14:07:14 w gateway.py[16522]:     mqtt.publish(_WORKERS_QUEUE.get(timeout=10).execute())
Aug 06 14:07:14 w gateway.py[16522]:   File "/home/w/bt-mqtt-gateway/workers_manager.py", line 34, in execute
Aug 06 14:07:14 w gateway.py[16522]:     messages = self._callback(*self._args)
Aug 06 14:07:14 w gateway.py[16522]:   File "/home/w/bt-mqtt-gateway/workers/toothbrush_homeassistant.py", line 104, in status_update
Aug 06 14:07:14 w gateway.py[16522]:     devices = scanner.scan(5.0)
Aug 06 14:07:14 w gateway.py[16522]:   File "/usr/local/lib/python3.6/dist-packages/bluepy/btle.py", line 852, in scan
Aug 06 14:07:14 w gateway.py[16522]:     self.start(passive=passive)
Aug 06 14:07:14 w gateway.py[16522]:   File "/usr/local/lib/python3.6/dist-packages/bluepy/btle.py", line 790, in start
Aug 06 14:07:14 w gateway.py[16522]:     self._mgmtCmd("le on")
Aug 06 14:07:14 w gateway.py[16522]:   File "/usr/local/lib/python3.6/dist-packages/bluepy/btle.py", line 312, in _mgmtCmd
Aug 06 14:07:14 w gateway.py[16522]:     raise BTLEManagementError("Failed to execute management command '%s'" % (cmd), rsp)
Aug 06 14:07:14 w gateway.py[16522]: bluepy.btle.BTLEManagementError: Failed to execute management command 'le on' (code: 17, error: Invalid Index)
Aug 06 14:07:15 w systemd[1]: bt-mqtt-gateway.service: Main process exited, code=exited, status=1/FAILURE
Aug 06 14:07:15 w systemd[1]: bt-mqtt-gateway.service: Failed with result 'exit-code'.
Aug 06 14:07:15 w systemd[1]: bt-mqtt-gateway.service: Service hold-off time over, scheduling restart.
Aug 06 14:07:15 w systemd[1]: bt-mqtt-gateway.service: Scheduled restart job, restart counter is at 570.
-- Subject: Automatic restarting of a unit has been scheduled
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- Automatic restarting of the unit bt-mqtt-gateway.service has been scheduled, as the result for
-- the configured Restart= setting for the unit.
Aug 06 14:07:15 w systemd[1]: Stopped Bluetooth MQTT gateway.
-- Subject: Unit bt-mqtt-gateway.service has finished shutting down
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- Unit bt-mqtt-gateway.service has finished shutting down.
Aug 06 14:07:15 w systemd[1]: Started Bluetooth MQTT gateway.
-- Subject: Unit bt-mqtt-gateway.service has finished start-up
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- Unit bt-mqtt-gateway.service has finished starting up.
-- 
-- The start-up result is RESULT.
Aug 06 14:07:16 w gateway.py[16569]: 14:07:16 Starting
Aug 06 14:07:18 w gateway.py[16569]: 02:07:18 PM Adding 2 miflora devices
Aug 06 14:07:18 w gateway.py[16569]: 02:07:18 PM Fatal error while executing worker command: BTLEManagementError
Aug 06 14:07:18 w gateway.py[16569]: Traceback (most recent call last):
Aug 06 14:07:18 w gateway.py[16569]:   File "/home/w/bt-mqtt-gateway/gateway.py", line 59, in <module>
Aug 06 14:07:18 w gateway.py[16569]:     raise e
Aug 06 14:07:18 w gateway.py[16569]:   File "/home/w/bt-mqtt-gateway/gateway.py", line 49, in <module>
Aug 06 14:07:18 w gateway.py[16569]:     mqtt.publish(_WORKERS_QUEUE.get(timeout=10).execute())
Aug 06 14:07:18 w gateway.py[16569]:   File "/home/w/bt-mqtt-gateway/workers_manager.py", line 34, in execute
Aug 06 14:07:18 w gateway.py[16569]:     messages = self._callback(*self._args)
Aug 06 14:07:18 w gateway.py[16569]:   File "/home/w/bt-mqtt-gateway/workers/toothbrush_homeassistant.py", line 104, in status_update
Aug 06 14:07:18 w gateway.py[16569]:     devices = scanner.scan(5.0)
Aug 06 14:07:18 w gateway.py[16569]:   File "/usr/local/lib/python3.6/dist-packages/bluepy/btle.py", line 852, in scan
Aug 06 14:07:18 w gateway.py[16569]:     self.start(passive=passive)
Aug 06 14:07:18 w gateway.py[16569]:   File "/usr/local/lib/python3.6/dist-packages/bluepy/btle.py", line 790, in start
Aug 06 14:07:18 w gateway.py[16569]:     self._mgmtCmd("le on")
Aug 06 14:07:18 w gateway.py[16569]:   File "/usr/local/lib/python3.6/dist-packages/bluepy/btle.py", line 312, in _mgmtCmd
Aug 06 14:07:18 w gateway.py[16569]:     raise BTLEManagementError("Failed to execute management command '%s'" % (cmd), rsp)
Aug 06 14:07:18 w gateway.py[16569]: bluepy.btle.BTLEManagementError: Failed to execute management command 'le on' (code: 17, error: Invalid Index)
Aug 06 14:07:18 w systemd[1]: bt-mqtt-gateway.service: Main process exited, code=exited, status=1/FAILURE
Aug 06 14:07:18 w systemd[1]: bt-mqtt-gateway.service: Failed with result 'exit-code'.
Aug 06 14:07:18 w systemd[1]: bt-mqtt-gateway.service: Service hold-off time over, scheduling restart.
Aug 06 14:07:18 w systemd[1]: bt-mqtt-gateway.service: Scheduled restart job, restart counter is at 571.
-- Subject: Automatic restarting of a unit has been scheduled
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- Automatic restarting of the unit bt-mqtt-gateway.service has been scheduled, as the result for
-- the configured Restart= setting for the unit.
Aug 06 14:07:18 w systemd[1]: Stopped Bluetooth MQTT gateway.
-- Subject: Unit bt-mqtt-gateway.service has finished shutting down
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- Unit bt-mqtt-gateway.service has finished shutting down.
Aug 06 14:07:18 w systemd[1]: Started Bluetooth MQTT gateway.
-- Subject: Unit bt-mqtt-gateway.service has finished start-up
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- Unit bt-mqtt-gateway.service has finished starting up.
-- 
-- The start-up result is RESULT.
^C

Command sudo hciconfig hci0 reset is no go: Can't get device info: No such device Something is breaking bluetooth, because command sudo hcitool lescan says: Could not open device: No such device. It works if I restart the whole server on nuc. Where can I search for the problem?

Before I had Monitor, also for scanning bluetooth devices, wich has been working non stop

joselito11 commented 5 years ago

@zewelor Every day after about 8hours of running gateway or at midnight it stops working. Gateway start to restart non stop. Any suggestion? I deleted now miflora, and only use toothbrush

zewelor commented 5 years ago

Looks like this issue: https://github.com/IanHarvey/bluepy/issues/190#issuecomment-394115354 . Im not linux bluetooth stack expert, so I dont have any ideas about this. Maybe some workers combination, doesnt want to work together. Maybe you could write down worker which are causing problems. Except of some bluetooth drivers / stack problems, it might be that some libs doesnt free interface correctly, or something should need to wait longer before pooling bluetooth data.

joselito11 commented 5 years ago

I installed gateway on 2 raspberrys, one with kodi, one with openmediavault, and it is now 1day 1hour up! With 2 workers: oralb and miflora! This was not possible on intel nuc(ubuntu server, docker, HA)!

zewelor commented 5 years ago

@joselito11 On NUC with HA, did you usd any bluetooth integration in HA ? Or maybe bluetooth drivers on NUC are just broken, or needs kernel upgrade etc ?

joselito11 commented 5 years ago

I first used bletooth tracker from HA, for miflora. Few day later I found your script. I have updated linux firmware for kernel? But for bluetooth drivers I found only old post for ubuntu 16.04, so I was not able to update.

Poeschl commented 4 years ago

Having the same issue on a Raspberry Pi Zero with the latest raspberian buster. Running on the newest bluepy version. Can I do anything to help?

jasoncook-fr commented 4 years ago

Hello. Using the bluepy module, I was struggling with a similar issue for a little while myself. I found a way around it thanks to the hints at this thread. On a raspberry zero (as central) receiving sensor data from an esp32 (peripheral). When I power off the ESP the Raspberry gets the initial BTLEDisconnectError then "BTLEInternalError: Helper not started (did you call connect()?)" Then exit. I got around these errors and managed to automatically reconnect by doing the following. Not terribly elegant. But a start. Seems to be working just fine now.

import binascii
import struct
import time
from bluepy.btle import UUID, Peripheral, BTLEDisconnectError, BTLEInternalError

adc_uuid = UUID(0x2A6E)
p = Peripheral()
p.connect("bt:ma:ca:dd:re:ss", "public")

def main():
    print("connecting...")
    ch = p.getCharacteristics(uuid=adc_uuid)[0]
    if (ch.supportsRead()):
        while 1:
            try:
                val = binascii.b2a_hex(ch.read())
                val = binascii.unhexlify(val)
                val = struct.unpack('<h', val)[0]
                print str(val)
                time.sleep(.01)

            except BTLEDisconnectError:
                print "Device disconnected!"
                continue

            except BTLEInternalError:
                print "internal error... ignoring"
                time.sleep(.5)
                print "attempting to reconnect..."
                p.connect("bt:ma:ca:dd:re:ss", "public")
                ch = p.getCharacteristics(uuid=adc_uuid)[0]
                if (ch.supportsRead()):
                    continue
                else:
                    "no connection!!!"

if __name__ == '__main__':
        main()
MissingDLL commented 4 years ago

I do also phase the same issue. Any progress on this?

ajayjohn commented 3 years ago

Same here. Have a Raspberry Pi Zero with dietpi running nothing else but bt-mqtt-gateway. How can I help?

FaserF commented 3 years ago

08:30:51 Error during update of thermostat device 'Bad' (00:1A:22:0A:F7:66): BTLEDisconnectError 08:31:23 Execution of command ThermostatWorker.status_update timed out after 35 seconds 08:31:48 Updating 2 thermostat devices

Same issue. Raspberry Pi 4

Any idea?