ESP32-P4/ESP32-C6 hosted issue (Unrecoverable host sdio state) (EHM-124)

[SebastianOtt]

Checklist

• Checked the issue tracker for similar issues to ensure this is not a duplicate.
• Provided a clear description of your suggestion.
• Included any relevant context or examples.

Issue or Suggestion Description

Hi,
we are using esp-hosted & wifi remote on our custom board with an esp32-p4 and an esp32-c6. Normally, this works and has worked before as expected. However, we noticed spontanous crashes of the host (can or can not occur once within e.g. 4 hours). Even in situations where basically no wifi traffic should be ongoing by user application.

To reproduce this issue, we integrated the iperf test example, where the host also crashed at the 2nd test.

Here is the output:

I (37614) IPERF: mode=tcp-server sip=localhost:5001, dip=0.0.0.0:5001, interval=3, time=30
I (37615) iperf: Socket created
iperf> I (42696) iperf: accept: 192.168.0.50,53720

Interval       Bandwidth
 0.0- 3.0 sec  1.81 Mbits/sec
 3.0- 6.0 sec  0.36 Mbits/sec
 6.0- 9.0 sec  0.00 Mbits/sec
 9.0-12.0 sec  0.00 Mbits/sec
W (56734) iperf: tcp server recv error, error code: 11, reason: No more processes
E (56735) sdmmc_io: sdmmc_io_rw_extended: sdmmc_send_cmd returned 0x107
I (56735) iperf: TCP Socket server is closed.
E (56746) H_SDIO_DRV: sdio_write_task: 0: Failed to send data: 263 66 66
E (56747) sdmmc_io: sdmmc_io_rw_extended: sdmmc_send_cmd returned 0x107
I (56747) iperf: iperf exit
E (56758) H_SDIO_DRV: sdio_write_task: 1: Failed to send data: 263 66 66
E (56769) H_SDIO_DRV: Unrecoverable host sdio state, reset host mcu
I (56770) os_wrapper_esp: Restarting host
ESP-ROM:esp32p4-eco2-20240710
Build:Jul 10 2024

Normally, we do not have such a problem:

iperf> I (28263) iperf: accept: 192.168.0.50,53734

Interval       Bandwidth
 0.0- 3.0 sec  13.44 Mbits/sec
 3.0- 6.0 sec  7.53 Mbits/sec
 6.0- 9.0 sec  8.53 Mbits/sec
 9.0-12.0 sec  8.40 Mbits/sec
12.0-15.0 sec  8.85 Mbits/sec
15.0-18.0 sec  8.60 Mbits/sec
18.0-21.0 sec  8.99 Mbits/sec
21.0-24.0 sec  10.50 Mbits/sec
24.0-27.0 sec  11.00 Mbits/sec

Thus, some questions arise:

• I guess the first log indicates that messages could not have been sent and some buffers were getting full?
• Regardless, is there a way to detect or solve this issue? It would not be great if our device has spontanous restarts because of this fault.
• Or is this already fixed in the newer version (master)?

this is our hosted version:

I (440) co-pro-main: *********************************************************************
I (440) co-pro-main:                 ESP-Hosted-MCU Slave FW version :: 2.3.2
I (446) co-pro-main:                 Transport used :: SDIO only
I (453) co-pro-main: *********************************************************************

[mantriyogesh]

guess the first log indicates that messages could not have been sent and some buffers were getting full?

The following log:

E (56735) sdmmc_io: sdmmc_io_rw_extended: sdmmc_send_cmd returned 0x107

indicates that the SDIO interface has become unresponsive or disconnected. This usually points to a slave-side issue — most likely a crash or a hang on the slave, which causes SDIO to stop responding.

Regardless, is there a way to detect or solve this issue? It would not be great if our device has spontaneous restarts because of this fault.

We can attempt to probe again, but this error is typically fatal. It is analogous to the hardware being suddenly removed while it was being accessed by the host.

Or is this already fixed in the newer version (master)?

This issue has not been observed unless the slave crashes. To analyze further, please share the following complete textual logs:

1. Host logs from flashing.
2. Slave logs from flashing.
3. sdkconfig files from both the host and the slave sides.

Please ensure you include the correct slave logs. If the slave is crashing, it will automatically reboot — in that case, the new boot-up logs are less useful. The logs from the crashing instance are what matter most.

