2.2.0 Exception (3):

[tablatronix]

Basic Infos

Using wifimanager library, on credential save, I get exceptions

Hardware

Hardware: nodemcu v1 12e
Core Version: 2.2.0 stable

Description

Need help deciphering this stack

Settings in IDE

ide 1.6.8

Module: nodemcu v1 12e
Flash Size: 4MB/1MB
CPU Frequency: 80Mhz
Flash Mode: qio
Flash Frequency: 80Mhz
Upload Using: SERIAL
Reset Method: nodemcu

Exception (3):
epc1=0x401003e9 epc2=0x00000000 epc3=0x00000000 excvaddr=0x4000cbd9 depc=0x00000000

ctx: cont 
sp: 3fff03f0 end: 3fff0990 offset: 01a0

Decoding 49 results
0x401003e9: _umm_malloc at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1380
0x40230770: etharp_output at ?? line ?
0x40231808: ip_output_if_opt at ?? line ?
0x401004f4: calloc at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1682
0x401073cc: pvPortZalloc at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/heap.c line 33
0x40220d4d: wifi_param_save_protect_with_check at ?? line ?
0x401057d2: spi_flash_read at ?? line ?
0x40220e35: system_param_save_with_protect at ?? line ?
0x40221224: wifi_station_ap_number_set at ?? line ?
0x4022137f: wifi_station_ap_number_set at ?? line ?
0x4022140c: wifi_station_ap_number_set at ?? line ?
0x40221448: wifi_station_set_config at ?? line ?
0x40202896: ESP8266WiFiSTAClass::begin(char const*, char const*, int, unsigned char const*, bool) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\libraries\ESP8266WiFi\src/ESP8266WiFiSTA.cpp line 505
0x402027b7: ESP8266WiFiSTAClass::begin(char const*, char const*, int, unsigned char const*, bool) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\libraries\ESP8266WiFi\src/ESP8266WiFiSTA.cpp line 505
0x4020a200: wifi_fpm_set_wakeup_cb at ?? line ?
0x40208d41: String::getBytes(unsigned char*, unsigned int, unsigned int) const at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/WString.cpp line 519
0x402423d0: bignum_exptmod at ?? line ?
0x40208d41: String::getBytes(unsigned char*, unsigned int, unsigned int) const at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/WString.cpp line 519
0x40208d6c: String::indexOf(char, unsigned int) const at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/WString.cpp line 519
0x402423d0: bignum_exptmod at ?? line ?
0x40208d90: String::indexOf(char) const at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/WString.cpp line 519
0x402048b0: FunctionRequestHandler::handle(ESP8266WebServer&, HTTPMethod, String) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\libraries\ESP8266WebServer\src\detail/RequestHandlersImpl.h line 53
0x40209638: Print::write(unsigned char const*, unsigned int) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/Print.cpp line 64
0x40208355: Print::write(char const*) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/Print.cpp line 64
0x40241508: bignum_exptmod at ?? line ?
0x40208355: Print::write(char const*) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/Print.cpp line 64
0x40220a9a: wifi_get_opmode at ?? line ?
0x402083a4: Print::println(__FlashStringHelper const*) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/Print.cpp line 64
0x4020276c: ESP8266WiFiSTAClass::status() at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\libraries\ESP8266WiFi\src/ESP8266WiFiSTA.cpp line 505
0x40206c4c: WiFiManager::connectWifi(String, String) at Documents\projects\arduino\sketches\libraries\WiFiManager/WiFiManager.cpp line 716
0x4020872c: String::changeBuffer(unsigned int) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/WString.cpp line 519
0x4020877b: String::reserve(unsigned int) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/WString.cpp line 519
0x402087ad: String::copy(char const*, unsigned int) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/WString.cpp line 519
0x402088b4: String::operator=(String const&) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/WString.cpp line 519
0x402010ae: delay at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/core_esp8266_wiring.c line 53
0x4024153c: bignum_exptmod at ?? line ?
0x40207a4f: WiFiManager::startConfigPortal(char const*, char const*) at Documents\projects\arduino\sketches\libraries\WiFiManager/WiFiManager.cpp line 716
0x4010068c: free at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1731
0x40241560: bignum_exptmod at ?? line ?
0x40207b85: WiFiManager::autoConnect(char const*, char const*) at Documents\projects\arduino\sketches\libraries\WiFiManager/WiFiManager.cpp line 716
0x4010068c: free at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1731
0x40207bdc: WiFiManager::autoConnect() at Documents\projects\arduino\sketches\libraries\WiFiManager/WiFiManager.cpp line 716
0x40206a5f: WiFiManager::WiFiManager() at Documents\projects\arduino\sketches\libraries\WiFiManager/WiFiManager.cpp line 716
0x40202024: setup at Documents\projects\arduino\sketches\libraries\WiFiManager\examples\AutoConnectWithFeedbackLED/AutoConnectWithFeedbackLED.ino line 51
0x40201f70: configModeCallback(WiFiManager*) at Documents\projects\arduino\sketches\libraries\WiFiManager\examples\AutoConnectWithFeedbackLED/AutoConnectWithFeedbackLED.ino line 20
0x402091b4: loop_wrapper at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/core_esp8266_main.cpp line 43
0x40100718: cont_norm at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/cont.S line 109

