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

Service hang up and didn't recover from it #227

Open Kirbo opened 3 years ago

Kirbo commented 3 years ago

Describe the bug Getting errors occasionally, until stops working.

I have setup this on brand spanking new Raspberry Pi 4+ with 8GB memory. I'm running this on docker container, via docker-compose.

There is nothing else running on the Rasp.

Started with command:

$ docker-compose up -d

Expected behaviour Not to crash/hang up OR at least recover if it did (restart automatically, or something)

Config Configuration is as following:

$ cat docker-compose.yml 
version: '3.7'

services:
  bt-mqtt-gateway:
    image: zewelor/bt-mqtt-gateway
    container_name: bt-mqtt-gateway
    restart: always
    # Uncomment to enable debug
    #environment:
    #  - DEBUG=true
    volumes:
      - ./config.yaml:/config.yaml
    cap_add:
      - NET_ADMIN
      - NET_RAW
    network_mode: host
$ cat config.yaml
mqtt:
  host: <redacted>
  port: 1883
  username: <redacted>
  password: <redacted>
  topic_prefix: rasp4
  client_id: bt-mqtt-gateway
  availability_topic: lwt_topic

manager:
  sensor_config:
    topic: homeassistant
    retain: true
  topic_subscription:
    update_all:
      topic: homeassistant/status
      payload: online
  command_timeout: 35
  command_retries: 0
  update_retries: 0
  workers:
    miflora:
      args:
        devices:
          Liuska-aralia: <redacted>
        topic_prefix: miflora
        per_device_timeout: 6
      update_interval: 300
    ruuvitag:
      args:
        devices:
          sauna: <redacted>
          takapiha: <redacted>
          parveke: <redacted>
          makuuhuone: <redacted>
          muksun_huone: <redacted>
          olohuone: <redacted>
          kylpyhuone: <redacted>
          eteinen: <redacted>
          keittio: <redacted>
          viileakaappi: <redacted>
          jaakaappi: <redacted>
          pakastin: <redacted>
        topic_prefix: ruuvitag
      update_interval: 60

Debug gateway logs Here's the log output:

Start in normal mode
16:50:23 Starting
16:50:23 Adding 1 miflora devices
16:50:24 Adding 12 ruuvitag devices
16:50:24 Updating 1 miflora devices
16:50:25 Updating 12 ruuvitag devices
16:51:00 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
16:51:24 Updating 12 ruuvitag devices
16:52:24 Updating 12 ruuvitag devices
16:53:24 Updating 12 ruuvitag devices
...
...
...
22:18:24 Updating 12 ruuvitag devices
22:18:59 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
22:19:24 Updating 12 ruuvitag devices
22:20:24 Updating 1 miflora devices
22:20:27 Updating 12 ruuvitag devices
22:21:28 Updating 12 ruuvitag devices
22:22:03 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
22:22:24 Updating 12 ruuvitag devices
22:23:24 Updating 12 ruuvitag devices
22:24:24 Updating 12 ruuvitag devices
22:24:59 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
22:25:24 Updating 1 miflora devices
22:25:29 Updating 12 ruuvitag devices
Exception ignored in: <generator object BleCommunicationNix.get_datas at 0xb5c709c8>
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/ruuvitag_sensor/adapters/nix_hci.py", line 109, in get_datas
    BleCommunicationNix.stop(procs[0], procs[1])
  File "/usr/local/lib/python3.8/site-packages/ruuvitag_sensor/adapters/nix_hci.py", line 67, in stop
    hcidump.close()
  File "/usr/local/lib/python3.8/site-packages/ptyprocess/ptyprocess.py", line 403, in close
    time.sleep(self.delayafterclose)
  File "/usr/local/lib/python3.8/site-packages/interruptingcow/__init__.py", line 74, in handler
    raise exception
exceptions.WorkerTimeoutError: Execution of command RuuvitagWorker.status_update timed out after 35 seconds
22:26:24 Updating 12 ruuvitag devices
Exception ignored in: <generator object BleCommunicationNix.get_datas at 0xb5c49d10>
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/ruuvitag_sensor/adapters/nix_hci.py", line 109, in get_datas
    BleCommunicationNix.stop(procs[0], procs[1])
  File "/usr/local/lib/python3.8/site-packages/ruuvitag_sensor/adapters/nix_hci.py", line 66, in stop
    hcitool.close()
  File "/usr/local/lib/python3.8/site-packages/ptyprocess/ptyprocess.py", line 403, in close
    time.sleep(self.delayafterclose)
  File "/usr/local/lib/python3.8/site-packages/interruptingcow/__init__.py", line 74, in handler
    raise exception
exceptions.WorkerTimeoutError: Execution of command RuuvitagWorker.status_update timed out after 35 seconds
22:27:24 Updating 12 ruuvitag devices
22:28:24 Updating 12 ruuvitag devices
22:29:24 Updating 12 ruuvitag devices
Exception ignored in: <generator object BleCommunicationNix.get_datas at 0xb5c45338>
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/ruuvitag_sensor/adapters/nix_hci.py", line 109, in get_datas
    BleCommunicationNix.stop(procs[0], procs[1])
  File "/usr/local/lib/python3.8/site-packages/ruuvitag_sensor/adapters/nix_hci.py", line 67, in stop
    hcidump.close()
  File "/usr/local/lib/python3.8/site-packages/ptyprocess/ptyprocess.py", line 403, in close
    time.sleep(self.delayafterclose)
  File "/usr/local/lib/python3.8/site-packages/interruptingcow/__init__.py", line 74, in handler
    raise exception
