Sluggish and MQTT reports out of memory

[plord12]

Hi,

I have a 5" cheap yellow display and am making progress designing my pages.

However, every so often the device becomes non-resposive and at the same time I see whilst telneted in

#[16:39:49.699][51188/78788 35][25016/25288  2] MQTT RCV: Out of memory

The web info page looks fairly healthly to my eyes

openHASP

Version	0.7.0-rc15 1ffd94a
Build DateTime	Feb 17 2025 20:12:29 UTC
Environment	sunton-8048s050c_16MB
Uptime	6m 39s
Idle	off
Active Page	1

Device Memory

Free Heap	65.76 KiB
Free Block	35.98 KiB
Fragmentation	45%
PSRam Free	7.18 MiB
PSRam Size	7.99 MiB

LVGL Memory

Total	64.00 KiB
Free	24.66 KiB
Fragmentation	2%

MQTT

Server	192.168.175.10
Username	homeassistant
Client ID	plate01_4cf244
Status	Connected
Received	1400
Published	38
Failed	3

Is there anything I can look at to get more info ? Thanks.

[fvanroie]

It sounds like an MQTT message loop, please post more of your log output.
Check the MQTT activity using a tool like MQTT Explorer.

If you overwhelm the ESP32 with MQTT messages faster than it can process, you can run into a situation where the MQTT receive buffer gets full.

[plord12]

Thanks.

I've just powered off and powered on the plate and recorded the logs via telnet as soon as I could

        open____ _____ _____ _____
          |  |  |  _  |   __|  _  |
          |     |     |__   |   __|
          |__|__|__|__|_____|__|
        Home Automation Switch Plate
        Open Hardware edition v0.7.0-rc15

