PSRAM memory leak?

[waltkind]

On my Lanbon L8 I realized, that the PSRAM is shrinking all the time. Now after an uptime of 4 days I printed 'tasmota.memory()' and then made a restart.

See the following results.
PSRAM shrank from 4072kB to 3552kB and
PSRAM_free from 3890kB to 2050kB

The other sizes keep constant.

Is there a log-file that eats memory?
But not only the free memory shrinks, also the total size.

16:44:03.552 {'stack_low': 19.5352, 'program_free': 514, 'program': 2365,
 'psram': 3552, 'stack_size': 24, 'flash_real': 8192,
 'iram_free': 35, 'flash': 8192, 'frag': 0, 'heap_free': 142, 
 'psram_free': 2050}

16:46:05.744 MQT: tasmota/lanbon_2/STATE = {"Time":"2024-01-25T16:46:05","Uptime":"4T04:15:14","UptimeSec":360914,"Heap":144,"SleepMode":"Dynamic","Sleep":10,"LoadAvg":99,"MqttCount":2,"Berry":{"HeapUsed":35,"Objects":664},"POWER1":"OFF","POWER2":"OFF","POWER3":"OFF","POWER4":"OFF","Dimmer":10,"Color":"1A1A1A","HSBColor":"0,0,10","Channel":[10,10,10],"Scheme":0,"Fade":"OFF","Speed":1,"LedTable":"ON","Wifi":{"AP":1,"SSId":"AstaroGuest","BSSId":"98:9B:CB:9F:40:02","Channel":6,"Mode":"11n","RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:04"}}

16:53:04.109 {'stack_low': 19.5352, 'program_free': 514, 'program': 2365,
 'psram': 4072, 'stack_size': 24, 'flash_real': 8192,
 'iram_free': 35, 'flash': 8192, 'frag': 0, 'heap_free': 143,
 'psram_free': 3890}

16:56:03.684 MQT: tasmota/lanbon_2/STATE = {"Time":"2024-01-25T16:56:03","Uptime":"0T00:05:09","UptimeSec":309,"Heap":145,"SleepMode":"Dynamic","Sleep":10,"LoadAvg":99,"MqttCount":1,"Berry":{"HeapUsed":35,"Objects":661},"POWER1":"OFF","POWER2":"OFF","POWER3":"OFF","POWER4":"OFF","Dimmer":10,"Color":"1A1A1A","HSBColor":"0,0,10","Channel":[10,10,10],"Scheme":0,"Fade":"OFF","Speed":1,"LedTable":"ON","Wifi":{"AP":1,"SSId":"AstaroGuest","BSSId":"98:9B:CB:9F:40:02","Channel":6,"Mode":"11n","RSSI":82,"Signal":-59,"LinkCount":1,"Downtime":"0T00:00:04"}}

[sfromis]

It may not be an issue to see PSRAM free falling over time, as long as there is "more than enough". Doing a few tasmota.memory() in quick succession, I saw psram_free sink by 5-6 KB every time, but all recovered after forcing a tasmota.gc() (which normally may not happen until "needed").

As you're seeing Berry Objects about same level after restart, there seems to be no leak here.

Not sure why psram size also falls (at a slower rate), but this also seemed to restitute after the garbage collection.

[waltkind]

I'll have an eye on this. Thank you

[waltkind]

Now I waited for some time to watch all. My first unit froze after 7 days and the second after 8 days.
The PSRAM shrank all the time. I don't know what the minimum was when they froze.
Now they are up for about 3 days and the free PSRAM is around 1700 KB.
When I force tasmota.gc() one unit shows 42347. The same value for two days, but no positive effect for PSRAM. It is still falling.
What can I check?
Do I need a cron job to restart every few days?

[sfromis]

Periodic restarts would at best be a questionable workaround.

What would be interesting to see when forcing a tasmota.gc() is not so much the returned value, but any effect on the output of tasmota.memory()

But if you're seeing psram_free falling, unaffected by doing tasmota.gc(), it does indeed look like a leak. To debug such, it is generally useful to zoom in on what step(s) results in available PSRAM falling, even after garbage collection.

Of course, what you're doing on the device, like features and usage, is also part of the story.

[waltkind]