[SebastianOtt]

Thanks for your advice. Unfortunately, i cannot monitor the P4 and C6 simultanously. But we have a switch to change uart line to P4/C6 for flashing and monitoring.

This issue has not been observed unless the slave crashes. To analyze further, please share the following complete textual logs:

1. Host logs from flashing.
2. Slave logs from flashing.
3. sdkconfig files from both the host and the slave sides.

My guess is you meant monitoring logs? or actually firmware flashing logs? I provide you monitoring logs for now.

I have now tried to trigger an error by starting iperf tests with the P4 as iperf client or server which took a while...

Error Logs

There is one C6 error log visible which is causing the host crash and reboot of the slave. I think the watchdog timer is triggered at the C6 and transport syncing is not possible for P4 which is causing the crash.

Slave(C6):

E (149034) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
E (149034) task_wdt:  - IDLE (CPU 0)
E (149034) task_wdt: Tasks currently running:
E (149034) task_wdt: CPU 0: wifi
E (149034) task_wdt: Print CPU 0 (current core) registers
Core  0 register dump:
MEPC    : 0x40020878  RA      : 0x4080033a  SP      : 0x40848040  GP      : 0x4081b3f4
--- 0x4080033a: esp_timer_impl_get_time at C:/Users/info/esp/master/esp-idf/components/esp_timer/src/esp_timer_impl_systimer.c:72
TP      : 0x408481d0  T0      : 0x400208f0  T1      : 0x0000000f  T2      : 0x01000000
S0/FP   : 0x40806448  S1      : 0x0000c350  A0      : 0x4081e490  A1      : 0x00000000
--- 0x40806448: systimer_ticks_to_us at C:/Users/info/esp/master/esp-idf/components/esp_hw_support/port/esp32c6/systimer.c:16
A2      : 0x00000000  A3      : 0x00000001  A4      : 0x00000000  A5      : 0x6000a000
A6      : 0xfff00000  A7      : 0xbfffffff  S2      : 0x00000000  S3      : 0x4084fa58
S4      : 0x00000001  S5      : 0x00000040  S6      : 0x4085930c  S7      : 0x40828fd8
S8      : 0x420c2000  S9      : 0x40880000  S10     : 0x4084fb10  S11     : 0x00000000
T3      : 0x00000000  T4      : 0x00000000  T5      : 0x00000000  T6      : 0x00000000
MSTATUS : 0x00001889  MTVEC   : 0x40800001  MCAUSE  : 0xdeadc0de  MTVAL   : 0xdeadc0de
--- 0x40800001: _vector_table at C:/Users/info/esp/master/esp-idf/components/riscv/vectors_intc.S:54
MHARTID : 0x00000000
Please enable CONFIG_ESP_SYSTEM_USE_FRAME_POINTER option to have a full backtrace.
E (154034) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
E (154034) task_wdt:  - IDLE (CPU 0)
E (154034) task_wdt: Tasks currently running:
E (154034) task_wdt: CPU 0: wifi
E (154034) task_wdt: Print CPU 0 (current core) registers
Core  0 register dump:

Switching UART route to Host (P4) i was able to see the following logs where it crashes and restarts the whole time:

I (1942) esp_psram: Adding pool of 32768K of PSRAM memory to heap allocator
I (1949) spi_flash: detected chip: winbond
I (1953) spi_flash: flash io: qio
I (1956) host_init: ESP Hosted : Host chip_ip[18]
I (1960) H_API: ESP-Hosted starting. Hosted_Tasks: prio:23, stack: 5120 RPC_task_stack: 5120
I (1968) H_API: ** add_esp_wifi_remote_channels **
I (1973) transport: Add ESP-Hosted channel IF[1]: S[0] Tx[0x400101b2] Rx[0x4002415a]
I (1980) transport: Add ESP-Hosted channel IF[2]: S[0] Tx[0x400100f2] Rx[0x4002415a]
sdio_mempool_create free:33666772 min-free:33666772 lfb-def:33030144 lfb-8bit:33030144

