retro-go icon indicating copy to clipboard operation
retro-go copied to clipboard

Published 20 hours ago • verified publisher icon ducalex

ESP32-WROVER: panic in rg_gui_init

Open mtojek opened this issue 3 years ago • 16 comments
trafficstars

Describe the bug

It looks like the application panics when the launcher tries to prepare the draw buffer.

To Reproduce

I used ESP32-WROVER with IDF SDK v4.4.1.

$ xtensa-esp32-elf-addr2line -fe launcher/build/launcher.elf Backtrace:0x4008b503:0x3ffbe5100x4008bc32:0x3ffbe530 0x400819fe:0x3ffbe550 0x40081a11:0x3ffbe580 0x40081c4d:0x3ffbe5a0 0x400dec65:0x3ffbe5c0 0x400db17b:0x3ffbe620 0x400de8f6:0x3ffbe640 0x400d5fbc:0x3ffbe820 0x400f85de:0x3ffbe910
??
??:0
heap_caps_malloc_base
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/heap/heap_caps.c:147
heap_caps_malloc
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/heap/heap_caps.c:167
heap_caps_calloc
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/heap/heap_caps.c:441
rg_alloc
/Users/x/Documents/Arduino/retro-go/components/retro-go/rg_system.c:865 (discriminator 4)
rg_gui_init
/Users/x/Documents/Arduino/retro-go/components/retro-go/rg_gui.c:41
rg_system_init
/Users/x/Documents/Arduino/retro-go/components/retro-go/rg_system.c:351
app_main
/Users/x/Documents/Arduino/retro-go/launcher/main/main.c:305
main_task
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/freertos/port/port_common.c:129

Full stacktrace

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:1
load:0x3fff0030,len:5996
ho 0 tail 12 room 4
load:0x40078000,len:15320
ho 0 tail 12 room 4
load:0x40080400,len:4428
entry 0x4008069c
I (30) boot: ESP-IDF v4.4.1-dirty 2nd stage bootloader
I (31) boot: compile time 15:34:46
I (31) boot: chip revision: 3
I (34) boot_comm: chip revision: 3, min. bootloader chip revision: 1
I (41) qio_mode: Enabling default flash chip QIO
I (46) boot.esp32: SPI Speed      : 80MHz
I (51) boot.esp32: SPI Mode       : QIO
I (56) boot.esp32: SPI Flash Size : 4MB
I (60) boot: Enabling RNG early entropy source...
I (66) boot: Partition Table:
I (69) boot: ## Label            Usage          Type ST Offset   Length
I (76) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (84) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (91) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (99) boot:  3 launcher         OTA app          00 10 00010000 00050000
I (106) boot:  4 nofrendo-go      OTA app          00 11 00060000 00070000
I (114) boot: End of partition table
I (118) boot_comm: chip revision: 3, min. application chip revision: 1
I (125) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=18b64h (101220) map
I (146) esp_image: segment 1: paddr=00028b8c vaddr=3ffb0000 size=01bd0h (  7120) load
I (147) esp_image: segment 2: paddr=0002a764 vaddr=40080000 size=058b4h ( 22708) load
I (157) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=28764h (165732) map
I (181) esp_image: segment 4: paddr=0005878c vaddr=400858b4 size=077ach ( 30636) load
I (187) esp_image: segment 5: paddr=0005ff40 vaddr=50000000 size=00010h (    16) load
I (193) boot: Loaded app from partition at offset 0x10000
I (194) boot: Disabling RNG early entropy source...

========================================================
launcher 1.33-12-g30f929d0-dirty (Aug 26 2022 15:33:41)
 built for: ODROID-GO. aud=0 disp=0 pad=0 sd=0 cfg=0
========================================================

[info] rg_system_init: Welcome! Reset reason: 4
[info] rg_storage_init: SD Card mounted at /sd. driver=1
[info] rg_settings_init: Settings loaded from /sd/retro-go/config/retro-go.json.
[info] rg_input_init: Input ready. driver='GPIO', state=00000000 00100000
[info] rg_display_init: Initialization...
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFC2A2C
[ino] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFC3430
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFC3E34
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFC4838
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFC523C
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFC5C40
E (584) spi: spi_bus_initialize(756): SPI bus already initlized.
[info] lcd_set_backlight: backlight set to 80.00%
[info] rg_display_init: Display ready.
[info] rg_gui_init: gui.screen_width=320, gui.screen_height=240
[info] rg_alloc: Want to allocate: SIZE=12800, CAPS=SPIRAM|8BIT
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x4008b506  PS      : 0x00060930  A0      : 0x8008bc35  A1      : 0x3ffbe510
A2      : 0xffffffff  A3      : 0xffffffff  A4      : 0x00000040  A5      : 0x00000080
A6      : 0x00000040  A7      : 0x00000000  A8      : 0x00000012  A9      : 0x00000007
A10     : 0x0000002b  A11     : 0x00003200  A12     : 0x00000012  A13     : 0x00000000
A14     : 0x00000000  A15     : 0x0000002b  SAR     : 0x00000008  EXCCAUSE: 0x0000001c
EXCVADDR: 0x0000002f  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0x00000000