If I compare the output of tasmota.memory() before and after tasmota.gc() the PSRAM and PSRAM_free are still falling.
The other numbers stay constant and are equal on both units.
I have two unit. One 'productive' and one 'experimental'. So I can do any tests, that you sugest.

[sfromis]

What I meant was not before/after a single gc, but doing the combination of gc/memory before/after some interval, with activities done in that interval, zooming in to get closer. If the after-gc value is falling and not "recovering", that is indicative of a leak.

[waltkind]

I'll wait for tomorrow and check again.

[sfromis]

The number from tasmota.gc() is not very interesting for PSRAM leaks. Anyway, as the docs says, it "returns the bytes currently allocated", which gives no specific hints about PSRAM. The stable level here only reiterates what was already visible, that it is not a growth in objects known to Berry.

What's much more interesting is zooming in on when you see PSRAM dwindling, over as short time as practical, along with what is happening on the device at the same time.

[waltkind]

What do you mean by 'zooming in'?
What commands are doing that?
Sorry for asking dump questions.

[sfromis]

Zooming in is figurative, getting closer to where it happens, like what I already posted:

To debug such, it is generally useful to zoom in on what step(s) results in available PSRAM falling, even after garbage collection.

If you can point at a single event resulting in PSRAM goint down if repeated, ideally something which can be repeated by others, that comes much closer to analyzing what happens.

[waltkind]

So I should cut my code in single activities and see what happens?

[sfromis]

That may be a step on the way, but first step is about observing what events cause a loss of available PSRAM. And since Berry memory is not going up, it does not look like the leak is in your code.

[s-hadinger]

Maybe the leak does not come from Berry but from another part of the code. How exactly is the device configured?

[waltkind]

Shall I show here all the code or parts of it? I have no problems with this.

[s-hadinger]

Anything that would be helpful to reproduce the problem

[waltkind]

It is not an analysis yet, but to visualize what happened the last 24 hours in the units.

So the max memory is falling constantly. (right scale) and the resulting free memory also (left scale).
It seems to me, that not single events eat the memory. It is like a log in the background that writes an increasing file and takes the memory space of the PSRAM.
Status 3 tells me, that SerialLog and WebLog are 2. Does this explain something?

I'll wait another day. I think then the free memory will be around zero and the unit will freeze.

[sfromis]

You keep zooming out to long intervals, instead of zooming in to short intervals and individual events. One event happening continuously is TelePeriod triggering, but there can be other events in the code to manage the display, also without a user actually operating the device.

Log level does not explain anything, but for debugging a higher log level may be useful for getting details to look at.

[waltkind]

Now I reduced my code to one single subscribed topic and the memory is still shrinking.
I show the code here.

## Definition der Variablen
var topic, st='subtopic', fo='format'

## Maps
# Solar
m4 = {"Verbr":"p1b63", "Erz":"p1b65", "Exp":"p1b67", "Imp":"p1b69",
     "PV":"p1b61", "Batt":"p1b70", "statBattDayMax":"p1b71"}


# Anzeige Solarwerte
def Sol(topic, idx, payload_s, payload_b)
  import string
  st = string.replace(topic, 'Solar/', '')
  if !m4.find(st) return end
  if st == 'PV' || st == 'Verbr' fo ='%5d W' end
  if st == 'Erz' || st == 'Exp' || st == 'Imp' fo ='%5.1f kWh' end
  if st == 'Batt'  fo = 'Batterie: %5.1f %%'  end
  if st == 'statBattDayMax' p1b71.x = int(number(payload_s)*2.3+5) return end
  global.member(f'{m4[st]}').text = string.format(fo,payload_s)
 return true
end

def subscribes()
  import mqtt
  mqtt.subscribe("Solar/#", Sol)
end

and the pages.jsonl

{"page":0,"comment":"---------- Upper stat line ----------"}
{"id":0,"text_color":"#FFFFFF"}
{"id":11,"obj":"label","x":0,"y":0,"w":240,"pad_right":90,"h":22,"bg_color":"#1fa3ec","bg_opa":255,"radius":0,"border_side":0,"text":" HASPmota","text_font":"montserrat-20"}
{"id":15,"obj":"lv_wifi_arcs","x":150,"y":0,"w":29,"h":22,"radius":0,"border_side":0,"bg_color":"#000000","line_color":"#FFFFFF"}
{"id":16,"obj":"lv_clock","x":180,"y":3,"w":55,"h":16,"radius":0,"border_side":0}

