v2.4.0 and Soft WDT reset while WiFi.forceSleepBegin() execution

[essenemari]

Basic Infos

After board upgrade: "esp8266 by Community" from 2.3.0 to 2.4.0 observed Soft WDT reset on WiFi.forceSleepBegin(); execution.

Hardware

Hardware: ESP-12E, ESP-07
Core Version: 2.4.0

Description

Hi Team,
thanks a lot for your awesome work on ESP8266! Appreciate!

I am using WiFi.forceSleepBegin(); as critical command to turn off WiFi module for 10 minutes then turnning on WiFi module for 15 seconds to execute commands then turn WiFi off again. On 2.3.0 it does work perfect (currently ~10 ESP devices).
Noticed recently, that there is new 2.4.0 ESP8266 board software version, so upgraded and found out that my ESPs are reseting. If you'll take a look for loop it crashes exactly after Serial.println("Before WiFi.forceSleepBegin()"); and usually on 2nd or 3rd loop.
When downgraded to esp v2.3.0 - back to normal.

Settings in IDE

Module: Generic ESP8266 Module
Flash Size: 521K
CPU Frequency: 80Mhz
Flash Mode: dio
Flash Frequency: 40Mhz
Upload Using: SERIAL
Reset Method: ck

Sketch

#include "JsonStreamingParser.h"
#include "JsonListener.h"
#include "ExampleParser.h"
#include "Base64.h"
#include <ESP8266WiFi.h>
long int cykl_counter_start = 600000;

void setup() {
}

void loop() {
for (cykl_counter = cykl_counter_start; cykl_counter > 0; cykl_counter--) {
delay(1);
if (cykl_counter == cykl_counter_delay) {
delay(100);
Serial.println("Before WiFi.forceSleepBegin()");
WiFi.forceSleepBegin();
delay(100);
Serial.println("Sleeping");
}
if (cykl_counter == 15000) {
Serial.println("WiFi.forceSleepWake()");
WiFi.forceSleepWake();
Serial.println("Wakeing");
delay(100);
}
if (cykl_counter == 10000) {
Serial.println("Tasks");
delay(100);
}
}
}

Debug Messages

Soft WDT reset

ctx: cont 
sp: 3fff0770 end: 3fff0970 offset: 01b0

>>>stack>>>
3fff0920:  0001360d 00000600 3ffef638 4022608c  
3fff0930:  0fffffff 4020533a 00000000 40205325  
3fff0940:  00000000 3ffef53c 3ffef540 40203a16  
3fff0950:  3fffdad0 00000000 3ffef93c 40207090  
3fff0960:  feefeffe feefeffe 3ffef950 40100710  
<<<stack<<<

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


 ets Jan  8 2013,rst cause:4, boot mode:(1,1)

wdt reset

[trentbrown13]

perhaps related to
#3662

[igrr]

@essenemari could you please add the definitions of cykl_counter and cykl_counter_delay?

Edit: never mind, figured out their values.
Can reproduce this with

long int cykl_counter_start = 6000;
long int cykl_counter = 0;
long int cykl_counter_delay = cykl_counter_start - 1000;

and 15000 and 10000 changed to 2000 and 3000.

However, i get hardware WDT reset instead of soft WDT, and it happens after "Sleeping" is printed.

[igrr]

@essenemari Could you please try with "lwIP Variant" set to "v1.4 Prebuilt" in Tools menu? I'm not getting my variant of the crash with lwIP 1.4.

[essenemari]

Hello igrr,
thanks a lot for looking into that. I have changed "lwIP Variant" set to "v1.4 Pre Built" but unfortunately it did not help. Because issue occurs around WiFi, let me put full Sketch and somekind of debugger. Tested on ESP-07.
Let me know if I can help.

Thank You!

Sketch

