moononournation / arduino-nofrendo

Clone from source http://www.baisoku.org/nofrendo-2.0pre1.zip
Other
81 stars 37 forks source link

panic: assert failed: remove_free_block heap_tlsf.c:211 #7

Closed mtojek closed 2 months ago

mtojek commented 1 year ago

Hi @moononournation ,

I'm having troubles with building the nofrendo on ESP32-WROVER. Here is the panic I caught:

0x400839dd: panic_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/panic.c line 402
0x4008d21d: esp_system_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/esp_system.c line 128
0x40092611: __assert_func at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/newlib/assert.c line 85
0x400839dd: panic_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/panic.c line 402
0x40091781: tlsf_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_tlsf.c line 198
0x4008d21d: esp_system_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/esp_system.c line 128
0x40091fc7: multi_heap_malloc_impl at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap.c line 197
0x40092611: __assert_func at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/newlib/assert.c line 85
0x4009223c: multi_heap_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap_poisoning.c line 230
0x40091781: tlsf_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_tlsf.c line 198
0x40083c6e: heap_caps_malloc_base at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c line 147
0x40091fc7: multi_heap_malloc_impl at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap.c line 197
0x40083c81: heap_caps_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c line 167
0x40083d2e: heap_caps_malloc_prefer at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c line 261
0x40102051: ff_memalloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/fatfs/port/freertos/ffsystem.c line 20
0x4009223c: multi_heap_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap_poisoning.c line 230
0x4010280d: vfs_fat_opendir at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/fatfs/vfs/vfs_fat.c line 733
0x40083c6e: heap_caps_malloc_base at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c line 147
0x400fc146: esp_vfs_opendir at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/vfs/vfs.c line 659
0x40083c81: heap_caps_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c line 167
0x40083d2e: heap_caps_malloc_prefer at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c line 261
0x40102051: ff_memalloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/fatfs/port/freertos/ffsystem.c line 20
0x400d3972: VFSFileImpl::VFSFileImpl(VFSImpl*, char const*, char const*) at /Users/x/Library/Arduino15/packages/esp32/hardware/esp32/2.0.4/libraries/FS/src/vfs_api.cpp line 291
0x400d4096: std::make_shared (VFSImpl*&&, char const*&, char const*&) at /Users/x/Library/Arduino15/packages/esp32/tools/xtensa-esp32-elf-gcc/gcc8_4_0-esp-2021r2-patch3/xtensa-esp32-elf/include/c++/8.4.0/new line 169
0x400d41f0: VFSImpl::open(char const*, char const*, bool) at /Users/x/Library/Arduino15/packages/esp32/hardware/esp32/2.0.4/libraries/FS/src/vfs_api.cpp line 46
0x400d34dd: fs::FS::open(char const*, char const*, bool) at /Users/x/Library/Arduino15/packages/esp32/hardware/esp32/2.0.4/libraries/FS/src/FS.cpp line 209
0x400d2fe6: setup() at /Users/x/Documents/Arduino/esp32-nofrendo-marcin/esp32-nofrendo-marcin.ino line 42
0x400ee782: loopTask(void*) at /Users/x/Library/Arduino15/packages/esp32/hardware/esp32/2.0.4/cores/esp32/main.cpp line 42
0x4010280d: vfs_fat_opendir at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/fatfs/vfs/vfs_fat.c line 733
0x400fc146: esp_vfs_opendir at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/vfs/vfs.c line 659
0x400d3972: VFSFileImpl::VFSFileImpl(VFSImpl*, char const*, char const*) at /Users/x/Library/Arduino15/packages/esp32/hardware/esp32/2.0.4/libraries/FS/src/vfs_api.cpp line 291
0x400d4096: std::make_shared (VFSImpl*&&, char const*&, char const*&) at /Users/x/Library/Arduino15/packages/esp32/tools/xtensa-esp32-elf-gcc/gcc8_4_0-esp-2021r2-patch3/xtensa-esp32-elf/include/c++/8.4.0/new line 169
0x400d41f0: VFSImpl::open(char const*, char const*, bool) at /Users/x/Library/Arduino15/packages/esp32/hardware/esp32/2.0.4/libraries/FS/src/vfs_api.cpp line 46
0x400d34dd: fs::FS::open(char const*, char const*, bool) at /Users/x/Library/Arduino15/packages/esp32/hardware/esp32/2.0.4/libraries/FS/src/FS.cpp line 209
0x400d2fe6: setup() at /Users/x/Documents/Arduino/esp32-nofrendo-marcin/esp32-nofrendo-marcin.ino line 42
0x400ee782: loopTask(void*) at /Users/x/Library/Arduino15/packages/esp32/hardware/esp32/2.0.4/cores/esp32/main.cpp line 42

