Guru Meditation Error: Core 0 panic'ed (LoadProhibited)

[mdeloof]

Answers checklist

• [X] I have read the documentation ESP-AT Programming Guide and the issue is not addressed there.
• [X] I have used the latest released firmware or have updated my ESP-AT branch (master or release) to the latest version and checked that the issue is present there.
• [X] I have searched the issue tracker for a similar issue and not found a similar issue.

AT+GMR

AT version:3.5.0.0-dev(88b4ea4 - ESP32 - Aug 16 2024 06:21:47)
SDK version:v5.0.6-dirty
compile time(613bf46b):Aug 28 2024 14:01:03
Bin version:v3.4.0.0(WROOM-32)

ESP-AT Firmware Source

Cloned from GitHub

Hardware Information

ESP32-WROOM-32E on custom PCB communicating to STM32F746 over SDIO

Power Supply used

External 3.3V

What is the expected behavior?

We're using the ESP32 in SoftAP mode as well as passthrough mode to stream data over wifi to a single client. Communication between our microcontroller (STM32F746) and the ESP32 happens over the SDIO bus. Before sending data to the ESP32 we read out the rtoken_data register to know how many buffers are available to be written. When there are no buffers available we keep reading this rtoken_data until new buffers are available. In ideal conditions we've been able to consistently stream at ~400KB/s for multiple hours.

What is the actual behavior?

We have observed that if the ESP32 is not able to push out data fast enough over wifi to the connected client (be it due to a poor connection or an arbitrary delay introduced in the receiving code) the ESP32 stops responding to our SDIO command to read rtoken_rdata and we have not found a way to recover from this.

Here is the full trace that was captured with Logic 2

Probability of recurrence

We can reliably reproduce this behavior by introducing a small delay between each TCP recv on the connected client.

AT+SYSRAM?

We're not able to execute this command when the bug occurs.

Steps to reproduce

Configure ESP32 in SoftAP mode, start listening on TCP port, wait for incoming connection, enable passthrough mode, start sending data from microcontroller to ESP32 over SDIO, on the client side perform recv operations with a small delay inbetween.

AT command port output

We're using passthrough mode so there is no AT command port output.

AT log port output

28/08/2024 15:02:06.710 [RX] - ets Jul 29 2019 12:21:46 
 