{"comment":"---------- Bottom buttons - prev/home/next ----------"}
{"id":101,"obj":"btn","x":0,"y":295,"w":80,"h":25,"action":"prev","bg_color":"#1fa3ec","radius":10,"border_side":1,"text":"\uF053","text_font":"montserrat-20"}
{"id":102,"obj":"btn","x":80,"y":295,"w":80,"h":25,"action":"back","bg_color":"#1fa3ec","radius":10,"border_side":1,"text":"\uF015","text_font":"montserrat-20"}
{"id":103,"obj":"btn","x":160,"y":295,"w":80,"h":25,"action":"next","bg_color":"#1fa3ec","radius":10,"border_side":1,"text":"\uF054","text_font":"montserrat-20"}

{"page":1,"comment":"---------- Page 1 ----------"}
{"id":0,"bg_color":"#0000A0","bg_grad_color":"#000000","bg_grad_dir":1,"text_color":"#FFFFFF"}

{"comment":"---------- Photovoltaik ----------"}
{"id":60,"obj":"label","x":5,"y":175,"w":115,"h":20,"text":"PV-Anlage:","align":"left","text_font":"montserrat-20"}
{"id":61,"obj":"label","x":120,"y":175,"w":115,"h":20,"text":"","align":"right","text_font":"montserrat-20"}
{"id":62,"obj":"label","x":5,"y":200,"w":58,"h":15,"text":"Verbrauch:","align":"left","text_font":"montserrat-10"}
{"id":63,"obj":"label","x":60,"y":200,"w":50,"h":15,"text":"","align":"right","text_font":"montserrat-10"}
{"id":64,"obj":"label","x":5,"y":215,"w":55,"h":15,"text":"Erzeugt:","align":"left","text_font":"montserrat-10"}
{"id":65,"obj":"label","x":55,"y":215,"w":55,"h":15,"text":"","align":"right","text_font":"montserrat-10"}
{"id":66,"obj":"label","x":120,"y":200,"w":60,"h":15,"text":"Export:","align":"left","text_font":"montserrat-10"}
{"id":67,"obj":"label","x":180,"y":200,"w":55,"h":15,"text":"","align":"right","text_font":"montserrat-10"}
{"id":68,"obj":"label","x":120,"y":215,"w":60,"h":15,"text":"Import:","align":"left","text_font":"montserrat-10"}
{"id":69,"obj":"label","x":180,"y":215,"w":55,"h":15,"text":"","align":"right","text_font":"montserrat-10"}
{"id":70,"obj":"bar","x":5,"y":233,"w":230,"h":20,"bg_color":"green","bg_color10":"lime","bg_opa":255,"val":0,"text":"Batterie:","align":"center","text_color":"#000000","text_font":"montserrat-14"}
{"id":71,"obj":"obj","x":0,"y":230,"w":3,"h":26,"bg_color":"red","bg_opa":255,"border_width":0,"comment":"--- Tagesmaximalwert ---"}

[waltkind]

1. payload_s is valid. I see it with a print command.
2. x is the x-coordinate of the object p1b71. It is a LVGL statement.
3. I tested the line now with:

 if st == 'statBattDayMax' p1b71.x = int(number('10.7')*2.3+5) end

and the memory is shrinking.

[waltkind]

To make it more precise, the line

  if st == 'statBattDayMax' p1b71.x = 25 end

also results in a shrinking memory.

I also compiled a new version. I am now on Tasmota 13.4.0.1. No change with this.

[s-hadinger]

There is nothing wrong with this code. The problem must lie between haspmota and lvgl.

[s-hadinger]

I found the culprit. I was calling repeatedly re.search(), which means that the memory leak is in the memory management of the compiled regex. I have fixed HASPmota to do a single call for now.

[waltkind]

Thank you for looking into that problem.
I compiled a new version from the development branch. It is still noted as 13.4.0.1(lvgl-haspmota). Is that OK or did I do something wrong?
It is now up and running and I will have an eye on the memory.

[s-hadinger]

The version number does not change for each commit, so it's normal.

[waltkind]

After one day I see no significant reduction of memory. So the problem seems to be solved.
I mark the thread as answered and thank you very much.