Random Fatal exception:4

[svefro]

i have about 70-80 esp8266 nodes around in my house.
They all run the same firmware. (made by me) and controls almost everything in my house.
Recently most of them have started to reboot with Fatal exception:4 flag:3.
Sometimes they stay online for 2 days other times 2 minutes.
Longest uptime now is 5 days due to a power outage on the supply to my house.

Previously i have had 100days++ uptime on them and i have only rebooted them to do a firmware update.
The software uses webserver, tcp client for remote console, mqtt, ntp time syncing, serial output (if pin is not used by something else) ota update+++

I have implemented a simple stack save function so i can read the stack dump for remote devices.
The stack trace on all of them points to functions outside my code.

I'll include 2 of the decoded stack traces here in attachments.
but this it what it looks like

Exception: 4 (Level1Interrupt: Level-1 interrupt as indicated by set level-1 bits in the INTERRUPT register)

epc1:     0x40267d22: pm_send_nullfunc at ??:?
epc2:     0x00000000
epc3:     0x00000000
excvaddr: 0x00000000
depc:     0x00000000

stack:

ctx: cont

sp:       0x3ffffc00
end:      0x3fffffc0
offset:   0x00000190
3fffeee0:
  [DATA (0x0x00000018)]
  [DATA (0x0x00012e0d)]
  [DATA (0x0x00000000)]
  0x40245c30: tcp_tmr at /home/earle/src/esp-quick-toolchain/arduino/tools/sdk/lwip2/builder/lwip2-src/src/core/tcp.c:239
3fffeef0:
  [DATA (0x0x00000000)]
  [DATA (0x0x00000000)]
  0x3fff2938: ?? at /home/earle/src/esp-quick-toolchain/arduino/tools/sdk/lwip2/builder/lwip2-src/src/core/timeouts.c:122
  0x402442cf: tcpip_tcp_timer at /home/earle/src/esp-quick-toolchain/arduino/tools/sdk/lwip2/builder/lwip2-src/src/core/timeouts.c:153
3fffef00:

garage2_gate-decoded.txt

vinterhage_heatpump-decoded.txt

To me it looks like there is a bug somewhere in lwip2-src/src/core/tcp.c
This is a file i'm not able to debug.

I have tested to disable functionality one by one but i can not get rid of the bug.
I have tried to reduce mqtt publish rate. Disable ntp sync. remove remote tcp console code.
Tried different access points from different vendors (ASUS and Unifi)
They appear to reboot even if there is nothing special happening to them.
I can stress test all the interfaces (HTTP, MQTT, TCP Console and serial) without them rebooting.
Then randomly they reboot. and point to tcp.c pm_send_nullfunc.

I almost consistently have 4 out of 70 nodes with less than 1 hour uptime
i can not find anything in common with the ones that reboot most often.
i have done a erase_flash on some of the nodes but it dit not help.

Can anyone think of what might cause this?

[svefro]

I managed to get my firmware working again by using
espressif8266@4.0.1 with PIO_FRAMEWORK_ARDUINO_ESPRESSIF_SDK3

This has been stable since the last post. (3 months)

Today i changed to the latest espressif arduino sdk for platform io and the random reboots returned.
espressif8266@4.1.0 with PIO_FRAMEWORK_ARDUINO_ESPRESSIF_SDK305

Exception: 4 (Level1Interrupt: Level-1 interrupt as indicated by set level-1 bits in the INTERRUPT register)

epc1:     0x4026a4f2: pm_send_nullfunc at /home/wchen/gwen/nonos/app/pp/pm.c:2060
epc2:     0x00000000
epc3:     0x00000000
excvaddr: 0x00000000
depc:     0x00000000

stack:

ctx: cont

sp:       0x3ffffc00
end:      0x3fffffc0
offset:   0x00000190
3fffeed0:
  [DATA (0x0x3ffebb78)]
  [DATA (0x0x3ffebb80)]
  [DATA (0x0x0000080c)]
  [DATA (0x0x00000002)]
3fffeee0:
  0x4026a2a0: pm_active_timeout at /home/wchen/gwen/nonos/app/pp/pm.c:1922
  [DATA (0x0x00000018)]
  [DATA (0x0x00000000)]
  [DATA (0x0x00000000)]
