Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Arc sending too many MQTT messages #88

Closed
nagyrobi opened this issue Mar 9, 2021 · 26 comments
Closed

Arc sending too many MQTT messages #88

nagyrobi opened this issue Mar 9, 2021 · 26 comments
Assignees

Comments

@nagyrobi
Copy link
Collaborator

nagyrobi commented Mar 9, 2021

Create a page like this:
image

{"page":2,"comment":"---------- Page 2 ----------"}
{"obj":"btn","id":1,"x":0,"y":0,"w":240,"h":30,"text":"HÁLÓSZOBA","value_font":22,"bg_color":"#2C3E50","text_color":"#FFFFFF","radius":0,"border_side":0}
{"obj":"btn","id":3,"x":195,"y":0,"h":30,"w":40,"text":"22.1°C","val":"0","bg_color":"#2C3E50","text_color":"#FFFFFF","radius":0,"border_side":0}
{"obj":"label","id":4,"x":10,"y":40,"w":220,"h":30,"text":"Kívánt hőmérséklet:","align":1,"padh":50}
{"obj":"arc","id":5,"x":20,"y":75,"w":200,"h":200,"min":150,"max":350,"border_side":0,"type":0,"rotation":0,"start_angle":135,"end_angle":45,"start_angle1":135,"end_angle1":45,"value_font":44,"value_color":"#2C3E50","adjustable":"true","groupid":7}
{"obj":"switch","id":6,"x":89,"y":235,"w":66,"h":30,"toggle":"TRUE"}