Backtrace:0x4008b503:0x3ffbe5100x4008bc32:0x3ffbe530 0x400819fe:0x3ffbe550 0x40081a11:0x3ffbe580 0x40081c4d:0x3ffbe5a0 0x400dec7d:0x3ffbe5c0 0x400db192:0x3ffbe620 0x400de90e:0x3ffbe640 0x400d5fc4:0x3ffbe820 0x400f85f6:0x3ffbe910




ELF file SHA256: a826076964f0fca7

Rebooting...

Side question: I'm also concerned about this line:

E (584) spi: spi_bus_initialize(756): SPI bus already initlized.

I'd like to use separate SPI buses for SD card and LCD, but I suppose it's impossible due to lack of DMA available on SPI3?

mtojek avatar Aug 27 '22 17:08 mtojek

E (584) spi: spi_bus_initialize(756): SPI bus already initlized. I'd like to use separate SPI buses for SD card and LCD, but I suppose it's impossible due to lack of DMA available on SPI3?

That SPI error is expected and can be ignored. It is possible to use two SPI peripherals but it can conflict with I2S's and SPIRAM's DMA and GPIO. If you're designing your own device you can have a look at using SDMMC instead.

ducalex avatar Aug 27 '22 18:08 ducalex

Thanks for looking up the backtrace. I don't know why esp-idf itself would crash. My best guess would be a SPIRAM issue.

You can try commenting line 854 in rg_system.c (the one with that sets MALLOC_CAP_SPIRAM) to see if it goes through.

You can also make sure SPIRAM is initialized, add that block towards the beginning of rg_system_init:

    multi_heap_info_t heap_info = {0};
    heap_caps_get_info(&heap_info, MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT);
    RG_LOGI("Internal memory: free=%d, total=%d\n", heap_info.total_free_bytes, heap_info.total_free_bytes + heap_info.total_allocated_bytes);
    heap_caps_get_info(&heap_info, MALLOC_CAP_SPIRAM|MALLOC_CAP_8BIT);
    RG_LOGI("External memory: free=%d, total=%d\n", heap_info.total_free_bytes, heap_info.total_free_bytes + heap_info.total_allocated_bytes);

Do you know if the esp-idf bundled for arduino is patched by them?

ducalex avatar Aug 27 '22 18:08 ducalex

Hi @ducalex,

Thanks for checking in!

========================================================
launcher 1.33-12-g30f929d0-dirty (Aug 27 2022 20:55:07)
 built for: ODROID-GO. aud=0 disp=0 pad=0 sd=0 cfg=0
========================================================

[info] rg_system_init: Welcome! Reset reason: 4
[info] rg_system_init: Internal memory: free=253295, total=307383
[info] rg_system_init: External memory: free=4192151, total=4192151

It looks like we have 4MB of PSRAM, which is good, I guess? I'd like to run only nofrendo + launcher.

After commenting the line 854, it went through. What does it mean to be honest? Is the application supposed to work now? Log output:

========================================================
launcher 1.33-12-g30f929d0-dirty (Aug 27 2022 20:55:07)
 built for: ODROID-GO. aud=0 disp=0 pad=0 sd=0 cfg=0
========================================================