[      17.417][57332/68360 16][25992/26152  1] TELN: Client login from 192.168.175.12
[      17.429][57332/67908 15][25992/26152  1] MQTT: [3] QUE p2b7.max => 3000
[      17.441][57332/66032 13][25992/26152  1] MQTT: [2] QUE p2b7.critical_value => 2000
[      17.452][55284/64148 13][25992/26152  1] MQTT: [1] QUE p2b7.format => 2
[      17.464][53236/62276 14][25992/26152  1] MQTT: [0] QUE p2b8.text => Estimated
[      17.487][51188/62216 17][25992/26144  1] MQTT RCV: p2b9.hidden = True
#[      17.943][57332/78756 27][25688/26108  2] MQTT: [11] QUE p2b10.hidden => True
#[      17.955][57332/76840 25][25688/26108  2] MQTT: [10] QUE p2b11.hidden => True
#[      17.967][57332/74928 23][25688/26108  2] MQTT: [10] QUE p2b12.hidden => True
#[      17.979][57332/73028 21][25688/26108  2] MQTT: [9] QUE p2b13.hidden => True
#[      17.990][57332/71128 19][25688/26108  2] MQTT: [8] QUE p2b14.hidden => True
#[      18.002][57332/69232 17][25688/26108  2] MQTT: [8] QUE p2b15.hidden => True
#[      18.014][57332/68160 15][25688/26108  2] MQTT: [7] QUE p2b16.hidden => True
#[      18.026][57332/66264 13][25688/26108  2] MQTT: [7] QUE p3b1.val => 120
#[      18.038][55284/64372 14][25688/26108  2] MQTT: [6] QUE p3b1.value_str => Master Bedroom
#[      18.376][53236/63060 15][25688/26080  2] MQTT: [16] QUE p3b1.bg_color => Blue
#[      18.986][53236/63864 16][25688/26076  2] MQTT: [35] QUE p3b1.min => 50.0
#[      19.046][51188/63644 19][25688/26076  2] MQTT: [36] QUE p3b1.max => 300.0
#[      19.191][51188/64356 20][25688/26076  2] MQTT: [40] QUE p3b1.format => 1
#[      19.397][51188/68604 25][25688/26076  2] ATTR: Unknown property format (38871)
#[      19.409][57332/78084 26][25688/26076  2] MQTT: [46] QUE p3b2.text => 18.5
#[      19.421][57332/76500 25][25688/26076  2] MQTT: [46] QUE p3b3.text => 12.0
#[      19.433][57332/78084 26][25688/26076  2] MQTT: [45] QUE p3b4.val => 120
#[      19.446][57332/78096 26][25688/26076  2] MQTT: [44] QUE p3b4.value_str => Dawns study
#[      19.460][57332/76500 25][25688/26048  2] MQTT: [44] QUE p3b4.bg_color => Blue
#[      19.472][57332/76500 25][25688/26040  2] MQTT: [43] QUE p3b4.min => 50.0
#[      19.484][57332/74904 23][25688/26040  2] MQTT: [43] QUE p3b4.max => 300.0
#[      19.496][57332/73188 21][25688/26040  2] MQTT: [42] QUE p3b4.format => 1
#[      19.508][57332/76484 25][25688/26040  2] ATTR: Unknown property format (38871)
#[      19.520][57332/76496 25][25688/26040  2] MQTT: [42] QUE p3b5.text => 19.1
#[      19.532][57332/76484 25][25688/26040  2] MQTT: [41] QUE p3b6.text => 12.0
#[      19.544][57332/76484 25][25688/26040  2] MQTT: [41] QUE p3b7.val => 120
#[      19.557][57332/78080 26][25688/26040  2] MQTT: [40] QUE p3b7.value_str => Bathroom
#[      19.572][57332/78096 26][25688/26020  2] MQTT: [40] QUE p3b7.bg_color => Blue
#[      19.585][57332/76184 24][25688/26012  2] MQTT: [39] QUE p3b7.min => 50.0
#[      19.596][57332/74276 22][25688/26012  2] MQTT: [38] QUE p3b7.max => 300.0
#[      19.608][57332/72380 20][25688/26012  2] MQTT: [38] QUE p3b7.format => 1
#[      19.620][57332/70484 18][25688/26012  2] ATTR: Unknown property format (38871)
#[      19.631][57332/68568 16][25688/26012  2] MQTT: [37] QUE p3b8.text => 18.9
#[      19.643][57332/66988 14][25688/26012  2] MQTT: [37] QUE p3b9.text => 12.0
#[      19.656][55284/66704 17][25688/26012  2] MQTT: [36] QUE p3b10.val => 120
#[      19.669][55284/64796 14][25688/26012  2] MQTT: [36] QUE p3b10.value_str => Petes study
#[      19.683][53236/62876 15][25912/25996  1] MQTT: [35] QUE p3b10.bg_color => Blue
#[      19.809][51188/62880 18][25884/25988  1] MQTT: [38] QUE p3b10.min => 50.0
#[      20.515][51188/63164 18][25884/25988  1] MQTT: [61] QUE p3b10.max => 300.0
#[      20.932][51188/62956 18][25884/25988  1] MQTT: [63] QUE p3b10.format => 1
#[      20.962][51188/62960 18][25884/25988  1] ATTR: Unknown property format (38871)
#[      21.462][51188/62960 18][25884/25988  1] MQTT RCV: Out of memory
#^[[B^[[B[      20.962][51188/62960 18][25884/25988  1] ATTR: Unknown property format (38871)
#[      26.093][45044/58048 22][25884/25988  1] MQTT: [63] QUE p3b11.text => 18.5
#[      26.216][45044/63876 29][25884/25988  1] MQTT: [63] QUE p3b12.text => 12.0
#[      26.228][45044/61980 27][25884/25988  1] MQTT: [63] QUE p3b13.val => 120
#[      26.241][45044/60084 25][25884/25988  1] MQTT: [62] QUE p3b13.value_str => Front bedroom
#[      26.241][45044/60084 25][25884/25988  1] MQTT: [62] QUE p3b13.value_str => Front bedroom
#[      26.809][45044/60204 25][25884/25988  1] MQTT RCV: Out of memory
#[      27.647][42996/58284 26][25860/25956  1] MQTT: [63] QUE p3b13.bg_color => Blue
#[      27.647][42996/58284 26][25860/25956  1] MQTT: [63] QUE p3b13.bg_color => Blue
#[      28.204][42996/58592 26][25860/25956  1] MQTT RCV: Out of memory
#[      47.846][42996/71272 39][25832/25948  1] MQTT: Disconnected
#[      47.846][42996/71272 39][25832/25948  1] MQTT: Disconnected

I'll see if I can find more clues with MQTT explorer.

[fvanroie]

