Hello,
I observe quite strange behavior with MQTT Client.
I have MQTT Hub, where all devices are published to topic homie/homey-5dd…1/#
I also have other devices which publish messages like openHab/# and UPS/#
I have two flows which subscribe to topic: UPS/status and openHab/Okno3/BlindsControl.
But those flows get disabled due to too much run.
What is most strange is log from MQTT Hub:
20210322-18:41:39 publish_options: {“qos”:0,“retain”:true}
20210322-18:41:39 send 0 on topic homie/homey-5dd…1/town/measure-cloudiness
20210322-18:41:39 OnMessage called
20210322-18:41:39 received ‘’ on ‘homie/homey-5dd…1/town/measure-cloudiness’
20210322-18:41:39 Trigger generic card for homie/homey-5dd…1/town/measure-cloudiness
20210322-18:41:39 send message to listeners via realtime api
20210322-18:41:39 homie/homey-5dd…1/town/measure-cloudiness:
20210322-18:41:39 Listener eventMQTT called
20210322-18:41:39 state.topic = homie/homey-5dd…1/town/measure-cloudiness topic = UPS/status
20210322-18:41:39 topic: homie/homey-5dd…1/town/measure-cloudiness pattern: UPS/status
20210322-18:41:39 We are not waiting for this topic
20210322-18:41:39 Listener eventMQTT called
20210322-18:41:39 state.topic = homie/homey-5dd…1/town/measure-cloudiness topic = openHab/Okno3/BlindsControl
20210322-18:41:39 topic: homie/homey-5dd…1/town/measure-cloudiness pattern: openHab/Okno3/BlindsControl
20210322-18:41:39 We are not waiting for this topic
20210322-18:41:39 SendMessageToTopic called
20210322-18:41:39 SendMessageToTopic: {“qos”:0,“retain”:“1”,“mqttTopic”:“homie/homey-5dd…1/town/description”,“mqttMessage”:“clear sky”}
20210322-18:41:39 publish_options: {“qos”:0,“retain”:true}
20210322-18:41:39 send clear sky on topic homie/homey-5dd…1/town/description
20210322-18:41:39 OnMessage called
20210322-18:41:39 received ‘clear sky’ on ‘homie/homey-5dd…1/town/description’
20210322-18:41:39 Trigger generic card for homie/homey-5dd…1/town/description
20210322-18:41:39 send message to listeners via realtime api
20210322-18:41:39 homie/homey-5dd…1/town/description: clear sky
20210322-18:41:39 SendMessageToTopic called
20210322-18:41:39 SendMessageToTopic: {“qos”:0,“retain”:“1”,“mqttTopic”:“homie/homey-5dd…1/town/conditioncode”,“mqttMessage”:“Clear”}
20210322-18:41:39 publish_options: {“qos”:0,“retain”:true}
20210322-18:41:39 send Clear on topic homie/homey-5dd…1/town/conditioncode
20210322-18:41:39 Listener eventMQTT called
20210322-18:41:39 state.topic = homie/homey-5dd…1/town/description topic = UPS/status
20210322-18:41:39 topic: homie/homey-5dd…1/town/description pattern: UPS/status
20210322-18:41:39 We are not waiting for this topic
20210322-18:41:39 Listener eventMQTT called
20210322-18:41:39 state.topic = homie/homey-5dd…1/town/description topic = openHab/Okno3/BlindsControl
20210322-18:41:39 topic: homie/homey-5dd…1/town/description pattern: openHab/Okno3/BlindsControl
20210322-18:41:39 We are not waiting for this topic
20210322-18:41:39 OnMessage called
20210322-18:41:39 received ‘Clear’ on ‘homie/homey-5dd…1/town/conditioncode’
20210322-18:41:39 Trigger generic card for homie/homey-5dd…1/town/conditioncode
20210322-18:41:39 send message to listeners via realtime api
20210322-18:41:39 homie/homey-5dd…1/town/conditioncode: Clear
20210322-18:41:39 Listener eventMQTT called
20210322-18:41:39 state.topic = homie/homey-5dd…1/town/conditioncode topic = UPS/status
20210322-18:41:39 topic: homie/homey-5dd…1/town/conditioncode pattern: UPS/status
20210322-18:41:39 We are not waiting for this topic
20210322-18:41:39 Listener eventMQTT called
20210322-18:41:39 state.topic = homie/homey-5dd…1/town/conditioncode topic = openHab/Okno3/BlindsControl 20210322-18:41:39 topic: homie/homey-5dd…1/town/conditioncode pattern: openHab/Okno3/BlindsControl
20210322-18:41:39 We are not waiting for this topic
20210322-18:41:40 getLogLines called
I do not understand what has OpenWheatherMap to do with my blinds?
What you see being logged is the MQTT Client app deciding which flows to trigger when a message comes in. For instance this:
20210322-18:41:39 topic: homie/homey-5dd…1/town/conditioncode pattern: openHab/Okno3/BlindsControl
20210322-18:41:39 We are not waiting for this topic
There’s an incoming message on the homie/homey-5dd…1/town/conditioncode topic, and the client checks if your trigger card which listens to openHab/Okno3/BlindsControl should handle the message. It obviously shouldn’t, hence the message “We are not waiting for this topic”.
The last screenshot you post shows that your UPS and Blinds flows have been disabled by Homey, so until you enable them again they won’t trigger.
For topic openHab/Okno3/BlindsControl there is retained message = 0 and I have checked - openhab is publishing only when device status is changed.
For topic UPS/status there is currently no message at all as it’s not retained and last message expired over month ago…
(I did those two scenarios by intent - because I try to solve this disabling issue for some time)
The system that disables flows because they get called too much has been acting strangely ever since it was introduced. For some people, it triggers way to often, for others, not enough. Athom hasn’t been able to fix this (I don’t even know if they consider it broken).
OK, I’ll try to contact support. Just to be sure - from logs provided do you think that it’s not MQTT client who is trying to start this flow so many times?
I have discovered that this task disable occurs every time I restart MQTT hub application - any logic in that?
reality is, that flow do not run many times - because I have added logging in my flows:
some flows didn’t run at all and are disabled after MQTT hub restart…
At startup the MQTT Hub does a ‘broadcast’. Meaning all capabilities of all devices are traversed and the current state/value is published to their representing mqtt topic. The number of messages being send adds up quickly with an increased number of devices.
If you’re listening to all mqtt messages with a topic wildcard within a flowcard, this flow will probably be called hundreds of times in a very short period.
That’s probably causing the flow to be disabled by Homey.
From what I understand though, flows that listen on a specific unrelated MQTT topic are also being disabled.
It feels like an(other) issue with the flow rate limiter. The way the MQTT Client works is that when it receives a message on any of the topics it’s subscribed to, it will call each flow trigger’s run listener to see if the topic in the flow trigger matches the incoming message (it has to work like this to be able to support wildcard subscriptions). When there’s no match, the trigger will “cancel” the flow.
I initially thought that because the run listener is called, Homey considers the flow to be started (and apply the rate limiter) even though the run listener can decide the message isn’t meant for it and cancel the flow. However, I haven’t been able to reproduce this.
You just know that Athom will be blaming the MQTT Hub app for this
That’s why I want to try and reproduce it without the MQTT Hub app, which hasn’t worked so far. I’ll try and mimic how the Hub app uses the MQTT Client app for publishing.
@Zimo which version of the MQTT Client app are you running?
That rate limiting problem was there also when Athom implemented rate limiting before. Then I complained about it and they changed it. Guess they made the same mistake again. You have to walk through the each trigger card. There is no other way. Back then Athom counted each check as part of the rate, no matter if the card was triggered or not.
Anyway… I dont feel like going to fight about that again.