rst:0x1 (POWERON_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:6984 
load:0x40078000,len:16068 
load:0x40080400,len:3620 
entry 0x40080618 
(27) boot: ESP-IDF v5.0.6-dirty 2nd stage bootloader 
(28) boot: compile time 11:25:56 
(28) boot: Unicore bootloader 
(31) boot: chip revision: v3.1 
(34) boot.esp32: SPI Speed      : 40MHz 
(39) boot.esp32: SPI Mode       : DIO 
(44) boot.esp32: SPI Flash Size : 4MB 
(48) boot: Enabling RNG early entropy source... 
(54) boot: Partition Table: 
(57) boot: ## Label            Usage          Type ST Offset   Length 
(65) boot:  0 phy_init         RF data          01 01 0000f000 00001000 
(72) boot:  1 otadata          OTA data         01 00 00010000 00002000 
(79) boot:  2 nvs              WiFi data        01 02 00012000 0000e000 
(87) boot:  3 at_customize     unknown          40 00 00020000 000e0000 
(94) boot:  4 ota_0            OTA app          00 10 00100000 00180000 
(102) boot:  5 ota_1            OTA app          00 11 00280000 00180000 
(109) boot: End of partition table 
(114) esp_image: segment 0: paddr=00100020 vaddr=3f400020 size=28610h (165392) map 
(182) esp_image: segment 1: paddr=00128638 vaddr=3ff80063 size=00008h (     8) load 
(182) esp_image: segment 2: paddr=00128648 vaddr=3ffb0000 size=032bch ( 12988) load 
(193) esp_image: segment 3: paddr=0012b90c vaddr=40080000 size=0470ch ( 18188) load 
(204) esp_image: segment 4: paddr=00130020 vaddr=400d0020 size=d1c94h (859284) map 
(515) esp_image: segment 5: paddr=00201cbc vaddr=4008470c size=119cch ( 72140) load 
(545) esp_image: segment 6: paddr=00213690 vaddr=400c0000 size=00064h (   100) load 
(556) boot: Loaded app from partition at offset 0x100000 
(556) boot: Disabling RNG early entropy source... 
no external 32k oscillator, disable it now. 
 
at param mode: 1 
 
module_name: WROOM-32 
 
max tx power=78, ret=0 
 
v3.4.0.0 
 
(930) at-sdio: invalid data:0 or len:-1 
connect reach max:1 
 
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled. 
 
Core  0 register dump: 
PC      : 0x4019f360  PS      : 0x00060233  A0      : 0x800e8a74  A1      : 0x3ffd5c30   
A2      : 0x0080ffff  A3      : 0x3ffd5c7c  A4      : 0x0081004b  A5      : 0x00000000   
A6      : 0x00000000  A7      : 0x00060f23  A8      : 0x8019f35d  A9      : 0x3ffd5c10   
A10     : 0x00000001  A11     : 0xffffffff  A12     : 0x00000000  A13     : 0x3ffb1ea0   
A14     : 0x3ffd1af8  A15     : 0x3ffb1ec0  SAR     : 0x0000001a  EXCCAUSE: 0x0000001c   
EXCVADDR: 0x00810037  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff   
 
 
Backtrace: 0x4019f35d:0x3ffd5c30 0x400e8a71:0x3ffd5c70 0x4019ebee:0x3ffd5cb0 
 
 
 
 
ELF file SHA256: 48908843aa66fcab 
 
Rebooting... 
ets Jul 29 2019 12:21:46 
 
rst:0xc (SW_CPU_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:6984 
load:0x40078000,len:16068 
load:0x40080400,len:3620 
entry 0x40080618 
(27) boot: ESP-IDF v5.0.6-dirty 2nd stage bootloader 
(27) boot: compile time 11:25:56 
(27) boot: Unicore bootloader 
(31) boot: chip revision: v3.1 
(34) boot.esp32: SPI Speed      : 40MHz 
(39) boot.esp32: SPI Mode       : DIO 
(44) boot.esp32: SPI Flash Size : 4MB 
(48) boot: Enabling RNG early entropy source... 
(54) boot: Partition Table: 
(57) boot: ## Label            Usage          Type ST Offset   Length 
(64) boot:  0 phy_init         RF data          01 01 0000f000 00001000 
(72) boot:  1 otadata          OTA data         01 00 00010000 00002000 
(79) boot:  2 nvs              WiFi data        01 02 00012000 0000e000 
(87) boot:  3 at_customize     unknown          40 00 00020000 000e0000 
(94) boot:  4 ota_0            OTA app          00 10 00100000 00180000 
(102) boot:  5 ota_1            OTA app          00 11 00280000 00180000 
(109) boot: End of partition table 
(114) esp_image: segment 0: paddr=00100020 vaddr=3f400020 size=28610h (165392) map 
(182) esp_image: segment 1: paddr=00128638 vaddr=3ff80063 size=00008h (     8) load 
(182) esp_image: segment 2: paddr=00128648 vaddr=3ffb0000 size=032bch ( 12988) load 
(193) esp_image: segment 3: paddr=0012b90c vaddr=40080000 size=0470ch ( 18188) load 
(204) esp_image: segment 4: paddr=00130020 vaddr=400d0020 size=d1c94h (859284) map 
(515) esp_image: segment 5: paddr=00201cbc vaddr=4008470c size=119cch ( 72140) load 
(545) esp_image: segment 6: paddr=00213690 vaddr=400c0000 size=00064h (   100) load 
(556) boot: Loaded app from partition at offset 0x100000 
(556) boot: Disabling RNG early entropy source... 
no external 32k oscillator, disable it now. 
 
at param mode: 1 
 
module_name: WROOM-32 
 
max tx power=78, ret=0 
 
v3.4.0.0 
 
(927) at-sdio: invalid data:0 or len:-1 (<< This log happens at boot up and not when the bug occurs.)

More Information.

We've had to change the configuration of the SDIO timings on the ESP32 to make it clock the SDIO bus on the correct edge.

// init sdio slave configuration
sdio_slave_config_t config = {
    .sending_mode       = SDIO_SLAVE_SEND_STREAM,
    .send_queue_size    = CONFIG_AT_SDIO_QUEUE_SIZE,
    .recv_buffer_size   = CONFIG_AT_SDIO_BLOCK_SIZE,
+   .timing             = SDIO_SLAVE_TIMING_NSEND_PSAMPLE
};