search

espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.82k stars 7.32k forks source link

ESP32S3 - Custom RMT encoder causes panic during SPIFFS access (IDFGH-11954) #13032

Closed higaski closed 9 months ago

higaski commented 10 months ago

Answers checklist.

IDF version.

ESP-IDF v5.2-beta1 (&ESP-IDF v5.3-dev-1353-gb3f7e2c8a4)

Espressif SoC revision.

ESP32-S3 (QFN56) (revision v0.1)

Operating System used.

Linux

How did you build your project?

Command line with idf.py

If you are using Windows, please specify command line type.

None

Development Kit.

ESP32-S3-DevKitC-1

Power Supply used.

USB

What is the expected behavior?

I've written a custom RMT encoder which triggers a core panic during SPIFFS access and I don't have the slightest idea why. I've had my fair share of "flash access during IRAM interrupt panics" (see #12271) but this one completely escapes me.

Since the RMT encoder alone is about 500 lines and can't really be shortened, here is the entire project folder: esp_idf_issue_13032.zip

Or here on GH: https://github.com/higaski/esp_idf_issue_13032

The entire example is basically an adapted version of the one I've already once linked in #12271.

What is the actual behavior?

For some reason there is a core panic exception once SPIFFS get accessed while RMT transmissions are running.

Steps to reproduce.

  1. Download the attached example
  2. Configure an SSID/passphrase to allow connecting to WiFi
  3. Flash the example on a ESP32-S3-DevKitC-1
  4. Wait for WiFi to establish a connection
  5. Use any web browser to send an HTTP GET request to the device

Debug Logs.

I (4487) example_connect: Start example_connect.
I (4487) pp: pp rom version: e7ae62f
I (4487) net80211: net80211 rom version: e7ae62f
I (4497) wifi:wifi driver task: 3fcbed50, prio:23, stack:6656, core=0
I (4497) wifi:wifi firmware version: 639ccf2
I (4497) wifi:wifi certification version: v7.0
I (4507) wifi:config NVS flash: disabled
I (4507) wifi:config nano formating: disabled
I (4517) wifi:Init data frame dynamic rx buffer num: 85
I (4517) wifi:Init static rx mgmt buffer num: 5
I (4517) wifi:Init management short buffer num: 32
I (4527) wifi:Init static tx buffer num: 32
I (4527) wifi:Init tx cache buffer num: 128
I (4537) wifi:Init static tx FG buffer num: 2
I (4537) wifi:Init static rx buffer size: 1600
I (4547) wifi:Init static rx buffer num: 24
I (4547) wifi:Init dynamic rx buffer num: 85
I (4547) wifi_init: rx ba win: 32
I (4557) wifi_init: tcpip mbox: 64
I (4557) wifi_init: udp mbox: 16
I (4557) wifi_init: tcp mbox: 6
I (4567) wifi_init: tcp tx win: 98304
I (4567) wifi_init: tcp rx win: 98304
I (4577) wifi_init: tcp mss: 1440
I (4577) wifi_init: WiFi/LWIP prefer SPIRAM
I (4587) wifi_init: WiFi IRAM OP enabled
I (4587) wifi_init: WiFi RX IRAM OP enabled
I (4597) phy_init: phy_version 620,ec7ec30,Sep  5 2023,13:49:13
I (4627) wifi:mode : sta (f4:12:fa:e8:a3:b0)
I (4627) wifi:enable tsf
I (4627) example_connect: Connecting to Klettermaxl...
I (4627) example_connect: Waiting for IP(s)
I (7037) wifi:new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1
I (7397) wifi:state: init -> auth (b0)
I (7407) wifi:state: auth -> assoc (0)
I (7407) wifi:Association refused temporarily, comeback time 1000 (TUs)
I (8427) wifi:state: assoc -> assoc (0)
I (8427) wifi:state: assoc -> run (10)
I (8437) wifi:connected with Klettermaxl, aid = 5, channel 11, BW20, bssid = 40:5f:7d:f8:bc:08
I (8437) wifi:security: WPA2-PSK, phy: bgn, rssi: -85
I (8437) wifi:pm start, type: 1

