ESP-IDF 4.2 reset on radio

[duncairn]

I have a project using an Wroom-32 which I developed using ESP-IDF 4.1 and the legacy build tools (i.e. msys2). But 4.1 is behind the times so I tried moving up to 4.2 (legacy tools with 4.2 Dev and Cmake with 4.2 relaese). With any 4.2 version the Wroom resets as soon as I enable Bluetooth:

I (13186) BLE: Starting nimble
I (13186) BTDM_INIT: BT controller compile version [d9cc6b1]
I (13196) system_api: Base MAC address is not set
I (13206) system_api: read default base MAC address from EFUSE
W (13226) phy_init: failed to load RF calibration data (0xffffffff), falling back to full calibration
ets Jun 8 2016 00:22:57

rst:0x8 (TG1WDT_SYS_RESET),boot:0x13 (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:0x3fff0030,len:4
load:0x3fff0034,len:7092
load:0x40078000,len:13696
load:0x40080400,len:4000
0x40080400: _init at ??:?
entry 0x40080688
I (58) boot: ESP-IDF v4.2-dev-1126-gd85d3d969 2nd stage bootloader
I (58) boot: compile time 21:03:42
I (58) boot: chip revision: 1
I (63) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (70) boot.esp32: SPI Speed : 40MHz
I (75) boot.esp32: SPI Mode : DIO
I (79) boot.esp32: SPI Flash Size : 2MB
W (84) boot.esp32: PRO CPU has been reset by WDT.
W (89) boot.esp32: WDT reset info: PRO CPU PC=0x400811ce
0x400811ce: xt_highint4 at G:/ESP32/idf4.2/esp-idf/components/esp_system/port/esp32/dport_panic_highint_hdl.S:62
W (95) boot.esp32: WDT reset info: APP CPU PC=0x4008b03a
0x4008b03a: ram_chip_i2c_readReg at /home/aiqin/git_tree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_ana.c:59
I (101) boot: Enabling RNG early entropy source...
I (107) boot: Partition Table:
I (110) boot: ## Label Usage Type ST Offset Length
I (118) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (125) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (133) boot: 2 factory factory app 00 00 00010000 00100000
I (140) boot: End of partition table

Apologies for the length of this post!

Anyway, you'll take one look at that and consider it's a power issue (yes, I did a lot of searching on this issue). However, I think that's a red herring because a) the code and hardware works perfectly well using IDF 4.1. In fact, I tried turning on WiFi and BLE on the Wroom and simultaneously a GSM modem (now there's a power sucker) and simultaneously a string of LEDs using ~100mA, and with IDF 4.1 it works fine. But 4.2 kills it if I just turn on BLE.

Another thing: I can run the example BLE apps with 4.2, just not my code. For reference, with 4.1 this is what happens:

I (10792) BLE: Starting nimble
I (10792) BTDM_INIT: BT controller compile version [6decaaf]
I (10812) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (11062) phy: phy_version: 4102, 2fa7a43, Jul 15 2019, 13:06:06, 0, 0
I (11312) BLE: host task started
I (11312) gatt_svr: registered service 0x1800 with handle=1
I (11312) gatt_svr: registering characteristic 0x2a00 with def_handle=2 val_handle=3

So, my supposition is that my code uses something that changed between 4.1 and 4.2 that causes this issue, and most likely that something isn't used by the simple example apps (or, at least, not triggered by them). How do I find out what that thing is?

Ah, and someone will pop up and say it's the partition size. I changed that too without success. However, the failure mode did change:

I (20286) USER: new state: waking
I (20286) BLE: Starting nimble
I (20286) BTDM_INIT: BT controller compile version [d9cc6b1]
I (20296) system_api: Base MAC address is not set
I (20306) system_api: read default base MAC address from EFUSE
W (20326) phy_init: failed to load RF calibration data (0xffffffff), falling back to full calibration
ets Jun 8 2016 00:22:57