I (1997) H_SDIO_DRV: sdio_data_to_rx_buf_task started
I (1997) main_task: Started on CPU1
I (2005) esp_psram: Reserving pool of 31K of internal memory for DMA/internal allocations
I (2012) main_task: Calling app_main()
I (2068) WIFI: Initializing WIFI Station...
I (2068) WIFI: Event handlers registered successfully
I (2068) WIFI: Creating netif wifi sta
I (2069) WIFI: Netif wifi sta created
I (2072) transport: Attempt connection with slave: retry[0]
W (2077) H_SDIO_DRV: Reset slave using GPIO[21]
I (2082) os_wrapper_esp: GPIO [21] configured
I (3288) sdio_wrapper: SDIO master: Slot 0, Data-Lines: 4-bit Freq(KHz)[40000 KHz]
I (3288) sdio_wrapper: GPIOs: CLK[43] CMD[44] D0[39] D1[40] D2[41] D3[42] Slave_Reset[21]
I (3292) sdio_wrapper: Queues: Tx[20] Rx[20] SDIO-Rx-Mode[1]
E (4298) SD_HOST: sd_host_slot_clock_update_command(917): sd_host_start_command returned 0x107
E (4298) SD_HOST: sd_host_slot_set_card_clk(500): sd_host_slot_set_card_clk: sd_host_slot_clock_update_command returned 0x107, failed to disable clk, 
E (4309) SD_TRANS: sd_host_slot_sdmmc_do_transaction(494): failed to set clk
E (4315) sdmmc_req: sdmmc_host_do_transaction(24): failed to do SD transaction
E (4322) sdio_wrapper: sdmmc_card_init failed
E (4326) H_SDIO_DRV: card init failed
I (4330) transport: Waiting for esp_hosted slave to be ready
I (4397) H_SDIO_DRV: SDIO Host operating in STREAMING MODE
I (4397) H_SDIO_DRV: Open data path at slave
Guru Meditation Error: Core  0 panic'ed (Load access fault). Exception was unhandled.

Core  0 register dump:
MEPC    : 0x4003dd12  RA      : 0x4003b692  SP      : 0x4ff2c360  GP      : 0x4ff1ed80
TP      : 0x4ff2c480  T0      : 0x4fc0a9f8  T1      : 0x0000001c  T2      : 0x00000000  
S0/FP   : 0x4ff2c374  S1      : 0x00000000  A0      : 0x00000000  A1      : 0x4ff2c374
A2      : 0x98011800  A3      : 0x88000000  A4      : 0x4ff2c3cf  A5      : 0x98011801  
A6      : 0x4000908c  A7      : 0xa0000000  S2      : 0x0000008c  S3      : 0x00000000
S4      : 0x0000008c  S5      : 0x00000000  S6      : 0x00000000  S7      : 0x00000000  
S8      : 0x00000000  S9      : 0x00000000  S10     : 0x00000000  S11     : 0x00000000  
T3      : 0x00000000  T4      : 0x00000000  T5      : 0x00000000  T6      : 0x00000000
MSTATUS : 0x00011880  MTVEC   : 0x4ff00003  MCAUSE  : 0x00000005  MTVAL   : 0x00000040
MHARTID : 0x00000000

Stack memory:
4ff2c360: 0x00000000 0x00000000 0x4ff2c3cf 0x4003b692 0x00000000 0x00000034 0x98011801 0x00000000
4ff2c380: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00001c00
4ff2c3a0: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x4003ba04
4ff2c3c0: 0x00000000 0x00000000 0x400c4000 0x01f13788 0x4ff2c40f 0x00000001 0x00000000 0x40024018
4ff2c3e0: 0x00000000 0x00000014 0x00000000 0x00000000 0x00000000 0x00000000 0x400c4000 0x40020e74
4ff2c400: 0x00000000 0x00000000 0x400c4000 0x0100112d 0x400c4704 0x000007cd 0x4000908c 0x4002144c
4ff2c420: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
4ff2c440: 0x00000000 0x00000000 0x00000000 0x4ff0bf0c 0x00000000 0x00000000 0x00000000 0x00000000
4ff2c460: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c480: 0x00000000 0x4ff2b0b0 0x4ff2b0b0 0x00000000 0x00000000 0x00000000 0xa5a5a5a5 0xa5a5a5a5
4ff2c4a0: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0x00000160 0x4ff2c350 0x00000960 0x4ff21c7c
4ff2c4c0: 0x4ff2efa8 0x4ff2c4b4 0x4ff21c74 0x00000002 0x00000000 0x00000000 0x4ff2c4b4 0x00000000
4ff2c4e0: 0x00000017 0x4ff2b0b0 0x6f696473 0x6165725f 0x00000064 0x00000000 0x7fffffff 0x4ff2c4a0
4ff2c500: 0x00000017 0x00000000 0x00000000 0x00000000 0x00000000 0x4ff26970 0x4ff269d8 0x4ff26a40
4ff2c520: 0x00000000 0x00000000 0x00000001 0x00000000 0x00000000 0x00000000 0x40007b6c 0x00000000
4ff2c540: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
4ff2c560: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
4ff2c580: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
4ff2c5a0: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
4ff2c5c0: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
4ff2c5e0: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
4ff2c600: 0x00000000 0x00000000 0x97f6fc5a 0x624ec36d 0x4ff2c4ac 0x0000000c 0x4ff2da2c 0x4ff263d4
4ff2c620: 0x4ff2c610 0x00001400 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c640: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c660: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c680: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c6a0: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c6c0: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c6e0: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c700: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c720: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5
4ff2c740: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5

My guess is to disable the watchdog timer (for cpu idle task)? Or is the C6 getting into a problematic state where it is stuck?

I have attached my sdk config files.

sdkconfig_slave.zip

sdkonfig_host.zip

[mantriyogesh]

My guess is to disable the watchdog timer (for cpu idle task)?

No. It would just hide the problem, but not for long.

Or is the C6 getting into a problematic state where it is stuck?

Thats right. Let me see the logs tomorrow again, for some hints. ideally c6 should not block like this. if you have additional information if any specific scenario this happens, would help to understand.

Host should ignore sdio init failed and continue without hosted

I (4397) H_SDIO_DRV: SDIO Host operating in STREAMING MODE
I (4397) H_SDIO_DRV: Open data path at slave
Guru Meditation Error: Core 0 panic'ed (Load access fault). Exception was unhandled.

Core 0 register dump:
MEPC : 0x4003dd12 RA : 0x4003b692 SP : 0x4ff2c360 GP : 0x4ff1ed80
TP : 0x4ff2c480 T0 : 0x4fc0a9f8 T1 : 0x0000001c T2 : 0x00000000
S0/FP : 0x4ff2c374 S1 : 0x00000000 A0 : 0x00000000 A1 : 0x4ff2c374
A2 : 0x98011800 A3 : 0x88000000 A4 : 0x4ff2c3cf A5 : 0x98011801
A6 : 0x4000908c A7 : 0xa0000000 S2 : 0x0000008c S3 : 0x00000000
S4 : 0x0000008c S5 : 0x00000000 S6 : 0x00000000 S7 : 0x00000000
S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000
T3 : 0x00000000 T4 : 0x00000000 T5 : 0x00000000 T6 : 0x00000000
MSTATUS : 0x00011880 MTVEC : 0x4ff00003 MCAUSE : 0x00000005 MTVAL : 0x00000040

Open data path at slave at host should have never called if sdio returned 0x107, basically no sdio hardware medium found and timed out. but this is after effect crash at host. This particular case known. in this case host should ideally just ignore hosted and continue ahead.

we need full monitor logs both sides to understand the things. I cannot figure out what is hosted version at host and slave. this specific host case, should ideally just ignore the hosted sdio. The related changes have pushed in 2.6.3. so suggest to test on latest host and latest slave. At the least >= 2.6.3.

[mantriyogesh]

Please get full logs, at both sides as we do not know the root cause when the slave went in inconsistent state. there are no rpc traces at slave so cannot figure out broader picture.

[SebastianOtt]

Hey @mantriyogesh, so far i was not able to reproduce and log the issue. I think i will just update to latest hosted version and report back, if i receive a spontanous crash again. We also improved the sdio line length matching a little bit for the next revision of our custom board. Like i said, the problem occurs really random and can happen multiple times a day or not at all throughout the week.

Thanks for your help so far.
Now we know that it was the C6 which was stuck for some reason and to keep the watchdog for IDLE task enabled.

This issue can be closed if you want. I will report back if the problem still persists and open a new one or answer here again.

[mantriyogesh]

Will close the issue for now. Anyway, need to keep an watch on slave log when issue happens.
If you encounter the same issue, please feel to re-open this thread. 👍