Yeah, something is hammering the display with messages faster than it can handle...
Check where all those messages are coming from, and maybe try to reduce the flood to see if that solves it.

[fvanroie]

Also try to group MQTT messages for the same object into one payload:

{ "page":3, "id":7, "val":120, "value_str":"Bathroom", "bg_color":"Blue", "min":50, "max":300 }

[plord12]

I don't think I have much control over how the messages are generated. In home assistant I've created a pages.jsonl and added the openhasp yaml configuration which lists the properties. For example :

    - obj: "p3b7"
      properties:
        "val": >
          {{ (state_attr("climate.wiser_bathroom","temperature")|float(0) * 10)|int }}
        "value_str": |
          Bathroom
        "bg_color": >
          {% if state_attr("climate.wiser_bathroom","control_output_state") == "On" %}
          Red
          {% else %}
          Blue
          {% endif %}
        "min": >
          {{ state_attr("climate.wiser_bathroom","min_temp")|float(0) * 10 }}
        "max": >
          {{ state_attr("climate.wiser_bathroom","max_temp")|float(0) * 10 }}
        "format": 1
      event:
        "changed":
          - service: climate.set_temperature
            data:
              temperature: "{{ val / 10 }}"
            target:
              entity_id: climate.wiser_bathroom

[plord12]

I put the broker into debug mode so messages are logged. I thought some messages might have a lot of repeats but not really.

over a 20min period, most messages were sent 14 times. Sticking with the example above -

