search

Hypfer / Valetudo

Cloud replacement for vacuum robots enabling local-only operation
https://valetudo.cloud
Apache License 2.0
6.57k stars 391 forks source link

MQTT handle * failed to configure #947

Closed bruvv closed 3 years ago

bruvv commented 3 years ago

Describe the bug

When I disable homie discovery the MQTT doesn't work anymore.

To Reproduce

Steps to reproduce the behavior:

  1. Go to settings
  2. Click on mqtt
  3. Scroll down to homie autodiscovery
  4. Click on Enabled (so it gets disabled)
  5. See the error in the vacuum log

Vacuum Model

Roborock S50

Valetudo Version

2021.05.0

Expected behavior

Stop homie discovery (since I have no homie, not needed)

Log

[2021-05-26T13:21:20.406Z] [WARN] MQTT handle valetudo/robot/ConsumableMonitoringCapability/brush-side_right failed to configure Error: Handle may only be configured while the MQTT controller is not initialized
    at PropertyMqttHandle.configure (/snapshot/Valetudo/backend/lib/mqtt/handles/MqttHandle.js:160:19)
    at ConsumableMonitoringCapabilityMqttHandle.configure (/snapshot/Valetudo/backend/lib/mqtt/handles/MqttHandle.js:167:29)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async ConsumableMonitoringCapabilityMqttHandle.configure (/snapshot/Valetudo/backend/lib/mqtt/handles/RobotStateNodeMqttHandle.js:30:9)
    at async /snapshot/Valetudo/backend/lib/mqtt/capabilities/ConsumableMonitoringCapabilityMqttHandle.js:162:17
    at async MqttController.reconfigure (/snapshot/Valetudo/backend/lib/mqtt/MqttController.js:452:13)
    at async ConsumableMonitoringCapabilityMqttHandle.findNewConsumables (/snapshot/Valetudo/backend/lib/mqtt/capabilities/ConsumableMonitoringCapabilityMqttHandle.js:153:13)
    at async ConsumableMonitoringCapabilityMqttHandle.refresh (/snapshot/Valetudo/backend/lib/mqtt/capabilities/ConsumableMonitoringCapabilityMqttHandle.js:168:9)
    at async RobotMqttHandle.refresh (/snapshot/Valetudo/backend/lib/mqtt/handles/MqttHandle.js:225:13)
[2021-05-26T13:21:20.409Z] [WARN] MQTT handle valetudo/robot/ConsumableMonitoringCapability/filter-main failed to configure Error: Handle may only be configured while the MQTT controller is not initialized
    at PropertyMqttHandle.configure (/snapshot/Valetudo/backend/lib/mqtt/handles/MqttHandle.js:160:19)
    at ConsumableMonitoringCapabilityMqttHandle.configure (/snapshot/Valetudo/backend/lib/mqtt/handles/MqttHandle.js:167:29)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async ConsumableMonitoringCapabilityMqttHandle.configure (/snapshot/Valetudo/backend/lib/mqtt/handles/RobotStateNodeMqttHandle.js:30:9)
    at async /snapshot/Valetudo/backend/lib/mqtt/capabilities/ConsumableMonitoringCapabilityMqttHandle.js:162:17
    at async MqttController.reconfigure (/snapshot/Valetudo/backend/lib/mqtt/MqttController.js:452:13)
    at async ConsumableMonitoringCapabilityMqttHandle.findNewConsumables (/snapshot/Valetudo/backend/lib/mqtt/capabilities/ConsumableMonitoringCapabilityMqttHandle.js:153:13)
    at async ConsumableMonitoringCapabilityMqttHandle.refresh (/snapshot/Valetudo/backend/lib/mqtt/capabilities/ConsumableMonitoringCapabilityMqttHandle.js:168:9)
    at async RobotMqttHandle.refresh (/snapshot/Valetudo/backend/lib/mqtt/handles/MqttHandle.js:225:13)
[2021-05-26T13:21:20.411Z] [WARN] MQTT handle valetudo/robot/ConsumableMonitoringCapability/sensor-all failed to configure Error: Handle may only be configured while the MQTT controller is not initialized
    at PropertyMqttHandle.configure (/snapshot/Valetudo/backend/lib/mqtt/handles/MqttHandle.js:160:19)
    at ConsumableMonitoringCapabilityMqttHandle.configure (/snapshot/Valetudo/backend/lib/mqtt/handles/MqttHandle.js:167:29)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async ConsumableMonitoringCapabilityMqttHandle.configure (/snapshot/Valetudo/backend/lib/mqtt/handles/RobotStateNodeMqttHandle.js:30:9)
    at async /snapshot/Valetudo/backend/lib/mqtt/capabilities/ConsumableMonitoringCapabilityMqttHandle.js:162:17
    at async MqttController.reconfigure (/snapshot/Valetudo/backend/lib/mqtt/MqttController.js:452:13)
    at async ConsumableMonitoringCapabilityMqttHandle.findNewConsumables (/snapshot/Valetudo/backend/lib/mqtt/capabilities/ConsumableMonitoringCapabilityMqttHandle.js:153:13)
    at async ConsumableMonitoringCapabilityMqttHandle.refresh (/snapshot/Valetudo/backend/lib/mqtt/capabilities/ConsumableMonitoringCapabilityMqttHandle.js:168:9)
    at async RobotMqttHandle.refresh (/snapshot/Valetudo/backend/lib/mqtt/handles/MqttHandle.js:225:13)
flacjacket commented 3 years ago

I'm seeing this as well, see #857 for the information I found there. There was an attempt to fix this between 2021.4 and 2021.5, but it looks like there is still some edge case around having one and not the other of the autodiscovery protocols enabled.

