Open seansimmons74 opened 2 weeks ago
Can you print some timestamp (or millis()
along with the logs and then try again?
I suspect the amount of free memory will deplete with every call, but if you stop making those calls, it should return about 2 minutes after the call was made that will now free its memory.
I know @me-no-dev has done some fixes in that code, so it should be less of an issue in 3.0.4, but I have not yet tested this myself. At least it should now no longer be possible to DDoS your ESP out of memory anymore.
please make the sketch shorter. Just the minimal necessary to reproduce the problem
@me-no-dev I have shortened the sketch by roughly half and ran it again to give a simplified serial output. @TD-er I added millis() in a few places to show how long the process is taking. I also added a delay(180000) after each run in hopes that it would free up memory but as you can see in my serial output, that is not the case. It seems to be sitting at around 147k (still running it right now) but maybe it will continue to drop after I let this run for a bit longer.
if it stabilizes at some value (147K in your case) that means that everything is OK. Only certain number of connections are kept in memory (and later released too). Log above is OK
I don't understand why it wouldn't free up those resources after finishing operations though. Like if I disconnect wifi too, shouldn't I get those resources back? Also, it's appearing stable now because that was only a few requests over maybe 20 minutes. If I let this run for longer, and shorten the request intervals to more realistic use cases, it will begin to drop again.
I did a few tests yesterday on some nodes and in my setup the previously observed behavior was no longer visible. This previous behavior was keeping some memory allocated after the client already closed the connection and fetched new data. For each call the amount of free memory was less and each of those were released after exactly 2 minutes.
This could allow an ESP to be DDoS'ed out of memory by just fetching some JSON for example. (lots of times, but still...)
As I'm now no longer seeing this behavior, I think we should get back to what you're observing and see if this makes sense or not.
First of all, you are checking the esp_get_minimum_free_heap_size()
which is obviously not going to get better ever until you reboot :)
Maybe ESP.getFreeHeap()
will help here :)
With the printing of millis(), I meant at each log line, so you could see how long it may take for the memory to return. Like this:
Serial.print(millis());
Serial.print(F(" : "));
Serial.println(....);
(Maybe best to also make a function of it.)
Also I didn't mean to just wait for a few minutes using delay()
, but rather keep track of the millis() in the log so you could see if there was any changes.
This while loop should also be done in the loop()
function. Now you are calling it still from the setup()
and I honestly have no idea if the code will behave differently if the setup()
never returns like in your test code.
Anyway, when starting some services, they will allocate some memory. Not sure if these are always freed again when those services are stopped. For example some may allocate static memory.
So it could be something like this:
void loop() {
static unsigned long lastLogPrint = 0;
if ((millis() - lastLogPrint) > 1000) {
Serial.print(millis());
Serial.print(F(" : "));
Serial.print(F("Free Heap: "));
Serial.println(ESP.getFreeHeap());
lastLogPrint = millis();
}
getHealth();
getJWT();
}
And maybe you should also remove the other Serial.print....
statements from your other code or else your ESP will run out of memory as the serial buffer cannot be read fast enough.
Hi @TD-er, sorry for the delay in responding. I have copied your code exactly (see new serial output below for results). The ESP Free Heap seems to properly "free up" after each request. I am seeing roughly 250k prior to the HTTP POST and it drops to 200k after, then back to 250k when finished. I have some questions though.
Here is the new serial printout:
6555 : Free Heap: 299148
Free heap: 253436 :: Heap Integrity: 1 :: ESP Free Heap: 299068 :: Minimum Free Heap: 247768 :: Task Count: 6
ESP Free Heap before HTTP POST: 252736
ESP Free Heap after HTTP POST: 204316
14444 : Free Heap: 251620
Free heap: 205908 :: Heap Integrity: 1 :: ESP Free Heap: 251540 :: Minimum Free Heap: 152040 :: Task Count: 10
ESP Free Heap before HTTP POST: 251628
ESP Free Heap after HTTP POST: 204100
16256 : Free Heap: 251388
Free heap: 205880 :: Heap Integrity: 1 :: ESP Free Heap: 251512 :: Minimum Free Heap: 151764 :: Task Count: 10
ESP Free Heap before HTTP POST: 251404
ESP Free Heap after HTTP POST: 203864
17793 : Free Heap: 251156
Free heap: 205444 :: Heap Integrity: 1 :: ESP Free Heap: 251076 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 251048
ESP Free Heap after HTTP POST: 203684
19022 : Free Heap: 250944
Free heap: 205232 :: Heap Integrity: 1 :: ESP Free Heap: 250864 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 250792
ESP Free Heap after HTTP POST: 203432
20455 : Free Heap: 250728
Free heap: 205016 :: Heap Integrity: 1 :: ESP Free Heap: 250648 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 250740
ESP Free Heap after HTTP POST: 203196
21888 : Free Heap: 250504
Free heap: 204792 :: Heap Integrity: 1 :: ESP Free Heap: 250424 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 250516
ESP Free Heap after HTTP POST: 202992
23320 : Free Heap: 250280
Free heap: 204568 :: Heap Integrity: 1 :: ESP Free Heap: 250404 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 250292
ESP Free Heap after HTTP POST: 202752
24758 : Free Heap: 250056
Free heap: 204344 :: Heap Integrity: 1 :: ESP Free Heap: 249976 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 249920
ESP Free Heap after HTTP POST: 202528
25980 : Free Heap: 249820
Free heap: 204108 :: Heap Integrity: 1 :: ESP Free Heap: 249740 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 249844
ESP Free Heap after HTTP POST: 202308
27417 : Free Heap: 249608
Free heap: 203896 :: Heap Integrity: 1 :: ESP Free Heap: 249528 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 249472
ESP Free Heap after HTTP POST: 202088
28648 : Free Heap: 249384
Free heap: 203672 :: Heap Integrity: 1 :: ESP Free Heap: 249304 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 249220
ESP Free Heap after HTTP POST: 201856
29876 : Free Heap: 249160
Free heap: 203448 :: Heap Integrity: 1 :: ESP Free Heap: 249068 :: Minimum Free Heap: 147020 :: Task Count: 10
ESP Free Heap before HTTP POST: 249024
ESP Free Heap after HTTP POST: 201648
31111 : Free Heap: 248936
Free heap: 203224 :: Heap Integrity: 1 :: ESP Free Heap: 248856 :: Minimum Free Heap: 144952 :: Task Count: 10
ESP Free Heap before HTTP POST: 248812
ESP Free Heap after HTTP POST: 201420
32538 : Free Heap: 248712
Free heap: 203204 :: Heap Integrity: 1 :: ESP Free Heap: 248836 :: Minimum Free Heap: 144952 :: Task Count: 10
ESP Free Heap before HTTP POST: 248588
ESP Free Heap after HTTP POST: 201176
33992 : Free Heap: 248484
Free heap: 202772 :: Heap Integrity: 1 :: ESP Free Heap: 248404 :: Minimum Free Heap: 144952 :: Task Count: 10
ESP Free Heap before HTTP POST: 248500
ESP Free Heap after HTTP POST: 200960
35406 : Free Heap: 248252
Free heap: 202540 :: Heap Integrity: 1 :: ESP Free Heap: 248172 :: Minimum Free Heap: 144952 :: Task Count: 10
ESP Free Heap before HTTP POST: 248128
ESP Free Heap after HTTP POST: 200712```
Additionally, after a longer runtime, I eventually seem to be having an ssl related issue? When this happens, I see a drop in all my health metrics I am logging. See below:
2084184 : Free Heap: 248248
Free heap: 202536 :: Heap Integrity: 1 :: ESP Free Heap: 248168 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 248136
ESP Free Heap after HTTP POST: 200980
2085401 : Free Heap: 248244
Free heap: 202532 :: Heap Integrity: 1 :: ESP Free Heap: 248164 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 248264
[2205807][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[2205907][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 247700
[2206007][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
2206147 : Free Heap: 250280
Free heap: 204568 :: Heap Integrity: 1 :: ESP Free Heap: 250200 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 249948
[2326538][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[2326637][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 245764
[2326737][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
2326877 : Free Heap: 248340
Free heap: 202628 :: Heap Integrity: 1 :: ESP Free Heap: 248260 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 248012
[2447269][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[2447369][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 243828
[2447469][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
2447609 : Free Heap: 246400
Free heap: 200688 :: Heap Integrity: 1 :: ESP Free Heap: 246320 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 246060
[2568098][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[2568198][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 241840
[2568298][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
2568438 : Free Heap: 244440
Free heap: 198728 :: Heap Integrity: 1 :: ESP Free Heap: 244360 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 244100
[2688933][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[2689032][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 239928
[2689132][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
2689271 : Free Heap: 242500
Free heap: 196788 :: Heap Integrity: 1 :: ESP Free Heap: 242420 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 242172
[2809661][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[2809761][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 237988
[2809861][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
2810001 : Free Heap: 240560
Free heap: 194848 :: Heap Integrity: 1 :: ESP Free Heap: 240480 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 240232
[2930494][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[2930594][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 236036
[2930694][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
2930833 : Free Heap: 238608
Free heap: 192896 :: Heap Integrity: 1 :: ESP Free Heap: 238528 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 238280
[3051224][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[3051324][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 234076
[3051424][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
3051563 : Free Heap: 236656
Free heap: 190944 :: Heap Integrity: 1 :: ESP Free Heap: 236576 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 236328
[3171955][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[3172054][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 232136
[3172154][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
3172293 : Free Heap: 234708
Free heap: 188996 :: Heap Integrity: 1 :: ESP Free Heap: 234628 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 234380
[3292687][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[3292789][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 230180
[3292888][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
3293028 : Free Heap: 232752
Free heap: 187040 :: Heap Integrity: 1 :: ESP Free Heap: 232672 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 232432
[3413515][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[3413615][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 228184
[3413715][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
3413855 : Free Heap: 230784
Free heap: 185072 :: Heap Integrity: 1 :: ESP Free Heap: 230704 :: Minimum Free Heap: 136912 :: Task Count: 10
ESP Free Heap before HTTP POST: 230456
[3534348][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[3534448][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 226260
[3534548][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
3534688 : Free Heap: 228832
Free heap: 183120 :: Heap Integrity: 1 :: ESP Free Heap: 228752 :: Minimum Free Heap: 120176 :: Task Count: 10
ESP Free Heap before HTTP POST: 228492
[3655077][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[3655177][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 224300
[3655277][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
3655416 : Free Heap: 226884
Free heap: 181172 :: Heap Integrity: 1 :: ESP Free Heap: 226804 :: Minimum Free Heap: 120176 :: Task Count: 10
ESP Free Heap before HTTP POST: 226544
[3775910][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[3776010][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
ESP Free Heap after HTTP POST: 222356
[3776110][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
3776250 : Free Heap: 224944
Free heap: 179232 :: Heap Integrity: 1 :: ESP Free Heap: 224864 :: Minimum Free Heap: 103440 :: Task Count: 10
ESP Free Heap before HTTP POST: 224604
[3896640][E][NetworkClientSecure.cpp:159] connect(): start_ssl_client: connect failed: -1
[3896740][E][NetworkClient.cpp:318] setSocketOption(): fail on 0, errno: 9, "Bad file number"
And eventually (around a runtime of 4500000) it seems to just sort itself out and get to what it was doing before??
The minimum free heap is actually a very descriptive term. It is the lowest point of free heap that was reached.
There is no general one-size-fits-all amount of free heap which is acceptable. For example in my project (ESPEasy) on ESP8266 I have situations where I have to keep running with less than 3k of free RAM.
There is more to it than just the amount of free ram. For example if your memory gets fragmented you can have like 100k of free memory, but the largest memory block could be less than a few kB, so any attempt to allocate more than this largest free block will fail.
Some libraries like for setting up TLS encryption may need quite a lot of memory (e.g. 20k - 30k, just as an example) So you need to be sure you can successfully keep allocating your runtime data. Typically I want to keep the free ram on ESP32-xx over 80k, but this is no hard limit.
I imagine "just google it" is the answer here but what methods have you had success with in order to prevent/prolong memory fragmentation issues? Do you encourage restarting the board often to prevent this (or in general)?
Main trick is to prevent (re)allocation of large memory chunks.
Thus use reserve
when possible to prevent reallocation.
And when possible use the move operator instead of copying.
This also makes your code faster.
When you need to have large chunks of memory, it is best to allocate those at startup. If you really need a lot of memory, then you can also look into those modules with PSRAM.
Board
ESP32 DevKit V1
Device Description
ESP32 DevKit V1, from Upload Terminal output: Chip is ESP32-D0WDQ5-V3 (revision v3.1) Purchased here
Hardware Configuration
For this example, the only connection to the ESP32 is the Micro USB connector. No debugger or other external connections at this time.
Version
v3.0.4
IDE Name
PlatformIO
Operating System
macOS Sonoma 14.3.1
Flash frequency
40MHz
PSRAM enabled
no
Upload speed
460800
Description
While conducting HTTP requests, I am tracking my min free heap and notice that it drops by quite a bit when I conduct either GET or POST requests. In this simplified version of my code, I am just looping an HTTP POST request to grab a JWT that I generate in the cloud. The message size is always less than 250 characters so it isn't an incoming payload size issue. This simplified version also outputs Free Heap, Heap Integrity, ESP Free Heap, Min Free Heap, and Task Count in a separate function.
I notice that the initial drop in min free heap is the worst (approx. 50k) and then it is followed by many, small drops (maybe 1k at most) with some later requests resulting in some medium sized drops (around 10k) mixed in. There is also a roughly 45k drop when WiFi connects initially but maybe this is expected?
Am I correct in assuming that the min free heap should "return" to previous levels after the http.end() function is called? Shouldn't this free up resources? What is an "acceptable" min free heap level for the aforementioned operations?
I have added a ton of Serial outputs in the main.cpp file and I have also made some changes in the HTTPClient to hopefully find where the issue may be.
In a less simplistic scenario, I will be conducting POST and GET operations every minute to different endpoints in my cloud along with many other things. This issue is a blocker for future plans as I intend to run multiple FreeRTOS tasks at the same time that handle things aside from those HTTP requests such as reading/writing to an SD card, taking sensor readings, and much more so seeing my min free heap drop by a substantial amount and continue to deplete is preventing me from using valuable resources for other duties.
My hunch as of right now: I believe the issue is buried somewhere in the HTTPClient, NetworkClient, or maybe the WiFi library.
I initially commented on a different issue when I noticed they had a similar drop in heap (issue: #10220) I also updated to V3.0.4 as suggested in that issue but the problems mentioned above continue.
Finally, thank you to @Jason2866 and @me-no-dev for responding promptly on the #10220 issue. I'm still fairly new to all this and appreciate any help I get.
**EDIT: As requested, I've shortened my sketch here to focus mainly on the HTTP POST. The WiFiConnect() is pretty standard and the getHealth() function prints out heap values as you'll see in the Serial output.
Sketch
Debug Message
Other Steps to Reproduce
This is not board specific as I've seen the exact same results on different boards. This is also not a memory fragmentation issue as this seems to happen even on the first HTTP request that the program performs (its my understanding that fragmentation happens after long runtimes). I verified that this is not a POST or GET specific issue as both have this problem.
I have also tried disconnecting WiFi after each request finishes and waiting for 3 minutes before reconnecting as well as throwing http.end() everywhere possible.
I have checked existing issues, online documentation and the Troubleshooting Guide