3fffeef0:
  0x40257f4e: sta_input at /home/wchen/gwen/nonos/app/net80211/ieee80211_sta.c:983
  [DATA (0x0x3ffefbe8)]
  [DATA (0x0x3ffefbe8)]
  [DATA (0x0x3ffed140)]
3fffef00:
  [DATA (0x0x00000000)]
  [DATA (0x0x3ffebf68)]
  [DATA (0x0x00000000)]
  [DATA (0x0x00000000)]
3fffef10:
  0x4026a2f8: pm_active_timeout at /home/wchen/gwen/nonos/app/pp/pm.c:1941
  [DATA (0x0x3ffebf68)]
  0x3fff1440: ?? at /home/wchen/gwen/nonos/app/main/ets_timer.c:55
  0x4026c03f: ppRxPkt at /home/wchen/gwen/nonos/app/pp/pp.c:1086
3fffef20:
  0x4027024d: ets_timer_handler_isr at /home/wchen/gwen/nonos/app/main/ets_timer.c:319
  [DATA (0x0x3ffed134)]
  [DATA (0x0x3fffdcc0)]
  [DATA (0x0x3ffec298)]

in the mean time i struggled with some random exception 28 after building the firmware.
if i place a print line where the exception is thrown it disappears and everything works fine, (the firmware never crashes)
That is until next time i make a small change and build a new version. i do the dance again and the firmware is stable again.
I usualy upload to a few devices and check that everything works fine for a few days before i update all my nodes.

Anybody have a clue what the root cause could be?

[Daryavahus]

You are not alone. A have got the same problem. Error SWT . I get mail with error reason, after ESP restart, so I know the place where firmware crashed. It's always pm_send_nullfunc. And I'm still thinking where is the bug. I've read, that it is because of TCP and Webserver refreshing. In some place CPU works too long. But error crashed randomly. Sometimes after 1 day, sometimes after 3-4 days.
Maybe should we call it to Arduino ESP workteam?

[svefro]

Someone that knows the inner workings of the arduino sdk should look in to this.
But it is hard to reproduce simply. My firmware for 1mb boards (lite in the list) is almost 500kb. and for larger boards (full in the list) about 540kb. i do not know how to reproduce it with a simple snippet.

I have about 70 devices online now running the almost the same firmware. I have tried everything i can think off.
I even went back to a old version from before the issue was noticed and the issue persisted.
It seems like the memory of the units get corrupted somehow, and then it starts.
I have tried clearing many of the nodes but it does not resolve the issue.

Some have been online since power on and some are rebooting inconsistently. (we had a power outage about 49 days ago)

[mhightower83]

@svefro

managed to get my firmware working again by using
espressif8266@4.0.1 with PIO_FRAMEWORK_ARDUINO_ESPRESSIF_SDK3

This has been stable since the last post. (3 months)

Today i changed to the latest espressif arduino sdk for platform io and the random reboots returned.
espressif8266@4.1.0 with PIO_FRAMEWORK_ARDUINO_ESPRESSIF_SDK305

I am confused by 4.0.1 and 4.1.0 are those version numbers correct? Or is it 3.0.1 and 3.1.0?

I got your pm_send_nullfunc crash the other day with a zero OOM count. I usually go for over 14 days before it just stops responding to Network requests. Other hangs like this are very rare for me. And as a remote device, I don't have a lot to work with.

I plan to look deeper at ieee80211_getmgtframe and esf_buf_alloc. I need to look for a non-OOM fail path.

The pre-release SDK 3.0 does not use IRAM Heap from esf_buf_alloc whereas SDK 3.0.5 does.

In your working and not working builds are both configured for:

1. an IRAM Heap?
2. VTables: "Flash"? See updated Exception 28 for my concern.
3. Any other possible differences in build options?

[svefro]

version numbers is correct.
platform = espressif8266@4.0.1 with PIO_FRAMEWORK_ARDUINO_ESPRESSIF_SDK3 is stable

I used to have PIO_FRAMEWORK_ARDUINO_MMU_CACHE16_IRAM48 for 1mb boards, and default for larger boards.
But in the latest version i use default for both to avoid having to 'clean' between builds.

That was the only differences.

I think i have a working setup now with:

platform = espressif8266@4.2.0

and