Want to back this issue? Post a bounty on it! We accept bounties via Bountysource.

[tablatronix]

And testing similar code ( a PR 157 on the wifimanager repo )

Exception (3):
epc1=0x40100255 epc2=0x00000000 epc3=0x00000000 excvaddr=0x40070bde depc=0x00000000

ctx: cont 
sp: 3fff0710 end: 3fff0b90 offset: 01a0

Decoding 30 results
0x40100255: _umm_free at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1298
0x4010020c: _umm_free at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1285
0x402441c0: bignum_exptmod at ?? line ?
0x4010068c: free at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1731
0x40105b32: spi_flash_read at ?? line ?
0x401075c0: vPortFree at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/heap.c line 18
0x40221a2a: wifi_param_save_protect_with_check at ?? line ?
0x402441c0: bignum_exptmod at ?? line ?
0x40221a47: wifi_param_save_protect_with_check at ?? line ?
0x40221aad: system_param_save_with_protect at ?? line ?
0x40221e9c: wifi_station_ap_number_set at ?? line ?
0x40221ff7: wifi_station_ap_number_set at ?? line ?
0x40222084: wifi_station_ap_number_set at ?? line ?
0x402220c0: wifi_station_set_config at ?? line ?
0x40202888: ESP8266WiFiSTAClass::disconnect(bool) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\libraries\ESP8266WiFi\src/ESP8266WiFiSTA.cpp line 505
0x4010053d: _umm_realloc at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1489
:  (inlined by) realloc at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1707
0x4010053d: _umm_realloc at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1489
:  (inlined by) realloc at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1707
0x40221712: wifi_get_opmode at ?? line ?
0x4022253b: wifi_station_get_connect_status at ?? line ?
0x40202990: ESP8266WiFiSTAClass::status() at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\libraries\ESP8266WiFi\src/ESP8266WiFiSTA.cpp line 505
0x40209338: String::changeBuffer(unsigned int) at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/WString.cpp line 519
0x402083bc: WiFiManager::startConfigPortal(char const*, char const*) at Documents\projects\arduino\sketches\libraries\WiFiManager/WiFiManager.cpp line 839
0x4010020c: _umm_free at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1285
0x4010068c: free at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc/umm_malloc.c line 1731
0x40208528: WiFiManager::startConfigPortal() at Documents\projects\arduino\sketches\libraries\WiFiManager/WiFiManager.cpp line 839
0x4020703f: WiFiManager::WiFiManager() at Documents\projects\arduino\sketches\libraries\WiFiManager/WiFiManager.cpp line 839
0x40201fc4: setup at Documents\projects\arduino\sketches\libraries\WiFiManager\examples\ConfigOnSwitch/ConfigOnSwitch.ino line 35
0x40209d90: loop_wrapper at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/core_esp8266_main.cpp line 43
0x40100718: cont_norm at AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266/cont.S line 109

[marwijn]

I got the same exception with the program below:

inline void handler (void)
{
  timer0_write(ESP.getCycleCount() + 500000); 
}

void setup() {
  Serial.begin(74880);
  noInterrupts();
  timer0_isr_init();
  timer0_attachInterrupt(handler);

  timer0_write(ESP.getCycleCount() + 160000);
  interrupts();

}

void loop() {
  Serial.println("Test");
  delay(1000);
}

Hopefully this helps in solving the issue.

[igrr]

@marwijn you are missing ICACHE_RAM_ATTR attribute on the interrupt handler.

[marwijn]

@igrr Thanks a lot never realised I needed it. This fixes my problem. So the original problem is probably not related.

[tablatronix]

I turned debugging on full

