icanos / hassio-plejd

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

Develop branch: Items reported incorrectly online #194

Open faanskit opened 3 years ago

faanskit commented 3 years ago

Issue - devices online when they are surely offline

Even though a BT module is not present, or if there are now Plejd devices available (due to power off). The devices are reported to to be online, and with that available in the Ui.

Expected behavior is that ./online is only sent if there is an active BLE device. (I know about the issue with reconnect).

hassio-plej log

2021-05-11 10:17:48 INF [plejd-ble] init()
2021-05-11 10:17:49 INF [plejd-mqtt] Connected to MQTT.
2021-05-11 10:17:49 INF [plejd-mqtt] Sending discovery for 4 Plejd output devices
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered CTR-01 (switch) named Relä (12 : C061998B0B5F_0).
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered DIM-02 (light) named Dimmer_2_1 (15 : D670E6FE619D_0).
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered DIM-02 (light) named Dimmer_2_2 (16 : D670E6FE619D_1).
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered DIM-01 (light) named Dimmer (13 : C12D372125FD_0).
2021-05-11 10:17:49 INF [plejd-mqtt] Sending discovery for 4 Plejd input devices
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered WPH-01 (device_automation) named Vippa (11 : F7EFCACF2614_I_1).
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered WPH-01 (device_automation) named Vippa (11 : F7EFCACF2614_I_2).
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered WPH-01 (device_automation) named Vippa (11 : F7EFCACF2614_I_3).
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered WPH-01 (device_automation) named Vippa (11 : F7EFCACF2614_I_0).
2021-05-11 10:17:49 INF [plejd-mqtt] Sending discovery for 2 Plejd scene devices
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered Scene (scene) named LeftOn (1 : ed815a49-5f12-4def-bb90-edc90e5c2603).
2021-05-11 10:17:49 INF [plejd-mqtt] Discovered Scene (scene) named LeftOff (2 : 8d74b717-9fe4-496a-b708-6d38786bc506).
2021-05-11 10:17:51 INF [device-comm] Plejd got turn off command for Relä (C061998B0B5F_0)
2021-05-11 10:17:51 INF [device-comm] Plejd got turn off command for Dimmer_2_1 (D670E6FE619D_0)
2021-05-11 10:17:51 INF [device-comm] Plejd got turn off command for Dimmer (C12D372125FD_0)
2021-05-11 10:17:54 INF [plejd-ble] BLE init done, waiting for devices.
2021-05-11 10:17:54 INF [plejd-main] Main init done
2021-05-11 10:17:54 INF [plejd-main] main() finished
2021-05-11 10:17:55 ERR [plejd-ble] Discovery timeout elapsed, no devices found. Starting reconnect loop...
2021-05-11 10:17:55 INF [plejd-ble] Starting reconnect loop...
2021-05-11 10:17:55 INF [device-comm] Bluetooth reconnecting...

MQTT log

homeassistant/switch/plejd/C061998B0B5F_0/state OFF
homeassistant/switch/plejd/C061998B0B5F_0/availability online
homeassistant/light/plejd/D670E6FE619D_0/availability online
homeassistant/light/plejd/D670E6FE619D_1/availability online
homeassistant/light/plejd/C12D372125FD_0/availability online
homeassistant/scene/plejd/ed815a49-5f12-4def-bb90-edc90e5c2603/availability online
homeassistant/scene/plejd/8d74b717-9fe4-496a-b708-6d38786bc506/availability online

Question 2 - Stray commands?

Each startup I see these three stray commands. Can someone please explain them? They surely do not originate from the BLE in this case since Bluetooth is offline. They are send every start since some time back.

2021-05-11 10:17:51 INF [device-comm] Plejd got turn off command for Relä (C061998B0B5F_0)
2021-05-11 10:17:51 INF [device-comm] Plejd got turn off command for Dimmer_2_1 (D670E6FE619D_0)
2021-05-11 10:17:51 INF [device-comm] Plejd got turn off command for Dimmer (C12D372125FD_0)
SweVictor commented 3 years ago

First issue is being discussed in #186, let's continue there. Basically I agree - BLE disconnect should trigger available=OFF.

Q2: Stray commands: I'm guessing mqtt? AFAIK mqtt and BLE are the only two sources of info. Can you see with more verbose logging the origin?

faanskit commented 3 years ago

Gone are the messages on MQTT, but now this comes in the logs instead. Strange. Repeats every restart of the app.

2021-05-11 21:01:52 INF [device-comm] startWriteQueue()
2021-05-11 21:01:52 DBG [device-comm] Write queue: Processing Relä (C061998B0B5F_0). Command Turn off. Total queue length: 2
2021-05-11 21:01:52 VRB [plejd-ble] Sending 6 byte(s) of data to Plejd. 0c0110009700
2021-05-11 21:01:52 DBG [device-comm] Write queue: Processing Dimmer_2_1 (D670E6FE619D_0). Command Turn off. Total queue length: 1
2021-05-11 21:01:52 VRB [plejd-ble] Sending 6 byte(s) of data to Plejd. 0f0110009700
2021-05-11 21:01:52 DBG [device-comm] Write queue: Processing Dimmer (C12D372125FD_0). Command Turn off. Total queue length: 0