rtc_get_reset_reason() doesn't return the real reason

[martinayotte]

Both using Arduino-esp32 directly or as an esp-idf component, the rtc_get_reset_reason() function doesn't return the real reset reason. It seem that bootloader grab it properly, but change it, so that end-user code can't rely on rtc_get_reset_reason() it in own code.
It seems related to bootloader error seen here "flash read err, 1000". What are those errors exactly ?

echo = sleep  <------ sleep command is issued here
ets Jun  8 2016 00:22:57

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
Falling back to built-in command interpreter.
OK
>ets Jun  8 2016 00:22:57

rst:0x7 (TG0WDT_SYS_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0x00
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0008,len:8
load:0x3fff0010,len:2016
load:0x40078000,len:7780
ho 0 tail 12 room 4
load:0x40080000,len:252
entry 0x40080034

Hello from ESP32AP-06FA84 !
Reset Reason = 7 
I (10391) wifi: wifi firmware version: 1f2a9e1
I (10392) wifi: config NVS flash: enabled
I (10392) wifi: config nano formating: disabled
I (10402) wifi: Init dynamic tx buffer num: 32
I (10402) wifi: Init static tx buffer num: 32
I (10403) wifi: wifi driver task: 3ffde7f0, prio:23, stack:3584
I (10407) wifi: Init static rx buffer num: 10
I (10411) wifi: Init dynamic rx buffer num: 0
I (10415) wifi: Init rx ampdu len mblock:7
I (10419) wifi: Init lldesc rx ampdu entry mblock:4
I (10424) wifi: wifi power manager task: 0x3ffe4358 prio: 21 stack: 2560
I (10431) wifi: wifi timer task: 3ffe53c0, prio:22, stack:3584
I (10453) wifi: mode : softAP (24:0a:c4:06:fa:85)
I (11116) wifi: mode : sta (24:0a:c4:06:fa:84) + softAP (24:0a:c4:06:fa:85)
ReConnecting to previous Remote AP ...
I (12441) wifi: ap channel adjust o:1,1 n:11,2
I (12441) wifi: n:11 0, o:1 0, ap:11 2, sta:11 0, prof:1
I (13100) wifi: state: init -> auth (b0)
I (13104) wifi: state: auth -> assoc (0)
I (13110) wifi: state: assoc -> run (10)
I (13127) wifi: connected with Giroles-Salon, channel 11
Starting TCPServer/OTA/mDNS !
ets Jun  8 2016 00:22:57
 <------ hardware reset is issued here
rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
Falling back to built-in command interpreter.
OK
>ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0x00
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0008,len:8
load:0x3fff0010,len:2016
load:0x40078000,len:7780
ho 0 tail 12 room 4
load:0x40080000,len:252
entry 0x40080034

Hello from ESP32AP-06FA84 !
Reset Reason = 16 
I (10401) wifi: wifi firmware version: 1f2a9e1
I (10402) wifi: config NVS flash: enabled
I (10402) wifi: config nano formating: disabled
I (10412) wifi: Init dynamic tx buffer num: 32
I (10413) wifi: Init static tx buffer num: 32
I (10413) wifi: wifi driver task: 3ffde7f0, prio:23, stack:3584
I (10417) wifi: Init static rx buffer num: 10
I (10421) wifi: Init dynamic rx buffer num: 0
I (10426) wifi: Init rx ampdu len mblock:7
I (10429) wifi: Init lldesc rx ampdu entry mblock:4
I (10434) wifi: wifi power manager task: 0x3ffe4358 prio: 21 stack: 2560
I (10442) wifi: wifi timer task: 3ffe53c0, prio:22, stack:3584
I (10463) wifi: mode : softAP (24:0a:c4:06:fa:85)
I (11127) wifi: mode : sta (24:0a:c4:06:fa:84) + softAP (24:0a:c4:06:fa:85)
ReConnecting to previous Remote AP ...
I (12453) wifi: ap channel adjust o:1,1 n:11,2
I (12453) wifi: n:11 0, o:1 0, ap:11 2, sta:11 0, prof:1
I (13111) wifi: state: init -> auth (b0)
I (13121) wifi: state: auth -> assoc (0)
I (13127) wifi: state: assoc -> run (10)
I (13137) wifi: connected with Giroles-Salon, channel 11
Starting TCPServer/OTA/mDNS !

[igrr]

Which reason does the rtc_get_reset_reason function return you, and which one do you expect to see?

[martinayotte]

Hi Ivan,
As shown in the above log, bootloader prints 5 for deepSleep(), but my code display 7.
And for the external reset, bootloader prints 1, but my code display 16.
I'm pretty sure it is related to intermediate "flash read err, 1000", but I don't know for which reason this is there.

[igrr]

Ah, sorry, missed those lines in the log.

As you can see, the last reset reason printed before your

Reset Reason = 7 

line is

rst:0x7 (TG0WDT_SYS_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)

And before

Reset Reason = 16 

goes

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)

So the rtc_get_reset_reason function returns exactly the reason of the last reset as it is seen by the bootloader.

[martinayotte]

I understood that, but why this intermediate TG0WDT_SYS_RESET is present while doing a wake up from deepSleep ? And why this intermediate RTCWDT_RTC_RESET is present when been started by external reset with POWERON_RESET ?
The above log represent only 2 actions, sleep and button reset. As you can see, it seems that bootloader is adding new reasons after each actions.
Why there are those between real reasons and the new ones :

flash read err, 1000
Falling back to built-in command interpreter.
OK

[igrr]

Both of these behaviours are described in the errata document:
http://espressif.com/sites/default/files/documentation/eco_and_workarounds_for_bugs_in_esp32_en.pdf

1. When the ESP32 (rev. 0) is powered on, a spurious RTCWDT_RTC_RESET occurs. There is no workaround for this issue. It will always happen for rev 0 silicon, and is fixed in rev. 1. ESP-IDF contains a workaround to prevent this issue from happening after deep sleep.

2. When the ESP32 (both rev. 0 and rev. 1) is powered on, or restarts after deep sleep, it may access the flash chip before the flash chip is fully powered on. Whether this issue occurs or not depends on the flash chip startup time. At power up with rev0 silicon, this issue is masked by the previously mentioned one. But it can be observed using rev0 silicon after deep sleep reset (your case) and both at power on and deep sleep reset when using rev1 silicon.
   ESP-IDF contains a workaround for the deep sleep reset case: you should set "Extra delay in deep sleep wake stub (in us)" option under "ESP32 specific" menu in menuconfig to some value like 500 (microseconds). This option introduces certain delay after deep sleep reset, which allows the flash chip to start up before the ROM bootloader will try to read the application.

[martinayotte]

Interesting ! I wasn't aware ...
For the RTCWDT_RTC_RESET, this is also true for external reset, not only powerup, right ?
I hope rev.1 production will ramp up soon...
For the deepSleep, the software workaround works ! Thanks for the hint !

[igrr]

ESP32 doesn't have a dedicated reset line, instead CHIP_PU pin is used both as a power down pin and a reset pin. So a low pulse on CHIP_PU is equivalent to a power off followed by power on. This is why an external reset is logged as a power on reset.