#include "Base64.h"
#include <ESP8266WiFi.h>
#define EIOT_USERNAME ""
#define EIOT_PASSWORD ""
#define EIOT_IP_ADDRESS ""
#define EIOT_PORT 81
#define USER_PWD_LEN 40
WiFiClient rPiClient;
char unameenc[USER_PWD_LEN];
int cykl_counter_start = 20000;
int cykl_counter = 0;
int cykl_counter_delay = cykl_counter_start - 100;
int WifiConnectionAttempt = 0;
const char* ssid = "";
const char* password = "";
void setup() {
Serial.begin(115200);
//initial Wifi and server connection
Serial.println();
Serial.print("Connecting to ");
Serial.println();
Serial.println(ssid);
WiFi.begin(ssid, password);
delay(8000);
if (WiFi.status() == WL_CONNECTED) {
Serial.println("Initial WiFi connection OK");
Serial.println(WiFi.localIP());
} else
Serial.println("Initial WiFi connection FAILED");
rPiClient.connect(EIOT_IP_ADDRESS, EIOT_PORT);
delay(10);
if (rPiClient.connect(EIOT_IP_ADDRESS, EIOT_PORT))
Serial.println("Initial connection to server OK");
else
Serial.println("Initial connection to server FAILED");
char uname[USER_PWD_LEN];
String str = String(EIOT_USERNAME) + ":" + String(EIOT_PASSWORD);
str.toCharArray(uname, USER_PWD_LEN);
memset(unameenc, 0, sizeof(unameenc));
base64_encode(unameenc, uname, strlen(uname));
}
void loop() {
for (cykl_counter = cykl_counter_start; cykl_counter > 0; cykl_counter--) {
delay(1);
if (cykl_counter == cykl_counter_delay) {
delay(100);
Serial.println("Before WiFi.forceSleepBegin()");
WiFi.forceSleepBegin();
delay(100);
Serial.println("Sleeping");
}
if (cykl_counter == 15000) {
Serial.println("WiFi.forceSleepWake()");
WiFi.forceSleepWake();
Serial.println("Wakeing");
delay(100);
}
if (cykl_counter == 10000) {
Serial.println("Tasks");
delay(100);
}
}
}
void connectivity() {
if (WiFi.status() != WL_CONNECTED || !rPiClient.connected()) {
while (WifiConnectionAttempt < 3) {
delay(1000);
WiFi.begin(ssid, password);
delay(10);
rPiClient.connect(EIOT_IP_ADDRESS, EIOT_PORT);
delay(10);
WifiConnectionAttempt++;
//Serial.println(WifiConnectionAttempt);
if (WifiConnectionAttempt == 3)
Serial.println("Not connected to WiFi or to Server. Skipping connection to next loop.");
}
if (WiFi.status() == WL_CONNECTED) {
Serial.println("WiFi connected");
Serial.println(WiFi.localIP());
}
if (rPiClient.connect(EIOT_IP_ADDRESS, EIOT_PORT)) {
Serial.println("Connected to Server");
}
}
}

Debbug

Initial WiFi connection OK
192.168.0.114
Initial connection to server OK
Before WiFi.forceSleepBegin()
Sleeping
WiFi.forceSleepWake()
Wakeing
Tasks
Before WiFi.forceSleepBegin()

Soft WDT reset

ctx: cont
sp: 3ffefc40 end: 3ffefe50 offset: 01b0

stack>>>
3ffefdf0: 0001360d 00000600 3ffeebbc 40219dac
3ffefe00: 0fffffff 402023f6 00000000 402023e1
3ffefe10: 00000000 3ffeedf0 3ffeeb78 4020209a
3ffefe20: 00000000 00000000 00000001 3ffeee1c
3ffefe30: 3fffdad0 00000000 3ffeee14 40203854
3ffefe40: feefeffe feefeffe 3ffeee30 40100710
<<<stack<<<

ets Jan 8 2013,rst cause:2, boot mode:(1,0)

ets Jan 8 2013,rst cause:4, boot mode:(1,0)

wdt reset

[Thelmos]

Same problem here...

Switched to 2.4.0-rc2 and all works again.

Exception was:

Soft WDT reset

ctx: cont 
sp: 3fff0e20 end: 3fff1090 offset: 01b0