Hypfer commented 3 years ago

Please check if 5b4b377f98c5030aa13f2133b5a220c3366fae57 solves this issue for you

flacjacket commented 3 years ago

I can confirm that using the version built here fixes this problem for me.

bruvv commented 3 years ago

Sorry for the late reply didn't test it yet, thanks for stepping in @flacjacket

bruvv commented 3 years ago 
[2021-06-25T05:47:26.170Z] [ERROR] unhandledRejection Error: client disconnecting
    at MqttClient._checkDisconnecting (/snapshot/Valetudo/node_modules/mqtt/lib/client.js:446:16)
    at MqttClient.publish (/snapshot/Valetudo/node_modules/mqtt/lib/client.js:489:12)
    at /snapshot/Valetudo/node_modules/async-mqtt/index.js:28:20
    at new Promise (<anonymous>)
    at AsyncClient.publish (/snapshot/Valetudo/node_modules/async-mqtt/index.js:27:12)
    at MqttController.setState (/snapshot/Valetudo/backend/lib/mqtt/MqttController.js:414:32)
    at /snapshot/Valetudo/backend/lib/mqtt/MqttController.js:479:32
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
[2021-06-25T05:47:27.542Z] [INFO] Connected successfully to MQTT broker

Still having issues, see above error. Followed the upgrade instructions (to upgrade to Valetudo 2021.06.0) and after reflashing system b and than a and reconfigure the MQTT client it successfully connected to the server. Now 24h later I see this spam of errors.

Hypfer commented 3 years ago

So theres still a race condition somewhere.

@Depau already had some ideas how to fix this properly:

Davide Depau 🏳️‍🌈, [31.05.21 11:24] I think this should need a more careful implementation using this mutex idea but with a proper finite state machine, with some additional internal states that map to homie state "init" but that has a more specific internal meaning

Davide Depau 🏳️‍🌈, [31.05.21 11:24] This way we can have a proper table of allowed state transitions

Davide Depau 🏳️‍🌈, [31.05.21 11:29] Which can be something like

DISCONNECTED → STARTUP → RECONFIGURE → READY reconfigure: READY → RECONFIGURE → READY shutdown: READY → TEARDOWN → DISCONNECTED

with STARTUP being a fake state that is only triggered explicitly by the mqtt controller to otherwise disallow going from disconnected to reconfigure, and TEARDOWN being otherwise identical to RECONFIGURE except any other state transition will fail

Davide Depau 🏳️‍🌈, [31.05.21 11:31] With allowed transitions:

DISCONNECTED: STARTUP STARTUP: RECONFIGURE RECONFIGURE: READY READY: RECONFIGURE, TEARDOWN TEARDOWN: DISCONNECTED

Davide Depau 🏳️‍🌈, [31.05.21 11:32] The advantage of this approach is that while it sounds kinda complex it's actually extremely easy to implement and extremely hard to mess up being there a finite number of states

Davide Depau 🏳️‍🌈, [31.05.21 11:37] It might make sense though to have an additional error state in case mqtt.js explodes

Davide Depau 🏳️‍🌈, [31.05.21 11:37] Which can only take the shutdown route, then needs to do the reconnection

Davide Depau 🏳️‍🌈, [31.05.21 11:39] I noticed that while mqtt.js technically does handle reconnection, it sometimes will lose subscriptions to topics, so it's probably better to stick in an error state as long as MQTT.js is not working, then take it down and reconnect

Knapoc commented 3 years ago

I'm having similar issues but for me it does not matter if Homie auto discovery is enabled or not (Home Assistant auto discovery is turned on).

[2021-07-30T11:01:12.266Z] [ERROR] MQTT reconfiguration error Error: client disconnecting
    at MqttClient._checkDisconnecting (/snapshot/Valetudo/node_modules/mqtt/lib/client.js:446:16)
    at MqttClient.publish (/snapshot/Valetudo/node_modules/mqtt/lib/client.js:489:12)
    at /snapshot/Valetudo/node_modules/async-mqtt/index.js:28:20
    at new Promise (<anonymous>)
    at AsyncClient.publish (/snapshot/Valetudo/node_modules/async-mqtt/index.js:27:12)
    at MqttController.setState (/snapshot/Valetudo/backend/lib/mqtt/MqttController.js:418:32)
    at /snapshot/Valetudo/backend/lib/mqtt/MqttController.js:475:32
    at item.task (/snapshot/Valetudo/node_modules/semaphore/lib/semaphore.js:40:29)
    at processTicksAndRejections (node:internal/process/task_queues:78:11)
[2021-07-30T11:01:12.275Z] [ERROR] unhandledRejection Error: client disconnecting
    at MqttClient._checkDisconnecting (/snapshot/Valetudo/node_modules/mqtt/lib/client.js:446:16)
    at MqttClient.publish (/snapshot/Valetudo/node_modules/mqtt/lib/client.js:489:12)
    at /snapshot/Valetudo/node_modules/async-mqtt/index.js:28:20
    at new Promise (<anonymous>)
    at AsyncClient.publish (/snapshot/Valetudo/node_modules/async-mqtt/index.js:27:12)
    at MqttController.setState (/snapshot/Valetudo/backend/lib/mqtt/MqttController.js:418:32)
    at /snapshot/Valetudo/backend/lib/mqtt/MqttController.js:483:32
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
bruvv commented 3 years ago

which version are you running @Knapoc ?

Knapoc commented 3 years ago

This log is based on the most recent release.

Hypfer commented 3 years ago

I didn't add the FSM because I'm lazy.

Anyways, it should be fixed. Please try https://github.com/Hypfer/Valetudo/actions/runs/1121289123