search

icanos / hassio-plejd

Hass.io add-on for Plejd home automation devices
Apache License 2.0
126 stars 37 forks source link

Plejd Add-ons stops communicating with Bluetooth USB #267

Open TompaNation opened 1 year ago

TompaNation commented 1 year ago

Hi

I have got some issues with my new Home Assistant Yellow PoE. Or rather I have got some issuse with my new Avantree DG40S USB Bluetooth 4.0. I’m using the Plejd Add-ons and this has not been a issue with my old settup with a rpi 4 with built-in WiFi/Bluetooth. The issue is that everything works fine for a couple of hours and then the Plejd Add-ons can’t communicate with the DG40S USB Bluetooth. I added the log from the Plejd Add-ons. But I really just want to know if more people have or had the same issue? And if anyone has a solution for this?

###########LOG########№#

2023-02-08 23:15:04 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 00:15:04 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 01:15:04 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 02:14:56 ERR [plejd-ble] 'Unlikely error' (0x0e) writing to Plejd. Will retry. Operation failed with ATT error: 0x0e DBusError: Operation failed with ATT error: 0x0e at _methodReturnHandlers. (/plejd/node_modules/dbus-next/lib/bus.js:343:27) at handleMessage (/plejd/node_modules/dbus-next/lib/bus.js:101:11) at EventEmitter. (/plejd/node_modules/dbus-next/lib/bus.js:151:9) at EventEmitter.emit (events.js:314:20) at /plejd/node_modules/dbus-next/lib/connection.js:116:14 at Socket. (/plejd/nodemodules/dbus-next/lib/message.js:63:9) at Socket.emit (events.js:314:20) at emitReadable (_stream_readable.js:557:12) at processTicksAndRejections (internal/process/task_queues.js:83:21) 2023-02-09 02:14:58 ERR [plejd-ble] 'Method "WriteValue" doesn't exist'. Plejd device is probably disconnected. 2023-02-09 02:14:58 WRN [plejd-ble] Write error indicates BLE is disconnected. Retry count 2. Reconnecting... 2023-02-09 02:14:58 INF [plejd-ble] Starting reconnect loop... 2023-02-09 02:14:58 INF [device-comm] Bluetooth reconnecting... 2023-02-09 02:15:03 INF [plejd-ble] Reconnecting BLE... 2023-02-09 02:15:03 INF [plejd-ble] init() 2023-02-09 02:15:08 INF [plejd-ble] BLE init done, waiting for devices. 2023-02-09 02:15:20 INF [plejd-ble] Device discovery done, found 1 Plejd devices 2023-02-09 02:15:20 INF [plejd-ble] Connecting to /org/bluez/hci0/dev_F6_64_3E_8A_46_CB 2023-02-09 02:15:32 INF [plejd-ble] onDeviceConnected() 2023-02-09 02:15:32 INF [plejd-ble] Connected device is a Plejd device with the right characteristics. 2023-02-09 02:15:32 INF [plejd-ble] authenticate() 2023-02-09 02:15:33 INF [plejd-ble] BLE Connected to undefined 2023-02-09 02:15:33 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 02:15:33 INF [plejd-ble] startPing() 2023-02-09 02:15:33 INF [device-comm] Bluetooth connected. Plejd BLE up and running! 2023-02-09 02:15:33 INF [device-comm] startWriteQueue() 2023-02-09 03:15:33 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 04:15:33 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 05:15:33 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 06:15:33 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 06:54:17 INF [device-comm] Plejd got turn on command for Lampa fönstersmyg (E49016EDF941_0), brightness undefined 2023-02-09 06:54:19 INF [device-comm] Plejd got turn off command for Lampa fönstersmyg (E49016EDF941_0) 2023-02-09 07:15:33 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 08:15:33 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 09:15:33 INF [plejd-ble] Requesting current Plejd time... 2023-02-09 09:46:35 WRN [plejd-ble] Write error indicates BLE is disconnected. Retry count 5. Reconnecting... 2023-02-09 09:46:35 INF [plejd-ble] Starting reconnect loop... 2023-02-09 09:46:35 INF [device-comm] Bluetooth reconnecting... 2023-02-09 09:46:40 INF [plejd-ble] Reconnecting BLE... 2023-02-09 09:46:40 INF [plejd-ble] init() 2023-02-09 09:46:45 INF [plejd-ble] disconnecting /org/bluez/hci0/dev_F6_64_3E_8A_46_CB. This can take up to 180 seconds 2023-02-09 09:46:50 ERR [plejd-ble] 'Unlikely error' (0x0e) writing to Plejd. Will retry. Operation failed with ATT error: 0x0e DBusError: Operation failed with ATT error: 0x0e at _methodReturnHandlers. (/plejd/node_modules/dbus-next/lib/bus.js:343:27) at handleMessage (/plejd/node_modules/dbus-next/lib/bus.js:101:11) at EventEmitter. (/plejd/node_modules/dbus-next/lib/bus.js:151:9) at EventEmitter.emit (events.js:314:20) at /plejd/node_modules/dbus-next/lib/connection.js:116:14 at Socket. (/plejd/nodemodules/dbus-next/lib/message.js:63:9) at Socket.emit (events.js:314:20) at emitReadable (_stream_readable.js:557:12) at processTicksAndRejections (internal/process/task_queues.js:83:21) 2023-02-09 09:48:35 WRN [plejd-ble] Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen! 2023-02-09 09:48:35 INF [device-comm] Bluetooth reconnecting... 2023-02-09 09:48:40 INF [plejd-ble] Reconnecting BLE... 2023-02-09 09:48:40 INF [plejd-ble] init() 2023-02-09 09:48:45 INF [plejd-ble] disconnecting /org/bluez/hci0/dev_F6_64_3E_8A_46_CB. This can take up to 180 seconds 2023-02-09 09:50:35 WRN [plejd-ble] Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen! 2023-02-09 09:50:35 INF [device-comm] Bluetooth reconnecting... 2023-02-09 09:50:40 INF [plejd-ble] Reconnecting BLE... 2023-02-09 09:50:40 INF [plejd-ble] init() 2023-02-09 09:50:45 INF [plejd-ble] disconnecting /org/bluez/hci0/dev_F6_64_3E_8A_46_CB. This can take up to 180 seconds 2023-02-09 09:52:35 WRN [plejd-ble] Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen! 2023-02-09 09:52:35 INF [device-comm] Bluetooth reconnecting... 2023-02-09 09:52:40 INF [plejd-ble] Reconnecting BLE... 2023-02-09 09:52:40 INF [plejd-ble] init() 2023-02-09 09:52:45 INF [plejd-ble] disconnecting /org/bluez/hci0/dev_F6_64_3E_8A_46_CB. This can take up to 180 seconds 2023-02-09 09:54:35 WRN [plejd-ble] Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen! 2023-02-09 09:54:35 INF [device-comm] Bluetooth reconnecting... 2023-02-09 09:54:40 INF [plejd-ble] Reconnecting BLE... 2023-02-09 09:54:40 INF [plejd-ble] init() 2023-02-09 09:54:45 INF [plejd-ble] disconnecting /org/bluez/hci0/dev_F6_64_3E_8A_46_CB. This can take up to 180 seconds 2023-02-09 09:56:35 WRN [plejd-ble] Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen! 2023-02-09 09:56:35 INF [device-comm] Bluetooth reconnecting... 2023-02-09 09:56:40 INF [plejd-ble] Reconnecting BLE... 2023-02-09 09:56:40 INF [plejd-ble] init() 2023-02-09 09:56:45 INF [plejd-ble] disconnecting /org/bluez/hci0/dev_F6_64_3E_8A_46_CB. This can take up to 180 seconds 2023-02-09 09:58:35 WRN [plejd-ble] Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen! 2023-02-09 09:58:35 INF [device-comm] Bluetooth reconnecting... 2023-02-09 09:58:40 INF [plejd-ble] Reconnecting BLE... 2023-02-09 09:58:40 INF [plejd-ble] init() 2023-02-09 09:58:45 INF [plejd-ble] disconnecting /org/bluez/hci0/dev_F6_64_3E_8A_46_CB. This can take up to 180 seconds 2023-02-09 10:00:35 WRN [plejd-ble] Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen! 2023-02-09 10:00:35 INF [device-comm] Bluetooth reconnecting... 2023-02-09 10:00:40 INF [plejd-ble] Reconnecting BLE... 2023-02-09 10:00:40 INF [plejd-ble] init() 2023-02-09 10:00:45 INF [plejd-ble] disconnecting /org/bluez/hci0/dev_F6_64_3E_8A_46_CB. This can take up to 180 seconds 2023-02-09 10:02:35 WRN [plejd-ble] Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen! 2023-02-09 10:02:35 INF [device-comm] Bluetooth reconnecting... 2023-02-09 10:02:40 INF [plejd-ble] Reconnecting BLE... 2023-02-09 10:02:40 INF [plejd-ble] init() 2023-02-09 10:02:45 INF [plejd-ble] disconnecting /org/bluez/hci0/dev_F6_64_3E_8A_46_CB. This can take up to 180 seconds 2023-02-09 10:04:35 WRN [plejd-ble] Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen! 2023-02-09 10:04:35 WRN [plejd-ble] Tried reconnecting 10 times. Will power cycle the BLE adapter now... 2023-02-09 19:13:54 INF [device-comm] Plejd got turn on command for Lampa fönstersmyg (E49016EDF941_0), brightness undefined

tezmo commented 1 year ago

I had the exact same issue, kept trying to reconnect and not able to create any stable Bluetooth connection.

Should have saved the logs, but managed to get my entire home assistant rolled back to before Feb 14th (apparently I did an update of something then) and everything started working again.

My guess is something in this Plejd add-on doesn't want to play nice with the new Bluetooth functionality in HA, but have no basis for that claim..

mist0706 commented 1 year ago

i have the same issue, have tried with multiple bluetooth devices and they all seem to work for the first 60 seconds and then the reconnection starts: image

SweVictor commented 1 year ago

These are always tricky. If you don't solve it, I suggest following the troubleshooting instructions, increasing the log level and uploading/linking a full log (formatted a bit easier to read), maybe someone can help. Also posting as code rather than text helps...

From the log above, the only odd thing I can see is the log line 

WRN [plejd-ble] Write error indicates BLE is disconnected. Retry count 5. Reconnecting...

I don't think I ever get write errors on my system... Maybe the BLE adapter is too far away from a Plejd device to get a good connection?