[info] rg_system_init: Welcome! Reset reason: 1
[info] rg_system_init: Internal memory: free=253295, total=307383
[info] rg_system_init: External memory: free=4192151, total=4192151
[info] rg_storage_init: SD Card mounted at /sd. driver=1
[info] rg_settings_init: Settings loaded from /sd/retro-go/config/retro-go.json.
[info] rg_input_init: Input ready. driver='GPIO', state=00000000 00100000
[info] rg_display_init: Initialization...
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFC9504
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFC9F08
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCA90C
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCB310
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DM|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCBD14
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCC718
E (1426) spi: spi_bus_initialize(756): SPI bus already initialized.
[info] lcd_set_backlight: backlight set to 80.00%
[info] rg_display_init: Display ready.
[info] rg_gui_init: gui.screen_width=320, gui.screen_height=240
[info] rg_alloc: Want to allocate: SIZE=12800, CAPS=8BIT
[info] rg_alloc: SIZE=12800, CAPS=8BIT, PTR=3FFCE5D0
[info] rg_gui_set_font_type: Font set to: points=12, scaling=1.00
[info] rg_gui_set_theme: Theme set to '(none)'!
[warn] rg_system_init: Button 0x0020 being held down...
[warn] rg_system_init: Button 0x0020 being held down...
[warn] rg_system_init: Button 0x0020 being held down...
[warn] rg_system_init: Button 0x0020 being held down...
[warn] rg_system_init: Button 0x0020 being held down...
[warn] rg_system_init: Button 0x0020 being held down...
[warn] recovery_mode: Entering recovery mode...
[info] rg_gui_dialog: text_buffer usage = 126

I can see the blank screen now, so I suppose it's a moment to figure out what's wrong with the LCD driver logic (ILI9341).

mtojek avatar Aug 27 '22 19:08 mtojek

Interesting, it fails few seconds later. It seems to be an issue with SPIRAM too:

[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCC2FC
E (920) spi: spi_bus_initialize(756): SPI bus already initialized.
[info] lcd_set_backlight: backlight set to 80.00%
[info] rg_display_init: Display ready.
[info] rg_gui_init: gui.screen_width=320, gui.screen_height=240
[info] rg_alloc: Want to allocate: SIZE=12800, CAPS=8BIT
[info] rg_alloc: SIZE=12800, CAPS=8BIT, PTR=3FFCE15C
[info] rg_gui_set_font_type: Font set to: points=12, scaling=1.00
[info] rg_gui_set_theme: Theme set to '(none)'!
[info] rg_audio_init: Audio ready. sink='Speaker', samplerate=32000, volume=50
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x4008e229  PS      : 0x00060130  A0      : 0x8008f0b7  A1      : 0x3ffbf050
A2      : 0x0000084f  A3      : 0x4008f0f8  A4      : 0x3ffbf094  A5      : 0x3ffbf0b0
A6      : 0x00060120  A7      : 0x00000001  A8      : 0x8008e39a  A9      : 0x3ffbf030
A10     : 0x00000854  A11     : 0x00060123  A12     : 0x00060120  A13     : 0x3ffbf094
A14     : 0x007aefcc  A15     : 0x003fffff  SAR     : 0x0000000f  EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000853  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0x00000000


Backtrace:0x4008e226:0x3ffbf0500x4008f0b4:0x3ffbf070 0x400d5228:0x3ffbf090 0x400e22d1:0x3ffbf0d0 0x400e2b46:0x3ffbf120 0x400d9e22:0x3ffbf380 0x40101596:0x3ffbf470 0x4008c181:0x3ffbf490

$ xtensa-esp32-elf-addr2line -fe launcher/build/launcher.elf Backtrace:0x4008e226:0x3ffbf0500x4008f0b4:0x3ffbf070 0x400d5228:0x3ffbf090 0x400e22d1:0x3ffbf0d0 0x400e2b46:0x3ffbf120 0x400d9e22:0x3ffbf380 0x40101596:0x3ffbf470 0x4008c181:0x3ffbf490
??
??:0
heap_caps_get_info
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/heap/heap_caps.c:499
update_statistics
/Users/x/Documents/Arduino/retro-go/components/retro-go/rg_system.c:169 (discriminator 4)
rg_system_init
/Users/x/Documents/Arduino/retro-go/components/retro-go/rg_system.c:374
app_main
/Users/x/Documents/Arduino/retro-go/launcher/main/main.c:305
main_task
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/freertos/port/port_common.c:129
vPortTaskWrapper
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/freertos/port/xtensa/port.c:131

mtojek avatar Aug 27 '22 19:08 mtojek

Yeah 4MB is what we'd expect. I'm not sure it's a SPIRAM issue per se but something seems to be corrupting the heap table? Because it seems to crash when we're just requesting info about it... That's usually caused by a stack overflow.

You can try ediitng base.sdkconfig as follows:

  • set CONFIG_SPIRAM_CACHE_WORKAROUND to y
  • set CONFIG_COMPILER_OPTIMIZATION_ASSERTIONS_ENABLE to y
  • set CONFIG_COMPILER_OPTIMIZATION_ASSERTIONS_SILENT to n
  • set CONFIG_COMPILER_STACK_CHECK_MODE_NONE to n
  • set CONFIG_COMPILER_STACK_CHECK_MODE_NORM to y

After that you'll have to run rg_tool.py clean or delete launcher/sdkconfig and launcher/build, depending on how you're building it.

I will do some testing with esp-idf 4.4.1 on my side as well. I always make sure that retro-go builds with esp-idf 4.0 - 4.4 but I only actually run the 4.1 builds.

ducalex avatar Aug 27 '22 19:08 ducalex

You can try ediitng base.sdkconfig as follows:

Unfortunately, I didn't reveal any more details.

I will do some testing with esp-idf 4.4.1 on my side as well. I always make sure that retro-go builds with esp-idf 4.0 - 4.4 but I only actually run the 4.1 builds.

Maybe I should downgrade the IDF to 4.1 or upgrade to 4.4.2?

Anyway, let me know if I can help with bug chasing. I will continue with my investigation.

mtojek avatar Aug 27 '22 20:08 mtojek

I've tested esp-idf 4.4.1 compiling retro-go for target odroid-go and it boots correctly on a bare esp32-wrover module (as far as I can tell, I don't have a compatible LCD to see). It also boots and runs correctly on the odroid-go handheld.