Log output:

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:1344
load:0x40078000,len:13864
load:0x40080400,len:3608
entry 0x400805f0
[⸮⸮mum⸮⸮⸮⸮2-hal-cpu.c:214] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
[   451][I][esp32-hal-psram.c:96] psramInit(): PSRAM enabled
E (455) wifi_init: Failed to deinit Wi-Fi driver (0x3001)
[  1040][W][sd_diskio.cpp:174] sdCommand(): no token received

assert failed: remove_free_block heap_tlsf.c:211 (prev && "prev_free field can not be null")

Backtrace:0x400839dd:0x3ffb22800x4008d21d:0x3ffb22a0 0x40092611:0x3ffb22c0 0x40091781:0x3ffb23f0 0x40091fc7:0x3ffb2410 0x4009223c:0x3ffb2430 0x40083c6e:0x3ffb2450 0x40083c81:0x3ffb2480 0x40083d2e:0x3ffb24a0 0x40102051:0x3ffb24f0 0x4010280d:0x3ffb2510 0x400fc146:0x3ffb2540 0x400d3972:0x3ffb2560 0x400d4096:0x3ffb25a0 0x400d41f0:0x3ffb25d0 0x400d34dd:0x3ffb2660 0x400d2fe6:0x3ffb2690 0x400ee782:0x3ffb2820 

Does it ring you a bell?

Kind regards

moononournation commented 1 year ago

At the time I am writing this, the Arduino-esp32 still at version 1.0.x. Please try the older Arduino-esp32 v1.0.6 in Arduino IDE working first.

mtojek commented 1 year ago

Thanks for the quick response, @moononournation!

With Arduino-esp32 v1.0.6, it's a different backtrace:

GUI: NES powered on
_my_malloc: 61440 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/bitmap.c:86
_my_malloc: 980 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/bitmap.c:48
Timer install, configTICK_RATE_HZ=1000, freq=60
_my_malloc: 31228 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/libsnss/libsnss.c:209
GUI: error: could not open SNSS file
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.
Core 1 register dump:
PC      : 0x40107444  PS      : 0x00060330  A0      : 0x8010740b  A1      : 0x3ffb1820  
A2      : 0x3ffb80c0  A3      : 0x00000000  A4      : 0x3f4049ce  A5      : 0x3ffb1860  
A6      : 0x3ffb1830  A7      : 0x00000008  A8      : 0x3ffc0e20  A9      : 0x3ffb1800  
A10     : 0x3ffb8058  A11     : 0x3ffb80c0  A12     : 0x00000000  A13     : 0x3f4049d7  
A14     : 0x00000018  A15     : 0x00000001  SAR     : 0x00000004  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000064  LBEG    : 0x4008b9a5  LEND    : 0x4008b9b5  LCOUNT  : 0xfffffff7  

ELF file SHA256: 0000000000000000

Backtrace: 0x40107444:0x3ffb1820 0x40107408:0x3ffb1840 0x400e3fa0:0x3ffb1860 0x400e9ba3:0x3ffb1880 0x400d876e:0x3ffb1cb0 0x400d10bd:0x3ffb1cd0 0x400e6fd8:0x3ffb1d70 0x400e70c8:0x3ffb1d90 0x400d980f:0x3ffb1db0 0x400d1131:0x3ffb1de0 0x400d972f:0x3ffb1e00 0x400d186e:0x3ffb1e20 0x400ee1c6:0x3ffb1fb0 0x4008d6aa:0x3ffb1fd0
0x40107444: _ftello_r at ../../../.././newlib/libc/stdio/ftello.c line 112
0x40107408: ftell at ../../../.././newlib/libc/stdio/ftell.c line 108
0x400e3fa0: SNSS_CloseFile at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/libsnss/libsnss.c line 263
0x400e9ba3: state_save at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nesstate.c line 408
0x400d876e: func_event_state_save at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/event.c line 98
0x400d10bd: osd_getinput at /Users/x/Documents/Arduino/esp32-nofrendo-marcin/osd.c line 184
0x400e6fd8: system_video at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes.c line 364
0x400e70c8: nes_emulate at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes.c line 405
0x400d980f: main_loop at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nofrendo.c line 178
0x400d1131: osd_main at /Users/x/Documents/Arduino/esp32-nofrendo-marcin/osd.c line 227
0x400d972f: nofrendo_main at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nofrendo.c line 218
0x400d186e: setup() at /Users/x/Documents/Arduino/esp32-nofrendo-marcin/esp32-nofrendo-marcin.ino line 85
0x400ee1c6: loopTask(void*) at /Users/x/Library/Arduino15/packages/esp32/hardware/esp32/1.0.6/cores/esp32/main.cpp line 18
0x4008d6aa: vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c line 143
moononournation commented 1 year ago

the error message is "could not open SNSS file", means failed to open the game file. You may try to use the default game file in data folder first.

mtojek commented 1 year ago

I see now :) It looks like we have an improvement, but /fs/Chase.nes is not a valid ROM image:

rst:0x1 (POWERON_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:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:10944
load:0x40080400,len:6388
entry 0x400806b4
[D][esp32-hal-psram.c:47] psramInit(): PSRAM enabled
[W][sd_diskio.cpp:101] sdWait(): Wait Failed
[E][sd_diskio.cpp:123] sdSelectCard(): Select Failed
[W][sd_diskio.cpp:175] sdCommand(): crc error
/fs/Chase.nes
NoFrendo start!

_my_malloc: 256 at /Users/x/Documents/Arduino/esp32-nofrendo-marcin/sound.c:26
_my_malloc: 980 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/bitmap.c:48
video driver: Simple DirectMedia Layer at 256x240
_my_malloc: 14 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nofrendo.c:242
[W][sd_diskio.cpp:101] sdWait(): Wait Failed
[E][sd_diskio.cpp:123] sdSelectCard(): Select Failed
[W][sd_diskio.cpp:101] sdWait(): Wait Failed
[E][sd_diskio.cpp:123] sdSelectCard(): Select Failed
[W][sd_diskio.cpp:101] sdWait(): Wait Failed
[E][sd_diskio.cpp:123] sdSelectCard(): Select Failed
_my_malloc: 14 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nofrendo.c:152
system type unknown, playing nofrendo NES intro.
_my_malloc: 14 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nofrendo.c:152
_my_malloc: 808 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes.c:522
_my_malloc: 92 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes.c:539
_my_malloc: 2048 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes.c:546
_my_malloc: 296 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/sndhrdw/nes_apu.c:990
_my_malloc: 7584 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes_ppu.c:127
_my_malloc: 1068 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes_rom.c:426
[W][sd_diskio.cpp:101] sdWait(): Wait Failed
[E][sd_diskio.cpp:123] sdSelectCard(): Select Failed
[W][sd_diskio.cpp:101] sdWait(): Wait Failed
[E][sd_diskio.cpp:123] sdSelectCard(): Select Failed
[W][sd_diskio.cpp:101] sdWait(): Wait Failed
[E][sd_diskio.cpp:123] sdSelectCard(): Select Failed
GUI: /fs/Chase.nes is not a valid ROM image
GUI: ROM freed
GUI: ROM not loaded
NoFrendo end!

I see also a white screen, so I guess that at this moment I should see at least a graphic loader, right?

moononournation commented 1 year ago

seems SD card read error

mtojek commented 1 year ago

@moononournation it isn't straightforward as I'm able to read the file content. I mounted the SD card using esp_vfs_fat_sdmmc_mount:

rst:0x1 (POWERON_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:0x3fff0018,len:4
load:0x3fff001c,len:1216
ho 0 tail 12 room 4
load:0x40078000,len:10944
load:0x40080400,len:6388
entry 0x400806b4
[D][esp32-hal-psram.c:47] psramInit(): PSRAM enabled
esp_vfs_fat_sdmmc_mount
sdmmc_card_print_info
Name: NCard
Type: SDHC/SDXC
Speed: 400 kHz
Size: 15279MB
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
[I][esp32-nofrendo-marcin.ino:115] setup(): Read from file: 'NES'
NoFrendo start!

_my_malloc: 256 at /Users/x/Documents/Arduino/esp32-nofrendo-marcin/sound.c:26
_my_malloc: 980 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/bitmap.c:48
video driver: Simple DirectMedia Layer at 256x240
_my_malloc: 14 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nofrendo.c:242
_fopen: /fs/Chase.nes
_fread: 16
E (3621) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0x107
E (3621) diskio_sdmmc: sdmmc_read_blocks failed (263)
after _fread: 0
_my_malloc: 14 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nofrendo.c:152
system type unknown, playing nofrendo NES intro.
_my_malloc: 14 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nofrendo.c:152
_my_malloc: 808 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes.c:522
_my_malloc: 92 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes.c:539
_my_malloc: 2048 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes.c:546
_my_malloc: 296 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/sndhrdw/nes_apu.c:990
_my_malloc: 7584 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes_ppu.c:127
_my_malloc: 1068 at /Users/x/Documents/Arduino/libraries/arduino-nofrendo-master/src/nes/nes_rom.c:437
_fopen: /fs/Chase.nes
_fread 2: 16
E (4709) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0x107
E (4709) diskio_sdmmc: sdmmc_read_blocks failed (263)
Wrong iNES magic: 8d000
GUI: /fs/Chase.nes is not a valid ROM image
GUI: ROM freed
GUI: ROM not loaded
NoFrendo end!

I don't know why nes_rom.c uses sdmmc_read_sectors_dma, but the same fread call with 16 bytes buffer doesn't.

EDIT:

I investigated it further and it looks like the dma issues start when the displayTask kicks off. Is it possible that there is any interference between the LCD and SD? They should operate on different SPI buses.