I (8447) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
I (8447) wifi:set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 25000, mt_pti: 0, mt_time: 10000
I (8477) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (9457) esp_netif_handlers: example_netif_sta ip: 192.168.0.10, mask: 255.255.255.0, gw: 192.168.0.1
I (9457) example_connect: Got IPv4 event: Interface "example_netif_sta" address: 192.168.0.10
I (9487) example_connect: Got IPv6 event: Interface "example_netif_sta" address: fe80:0000:0000:0000:f612:faff:fee8:a3b0, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (9487) example_common: Connected to example_netif_sta
I (9487) example_common: - IPv4 address: 192.168.0.10,
I (9497) example_common: - IPv6 address: fe80:0000:0000:0000:f612:faff:fee8:a3b0, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (9507) gpio: GPIO[19]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
Guru Meditation Error: Core  0 panic'ed (Cache disabled but cached memory region accessed).

Core  0 register dump:
PC      : 0x4037c34f  PS      : 0x00060034  A0      : 0x8037c656  A1      : 0x3fca1af0
0x4037c34f: rmt_encode_check_result at /home/vinci/esp/esp-idf/components/driver/rmt/rmt_tx.c:605

A2      : 0x3fcd6748  A3      : 0x3fcd67e4  A4      : 0x00000000  A5      : 0x00060023
A6      : 0x3fca517c  A7      : 0x3fcd6748  A8      : 0xbad00bad  A9      : 0x00000001
A10     : 0x3c1347d0  A11     : 0x00000003  A12     : 0x3fcd7890  A13     : 0x00000004
A14     : 0x3fca1af0  A15     : 0x00000000  SAR     : 0x00000020  EXCCAUSE: 0x00000007
EXCVADDR: 0x00000000  LBEG    : 0x40056f5c  LEND    : 0x40056f72  LCOUNT  : 0xffffffff
0x40056f5c: memcpy in ROM

0x40056f72: memcpy in ROM

Backtrace: 0x4037c34c:0x3fca1af0 0x4037c653:0x3fca1b20 0x4037c7b1:0x3fca1b40 0x4037c9dd:0x3fca1b70 0x4037a9f9:0x3fca1b90 0x4037be19:0x3fca1bb0 0x403887b7:0x3fcbbe80 0x4038e453:0x3fcbbea0 0x4037d71f:0x3fcbbf20 0x42012d92:0x3fcbbf60 0x4200b1bf:0x3fcbbf90 0x4200eccb:0x3fcbbfc0 0x4200c94d:0x3fcbbff0 0x4200e121:0x3fcbc040 0x4200bead:0x3fcbc080 0x4200ae26:0x3fcbc0b0 0x42007262:0x3fcbc160 0x4207b819:0x3fcbc180 0x42009532:0x3fcbc1a0 0x4201c117:0x3fcbc240 0x4201d229:0x3fcbc280 0x4201d328:0x3fcbc310 0x4201b528:0x3fcbc330 0x4201a764:0x3fcbc350 0x42089a57:0x3fcbc370 0x4201af2a:0x3fcbc390 0x4201af97:0x3fcbc3e0 0x403864ed:0x3fcbc400
0x4037c34c: rmt_encode_check_result at /home/vinci/esp/esp-idf/components/driver/rmt/rmt_tx.c:605

0x4037c653: rmt_tx_do_transaction at /home/vinci/esp/esp-idf/components/driver/rmt/rmt_tx.c:690

0x4037c7b1: rmt_isr_handle_tx_done at /home/vinci/esp/esp-idf/components/driver/rmt/rmt_tx.c:917

0x4037c9dd: rmt_tx_default_isr at /home/vinci/esp/esp-idf/components/driver/rmt/rmt_tx.c:1032

0x4037a9f9: shared_intr_isr at /home/vinci/esp/esp-idf/components/esp_hw_support/intr_alloc.c:443

0x4037be19: _xt_medint3 at /home/vinci/esp/esp-idf/components/xtensa/xtensa_vectors.S:1409