*WM: Sent wifi save page
:rcl
:abort
*WM: Connecting to new AP
*WM: Connecting as wifi client...
there is no poison after the block. Expected poison address: 0x3fff3e90, actual data: 0x0 0x5 0x8d 0xfe

Panic AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc\umm_malloc.c:851 check_poison_block

ctx: cont 
sp: 3fff1050 end: 3fff1590 offset: 01b0

[tablatronix]

Seems like the same problems over and over #1856 #1699 #1675

can reproduce similar problem with that #1699 (comment) sketch, but my flash seems ok

Flash real id:   001640E0
Flash real size: 4194304

Flash ide  size: 4194304
Flash ide speed: 40000000
Flash ide mode:  DIO
Flash Chip configuration ok.

[tablatronix]

I had to install esptool.py again and use it for erasing flash to fix this.
Esptool.exe -ce was not doing anything

It works for a second and then does this ( the checkflash sketch again )

Joining network
[WIFI][APlistAdd] add SSID: myNetworkName
[WIFI] delete old wifi config...
there is no poison after the block. Expected poison address: 0x3fff1880, actual data: 0x0 0x5 0xff 0x3f

Panic C:\Users\alverson\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.2.0\cores\esp8266\umm_malloc\umm_malloc.c:851 check_poison_block

ctx: cont 
sp: 3fff02c0 end: 3fff0700 offset: 01b0

>>>stack>>>
3fff0470:  feefeffe feefeffe feefeffe 40100334  
3fff0480:  feefeffe 00000ca0 3ffef5f4 40100435  
3fff0490:  feefeffe feefeffe feefeffe 40100537  
3fff04a0:  feefeffe 00001000 00000484 401006f5  
3fff04b0:  00000484 00001000 000003fe 40107014  
3fff04c0:  40004b31 3fff04f0 0000001c 4021ad41  
3fff04d0:  4010571a 4021ae29 3fff13fc 000003ff  
3fff04e0:  000003fd 3fff0590 3fff13fc 000003fd  
3fff04f0:  ffffff01 55aa55aa 00000009 0000001c  
3fff0500:  0000001c 00000063 00000063 000003ff  
3fff0510:  4021b218 3fff13fc 3fff13fc 000000ff  
3fff0520:  00000001 3fff05b0 4021b373 00000008  
3fff0530:  3fff13fc 000000ff 3fff0590 00000000  
3fff0540:  3fff14bc 3fff05f1 00000001 4021b400  
3fff0550:  3fff0590 3fff13fc 3ffef618 fffffffe  
3fff0560:  3fff05b0 3fff7734 3fff13fc 3ffef618  
3fff0570:  4021b43c 00000000 00000000 6c6f2065  
3fff0580:  402024ec 63206966 69666e6f 2e2e2e67  
3fff0590:  3fff0000 40106e68 3ffef618 00000008  
3fff05a0:  3ffef618 00000029 3fff05f9 402036d0  
3fff05b0:  3fff0500 3fff05c0 00000008 0000002a  
3fff05c0:  3ffef618 00000008 60000000 0000007e  
3fff05d0:  6000001c 0000002b 3ffef4b4 00400000  
3fff05e0:  3ffe8780 53532064 3fff05c0 3fff05f0  
3fff05f0:  3fff088c 402025b0 fe000a65 fffffffe  
3fff0600:  3ffef618 3ffef4b4 00000000 40202283  
3fff0610:  3fff0650 3fff0620 00000008 401006d8  
3fff0620:  4f494420 3030000a 3fff083c 3fff13c4  
3fff0630:  3fff0670 3fff083c 00000018 4020238b  
3fff0640:  3ffe8874 3ffe84b4 3fff0620 3fff0650  
3fff0650:  3fff0690 0000000e 00000009 3fff083c  
3fff0660:  3ffef4a8 3ffe84b4 3ffef618 4020249d  
3fff0670:  3fff083c 3fff13c4 3ffef4a8 40202f61  
3fff0680:  3ffe8494 3ffef5f8 3ffef618 3ffef5f8  
3fff0690:  00400000 3ffef4a8 3ffef618 3ffef5f8  
3fff06a0:  00400000 3ffef4a8 3ffef618 40201d37  
3fff06b0:  feefeffe feefeffe feefeffe feefeffe  
3fff06c0:  00000002 feefeffe feefeffe feefeffe  
3fff06d0:  feefeffe feefeffe feefeffe 3ffef6d4  
3fff06e0:  3fffdad0 00000000 3ffef6cc 40203553  
3fff06f0:  feefeffe feefeffe 3ffef6e0 40100958  
<<<stack<<<

 ets Jan  8 2013,rst cause:2, boot mode:(3,6)