exceptions.WorkerTimeoutError: Execution of command RuuvitagWorker.status_update timed out after 35 seconds
22:30:25 Updating 1 miflora devices
22:30:31 Error during update of miflora device 'Liuska-aralia' (<redacted>): BluetoothBackendException
22:30:31 Updating 12 ruuvitag devices
22:31:06 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
22:31:24 Updating 12 ruuvitag devices
Exception ignored in: <function _releaseLock at 0xb6b4d970>
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/logging/__init__.py", line 227, in _releaseLock
    def _releaseLock():
  File "/usr/local/lib/python3.8/site-packages/interruptingcow/__init__.py", line 74, in handler
    raise exception
exceptions.WorkerTimeoutError: Execution of command RuuvitagWorker.status_update timed out after 35 seconds

// Here it hang up, didn't crash nor recover, had to manually call `docker-compose restart`

Start in normal mode
08:26:57 Starting
08:26:58 Adding 1 miflora devices
08:26:58 Adding 12 ruuvitag devices
08:26:58 Updating 1 miflora devices
08:27:04 Time out during update of miflora device 'Liuska-aralia' (<redacted>)
08:27:04 Updating 12 ruuvitag devices
08:27:39 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:27:58 Updating 12 ruuvitag devices
08:28:58 Updating 12 ruuvitag devices
08:29:58 Updating 12 ruuvitag devices
08:30:58 Updating 12 ruuvitag devices
08:31:58 Updating 1 miflora devices
08:31:59 Updating 12 ruuvitag devices
08:32:58 Updating 12 ruuvitag devices
08:33:33 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:33:58 Updating 12 ruuvitag devices
08:34:33 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:34:58 Updating 12 ruuvitag devices
08:35:58 Updating 12 ruuvitag devices
08:36:58 Updating 1 miflora devices
08:37:00 Updating 12 ruuvitag devices
08:37:35 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:37:58 Updating 12 ruuvitag devices
08:38:58 Updating 12 ruuvitag devices
08:39:33 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:39:58 Updating 12 ruuvitag devices
08:40:58 Updating 12 ruuvitag devices
08:41:33 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:41:58 Updating 1 miflora devices
08:42:03 Error during update of miflora device 'Liuska-aralia' (<redacted>): BluetoothBackendException
08:42:03 Updating 12 ruuvitag devices
Exception ignored in: <generator object BleCommunicationNix.get_datas at 0xb5e99e98>
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/ruuvitag_sensor/adapters/nix_hci.py", line 109, in get_datas
    BleCommunicationNix.stop(procs[0], procs[1])
  File "/usr/local/lib/python3.8/site-packages/ruuvitag_sensor/adapters/nix_hci.py", line 66, in stop
    hcitool.close()
  File "/usr/local/lib/python3.8/site-packages/ptyprocess/ptyprocess.py", line 403, in close
    time.sleep(self.delayafterclose)
  File "/usr/local/lib/python3.8/site-packages/interruptingcow/__init__.py", line 74, in handler
    raise exception
exceptions.WorkerTimeoutError: Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:42:58 Updating 12 ruuvitag devices
08:43:58 Updating 12 ruuvitag devices
08:44:58 Updating 12 ruuvitag devices
08:45:33 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:45:58 Updating 12 ruuvitag devices
08:46:33 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:46:58 Updating 1 miflora devices
08:47:02 Updating 12 ruuvitag devices
08:47:58 Updating 12 ruuvitag devices
08:48:58 Updating 12 ruuvitag devices
08:49:58 Updating 12 ruuvitag devices
08:50:58 Updating 12 ruuvitag devices
08:51:58 Updating 1 miflora devices
08:51:59 Updating 12 ruuvitag devices
08:52:58 Updating 12 ruuvitag devices
08:53:33 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:53:58 Updating 12 ruuvitag devices
08:54:58 Updating 12 ruuvitag devices
08:55:33 Execution of command RuuvitagWorker.status_update timed out after 35 seconds
08:55:58 Updating 12 ruuvitag devices
08:56:33 Execution of command RuuvitagWorker.status_update timed out after 35 seconds

Server (please complete the following information):

$ cat /etc/os-release 
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
$ bluetoothctl -v
bluetoothctl: 5.50
$ cat /etc/rpi-issue
Raspberry Pi reference 2021-03-04
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 461109415073d2eb67083709662ba983cc191f14, stage5
$ vcgencmd version
Feb 25 2021 12:10:40 
Copyright (c) 2012 Broadcom
version 564e5f9b852b23a330b1764bcf0b2d022a20afd0 (clean) (release) (start)
$ uname -a
Linux raspberrypi 5.10.17-v7l+ #1403 SMP Mon Feb 22 11:33:35 GMT 2021 armv7l GNU/Linux
jjimenezlopez commented 2 years ago

Hi, any update on this? I've started using bt-mqtt-gateway some days ago and I'm having the same issue.

Kirbo commented 2 years ago

I don’t know. I bought a Ruuvi Gateway and use it to listen to RuuviTags and Xiaomi MiFlora sensors, with this addon on Home Assistant and everything is working perfectly for me: https://github.com/kirbo/ha-addons-repository