But I don't know if your sdk was modified for arduino (at least from your snippet you seem to be using the one provided by arduino-esp32).

Can you tell me what changes you've made to retro-go (if any) and what commands you use to compile and run?

ducalex avatar Aug 27 '22 21:08 ducalex

But I don't know if your sdk was modified for arduino (at least from your snippet you seem to be using the one provided by arduino-esp32).

Oh, it's just a random location. As most of my projects are Arduino related, I unpacked and installed this one too.

Speaking of IDF v4.4.1 - git: 1329b19fe494500aeb79d19b27cfd99b40c37aec

Git diff:

diff --git a/components/driver/sdspi_host.c b/components/driver/sdspi_host.c
index 591e169b6f..5d6fcd875c 100644
--- a/components/driver/sdspi_host.c
+++ b/components/driver/sdspi_host.c
@@ -453,6 +453,7 @@ esp_err_t sdspi_host_start_command(sdspi_dev_handle_t handle, sdspi_hw_cmd_t *cm
         if (flags & SDSPI_CMD_FLAG_WRITE) {
             ret = start_command_write_blocks(slot, cmd, data, data_size, multi_block, stop_transmission);
         } else {
+           go_idle_clockout(slot);
             ret = start_command_read_blocks(slot, cmd, data, data_size, stop_transmission);
         }
     } else {
diff --git a/components/esp_system/panic.c b/components/esp_system/panic.c
index 722975b7c7..cd5f3cc528 100644
--- a/components/esp_system/panic.c
+++ b/components/esp_system/panic.c
@@ -73,11 +73,17 @@ static wdt_hal_context_t rtc_wdt_ctx = {.inst = WDT_RWDT, .rwdt_dev = &RTCCNTL};
 #if CONFIG_ESP_CONSOLE_UART
 static uart_hal_context_t s_panic_uart = { .dev = CONFIG_ESP_CONSOLE_UART_NUM == 0 ? &UART0 :&UART1 };

+void __attribute__((weak)) esp_panic_putchar_hook(char c)
+{
+    // nothing
+}
+
 void panic_print_char(const char c)
 {
     uint32_t sz = 0;
     while (!uart_hal_get_txfifo_len(&s_panic_uart));
     uart_hal_write_txfifo(&s_panic_uart, (uint8_t *) &c, 1, &sz);
+    esp_panic_putchar_hook(c);
 }
 #endif // CONFIG_ESP_CONSOLE_UART

diff --git a/tools/idf_tools.py b/tools/idf_tools.py
index 69851be55d..2726ffc245 100755
--- a/tools/idf_tools.py
+++ b/tools/idf_tools.py
@@ -40,6 +40,7 @@ import platform
 import re
 import shutil
 import ssl
+ssl._create_default_https_context = ssl._create_unverified_context
 import subprocess
 import sys
 import tarfile

Can you tell me what changes you've made to retro-go (if any) and what commands you use to compile and run?

https://github.com/mtojek/retro-go/commit/a36701cca861d1c43335a80fab72cc45281e8c73

Commands:

./rg_tool.py build-img launcher nofrendo-go
esptool.py write_flash --flash_size detect 0x0 retro-go_*.img

mtojek avatar Aug 27 '22 22:08 mtojek

The first problem I see is that you use GPIO16 and 17 but on the WROVER they are used by PSRAM¹ (I don't think they are even exposed, so this is probably a typo in your code?).

The second possible problem is that RG_GPIO_LCD_HOST and RG_GPIO_SDSPI_HOST are set to the same host but different pins. This can't work. One of them should be set to SPI3_HOST. (But again, using SPI3_HOST may conflict with PSRAM).

¹ https://www.espressif.com/sites/default/files/documentation/esp32-wrover_datasheet_en.pdf pages 14 and 19

ducalex avatar Aug 28 '22 21:08 ducalex

The first problem I see is that you use GPIO16 and 17 but on the WROVER they are used by PSRAM¹ (I don't think they are even exposed, so this is probably a typo in your code?).

Yes, it's my bad. Found by trials and already corrected it (uncommitted). Thanks for the explanation.

The second possible problem is that RG_GPIO_LCD_HOST and RG_GPIO_SDSPI_HOST are set to the same host but different pins. This can't work. One of them should be set to SPI3_HOST. (But again, using SPI3_HOST may conflict with PSRAM).

The reason why I started experimenting with this is that I want to keep the LCD on HSPI, but SD card on VSPI. I don't know if it's possible here.

PS. I'm still learning the ESP platform, so please don't shoot for making rookie mistakes...

mtojek avatar Aug 28 '22 21:08 mtojek

If I may suggest maybe you can try getting it to work with the original pinout first, and then try moving peripherals around.

PS. I'm still learning the ESP platform, so please don't shoot for making rookie mistakes...

Of course, I'm sorry if I came across as rude that wasn't my intention at all!

I guess it may be worth trying accessing the PSRAM before doing anything with SPI or GPIOs. Like putting this at the top of rg_system_init:

char *ptr = heap_caps_malloc(0x100000, MALLOC_CAP_SPIRAM|MALLOC_CAP_8BIT);
printf("allocated 1M at %p\n", ptr);
strcpy(ptr, "Hello World!");
printf("written '%s' to %p\n", ptr, ptr);
// then for good measure let's try a calloc, which is what rg_alloc does.
char *ptr2 = heap_caps_calloc(1, 0x100000, MALLOC_CAP_SPIRAM|MALLOC_CAP_8BIT);
printf("allocated another 1M at %p\n", ptr);

BTW I see you've changed the shebang to use python3 in rg_tool.py. That is a good change, rg_tool.py stopped being python2 friendly very long ago and I know many OS do not even have an executable named python anymore. Do you want to submit a PR about that? Otherwise I'll commit it myself later.

ducalex avatar Aug 28 '22 21:08 ducalex

Of course, I'm sorry if I came across as rude that wasn't my intention at all!

I really appreciate all your efforts to help me. Thank you!

The reason why I modified the pinout is to separate buses. My SD card reader seems to be a bit chatty, so it's safer to connect it to a separate bus.

Unfortunately with this pinout, IDF complains about DMA channel:

========================================================
launcher 1.33-13-ga36701cc-dirty (Aug 29 2022 17:39:13)
 built for: ODROID-GO. aud=0 disp=0 pad=0 sd=0 cfg=0
========================================================

[info] rg_system_init: Welcome! Reset reason: 4
[info] rg_system_init: Internal memory: free=251343, total=305431
[info] rg_system_init: External memory: free=4192151, total=4192151
allocated 1M at 3F80086C
written 'Hello World!' to 3F80086C
allocated another 1M at 3F900870
[info] rg_storage_init: SD Card mounted at /sd. driver=1
[info] rg_settings_init: Settings loaded from /sd/retro-go/config/retro-go.json.
[info] rg_input_init: Input ready. driver='GPIO', state=00000000 00100000
[info] rg_display_init: Initialization...
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFC9CA4
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCA6A8
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCB0AC
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCBAB0
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCC4B4
[info] rg_alloc: Want to allocate: SIZE=2560, CAPS=DMA|8BIT
[info] rg_alloc: SIZE=2560, CAPS=DMA|8BIT, PTR=3FFCCEB8
E (1332) spi: alloc_dma_chan(221): no available dma channel

assert failed: dma_chan_free spi_common.c:321 (spi_dma_chan_enabled & BIT(dma_chan))


Backtrace:0x4008211d:0x3ffbf5500x4008d64d:0x3ffbf570 0x400938ad:0x3ffbf590 0x400f6043:0x3ffbf6c0 0x400f6fd5:0x3ffbf6e0 0x400de39c:0x3ffbf720 0x400e377e:0x3ffbf8c0 0x400da2ca:0x3ffbfb20 0x40105c86:0x3ffbfc10 0x40090495:0x3ffbfc30

__assert_func
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/newlib/assert.c:85
dma_chan_free
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/driver/spi_common.c:321 (discriminator 1)
spi_bus_initialize
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/driver/spi_common.c:847
spi_init
/Users/x/Documents/Arduino/retro-go/components/retro-go/rg_display.c:154
rg_system_init
/Users/x/Documents/Arduino/retro-go/components/retro-go/rg_system.c:365
app_main
/Users/x/Documents/Arduino/retro-go/launcher/main/main.c:305
main_task
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/freertos/port/port_common.c:129
vPortTaskWrapper
/Users/x/Documents/Arduino/esp-idf-v4.4.1/components/freertos/port/xtensa/port.c:131

I'm wondering if it's possible to disable the DMA for the SD card bus (SPI3).

EDIT:

it looks like I can get rid of that error (at least temporarily), if I assign two different DMA channels (1 & 2). LCD is white so far, researching...

mtojek avatar Aug 29 '22 16:08 mtojek

Success!! I managed to run NES emulator.

I noticed one bug, not sure if we should discuss it in this thread or another. After a few seconds of gaming, the screen colors become inverted, and after a minute of play the screen becomes white. Is it a known issue? It's a Chinese no-name TFT LCD on ILI9341. rg_display.c

301911630_818536639324864_3942250689958384539_n 302024920_1242942916544518_2796033044452585439_n

mtojek avatar Aug 29 '22 21:08 mtojek

The reason why I modified the pinout is to separate buses. My SD card reader seems to be a bit chatty, so it's safer to connect it to a separate bus.

I absolutely understand, I've spent countless hours working around the limitations of having to share a bus and in my own designs I use SDMMC instead. I was only suggesting sticking to the untouched config first to help narrow down the problem.

Glad to see it now (mostly) works! Can you sum up the resolution? Can you think of code changes I could make that would have helped you find the issue faster?

For the LCD it is not a known issue but I can think of a few ways this could happen. If you open a new issue please include your new pinout :) .

ducalex avatar Aug 30 '22 18:08 ducalex

Glad to see it now (mostly) works! Can you sum up the resolution? Can you think of code changes I could make that would have helped you find the issue faster?

Keep in mind that I didn't have prior experience with ESP32, so it's highly likely one the reasons why it took me longer. I had to read a bit about the SPI driver and VFS.

  1. Select the correct DMA channel

When you're using 2 SPI buses (as I do), the SPI_DMA_CH_AUTO doesn't work properly. You have to select 1 and 2 specifically. Otherwise, the RG complains about unavailable DMA channels.

  1. Tune the SD card reader settings

The option that worked in my case was:

host_config.max_freq_khz = SDMMC_FREQ_PROBING
  1. Magic around SPIRAM

Once I commented this line in rg_system.c, my ESP32 stopped panicking:

    //esp_caps |= (caps & MEM_SLOW ? MALLOC_CAP_SPIRAM : (caps & MEM_FAST ? MALLOC_CAP_INTERNAL : 0));
     esp_caps |= (caps & MEM_DMA ? MALLOC_CAP_DMA : 0);
     esp_caps |= (caps & MEM_EXEC ? MALLOC_CAP_EXEC : 0);
     esp_caps |= (caps & MEM_32BIT ? MALLOC_CAP_32BIT : MALLOC_CAP_8BIT);

I don't know what's wrong with this particular alloc property.

As you can see, you gave me valuable hints and I really appreciate it. Thanks! I still have components to enable (audio, joysticks) and I'm excited about it :)

Regarding the LCD issue, I will open another issue and provide relevant data.

mtojek avatar Aug 31 '22 07:08 mtojek

Thank you for the feedback :)

I was actually breaking SPI_DMA_CH_AUTO by overriding it and this was very recently fixed in 1892c16342f786cad57f248b187ddf076abb51b2.

The option that worked in my case was: host_config.max_freq_khz = SDMMC_FREQ_PROBING

Yeah esp32 is picky with SD Card, especially when the circuit isn't perfect. I have now added a fallback to probing speed in https://github.com/ducalex/retro-go/commit/9eebd489d65f08d19a1759b09d46e5d974a07f54 . Maybe this should be tunable in the target file too, though.

ducalex avatar Sep 01 '22 12:09 ducalex