load 0x4010f000, len 1264, room 16 
tail 0
chksum 0x0f
csum 0x0f

[igrr]

Reproduced this, thanks for detailed report. Looks like an out-of-bound write in SDK code. Will dig deeper on Monday.

[kentaylor]

@tablatronix tested WifiManager, found it to fail, provided the trace and @igrr was able to reproduce it.

I believe this is the same problem that led me to finding WiFiManager flaky and which further led to
to my "PR 157 on the wifimanager repo". I believe tzapu/WiFiManager#157 fixes the problem. I always thought there was an underlying issue in the Espressif SDK but assumed Espressif would be unlikely to fix it. It is fascinating to see that @igrr is now interested in fixing this on behalf of Espressif. I further think the issue in the Espressif SDK is subtle and it can also be fixed for Arduino without modifying the Espressif SDK by modifying the ESP8266WiFiSTAClass::begin method.

@tablatronix provides a trace of my version failing as well but the memory corruption could have occurred when running tzapu/WiFiManager and still have been there when later testing with https://github.com/kentaylor/WiFiManager/. I haven't had my version fail during testing and the fix I think was calling WiFi.disconnect(true) before calling WiFi.begin(new SSID, new password) as shown at kentaylor/WiFiManager@3bb5fad#diff-bfe0a2d15de63f0ead6d59ff54dd518eR241 .

I found that calling Wifi.begin(existing SSID, existing password) never failed but calling WiFi.begin(new SSID, new password) or WiFi.begin() will occasionally cause the ESP8266 to fail to connect to WiFi until rebooted and rarely put it into a state that requires reflashing to fix the corrupted memory. Usually rebooting was enough. It was never repeatable for me but the probability of failure did seem to depend on where it was up to in connecting to the access point.

Most people hard code Wifi.begin(SSID, password) into their sketch so are effectively calling Wifi.begin(existing SSID, existing password) which never causes a problem. In this case the Espressif SDK functions wifi_station_set_config, wifi_station_set_config_current and wifi_station_connect are not called. See

Arduino/libraries/ESP8266WiFi/src/ESP8266WiFiSTA.cpp

Line 135 in e82b74e

if(sta_config_equal(current_conf, conf)) {

. So the problem must be associated with calling these functions.

The ESP8266 will autoconnect to WiFi at startup using the stored SSID and password. Currently if Wifi.begin(new SSID, new password) is called while already connecting to WiFi then wifi_station_set_config or wifi_station_set_config_current will be called at an indeterminate time in the WiFi connection sequence. Wifi.begin(new SSID, new password) and WiFi.begin() call the Espressif SDK function wifi_station_connect() when it is already connecting. Mostly it doesn't matter but it seems that if wifi_station_connect() is called when it is at a particular point in the WiFi connection process it causes problems.

Therefore the solution for Arduino is to call wifi_station_disconnect() prior to calling wifi_station_set_config or wifi_station_set_config_current and to not call wifi_station_connect() when it is already connecting to WiFi.

The problem is occurring because wifi_station_connect() is being called when it is not required and can be fixed in Arduino by only calling wifi_station_connect() when required. However, the Espressif SDK should also be modified so that calling wifi_station_connect() is never harmful even if called when not required.

[tablatronix]

Another issue I referenced above had succesfully workaround by setting persistant to false avoiding the saves i am assuming.

[kentaylor]

@tablatronix Yes, if persistent is false wifi_station_set_config_current is called which doesn't write data to flash according to @igrr in #1054. If persistent is true wifi_station_set_config is called which does write data to flash. So it seems setting persistent to false is likely to avoid corrupting the flash.

But WiFi also fails sometimes for me when calling WiFi.begin() and persistent is irrelevant in that case. WiFi.begin() calls the Espressif SDK function wifi_station_connect() see

Arduino/libraries/ESP8266WiFi/src/ESP8266WiFiSTA.cpp

Line 181 in e82b74e

wifi_station_connect();

and wifi_station_dhcpc_start(). I think calling these functions when it is already automatically connecting to WiFi can be harmful.

[igrr]

Okay, the issue in SDK code has been found and will be fixed in the next release. In the meantime I will push a workaround which prevents buffer overrun.