>>>stack>>>
3fff0fd0:  0001360d 00000600 3ffefd28 40234330  
3fff0fe0:  0fffffff 40203822 00000000 4020380d  
3fff0ff0:  3ffefd1c 3ffefd24 3ffefd28 402025d1  
3fff1000:  3ffefd1c 3ffefd24 3ffeffa0 40203252  
3fff1010:  00000000 00000000 00000000 00000000  
3fff1020:  00000000 00000000 00000000 00000000  
3fff1030:  00000000 00000000 00000000 00000000  
3fff1040:  00000001 00000000 00000000 40106a05  
3fff1050:  00000000 3ffefd18 3fff0059 3fff0060  
3fff1060:  3fffdad0 00000000 3fff0059 4020328d  
3fff1070:  3fffdad0 00000000 3fff0059 402094f4  
3fff1080:  feefeffe feefeffe 3fff0070 40100710  
<<<stack<<<

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


 ets Jan  8 2013,rst cause:4, boot mode:(1,6)

wdt reset

Decoded stack trace:

Decoding 9 results
0x40234330: dhcp_renew at core/dhcp.c line 1083
0x40203822: WiFiEventHandlerOpaque::operator()(_esp_event*) at c:\users\thelmos\appdata\local\arduino15\packages\esp8266\tools\xtensa-lx106-elf-gcc\1.20.0-26-gb404fb9-2\xtensa-lx106-elf\include\c++\4.8.2/functional line 1954
:  (inlined by) ESP8266WiFiGenericClass::_eventCallback(void*) at C:\Users\Thelmos\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.4.0-rc2\libraries\ESP8266WiFi\src/ESP8266WiFiGeneric.cpp line 233
0x4020380d: std::list  , std::allocator   > >::_M_erase(std::_List_iterator   >) at c:\users\thelmos\appdata\local\arduino15\packages\esp8266\tools\xtensa-lx106-elf-gcc\1.20.0-26-gb404fb9-2\xtensa-lx106-elf\include\c++\4.8.2/functional line 1954
:  (inlined by) std::list  , std::allocator   > >::erase(std::_List_iterator   >) at c:\users\thelmos\appdata\local\arduino15\packages\esp8266\tools\xtensa-lx106-elf-gcc\1.20.0-26-gb404fb9-2\xtensa-lx106-elf\include\c++\4.8.2\bits/list.tcc line 112
:  (inlined by) ESP8266WiFiGenericClass::_eventCallback(void*) at C:\Users\Thelmos\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.4.0-rc2\libraries\ESP8266WiFi\src/ESP8266WiFiGeneric.cpp line 230
0x402025d1: printConnectionType(int) at F:\Proyectos\Arduino\Alarma\Alarma/espWiFi2eeprom.ino line 135
0x40203252: ESP8266WiFiAPClass::softAPConfig(IPAddress, IPAddress, IPAddress) at C:\Users\Thelmos\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.4.0-rc2\libraries\ESP8266WiFi\src/ESP8266WiFiAP.cpp line 294
0x40106a05: timer0_isr_handler at C:\Users\Thelmos\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.4.0-rc2\cores\esp8266/core_esp8266_timer.c line 80
0x4020328d: ESP8266WiFiAPClass::softAPConfig(IPAddress, IPAddress, IPAddress) at C:\Users\Thelmos\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.4.0-rc2\libraries\ESP8266WiFi\src/ESP8266WiFiAP.cpp line 294
0x402094f4: std::_Sp_counted_base(__gnu_cxx::_Lock_policy)0>::_M_release() at c:\users\thelmos\appdata\local\arduino15\packages\esp8266\tools\xtensa-lx106-elf-gcc\1.20.0-26-gb404fb9-2\xtensa-lx106-elf\include\c++\4.8.2\bits/shared_ptr_base.h line 157
:  (inlined by) std::__shared_count(__gnu_cxx::_Lock_policy)0>::~__shared_count() at c:\users\thelmos\appdata\local\arduino15\packages\esp8266\tools\xtensa-lx106-elf-gcc\1.20.0-26-gb404fb9-2\xtensa-lx106-elf\include\c++\4.8.2\bits/shared_ptr_base.h line 546
0x40100710: cont_norm at C:\Users\Thelmos\AppData\Local\Arduino15\packages\esp8266\hardware\esp8266\2.4.0-rc2\cores\esp8266/cont.S line 113

[d-a-v]

Hi, I also reproduced the bug.
It is also reproducable with WiFiOn/WiFiOff imported from at least #2330.
I slightly modified WiFiOff then I get it no more.
The added waiting loop has been running 66 times over 320 main loops (20 seconds each) (edit: 791/4401 24h later).
The test seems to be working but is not very statisfactory since it relies on dhcp state.
If it is proven working, I will try to find a lwip1/lwip2 compatible way to check the netif UP state instead.