0x403887b7: spimem_flash_ll_get_addr_bitlen at /home/vinci/esp/esp-idf/components/hal/esp32s3/include/hal/spimem_flash_ll.h:534
 (inlined by) spi_flash_hal_read at /home/vinci/esp/esp-idf/components/hal/spi_flash_hal_common.inc:188

0x4038e453: spi_flash_chip_generic_read at /home/vinci/esp/esp-idf/components/spi_flash/spi_flash_chip_generic.c:246

0x4037d71f: esp_flash_read at /home/vinci/esp/esp-idf/components/spi_flash/esp_flash_api.c:899

0x42012d92: esp_partition_read at /home/vinci/esp/esp-idf/components/esp_partition/partition_target.c:38

0x4200b1bf: spiffs_api_read at /home/vinci/esp/esp-idf/components/spiffs/spiffs_api.c:27

0x4200eccb: spiffs_phys_rd at /home/vinci/esp/esp-idf/components/spiffs/spiffs/src/spiffs_cache.c:161

0x4200c94d: spiffs_obj_lu_find_entry_visitor at /home/vinci/esp/esp-idf/components/spiffs/spiffs/src/spiffs_nucleus.c:166

0x4200e121: spiffs_object_find_object_index_header_by_name at /home/vinci/esp/esp-idf/components/spiffs/spiffs/src/spiffs_nucleus.c:1711

0x4200bead: SPIFFS_stat at /home/vinci/esp/esp-idf/components/spiffs/spiffs/src/spiffs_hydrogen.c:804

0x4200ae26: vfs_spiffs_stat at /home/vinci/esp/esp-idf/components/spiffs/esp_spiffs.c:628

0x42007262: esp_vfs_stat at /home/vinci/esp/esp-idf/components/vfs/vfs.c:631 (discriminator 3)

0x4207b819: stat at /builds/idf/crosstool-NG/.build/xtensa-esp-elf/src/newlib/newlib/libc/syscalls/sysstat.c:11 (discriminator 1)

0x42009532: wildcard_get_handler(httpd_req*) at /home/vinci/Develop/VSCode/esp_idf_issue_12271/main/app_main.cpp:50

0x4201c117: httpd_uri at /home/vinci/esp/esp-idf/components/esp_http_server/src/httpd_uri.c:329

0x4201d229: httpd_parse_req at /home/vinci/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:667

0x4201d328: httpd_req_new at /home/vinci/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:795

0x4201b528: httpd_sess_process at /home/vinci/esp/esp-idf/components/esp_http_server/src/httpd_sess.c:426

0x4201a764: httpd_process_session at /home/vinci/esp/esp-idf/components/esp_http_server/src/httpd_main.c:255

0x42089a57: httpd_sess_enum at /home/vinci/esp/esp-idf/components/esp_http_server/src/httpd_sess.c:50 (discriminator 1)

0x4201af2a: httpd_server at /home/vinci/esp/esp-idf/components/esp_http_server/src/httpd_main.c:305

0x4201af97: httpd_thread at /home/vinci/esp/esp-idf/components/esp_http_server/src/httpd_main.c:327

0x403864ed: vPortTaskWrapper at /home/vinci/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:134

More Information.

No response

suda-morris commented 10 months ago

The backtrace shows the rmt_encode_check_result is accessing a function or data that is not in the internal RAM. I highly suspect this is caused by your customized encoding function and the encoder object is not in the internal RAM.

For example, here, this object will be malloc from PSRAM because you set the Kconfig CONFIG_SPIRAM_MALLOC_ALWAYSINTERNAL

higaski commented 10 months ago

Thank you that has been the issue yes.

Maybe the following snippet (from rmt_private.h) should be made visible so that custom encoders can use it?

#if CONFIG_RMT_ISR_IRAM_SAFE || CONFIG_RMT_RECV_FUNC_IN_IRAM
#define RMT_MEM_ALLOC_CAPS      (MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT)
#else
#define RMT_MEM_ALLOC_CAPS      MALLOC_CAP_DEFAULT
#endif