-D PIO_FRAMEWORK_ARDUINO_LWIP2_HIGHER_BANDWIDTH 
-D PIO_FRAMEWORK_ARDUINO_ESPRESSIF_SDK305 

But i have not updated all devices yet.

I have a stack overflow possibility that needs a fix before i test a new version on all my nodes.
but i have not had the time to fix it due to other stuff.
In a edge case i get realy close to 4000 bytes in the stack.

I'll try different vtable locations if i still have random reboots in next version.

By the way: Same firmware with small modifications runs without issue on ESP32 boards.

[mhightower83]

This may be reaching a bit or not.

I suspect there may be a problem with running out of memory. The random Exception 28 hints at that.

Exception 28

"LoadProhibitedCause - A load referenced a page mapped with an attribute that does not permit loads" - Memory read with an invalid address. For us, these are commonly memory address ranges without any memory behind them on the SoC. Register EXCVADDR will have the invalid pointer address used in the load operation. And register EPC1 will have the code address performing the access.

1. Reading memory with a NULL or uninitialized pointer containing an invalid address value.

2. When out of memory (OOM), malloc returns a NULL pointer. Be sure to verify success after malloc or other Heap allocation functions.

3. Another possible cause is attempting to dereference a read pointer stowed in a previously freed heap allocation. After a subsequent reallocation of the block, the pointer is destroyed. Be sure to zero old references to freed Heap allocations. For debugging, it may also help to zero any reference pointers in a Heap allocation before free.

4. Attempts to read strings, tables, or any other elements in Flash from an ISR may sometimes read zeros. Pointers to pointers in the Flash address space are more likely to result in this exception than the other data read.

5. There may be an issue with the VTables: "Flash" option and an ISR using any "C++" classes or methods. Try VTables: "DRAM" or VTables: "IRAM".

After a superficial look with objdump, pm_send_nullfunc at /home/wchen/gwen/nonos/app/pp/pm.c:2060 is very close to a jp $ instruction. I've see this before, the SDK loop till SWDT kicks in. IMO Not a useful failure mode.

The jp $ instruction follows a failed call to ieee80211_getmgtframe. And ieee80211_getmgtframe will fail when esf_buf_alloc returns NULL.

There is a build option that will allow you to monitor the heap for a low-water mark. See the example give in https://arduino-esp8266.readthedocs.io/en/latest/faq/a06-global-build-options.html#how-to-specify-global-build-defines-and-options .

With so many device - in the event you do not have a convenient way to erase WiFi setting when changing SDKs, I'll leave this pointer

• A new approach for erasing WiFi Settings #8828

Edit: Expanded Exception 28 description

[svefro]

I forgot to implement the low watermark function yesterday. i included it now.
Had to do away with ESP.getMaxFreeBlockSize() and ESP.getHeapFragmentation() since "UMM_STATS_FULL" undefines "UMM_INFO"

On my testdevice it returned "19144" witch i thought was high.
but after umm_free_heap_size_min_reset() it it showed '270048'
Even after testing all functions.

I'm always build in release mode but i did a debug build to see if anything changed.
And got this when running:

Stack smashing detected.
Exception (5):
epc1=0x401003aa epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000000 depc=0x00000000
>>>stack>>>
ctx: sys
sp: 3fffff90 end: 3fffffb0 offset: 0000
3fffff90:  3fffdad0 00000000 3fffdab0 401003aa  
3fffffa0:  feefeffe feefeffe feefeffe 40257b34  
<<<stack<<<

After adding some print calls to my loop i figured out that the crash happens after the first run of loop() before next loop starts.

Exception decoder says:

