WDT resets with reduced logging level

timredfern
Posts: 31
Joined: Sun Feb 25, 2018 10:59 am

WDT resets with reduced logging level

Postby timredfern » Wed Aug 22, 2018 10:42 am

I'm doing long term tests for a firmware release, I'm seeing a strange phenomenon, posting to see if it rings a bell for anyone:

With otherwise identical firmware, when I disable console logging, the firmware experiences periodic WDT resets (from every few minutes to several hours). If logging is reinstated, these errors go away complelely.

I'm disabling console logging thus:

Code: Select all

esp_log_level_set("*",ESP_LOG_NONE);
The resets show no stack trace when they are triggered, when the device reboots I see this:

Code: Select all

rst:0x8 (TG1WDT_SYS_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:5892
load:0x40078000,len:9308
load:0x40080400,len:6148
entry 0x40080748
W (29) boot: PRO CPU has been reset by WDT.
W (29) boot: WDT reset info: PRO CPU PC=0x40083019
W (29) boot: WDT reset info: APP CPU PC=0x40082187
The addresses point to the cpu halt/ logging code in the esp-idf library.

I'm using esp-idf v3.0-dev-2771-g9a55b42f which doesn't contain https://github.com/espressif/esp-idf/co ... ae30c4ad72

However I'm struggling to understand the interaction with the console log level.

User avatar
kolban
Posts: 1683
Joined: Mon Nov 16, 2015 4:43 pm
Location: Texas, USA

Re: WDT resets with reduced logging level

Postby kolban » Wed Aug 22, 2018 5:15 pm

I'll make a guess.

Imagine some code in a task which reads:

Code: Select all

Task() {
  LOG("We are starting");
  Initialize();
}

Now imagine some code which creates the task:

Code: Select all

Create Task();
Use Task();
Looks pretty innocuous. But look closer at the bottom code, it Creates a task and then immediately assumes that the task has been initialized. When you have logging "disabled", the path length before initialize() is called is shorted than if logging is enabled. Thus you may have a timing puzzle such that you are using a resource before it has been initialized. When debugging is off, the majority of the time the intialization() is reached before you use it ... but when debugging is on, there is a context switch (sometimes) back to where you use it before it has been initialized().

Again ... just a guess.
Free book on ESP32 available here: https://leanpub.com/kolban-ESP32

timredfern
Posts: 31
Joined: Sun Feb 25, 2018 10:59 am

Re: WDT resets with reduced logging level

Postby timredfern » Thu Aug 23, 2018 9:10 am

Hi Kolban thanks, this is very helpful.

The WDT timeout is set to the default, 5 seconds.

My code only starts new tasks during bootup, but I think functions that invoke other hardware systems could have a similar effect?

So in this scenario, a timeout can be be caused where:

- a new task is spawned or a process that affects an autonomous hardware subsystem (ie initialising wifi?) is invoked
- the timing change due to logging causes something that depends on the new task or process to hang (indefinitely, or for over 5 seconds)

I can use selective log level based on tags to narrow down where this could be happening.

__RjAX__
Posts: 1
Joined: Tue Apr 26, 2022 1:55 pm

Re: WDT resets with reduced logging level

Postby __RjAX__ » Tue Apr 26, 2022 1:58 pm

For me, putting the dev board on a breadboard solved the issue, prehaps by eliminating the floating pin issue? (I think I had read in some other post).

Who is online

Users browsing this forum: Bing [Bot] and 71 guests