rst:0x8 (TG1WDT_SYS_RESET),boot:0x13 (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:0x3fff0030,len:4
load:0x3fff0034,len:7092
load:0x40078000,len:13696
load:0x40080400,len:4000
0x40080400: _init at ??:?
entry 0x40080688
I (58) boot: ESP-IDF v4.2-dev-1126-gd85d3d969 2nd stage bootloader
I (58) boot: compile time 20:59:28
I (58) boot: chip revision: 1
I (63) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (70) boot.esp32: SPI Speed : 40MHz
I (75) boot.esp32: SPI Mode : DIO
I (79) boot.esp32: SPI Flash Size : 2MB
W (84) boot.esp32: PRO CPU has been reset by WDT.
W (89) boot.esp32: WDT reset info: PRO CPU PC=0x400811ce
0x400811ce: xt_highint4 at G:/ESP32/idf4.2/esp-idf/components/esp_system/port/esp32/dport_panic_highint_hdl.S:62
W (95) boot.esp32: WDT reset info: APP CPU PC=0x4008b075
0x4008b075: ram_chip_i2c_readReg at /home/aiqin/git_tree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_ana.c:63 (discriminator 5)
I (101) boot: Enabling RNG early entropy source...
I (107) boot: Partition Table:
I (110) boot: ## Label Usage Type ST Offset Length
I (118) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (125) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (133) boot: 2 factory factory app 00 00 00010000 00124f80
I (140) boot: End of partition table

Both the above are repeatable, BTW. That is, the results are not flaky but give the same thing every time.

[ESP_Sprite]

Did you run a 'git submodule update' when you updated esp-idf? Could be that the libs are out of sync. (Also, fancy colors in the listing!)

[duncairn]

Yep, did the update, mostly because I wanted to be sure the updated nimble module was there, and it was easier to update the lot than just that

[duncairn]

If anyone is still interested in this, I think I found the cause...

It is rmt! Yes, nothing to do with radio at all. Just a coincidence that my project uses rmt to drive a bunch of LEDs which come on a little before the radio is connected. It takes a couple of seconds for rmt to overwrite memory, hence why there is no sensible crash report and it looks like a hardware power issue.

This is something that's occurred in 4.2 (maybe 4.1 - didn't try). If I copy rmt.c and rmt.h from 4.0 I don't get a crash. Unfortunately, there are a LOT of changes in 4.2 and it's beyond me to figure out what's going on. I know the function though: rmt_fill_memory().

[ESP_Sprite]

Interesting. Any chance you could whittle down your project into something small that still exhibits the behaviour?

[duncairn]

I'll see what I can do.

[amruta]

I am facing similar issue when migrated from v4.0.1 to v4.2
The device reboots almost every 10sec
Attaching a very basic code with sdkconfig from original project. So, I am guessing, it's something in sdkconfig

Here is the log

Code: Select all

ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (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:0x3fff0030,len:4
load:0x3fff0034,len:7172
load:0x40078000,len:13200
load:0x40080400,len:4568
0x40080400: _init at ??:?

entry 0x400806f4
I (29) boot: ESP-IDF v4.2-rc-5-g511965b26-dirty 2nd stage bootloader
I (29) boot: compile time 16:49:44
I (29) boot: chip revision: 0
I (43) boot.esp32: SPI Speed      : 40MHz
I (43) boot.esp32: SPI Mode       : DIO
I (43) boot.esp32: SPI Flash Size : 4MB
I (48) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (64) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (71) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (79) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (86) boot:  3 ota_0            OTA app          00 10 00010000 00180000
I (94) boot:  4 ota_1            OTA app          00 11 00190000 00180000
I (101) boot: End of partition table
I (105) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x03058 ( 12376) map
I (119) esp_image: segment 1: paddr=0x00013080 vaddr=0x3ffbdb60 size=0x016a8 (  5800) load
I (126) esp_image: segment 2: paddr=0x00014730 vaddr=0x40080000 size=0x00404 (  1028) load
0x40080000: _WindowOverflow4 at F:/ESP32/toolchain/v4.2_rc/esp-idf/components/freertos/xtensa/xtensa_vectors.S:1730

I (133) esp_image: segment 3: paddr=0x00014b3c vaddr=0x40080404 size=0x083fc ( 33788) load
I (156) esp_image: segment 4: paddr=0x0001cf40 vaddr=0x00000000 size=0x030d8 ( 12504)
I (161) esp_image: segment 5: paddr=0x00020020 vaddr=0x400d0020 size=0x159a8 ( 88488) map
0x400d0020: _stext at ??:?

I (201) boot: Loaded app from partition at offset 0x10000
I (201) boot: Disabling RNG early entropy source...

Platform Details:

• Platform: Windows
• esp-idf version: release/v4.2 (commit: 511965b269452e247a610f44c209020a7d1f05c2)
• git modules are updated

[amruta]

It is the RTC watchdog causing this problem.

Possible solutions:

• Disable RTC watchdog: Bootloader config->Use RTC watchdog in start code
• Increase RTC timeout Bootloader config->Timeout for RTC watchdog
• Feed RTC watchdog: import "soc/rtc_wdt.h" and invoke "rtc_wdt_feed();" periodically

Check this thread for more details: https://github.com/espressif/arduino-esp32/issues/2230

For me, everything was working fine with esp-idf v4.0.1 but had to do above changes when using esp-idf v4.1 and above