espressif / esp-adf

Espressif Audio Development Framework
Other
1.54k stars 677 forks source link

Enabling CONFIG_COMPILER_OPTIMIZATION_SIZE in sdkconfig causes core dump with [spiffs]-->[mp3decoder]-->[pwm] pipeline (AUD-2507) #507

Closed justintconroy closed 2 years ago

justintconroy commented 3 years ago

Environment

Problem Description

When using compiler optimizations, somewhere in the pipeline [spiffs]-->[mp3decoder]-->[pwm], there's some code that is trying to run while spi flash is being accessed, thus causing a core dump.

Guru Meditation Error: Core  0 panic'ed (Cache disabled but cached memory region accessed)

Expected Behavior

Behavior should be identical no matter which optimizations are turned on.

Actual Behavior

Instead we get a core dump. I suspect some function in that chain is missing an IRAM_ATTR, but I haven't dug down deep enough to pinpoint the problem code. ref

Steps to reproduce

  1. Setup an audio pipeline using ESP-ADF with the following audio elementselements:

    • spiffs_stream (cfg.type = AUDIO_STREAM_READER)
    • mp3_decoder
    • pwm_stream
  2. Start the pipeline

  3. Attempt to play a file out of spiffs through pwm.

Code to reproduce this issue

See gist for a code example. Before building, make sure CONFIG_COMPILER_OPTIMIZATIONS_SIZE=y appears in you sdkconfig file.

Debug Logs

I (1240) TEST-ADF: [5.*] Receive music info from mp3 decoder: sample_rate=44100, bits=16, ch=2
D (1250) intr_alloc: Connected src 14 to int 17 (cpu 0)
D (1290) SPIFFS_STREAM: read len=2048, pos=12288/741459
Guru Meditation Error: Core  0 panic'ed (Cache disabled but cached memory region accessed)
Core 0 register dump:
PC      : 0x400d7044  PS      : 0x00060034  A0      : 0x40082264  A1      : 0x3ffb0660
0x400d7044: ledc_set_left_duty_fast at C:/util/esp-adf/components/audio_stream/pwm_stream.c:209

0x40082264: _xt_lowint1 at C:/util/esp-idf/components/freertos/xtensa_vectors.S:1153

A2      : 0x3ffb7ad4  A3      : 0x3ffb2766  A4      : 0x00000008  A5      : 0x40084e2c
0x40084e2c: _frxt_int_enter at C:/util/esp-idf/components/freertos/portasm.S:119

A6      : 0xe0000000  A7      : 0x00000000  A8      : 0x800826d4  A9      : 0x3ffb0640
A10     : 0x00000083  A11     : 0x3ffb2766  A12     : 0xfffffff7  A13     : 0x3ffbd4c0
A14     : 0x00000020  A15     : 0x00003004  SAR     : 0x00000020  EXCCAUSE: 0x00000007
EXCVADDR: 0x00000000  LBEG    : 0x4000c349  LEND    : 0x4000c36b  LCOUNT  : 0xffffffff
Core 0 was running in ISR context:
EPC1    : 0x400895d8  EPC2    : 0x00000000  EPC3    : 0x00000000  EPC4    : 0x400d7044
0x400895d8: spi_flash_ll_cmd_is_done at C:/util/esp-idf/components/soc/esp32/include/hal/spi_flash_ll.h:71 (discriminator 1)
 (inlined by) spi_flash_hal_poll_cmd_done at C:/util/esp-idf/components/soc/src/hal/spi_flash_hal_common.inc:31 (discriminator 1)

0x400d7044: ledc_set_left_duty_fast at C:/util/esp-adf/components/audio_stream/pwm_stream.c:209

ELF file SHA256: 2bd5ce4e20f9f7ad

Backtrace: 0x400d7041:0x3ffb0660 0x40082261:0x3ffb0690 0x400895d5:0x3ffbd500 0x40089416:0x3ffbd520 0x40089a07:0x3ffbd540 0x400835fa:0x3ffbd560 0x400e1d35:0x3ffbd590 0x400d845f:0x3ffbd5b0 0x400db82d:0x3ffbd5e0 0x400d93f9:0x3ffbd610 0x

400db358:0x3ffbd640 0x400d8b08:0x3ffbd680 0x400d8285:0x3ffbd6b0 0x400d302a:0x3ffbd6d0 0x4000bdbb:0x3ffbd6f0 0x40001125:0x3ffbd710 0x400594e9:0x3ffbd730 0x400e4ad5:0x3ffbd750 0x400e4b65:0x3ffbd790 0x400d6bd1:0x3ffbd7b0 0x400d48c3:0x3f

fbd820 0x400d6c59:0x3ffbd850 0x400d4f55:0x3ffbd870
0x400d7041: spiffs_stream_init at C:/util/esp-adf/components/audio_stream/spiffs_stream.c:267 (discriminator 2)

0x40082261: _xt_lowint1 at C:/util/esp-idf/components/freertos/xtensa_vectors.S:1153

0x400895d5: get_spi_dev at C:/util/esp-idf/components/soc/src/hal/spi_flash_hal_common.inc:26
 (inlined by) spi_flash_hal_poll_cmd_done at C:/util/esp-idf/components/soc/src/hal/spi_flash_hal_common.inc:31

0x40089416: spi_flash_hal_read at C:/util/esp-idf/components/soc/src/hal/spi_flash_hal_common.inc:99

0x40089a07: spi_flash_chip_generic_read at C:/util/esp-idf/components/spi_flash/spi_flash_chip_generic.c:152

0x400835fa: esp_flash_read at C:/util/esp-idf/components/spi_flash/esp_flash_api.c:556

0x400e1d35: esp_partition_read at C:/util/esp-idf/components/spi_flash/partition.c:347

0x400d845f: spiffs_api_read at C:/util/esp-idf/components/spiffs/spiffs_api.c:36

0x400db82d: spiffs_phys_rd at C:/util/esp-idf/components/spiffs/spiffs/src/spiffs_cache.c:161

0x400d93f9: spiffs_page_data_check at C:/util/esp-idf/components/spiffs/spiffs/src/spiffs_nucleus.c:20

0x400db358: spiffs_object_read at C:/util/esp-idf/components/spiffs/spiffs/src/spiffs_nucleus.c:2035

0x400d8b08: spiffs_hydro_read at C:/util/esp-idf/components/spiffs/spiffs/src/spiffs_hydrogen.c:414
 (inlined by) SPIFFS_read at C:/util/esp-idf/components/spiffs/spiffs/src/spiffs_hydrogen.c:426

0x400d8285: vfs_spiffs_read at C:/util/esp-idf/components/spiffs/esp_spiffs.c:491

0x400d302a: esp_vfs_read at C:/util/esp-idf/components/vfs/vfs.c:446 (discriminator 3)

0x400e4ad5: _fread_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fread.c:228

0x400e4b65: fread at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fread.c:266

0x400d6bd1: _spiffs_read at C:/util/esp-adf/components/audio_stream/spiffs_stream.c:155

0x400d48c3: audio_element_input at C:/util/esp-adf/components/audio_pipeline/audio_element.c:354

0x400d6c59: _spiffs_process at C:/util/esp-adf/components/audio_stream/spiffs_stream.c:180

0x400d4f55: audio_element_process_running at C:/util/esp-adf/components/audio_pipeline/audio_element.c:308
 (inlined by) audio_element_task at C:/util/esp-adf/components/audio_pipeline/audio_element.c:463
jason-mao commented 3 years ago

@justintconroy Thanks for your report. Cache disabled but cached memory region accessed is the root cause.