Exception: 5 (Alloca: MOVSP instruction, if caller's registers are not in the register file)

epc1:     0x401003aa: cont_check at C:\Users\svefr\.platformio\packages\framework-arduinoespressif8266\cores\esp8266/cont_util.cpp:58
epc2:     0x00000000
epc3:     0x00000000
excvaddr: 0x00000000
depc:     0x00000000

stack:

ctx: sys

sp:       0x3fffff90
end:      0x3fffffb0
offset:   0x00000000
3fffff90:
  [DATA (0x0x3fffdad0)]
  [DATA (0x0x00000000)]
  [DATA (0x0x3fffdab0)]
  0x401003aa: cont_check at C:\Users\svefr\.platformio\packages\framework-arduinoespressif8266\cores\esp8266/cont_util.cpp:58
3fffffa0:
  [DATA (0x0xfeefeffe)]
  [DATA (0x0xfeefeffe)]
  [DATA (0x0xfeefeffe)]
  0x40257c14: loop_wrapper() at C:\Users\svefr\.platformio\packages\framework-arduinoespressif8266\cores\esp8266/core_esp8266_main.cpp:260

Any idea what can cause this to happen in debug only?
Building in release again everything works fine.

I guess i need to disable features and see when this goes away in debug mode

[mcspr]

Stack smashing detected.

Our user task stack size is limited to 4096 bytes, so something is likely blows it up and overwrites private memory that causes 'stack smashing' check to fail.

Check out GCC warning
#7398

iirc I had problems moving this check inside of task itself, since it could not detect immediate point of failing. but, hw breakpoints are an option to overcome that #5158

It would have to watch these two points of our task struct

Arduino/cores/esp8266/cont.h

Line 52 in 57fa6cd

extern cont_t* g_pcont;

Arduino/cores/esp8266/cont.h

Line 44 in 57fa6cd

unsigned stack_guard1;

Arduino/cores/esp8266/cont.h

Line 48 in 57fa6cd

unsigned stack_guard2;

[mhightower83]

Had to do away with ESP.getMaxFreeBlockSize() and ESP.getHeapFragmentation() since "UMM_STATS_FULL" undefines "UMM_INFO"

Both are allowed. The umm_malloc_cfgport.h assumes a set of defaults. When you start setting defines in the area of metrics, assumptions/defaults are not made allowing the new build defines to control the selection entirely.

but after umm_free_heap_size_min_reset() it it showed '270048'

I assume that is a typo and the number is 27048?

Unless there is an unusual event that has huge demands on the heap or leads to a memory leak, I don't understand the pm_send_nullfunc at /home/wchen/gwen/nonos/app/pp/pm.c:2060 crashes.

[svefro]

it was not a typo, copy paste. 270048 made no sense.

Tested again. after boot umm_free_heap_size_min() returns '17808'
And after umm_free_heap_size_min_reset() umm_free_heap_size_min() returned '16792'
After testing all http endpoints umm_free_heap_size_min() returned '7960'

That makes more sense. i'll look in to this on other devices that have more modules active.
All my nodes use the same firmware but they are configured in many different ways

I did try to define UMM_INFO and some of the other options but it gave some weird linker errors so i just commented out my use of ESP.getMaxFreeBlockSize() and ESP.getHeapFragmentation()

I noticed before that freeblock size drops at some points. as low as 6000.
I mentioned that i use the same string for sending web page chunks.
After each send() i just set the string to ""

sys.net_server_web.sendContent(WebPage);
WebPage = "";

Will that free the memory used? Or do i need to .invalidate() or .clear() it?
I use a lot of WebPage += F("some text");

Regarding the stack smashing in debug build:
i disabled almost everything in (loop)... still stack smashing
disabled almost everything in setup() ... no stack smashing
Enabled one at a time different things and got stack smashing after enabling mqtt

mqtt.setClient(net_client_mqtt);
mqtt.setCallback(mqtt_callback);

it is not even used in the loop.
so i disabled mqtt again and enabled something else.
...stack smashing again. sigh....

Went back to release build and everything works again.
I have never used debug build since i need all the space i can get to be able to OTA.

if anybody wants to have a look at my code i can send a zip with the source. send me a email at svefro gmail.com

i'll continue to investigate with umm_free_heap_size_min() on other devices when i have the time. :)

[mhightower83]

I did try to define UMM_INFO and some of the other options but it gave some weird linker errors

I usually take those as an indicator that make clean or equal is needed.

Will that free the memory used? Or do i need to .invalidate() or .clear() it?

.invalidate() is a protected method and .clear() only sets the length to 0 and does not free resources.

I could not find a discussion that identified the solution. Long ago I had switched from a mixture of =String(); and =""; to =emptyString, but I just retested those and only =String(); works. Also, I just tried = NULL and that works as well.

In summary, these seem to be working:

WebPage = String();
// or
WebPage = NULL;

The matching overloaded operator methods for those will call .invalidate(). I see the method that handles =NULL in the code. I am not sure which is processing =String().

[Daryavahus]

I've noticed, if free RAM is less than 22KB, then ESP has many problems with stability. I'm using ESP mail client and AsynsWebSrv/TCP(5 webpagegs use Strings taken from 4 sensors, RTC and EEPROM). Those libraries use a lot of RAM and RAM defragmentation is more than 30-40%. I moved few voids to ICACHE_FLASH_ATTR. And now ESP can work for even 5 days. But after that SWDT and pm_send_nullfunc error will come. My sketch uses 707KB of flash and almost 62KB of RAM. After 2-3 days free RAM is about 10-11KB.
My configuration:

errors.txt

[mhightower83]

My first thoughts:

1. Set "Preferences: Compiler Warnings: All" and clear all warnings.
2. Verify that every malloc and new resolves to a not NULL pointer
   • I don't remember how a class instantiation fails - I try to avoid having situation where it can occur.
3. Reduce heap fragmentation:
   • Reduce the String class's use of realloc by using the reserve method and test result.
   • Allocated non-temporary memory early.
4. Try and assign as much as you can to the 2nd heap. When possible, the least used first.
5. Use umm_info ESP.getMaxFreeBlockSize() to look closer at the fragmentation reported by ESP.getHeapFragmentation and see what your largest contiguous block size is. (corrected function reference, umm_info is a low-level function used to implement the others.)
   • These calls disable interrupts and do a full sweep through all the used and free allocations in the Heap. The larger the Heap the longer you run with interrupts disabled. This, should not be done often as it may effect the stability of the WiFi operation.

[Daryavahus]

1. Done.
2. I had few errors:
   In file included from d:\Moje Dokumenty\Arduino\libraries\ESP_Mail_Client\src\ESP_Mail_Client.cpp:42:
   d:\Moje Dokumenty\Arduino\libraries\ESP_Mail_Client\src\ESP_Mail_SMTP.h: In member function 'void ESP_Mail_Client::getResponseStatus(const char*, esp_mail_smtp_status_code, int, esp_mail_smtp_response_status_t&)':
   d:\Moje Dokumenty\Arduino\libraries\ESP_Mail_Client\src\ESP_Mail_SMTP.h:2962:25: warning: comparison of integer expressions of different signedness: 'size_t' {aka 'unsigned int'} and 'int' [-Wsign-compare]
   2962 | if (strlen(buf) > codeLength && (buf[codeLength] == ' ' || buf[codeLength] == '-') && textLength > 0)
   | ~~~~~~~~~~~~^~~~~~~~~~~~
   d:\Moje Dokumenty\Arduino\libraries\ESP_Mail_Client\src\ESP_Mail_SMTP.h:2983:26: warning: comparison of integer expressions of different signedness: 'int' and 'size_t' {aka 'unsigned int'} [-Wsign-compare]
   2983 | while (i < strlen(buf) && buf[i] != ' ')
   | ~~^~~~~~~~~~~~~
   d:\Moje Dokumenty\Arduino\libraries\ESP_Mail_Client\src\ESP_Mail_SMTP.h:2987:24: warning: comparison of integer expressions of different signedness: 'int' and 'size_t' {aka 'unsigned int'} [-Wsign-compare]
   2987 | i = (i < strlen(buf) - 1) ? i + 1 : codeLength + 1;
   | ~~^~~~~~~~~~~~~~~~~

Is it possible to generate null_function?
3. Done(partly)
4. Done
5. I'm still working on it.

[mhightower83]

Is it possible to generate null_function?

I am not sure I understand the question. An ISR function could appear to be NULL if it is not defined with IRAM_ATTR. is not in ICACHE at the time of the call. (Might also need to be in the middle of a flash read/write operation as well to fail.)
When a flash read/write operation is in process and an ISR interrupts. If the ICACHE is offline at that moment, the ICACHE address space is read as zeros.

Weak functions that are defined by prototype, but never created can pass the link phase and crash when called.

5. Updated. Oops, sorry umm_info() is not an exposed API. It is the low-level function used to implement ESP.getMaxFreeBlockSize() and a few others.

[Daryavahus]

I finally found the reason of pm_send_nullfunc error. ESP receives data from DHT11. And if it receives NaN, ESP crashes, when convert data to next steps: save in eeprom or display on LCD/webpage(that why I had random reset). When I added NaN verification all problems disappear.