I have no explanation why it was working with 2.4.0rc2.
What I can say is that it crashes when rm 0 is coming too late hence the loop to wait for it (and fortunately wifi_station_get_connect_status helps with that).

Normal loop:

---disconnect
state: 5 -> 0 (0)
rm 0
pm close 7
---disconnected
---off...

With waiting loop otherwise crash happen:

---disconnect
---disconnected
dhcp not stopped?
state: 5 -> 0 (0)
rm 0
pm close 7
---off...

Updated full sketch:

#include <ESP8266WiFi.h>
#include <user_interface.h>

void WiFiOn()
{
  wifi_fpm_do_wakeup();
  wifi_fpm_close();
  wifi_set_opmode(STATION_MODE);
  wifi_station_connect();
}


void WiFiOff()
{
  Serial.println("---disconnect");
  wifi_station_disconnect();
  Serial.println("---disconnected");
  bool stopped;
  do
  {
    stopped = wifi_station_get_connect_status() == DHCP_STOPPED;
    if (!stopped)
    {
      Serial.println("dhcp not stopped?");
      delay(100);
    }
  } while (!stopped);
  Serial.println("---off...");
  wifi_set_opmode(NULL_MODE);
  wifi_set_sleep_type(MODEM_SLEEP_T);
  wifi_fpm_open();
  wifi_fpm_do_sleep(0xFFFFFFF);
}

void setup() {
  Serial.begin(115200);
  Serial.setDebugOutput(true);
  WiFi.mode(WIFI_STA);
  WiFi.persistent(false);
  WiFi.begin("open", "");
  Serial.print("Connecting");
  while (WiFi.status() != WL_CONNECTED) {
    Serial.print(".");
    delay(200);
  }
  Serial.println("ok");
}

void loop() {
  for (long int cykl_counter = 20000; cykl_counter > 0; cykl_counter--) {
    delay(1);
    if (cykl_counter == 18000) {
      delay(100);
      Serial.println("\n------------\nBEFORE OFF");
      Serial.println(system_get_free_heap_size());
      WiFiOff(); //WiFi.forceSleepBegin();
      delay(100);
      Serial.println("OFF");
    }
    if (cykl_counter == 15000) {
      Serial.println("\n------------\nBEFORE ON");
      Serial.println(system_get_free_heap_size());
      WiFiOn(); //WiFi.forceSleepWake();
      Serial.println("ON");
      delay(100);
    }
    if (cykl_counter == 10000) {
      Serial.println("Tasks");
      delay(100);
    }
  }
}

[d-a-v]

@Thelmos @essenemari can you try this fix ?

[essenemari]

@d-a-v
thanks a lot that you've looked into that.

Just started the tests off your fix.
First, I am going check several hundred 45 second loop
Then, I am going to check dozens 10 minutes loop.

For now, the 45 second loop works fine.

Thanks!

//4 hours later
flawless

[Teddyz]

I tested the WiFiOff(), WiFiOn() -functions above with 2.4.0 code and lwIP v1.4 prebuilt. Their functionality was put into my project involving conencting to an MQTT-broker via "256dpi/arduino-mqtt". My goal was to run ESP on less power by having no WiFi when not needed.
WiFiOff() turned off Wifi properly, but the current consumption rarely/randomly went down to the lower ,20-ish mA, power consumption from the normal ~70 mA. My solution was to add WiFi.forceSleepBegin() to the end of that function. Now it seems reliable.
Also, it sometimes gets stuck in the "dhcp not stopped?"-loop. I have not yet managed to capture the output before this happens.

[ardyesp]

I ran into same issue with 2.4.2, getting SoftWDT when invoking forceSleepBegin().
The issue does not appear when forceSleepBegin() is called within few short seconds of WiFi.forceSleepWake(), which might explain why some never experience it.

My workaround is to add a delay between disconnect and sleep. This code snippet works:

WiFi.disconnect(); 
delay(1000);
WiFi.mode(WIFI_OFF);
WiFi.forceSleepBegin();
delay(100);