$ grep hasp mqtt.log | cut -c20- | sort | uniq -c | sort -n | grep p3b7

   2 : Sending PUBLISH to mqtt-explorer-741fc776 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.bg_color', ... (4 bytes))
   2 : Sending PUBLISH to mqtt-explorer-741fc776 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.format', ... (1 bytes))
   2 : Sending PUBLISH to mqtt-explorer-741fc776 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.max', ... (5 bytes))
   2 : Sending PUBLISH to mqtt-explorer-741fc776 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.min', ... (4 bytes))
   2 : Sending PUBLISH to mqtt-explorer-741fc776 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.val', ... (3 bytes))
   2 : Sending PUBLISH to mqtt-explorer-741fc776 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.value_str', ... (8 bytes))
   6 : 	hasp/plate01/state/p3b7
   6 : 	hasp/plate01/state/p3b7 (QoS 0)
   6 : 6x5LZWh2hBzjDTGdHvFv5k 0 hasp/plate01/state/p3b7
   6 : 6x5LZWh2hBzjDTGdHvFv5k hasp/plate01/state/p3b7
  14 : Received PUBLISH from 6x5LZWh2hBzjDTGdHvFv5k (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.bg_color', ... (4 bytes))
  14 : Received PUBLISH from 6x5LZWh2hBzjDTGdHvFv5k (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.format', ... (1 bytes))
  14 : Received PUBLISH from 6x5LZWh2hBzjDTGdHvFv5k (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.max', ... (5 bytes))
  14 : Received PUBLISH from 6x5LZWh2hBzjDTGdHvFv5k (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.min', ... (4 bytes))
  14 : Received PUBLISH from 6x5LZWh2hBzjDTGdHvFv5k (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.val', ... (3 bytes))
  14 : Received PUBLISH from 6x5LZWh2hBzjDTGdHvFv5k (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.value_str', ... (8 bytes))
  14 : Sending PUBLISH to plate01_4cf244 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.bg_color', ... (4 bytes))
  14 : Sending PUBLISH to plate01_4cf244 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.format', ... (1 bytes))
  14 : Sending PUBLISH to plate01_4cf244 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.max', ... (5 bytes))
  14 : Sending PUBLISH to plate01_4cf244 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.min', ... (4 bytes))
  14 : Sending PUBLISH to plate01_4cf244 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.val', ... (3 bytes))
  14 : Sending PUBLISH to plate01_4cf244 (d0, q0, r0, m0, 'hasp/plate01/command/p3b7.value_str', ... (8 bytes))

I've setup 10 pages with a total of 159 objects.

I know there are some constants in the home assistant yaml that could be moved to pages.jsonl, but I would rather not.

[fvanroie]

I know there are some constants in the home assistant yaml that could be moved to pages.jsonl, but I would rather not.

That was going to be my next suggestion. Why not?

[fvanroie]

over a 20min period, most messages were sent 14 times.

14 times to p3b7 only, but you have 159 objects. If they all get those updates, I'm not surprised the ESP32 is sluggish.
Your focus really should be on reducing the messages to essential updates instead of repeating static values over and over.

[plord12]

I know there are some constants in the home assistant yaml that could be moved to pages.jsonl, but I would rather not.

That was going to be my next suggestion. Why not?

I like to keep UI design (eg dial position, size) separate to data (eg dial value, label) ... otherwise you end up editing two files.

[plord12]

over a 20min period, most messages were sent 14 times.

14 times to p3b7 only, but you have 159 objects. If they all get those updates, I'm not surprised the ESP32 is sluggish. Your focus really should be on reducing the messages to essential updates instead of repeating static values over and over.

This would require code changes to the openhasp home assistant plugin I believe (or have I missed something ... I'm not seeing an option to optionally send an update or to optimize multiple properties to one message).

Or, I suppose, avoid using the plugin and roll my own automations that send more optimized mqtt messages

[fvanroie]

Either that, or remove the static min, max, text, etc values from the updates... There is no one solution.

If a value changes, only update the value on the screen and don't resend every static property. You're now multiplying the messages just to refrain from editing two files.

The main issue I believe is, that when HA boots it sends all values from all sensors at once which overwhelms the device.

[plord12]

If the number of messages is an issue and the MQTT buffer can't be increased, I wondered if there was a way to stop sending messages for pages that arn't visible.

[fvanroie]

You can increase the buffer in the source code, but you'll need to compile your custom firmware for that.
imho, only send updates for values that need changing. Sending over constants repeatedly is only burdening the device MCU.

[plord12]

One thing I noticed from time to time is what looks like a re-sending pages.jsonl. I don't think these are normally logged but show up when the queue is dumped

#[09:21:53.005][51188/78860 35][25024/25340  2] MQTT: [63] QUE jsonl => {"id":35,"obj":"img","x":660,"y":210,"w":40,"h":40,"src":"L:/z-128-cloudy.png","zoom":200}
{"id":36,"obj":"label","x":400,"y":340,"w":200,"h":60,"text_font":32,"align":"left", "text":"Wednesday", "text_font":26}
{"id":37,"obj":"label","x":540,"y":340,"w":200,"h":60,"text_font":32,"align":"left", "text":"10C", "text_font":26}
{"id":38,"obj":"img","x":660,"y":290,"w":40,"h":40,"src":"L:/z-128-cloudy.png","zoom":200}
{"id":39,"obj":"label","x":400,"y":420,"w":200,"h":60,"text_font":32,"align":"left", "text":"Thursday", "text_font":26}
{"id":40,"obj":"label","x":540,"y":420,"w":200,"h":60,"text_font":32,"align":"left", "text":"10C", "text_font":26}
{"id":41,"obj":"img","x":660,"y":370,"w":40,"h":40,"src":"L:/z-128-cloudy.png","zoom":200}

#[09:21:53.103][51188/74704 31][25024/25340  2] MQTT: [63] QUE p0b5.text => 9.7km/h
#[09:21:53.115][51188/72792 29][25024/25340  2] MQTT: [63] QUE p0b6.text => 8.1°C
#[09:21:53.129][51188/70896 27][25024/25340  2] MQTT: [62] QUE p0b7.src => L:/z-32-cloudy.png
#[09:21:53.154][51188/68980 25][25024/25340  2] MQTT: [62] QUE p1b1.val => 308
#[09:21:53.167][51188/66852 23][25024/25340  2] MQTT: [62] QUE p1b1.value_str => kW
#[09:21:53.181][51188/64944 21][25024/25340  2] MQTT: [61] QUE p1b1.bg_color => Blue
#[09:21:53.193][49140/63044 22][25024/25340  2] MQTT: [60] QUE p1b1.min => 0
#[09:21:53.817][49140/62092 20][25024/25340  2] MQTT RCV: Out of memory

I guess I can copy pages.jsonl to the device to avoid this.

[fvanroie]

Placing pages.jsonl on device will reduce the MQTT load, yes.
But I think this only happens at HA restart, but that's when you're also flooding the device with sensor updates.
You end up setting the sames values over and over, and the small device just can't keep up.

[plord12]

[ deleted incorrect post ]

With a bit more research, I'm beginning to think this is triggered by a network issue.

Looking back a little in the logs I see -

#[08:21:33.861][57332/81996 30][24344/24608  2] MQTT: Disconnected
...
#[08:21:53.506][45044/59264 23][45044/59264 23][24440/24796  2] MQTT RCV: Out of memory

The disconnect seems to occur first. After a re-connect there is a queue of messages to be processed, plus a re-send of pages.jsonl making the problem worse.

The code that is reporting Out of memory here is -

    {
        size_t attempt = 0;
        while(xQueueSend(queue, &data, (TickType_t)0) == errQUEUE_FULL && attempt < 100) {
            delay(5);
            attempt++;
        };
        if(attempt >= 100) {
            LOG_ERROR(TAG_MQTT_RCV, D_ERROR_OUT_OF_MEMORY);
        }
    }

So we could bump up the size of the xqueue -

 void mqttSetup()
 {
-    queue = xQueueCreate(64, sizeof(mqtt_message_t));
+    queue = xQueueCreate(512, sizeof(mqtt_message_t));

But I think we need to investigate the network issue first.

In a separate test run I saw -

#[09:37:45.947][49140/67936 27][49140/67936 27][24444/24796  2] MQTT: Disconnected

which seems to correspond with large ping delays -

Feb 23 09:37:24 64 bytes from 192.168.175.241: icmp_seq=862 ttl=255 time=3.83 ms
Feb 23 09:37:25 64 bytes from 192.168.175.241: icmp_seq=863 ttl=255 time=25.5 ms
Feb 23 09:37:27 64 bytes from 192.168.175.241: icmp_seq=864 ttl=255 time=984 ms
Feb 23 09:37:28 64 bytes from 192.168.175.241: icmp_seq=865 ttl=255 time=1100 ms
Feb 23 09:37:29 64 bytes from 192.168.175.241: icmp_seq=866 ttl=255 time=1216 ms
Feb 23 09:37:30 64 bytes from 192.168.175.241: icmp_seq=867 ttl=255 time=1136 ms
Feb 23 09:37:31 64 bytes from 192.168.175.241: icmp_seq=868 ttl=255 time=1057 ms
Feb 23 09:37:32 64 bytes from 192.168.175.241: icmp_seq=869 ttl=255 time=1086 ms
Feb 23 09:37:33 64 bytes from 192.168.175.241: icmp_seq=870 ttl=255 time=1103 ms
Feb 23 09:37:34 64 bytes from 192.168.175.241: icmp_seq=871 ttl=255 time=722 ms
Feb 23 09:37:35 64 bytes from 192.168.175.241: icmp_seq=872 ttl=255 time=783 ms
Feb 23 09:37:36 64 bytes from 192.168.175.241: icmp_seq=873 ttl=255 time=873 ms
Feb 23 09:37:37 64 bytes from 192.168.175.241: icmp_seq=874 ttl=255 time=1405 ms
Feb 23 09:37:38 64 bytes from 192.168.175.241: icmp_seq=875 ttl=255 time=1112 ms
Feb 23 09:37:39 64 bytes from 192.168.175.241: icmp_seq=876 ttl=255 time=1032 ms
Feb 23 09:37:40 64 bytes from 192.168.175.241: icmp_seq=877 ttl=255 time=850 ms
Feb 23 09:37:41 64 bytes from 192.168.175.241: icmp_seq=878 ttl=255 time=1285 ms
Feb 23 09:37:42 64 bytes from 192.168.175.241: icmp_seq=879 ttl=255 time=1078 ms
Feb 23 09:37:43 64 bytes from 192.168.175.241: icmp_seq=880 ttl=255 time=1409 ms
Feb 23 09:37:44 64 bytes from 192.168.175.241: icmp_seq=881 ttl=255 time=1249 ms
Feb 23 09:37:45 64 bytes from 192.168.175.241: icmp_seq=882 ttl=255 time=944 ms

We do have a bug report in this area for this play, #592, so I think the next step is to play around with the display settings so that wifi is stable (and the display actually works). Some discussions here #861

[plord12]

I raised #868 with a PR to set TFT_PREFER_SPEED to a value that both gets the display working and reduces wifi errors. This seems sufficient to stop disconnects and hence trigger the out of memory.