(don't forget to adjust font sizes to values supported by your build)

Create an automation in Home Assistant to update values:

- alias: lanbon-arc-update
  initial_state: 'on'
  trigger:
    - platform: mqtt
      topic: 'hasp/plate/state/p2b5'
  condition:
    - condition: template
      value_template: "{{ trigger.payload_json.event == 'changed' }}"
  action:
    - service: mqtt.publish
      data:
        topic: hasp/plate/command/p2b5.value_str
        payload: "{{ trigger.payload_json.val / 10 | float }}"

Try to move the handle of the arc, relatively fast, to about 50%. You'll notice how slow the value updates in the middle.
The reason is that MQTT is flooded with a lot of messages, and Home Assistant tries to process all of them:

2021-03-09 22:34:54 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:23 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:25 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:35:26 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:58 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:59 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:59 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:59 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:59 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:59 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:59 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:59 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:59 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:39:59 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:40:02 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:40:02 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:40:02 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:40:02 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:40:02 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running
2021-03-09 22:40:02 WARNING (MainThread) [homeassistant.components.automation.lanbon_arc_update] lanbon-arc-update: Already running

Of course if we use a smaller interval for arc, like "min":15,"max":35 messages will be much fewer, but that's not acceptable because of #81.

@nagyrobi nagyrobi added the bug Something isn't working label Mar 9, 2021
@fvanroie fvanroie removed the bug Something isn't working label Mar 9, 2021
@fvanroie
Copy link
Collaborator

fvanroie commented Mar 9, 2021

These are messages from Home-Assistant, so not sure why this would be labeled a bug.
It seems this is the default behavior and Home-Assistant can handle these situations using Automation Modes.

@htvekov
Copy link

htvekov commented Mar 9, 2021

FYI:
I use mode: restart for my volume slider automations. IMO this gives the best result with sliders, arcs etc. that issues sh*tloads of mqtt messages. I sync my sliders across all active plates as well (four so far) and with HA and Sonos component itself. So the mqtt messages explodes when i pull a volume slider 😆

parallel mode most likely won't work well, as it will soon run out of threads if you yank the arc vigorously.
queued mode will produce massive 'elastic' sensor delays in HA several seconds after if you 'play' with arc.
single mode will (as you know) miss several mqtt messages which ends up in HA's log as warnings instead

@fvanroie
Copy link
Collaborator

fvanroie commented Mar 9, 2021

The actual question is how many is too much. It really depends on the automation system I guess.

@htvekov
Copy link

htvekov commented Mar 10, 2021

Is the 0,1 degree interval needed for what i expect is an ambient temperature setting ?
Most commercial sensors act on typical 0,5 degree intervals.

@nagyrobi
Copy link
Collaborator Author

Is the 0,1 degree interval needed for what i expect is an ambient temperature setting ?

The system in our house works at 0,1 intervals, 0,5 is too much here. A 0,3 degree temperature rising increases comfort significantly, 0,5 is too much.

But all this is less relevant, there are a plethora of cases when one would use an arc or a slider with a 200 value-range.

@nagyrobi
Copy link
Collaborator Author

nagyrobi commented Mar 10, 2021

The actual question is how many is too much. It really depends on the automation system I guess.

My Home Assistant and MQTT server instance is running on an HP DL380 server in a VM provisioned with 8GB of ram and connected to the network at 4x1Gbit LACP, and WiFi is provided by an UniFi system. So that's not the bottleneck. I would rather think that the ESP-WROOM's WiFi connectivity is maxed during these peaks.

I think we should approach it differently. It doesn't really worth sending updates on MQTT when moving the slider handle based on the value change, instead it should be considered to send the updates based on a timer. Say, every 200ms should be enough. One might drag the handle slow, somebody else may drag is fast, the result should be the same in the end, send the last message when the handle stopped moving. If somebody will use a slider with min:0 and max:1000 it shouldn't be dependent on the value.
Another approach would be maybe look at the pixel distance the slider travelled. On a Lanbon L8 when touching with a finger and moving the slider, I assume it only makes sense to send an MQTT message only if more than 10px movement has detected.

In my log above at 22:35:26 Home Assistant filled 17 automation start attempts and I was moving the slider slowly during 1 second. This is way too much and causes useless load and lag behind, elasticness like htvekov mentioned.

@nagyrobi
Copy link
Collaborator Author

I use mode: restart for my volume slider automations. IMO this gives the best result with sliders, arcs etc.

I commented my mode setting because otherwise the error message is suppressed from the log. Forgot to mention that even with mode: restart the behavior is still annoyingly "elastic".

@nagyrobi
Copy link
Collaborator Author

nagyrobi commented Mar 10, 2021

These are messages from Home-Assistant, so not sure why this would be labeled a bug.
It seems this is the default behavior and Home-Assistant can handle these situations using Automation Modes.

Github labels these automatically, it was not me who puts this label on. I don't have permission to change labels afterwards.
I included logs from Home Assistant just to show the consequence, as Home Assistant is one of the targets we need to be mostly compatible with.

@htvekov
Copy link

htvekov commented Mar 10, 2021

Strange indeed...

In general I don't think that ESP speed is the bottleneck here.
In all my previous issues (and I had many 😉) Home Assistant came out as the culprit - everytime.
HA is great, but state machine and processing certain types of automation is simply notoriously slow. No matter what hw is used (almost). Some of my previous issues involving Z2M, lights, zigbee remotes, HA's state machine and Appdaemon addon's ended up in some 200-200ms processing time for conditional flipping a light... I had to tweak & tweak, kill off template sensors and rely on pure MQTT automations to get almost near instant toggle of lights.

HA actually got all the MQTT messages nicely, but is so slow processing even your simple automation that it ends up logging 19 attempts to finish automation.

As I said, I didn't experience any special lag issues with my cross plates volume slider update (100 values range)
Well, during tests I've looked at all other plates than the active plate.

On the active plate indeed there are real lag issues updating value_str on same object (or a different object on same page).
Extreme lag up to some 2-3 seconds. Actually I wouldn't call it lag, as objects value_str doesn't get updated at all before slider is released.

Looks like all inbound mqtt messages are buffered and not processed while hasp-lvgl is busy with arc/slider object changes ?
Don't know if this behaviour could easily be altered or deeply buried in the graphics library itself ?

EDIT: I'm currently at 0.4.0 dev dated 090321. Not that i believe it makes any difference.

@fvanroie ?

@nagyrobi
Copy link
Collaborator Author

My goal would be to place a Lanbon in each room and offer temperature setting there. So I wouldn't need to display real time the arch value change on other screens, just on the one being handled.

@htvekov
Copy link

htvekov commented Mar 10, 2021

If you dap along the arc very quickly you'll get instant value_str updates, right ?

@nagyrobi
Copy link
Collaborator Author

@htvekov
Copy link

htvekov commented Mar 10, 2021

I have 100% identical experience with my volume slider

@nagyrobi
Copy link
Collaborator Author

I don't think this is OK.

@htvekov
Copy link

htvekov commented Mar 10, 2021

We'll have to see what @fvanroie has to say on the subject.
He knows his code backwards and forwards - even while asleep 😉

I would call this an unintended design flaw, not showing up until now.

Best solution was if hasp-lvgl code could handle this internally. Update objects value_str if already predefined in jsonl.
This check is needed, as not all sliders, arcs etc. neccesarily has an value_str to be displayed.

Second best solution was to deal with the mqtt delays for inbound messages to active plate page.
I guess that code temporarily disables handling of inbound mqtt messages, in order to be able to send outbound messages without any delays. Or code isn't fully async or can't run async for any number of reasons - MQTT message buffer limit or other ressource issues. I really don't know - just guessing 😁

@nagyrobi
Copy link
Collaborator Author

Best solution was if hasp-lvgl code could handle this internally.

Agree. And an option to only send a single MQTT message when movement ended.

@htvekov
Copy link

htvekov commented Mar 10, 2021

Btw. how the hell did you manage to find and upload a working .zi fontfile ?

As .zi font support currently is flawed and needs to be corrected when our 'one man army' @fvanroie at some point finds the time to check this as well.

@nagyrobi
Copy link
Collaborator Author

nagyrobi commented Mar 10, 2021

.zi bricked my device too so I had to reflash.
Instead I modified the built-in font: #74

our 'one man army' @fvanroie

I'd love to help as much as possible.

@htvekov
Copy link

htvekov commented Mar 10, 2021

Believe me, so would I.
Unfortunately my programming skills is not up to speed with the task.
But I can at the very least make an effort and descrribe issues found as accurately as possible for @fvanroie and help testing as much as possible 😉
Regarding fonts I'll just wait until an update is ready. Not that urgent to find a solution right now.
I have plenty on 'the plate' with my prototype in wall display 😆

@fvanroie
Copy link
Collaborator

Hasp-lvgl is conceptually a lvgl front-end over mqtt. Everything is implemented as a wrapper around lvgl objects, functions, features... with a mqtt command set. Anything that doesn't fit that concept is deemed to be an off-device feature, typically handled by home-automation software.

We try not to pose limits any on what can be done, what you do with the exposed commands depends on the use case and user. If lvgl sends 100 value updates while dragging a slider, you will get 100 mqtt updates. This doesn't mean it's a good idea to send 100 values back to the device though...

At this stage I'm still implementing the basic feature set. So adding mqtt message throttling is not high up on the list, since it can be done off-device too.

@nagyrobi
Copy link
Collaborator Author

nagyrobi commented Mar 12, 2021

I see your point but look practically. There's no easy way to decide on the other side what not to send back to the device to do some throttling as the end is unknown there. There's nowhere to know in advance when was the handle released and know which was the last message... so we could ignore the rest in between... In HA Automation Modes can't handle this.

This will mostly make it usable exclusively with https://github.com/dgomes/hasp-lvgl-custom-component/ since these things can only be handled at lower level.

@htvekov
Copy link

htvekov commented Mar 12, 2021

Hi' @fvanroie

The main issue is not really the extensive amount of MQTT messages. HA could easily just do restart mode, if flooded with more MQTT messages than possible to process. Or keep track of time delta between messages or use other means to diminish the abundance of MQTT messages. If new MQTT message arrives at HA from same button but with new value, then HA should just abort and restart as data is already obsolete.

The real issue here is that hasp-lvgl doesn't seem to process any inbound MQTT messages for active plate (or at all ?) as long as an object is actively pressed or pulled. So no matter how few MQTT messages are returned to hasp, hasp doesn't process these before object button is released -> hence no 'on the fly' eg. value_str update possible yanking a volume slider or pulling an temperature arc back and forth. It won't update before button is released.

I guess this is most likely by design to avoid MQTT message queue issues (inbound/outbound collisions).
That's why I suggested the internal hasp-lvgl handling of this specific type of update perhaps could be the only possible solution ?

But I agree with you priorities. Core basic features first !

Ciao !

@nagyrobi
Copy link
Collaborator Author

nagyrobi commented Mar 23, 2021

We could functionally separate the needs. For example we could avoid this behavior with a workaround: if we had down and up events for arc/slider (corresponding to touch/grab handle and release handle respectively), which would send us an MQTT message with the actual val, we could differentiate trigger MQTT responses.

In this example up would be enough to set the climate and thus send back the value to the plate.
We could still use changed event to control other entities which are not on this plate so no flooding feedback occurs.

fvanroie added a commit that referenced this issue Mar 26, 2021
@fvanroie
Copy link
Collaborator

Feel free to test this feature branch. If OK I'll merge it in master.

@nagyrobi
Copy link
Collaborator Author

It's OK on my Lanbon L8 thank you!

@htvekov
Copy link

htvekov commented Mar 27, 2021

Seems stable enough 👍

I've had so many issues last couple of days testing more that 10 builds across 4 different plates with 3 different display hw setups. Main worry was that all plates at some point froze and just stopped sending mqtt messages completely. Really have no idea what happened ? Perhaps a small memory leak somewhere, triggered by the many, many hundreds in- /out bound mqtt messages in only minutes when testing arc/slider ? But now I'll stick with this latest build for a couple of days to test reliability in my environment. My general mqtt broker load is also now below 160 (recieved) messages/minut. Under previous testing it hit some 500+ recieved messages/minut - easily.... 🤯

The mqtt throttling seems to work perfectly. And on top of this the 'event up' message for sliders/arcs - what's not to like 😉
I'll now be able to rewrite and simplify some of my automations with this.

Thanks !!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants