Intermittent assert failure in SPI driver when using W5500 Ethernet and ST7789 LCD

[dsuliuno]

I am using a W5500 Ethernet module on the same SPI bus as an ST7789 graphic display, on a custom PCB with an ESP32-S3.
I have been intermittently getting the below assert failure and backtraces from the W5500 driver.
I am using IDF v5.4.1

The ST7789 graphic display is displaying data and updating secondly.

The W5500 successfully detects the Ethernet connection, gets a DHCP address, and subsequently handles a bunch of traffic (Successfully completing an SNTP time request, establishing a TLS MQTT connection, and sending numerous MQTT messages). However after some time (sooner if there are frequent MQTT messages being sent), my application crashes with the below (or similar) backtrace. This is almost always associated with some graphic display corruption (a black rectangle somewhere on the graphic display), which I take to indicate an LCD transaction has been corrupted by the ethernet.

If I disable the LCD, the application runs without triggering this crash. I can also run the device on wifi instead of ethernet with no problems.

The crash occurs in 3 different locations that I have observed (see below backtraces):

• in the eth_check_link_timer_cb in the timer task
• in the tcp task
• in the w5500 task

I see that the w5500_spi_read and w5500_spi_write functions protect the underlying spi_device_polling_transmit functions with a mutex, and I have never seen a crash backtrace that didn't occur in a section that was protected by this mutex (ie. all occur within w5500_spi_write or w5500_spi_read), so I don't think it is occurring due to conflicts within the ethernet device transactions, but rather between the ethernet and lcd transactions.

I also do not think it is related to stack overflow, as it occurs in multiple different tasks, and I have plenty of stack headroom on all my tasks (500B to >1KB)

I have previously encountered extensive issues with the threadsafety of the SPI bus being buggy, particularly when a bus is used across different CPU cores, and I am once again suspicious of this.

Looking at the LCD_IO SPI driver, it makes extensive use of queued transactions, and I am wondering if these are causing problems sharing with the ethernet driver.

I have tried (without effect):

• Increasing task stacks
• Moving the esp_timer task, the TCP task, and the w5500 task to use the same CPU core as the graphic display transactions
• Changing the w5500_spi_lock function to acquire the bus using spi_device_acquire_bus before taking the w5500 mutex (this caused the graphic display to eventually freeze, I think the bus acquisition failed to release correctly at some point)
• Disabling the graphic display (this was the only thing that seemed to prevent the fault from appearing).

Any suggestions or troubleshooting tips are welcomed.

Backtrace from failure in the timer task link check callback:

Code: Select all

assert failed: spi_hal_setup_trans /IDF/components/hal/spi_hal_iram.c:45 (spi_ll_get_running_cmd(hw) == 0)


Backtrace: 0x4037611d:0x3fcb4fc0 0x40380e19:0x3fcb4fe0 0x4038ae89:0x3fcb5000 0x40387d99:0x3fcb5120 0x4037a514:0x3fcb5150 0x4037a95f:0x3fcb51a0 0x4037aa2a:0x3fcb51e0 0x42037a0f:0x3fcb5200 0x4216aad7:0x3fcb5260 0x42036add:0x3fcb5280 0x4216aa8d:0x3fcb52b0 0x42038413:0x3fcb52d0 0x42038511:0x3fcb5310 0x4216aabf:0x3fcb5340 0x420a71ae:0x3fcb5360 0x420a71fd:0x3fcb5390 0x40384a99:0x3fcb53b0
--- 0x4037611d: panic_abort at /home/dos/esp/esp-idf/components/esp_system/panic.c:469
--- 0x40380e19: esp_system_abort at /home/dos/esp/esp-idf/components/esp_system/port/esp_system_chip.c:87
--- 0x4038ae89: __assert_func at /home/dos/esp/esp-idf/components/newlib/assert.c:80
--- 0x40387d99: spi_hal_setup_trans at /home/dos/esp/esp-idf/components/hal/spi_hal_iram.c:45
--- 0x4037a514: spi_new_trans at /home/dos/esp/esp-idf/components/esp_driver_spi/src/gpspi/spi_master.c:804
--- 0x4037a95f: spi_device_polling_start at /home/dos/esp/esp-idf/components/esp_driver_spi/src/gpspi/spi_master.c:1414
--- 0x4037aa2a: spi_device_polling_transmit at /home/dos/esp/esp-idf/components/esp_driver_spi/src/gpspi/spi_master.c:1469
--- 0x42037a0f: w5500_spi_read at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:171
--- 0x4216aad7: w5500_read at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:191
--- 0x42036add: emac_w5500_read_phy_reg at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:439
--- 0x4216aa8d: eth_phy_reg_read at /home/dos/esp/esp-idf/components/esp_eth/src/esp_eth.c:85
--- 0x42038413: w5500_update_link_duplex_speed at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_phy_w5500.c:69
--- 0x42038511: w5500_get_link at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_phy_w5500.c:112
--- 0x4216aabf: eth_check_link_timer_cb at /home/dos/esp/esp-idf/components/esp_eth/src/esp_eth.c:171
--- 0x420a71ae: timer_process_alarm at /home/dos/esp/esp-idf/components/esp_timer/src/esp_timer.c:435
--- 0x420a71fd: timer_task at /home/dos/esp/esp-idf/components/esp_timer/src/esp_timer.c:461
--- 0x40384a99: vPortTaskWrapper at /home/dos/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:139

Backtrace from failure in the w5500 task:

Code: Select all

assert failed: spi_hal_setup_trans /IDF/components/hal/spi_hal_iram.c:45 (spi_ll_get_running_cmd(hw) == 0)


Backtrace: 0x4037611d:0x3fcdadc0 0x40380e19:0x3fcdade0 0x4038ae89:0x3fcdae00 0x40387d99:0x3fcdaf20 0x4037a514:0x3fcdaf50 0x4037a95f:0x3fcdafa0 0x4037aa2a:0x3fcdafe0 0x4203797b:0x3fcdb000 0x4216aa3f:0x3fcdb060 0x42036dd3:0x3fcdb080 0x42036f05:0x3fcdb0c0 0x420372ea:0x3fcdb100 0x40384a99:0x3fcdb140
--- 0x4037611d: panic_abort at /home/dos/esp/esp-idf/components/esp_system/panic.c:469
--- 0x40380e19: esp_system_abort at /home/dos/esp/esp-idf/components/esp_system/port/esp_system_chip.c:87
--- 0x4038ae89: __assert_func at /home/dos/esp/esp-idf/components/newlib/assert.c:80
--- 0x40387d99: spi_hal_setup_trans at /home/dos/esp/esp-idf/components/hal/spi_hal_iram.c:45
--- 0x4037a514: spi_new_trans at /home/dos/esp/esp-idf/components/esp_driver_spi/src/gpspi/spi_master.c:804
--- 0x4037a95f: spi_device_polling_start at /home/dos/esp/esp-idf/components/esp_driver_spi/src/gpspi/spi_master.c:1414
--- 0x4037aa2a: spi_device_polling_transmit at /home/dos/esp/esp-idf/components/esp_driver_spi/src/gpspi/spi_master.c:1469
--- 0x4203797b: w5500_spi_read at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:171
--- 0x4216aa3f: w5500_read at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:191
--- 0x42036dd3: w5500_get_rx_received_size at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:244
--- 0x42036f05: emac_w5500_alloc_recv_buf at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:625
--- 0x420372ea: emac_w5500_task at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:783
--- 0x40384a99: vPortTaskWrapper at /home/dos/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:139

Backtrace from failure in the TCPIP task:

Code: Select all

assert failed: spi_hal_setup_trans /IDF/components/hal/spi_hal_iram.c:45 (spi_ll_get_running_cmd(hw) == 0)


Backtrace: 0x4037611d:0x3fcd8180 0x40380e19:0x3fcd81a0 0x4038ae89:0x3fcd81c0 0x40387d99:0x3fcd82e0 0x4037a514:0x3fcd8310 0x4037a95f:0x3fcd8360 0x4037aa2a:0x3fcd83a0 0x42037877:0x3fcd83c0 0x4216a9d1:0x3fcd8420 0x420374bb:0x3fcd8440 0x42035ac2:0x3fcd8480 0x420d23a1:0x3fcd84b0 0x420d2c91:0x3fcd84e0 0x420ce50b:0x3fcd8500 0x420c74f4:0x3fcd8520 0x420c7521:0x3fcd8550 0x420c7694:0x3fcd8580 0x420c7731:0x3fcd85a0 0x420c4bba:0x3fcd85c0 0x420c4d09:0x3fcd85e0 0x420bc43a:0x3fcd8600 0x420bc50a:0x3fcd8620 0x40384a99:0x3fcd8650
--- 0x4037611d: panic_abort at /home/dos/esp/esp-idf/components/esp_system/panic.c:469
--- 0x40380e19: esp_system_abort at /home/dos/esp/esp-idf/components/esp_system/port/esp_system_chip.c:87
--- 0x4038ae89: __assert_func at /home/dos/esp/esp-idf/components/newlib/assert.c:80
--- 0x40387d99: spi_hal_setup_trans at /home/dos/esp/esp-idf/components/hal/spi_hal_iram.c:45
--- 0x4037a514: spi_new_trans at /home/dos/esp/esp-idf/components/esp_driver_spi/src/gpspi/spi_master.c:804
--- 0x4037a95f: spi_device_polling_start at /home/dos/esp/esp-idf/components/esp_driver_spi/src/gpspi/spi_master.c:1414
--- 0x4037aa2a: spi_device_polling_transmit at /home/dos/esp/esp-idf/components/esp_driver_spi/src/gpspi/spi_master.c:1469
--- 0x42037877: w5500_spi_write at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:147
--- 0x4216a9d1: w5500_write at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:200
--- 0x420374bb: emac_w5500_transmit at /home/dos/esp/esp-idf/components/esp_eth/src/spi/w5500/esp_eth_mac_w5500.c:595
--- 0x42035ac2: esp_eth_transmit at /home/dos/esp/esp-idf/components/esp_eth/src/esp_eth.c:360
--- 0x420d23a1: esp_netif_transmit at /home/dos/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1302
--- 0x420d2c91: ethernet_low_level_output at /home/dos/esp/esp-idf/components/esp_netif/lwip/netif/ethernetif.c:84
--- 0x420ce50b: ethernet_output at /home/dos/esp/esp-idf/components/lwip/lwip/src/netif/ethernet.c:320
--- 0x420c74f4: etharp_raw at /home/dos/esp/esp-idf/components/lwip/lwip/src/core/ipv4/etharp.c:1173
--- 0x420c7521: etharp_request_dst at /home/dos/esp/esp-idf/components/lwip/lwip/src/core/ipv4/etharp.c:1200
--- 0x420c7694: etharp_request at /home/dos/esp/esp-idf/components/lwip/lwip/src/core/ipv4/etharp.c:1218
--- 0x420c7731: etharp_tmr at /home/dos/esp/esp-idf/components/lwip/lwip/src/core/ipv4/etharp.c:229
--- 0x420c4bba: lwip_cyclic_timer at /home/dos/esp/esp-idf/components/lwip/lwip/src/core/timeouts.c:245
--- 0x420c4d09: sys_check_timeouts at /home/dos/esp/esp-idf/components/lwip/lwip/src/core/timeouts.c:403
--- 0x420bc43a: tcpip_timeouts_mbox_fetch at /home/dos/esp/esp-idf/components/lwip/lwip/src/api/tcpip.c:109
--- 0x420bc50a: tcpip_thread at /home/dos/esp/esp-idf/components/lwip/lwip/src/api/tcpip.c:142
--- 0x40384a99: vPortTaskWrapper at /home/dos/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:139

[nopnop2002]

What happens if you change this setting?

[dsuliuno]

Thanks nopnop,
I already have the options set as per your suggestion while I am having these crashes. The SPI master ISR function into IRAM is enabled in my project, and was enabled when I was having these issues.

I will try to enable Place transmitting functions of SPI master into IRAM, and will get back to you tomorrow when I have a chance to test again.