Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
3 tasks done
mdeloof opened this issue Aug 28, 2024 · 3 comments
Open
3 tasks done

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

mdeloof opened this issue Aug 28, 2024 · 3 comments

Comments

@mdeloof
Copy link

mdeloof commented Aug 28, 2024

Answers checklist

  • I have read the documentation ESP-AT Programming Guide and the issue is not addressed there.
  • 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.
  • 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

image

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
};
@mdeloof
Copy link
Author

mdeloof commented Sep 9, 2024

In the meantime I've seen that the AT log port contains an unhandled exception Guru Meditation Error: Core 0 panic'ed (LoadProhibited) which causes a reboot, so that probably explains the SDIO bus no longer responding. But how can we avoid triggering this exception?

@mdeloof mdeloof changed the title SDIO bus stops responding Guru Meditation Error: Core 0 panic'ed (LoadProhibited) Sep 9, 2024
@ustccw
Copy link
Collaborator

ustccw commented Oct 10, 2024

@mdeloof Hi, could you please enable AT logs for us to see what happened, we will try to reproduce that.

  • python build.py menuconfig -> Component config -> Log output -> Default log verbosity -> Info // comment: enable system logs
  • python build.py menuconfig -> Component config -> AT -> Enable ESP-AT Debug -> Enable Network Debug // comment: enable esp-at and network logs
  • python build.py menuconfig -> Component config -> Bluetooth -> disable // comment: disable bluetooth to reduce bin size

in the compile steps, you can choose PLATFORM_ESP32, ESP32-SDIO, No as the default the way.

@mdeloof
Copy link
Author

mdeloof commented Oct 14, 2024

Hi, I have enabled the AT logs and rerun the tests, and it appears that the extra logs significantly lower the data rate. So far we have not seen the Guru Meditation Error: Core 0 panic'ed (LoadProhibited) error, but we're now consistently getting a task watchdog error:

(80966) intf-rx: 0x3ffb43c5   80 00 00 80 00 00 7f ff  ff c0 00 00 80 00 00 80  |................|
(80976) intf-rx: 0x3ffb43d5   00 00 80 00 00 80 00 00  80 00 00 80 00 00 80 00  |................|
(80985) intf-rx: 0x3ffb43e5   00 7f ff ff c0 00 00 80  00 00 80 00 00 80 00 00  |................|
(80995) intf-rx: 0x3ffb43f5   80 00 00 80 00 00 80 00  00 80 00 00 7f ff ff c0  |................|
(81005) intf-rx: 0x3ffb4405   00 00 80 00 00 80 00 00  80 00 00 80 00 00 80 00  |................|
(81015) intf-rx: 0x3ffb(81017) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
(81017) task_wdt:  - IDLE (CPU 0)
(81017) task_wdt: Tasks currently running:
(81017) task_wdt: CPU 0: at_recv_task
(81017) task_wdt: Aborting.
(81017) task_wdt: Print CPU 0 (current core) backtrace




Backtrace: 0x400d672d:0x3ffd7340 0x400d6e73:0x3ffd7370 0x400d659f:0x3ffd7390 0x400d5ada:0x3ffd73b0 0x4000bd83:0x3ffd73d0 0x4000117d:0x3ffd73f0 0x400592fe:0x3ffd7410 0x4005937a:0x3ffd7430 0x40058ca4:0x3ffd7450 0x4018e077:0x3ffd7470 0x4018e08f:0x3ffd7490 0x4018e1b6:0x3ffd74b0 0x40194f6d:0x3ffd7560 0x401a3605:0x3ffd7590 0x4008d461:0x3ffd75c0 0x400fc286:0x3ffd7610 0x400ed3ad:0x3ffd76b0 0x400da825:0x3ffd76d0 0x400e92f0:0x3ffd76f0 0x401a055a:0x3ffd78a0




ELF file SHA256: 1da31668b0aba2e3

Rebooting...

Here you can find the full AT log: esp-at-sdio-task-watchdog-log.log

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants