search

espressif / esp-homekit-sdk

541 stars 98 forks source link

Problem with SPI SRAM in ESP32-S3WRM1N8R2 #87

Open MacWyznawca opened 2 years ago

MacWyznawca commented 2 years ago

After first reading the characteristics by HomeKit, the heap_caps_get_free_size(MALLOC_CAP_8BIT) function returns negative values.

From this point on, any attempt to allocate memory in SPIRAM ends with a forbidden write error and an endless restart loop with a SPIRAM memory check error during initialization.

I (0) cpu_start: App cpu up.
I (645) spiram: SPI SRAM memory test OK
I (654) cpu_start: Pro cpu start user code
I (654) cpu_start: cpu freq: 160000000
I (654) cpu_start: Application information:
I (657) cpu_start: Project name:     LuON_Base
I (662) cpu_start: App version:      esp_homekit_release_3.0.r3-42-g
I (669) cpu_start: Compile time:     Mar 24 2022 14:48:49
I (675) cpu_start: ELF file SHA256:  487eb8f14ae4596f...
I (681) cpu_start: ESP-IDF:          v4.4-367-gc29343eb94
I (687) heap_init: Initializing. RAM available for dynamic allocation:
I (695) heap_init: At 3FCA0258 len 0003FDA8 (255 KiB): D/IRAM
I (701) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
I (708) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (714) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
I (720) spiram: Adding pool of 2048K of external SPI memory to heap allocator
I (729) spi_flash: detected chip: generic
I (733) spi_flash: flash io: dio
I (737) sleep: Configure to isolate all GPIO pins in sleep state
I (744) sleep: Enable automatic switching of GPIO sleep configuration
I (751) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (766) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (00:00:00.115) Lu Main: Reset 0: 1, reset 1: 1
I (00:00:00.121) Lu Main: install WS2812 driver OK
I (00:00:00.126) Lu Main: HomeKit Configuration: task_stack_size = 4096
I (00:00:00.133) Lu Main: HomeKit Configuration: task_priority = 7
I (00:00:00.140) Lu Main: HomeKit Configuration: max_event_notif_chars = 8
I (00:00:00.148) Lu Main: HomeKit Configuration: unique_param = 1
I (00:00:00.154) Lu Main: HomeKit Configuration: recv_timeout = 10
I (00:00:00.161) Lu Main: HomeKit Configuration: send_timeout = 10
I (00:00:00.168) Lu Main: After change hap_cfg RAM: 2419150/2064384
I (00:00:00.198) Lu Main: After NVS init RAM: 2416966

After first HAP read/write:

I (15:18:31.751) Lu Main: Received WRITE from 88D49793-F21D-4C8A-8093-CD523EF7B102
I (15:19:43.340) Lu Main: After r/w HAP RAM: -840973488

When allocated memory:

E (15:26:40.851) LuLine: Frame 0 send problem: 259
Guru Meditation Error: Core  0 panic'ed (StoreProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40380439  PS      : 0x00060b33  A0      : 0x8038358d  A1      : 0x3fcbdf70  
0x40380439: compare_and_set_native at /Users/jkk/esp/esp-idf/components/esp_hw_support/include/soc/compare_set.h:25
 (inlined by) spinlock_acquire at /Users/jkk/esp/esp-idf/components/esp_hw_support/include/soc/spinlock.h:103
 (inlined by) xPortEnterCriticalTimeout at /Users/jkk/esp/esp-idf/components/freertos/port/xtensa/port.c:288

A2      : 0xdddddddd  A3      : 0xffffffff  A4      : 0x00000000  A5      : 0x00000010  
A6      : 0x3fcc3898  A7      : 0x00000010  A8      : 0x0000cdcd  A9      : 0x0000cdcd  
A10     : 0x00060b20  A11     : 0x0000abab  A12     : 0xb33fffff  A13     : 0x00060b23  
A14     : 0x00000000  A15     : 0x3fcc388c  SAR     : 0x0000001a  EXCCAUSE: 0x0000001d  
EXCVADDR: 0xdddddddd  LBEG    : 0x400570e8  LEND    : 0x400570f3  LCOUNT  : 0x00000000  

Backtrace:0x40380436:0x3fcbdf700x4038358a:0x3fcbdf90 0x40375c8e:0x3fcbdfb0 0x40375cb1:0x3fcbdfe0 0x40375f9b:0x3fcbe000 0x42032b92:0x3fcbe020 0x42060c07:0x3fcbe070 0x42060bd1:0x3fcbe0e0 0x4205ec11:0x3fcbe100 0x4205f12d:0x3fcbe140 0x4200bb31:0x3fcbe190 0x4200c4d3:0x3fcbe1d0 0x4200f537:0x3fcbe2b0 0x42009f1e:0x3fcbe430 0x42009fb9:0x3fcbe460 0x42017076:0x3fcbe4f0 0x42056566:0x3fcbe9c0 0x420553d5:0x3fcbea00 0x42055915:0x3fcbeab0 0x4205466a:0x3fcbead0 0x420bd00d:0x3fcbeaf0 0x4205477d:0x3fcbeb10 
0x40380436: compare_and_set_native at /Users/jkk/esp/esp-idf/components/esp_hw_support/include/soc/compare_set.h:25
 (inlined by) spinlock_acquire at /Users/jkk/esp/esp-idf/components/esp_hw_support/include/soc/spinlock.h:103
 (inlined by) xPortEnterCriticalTimeout at /Users/jkk/esp/esp-idf/components/freertos/port/xtensa/port.c:288

0x4038358a: vPortEnterCritical at /Users/jkk/esp/esp-idf/components/freertos/port/xtensa/include/freertos/portmacro.h:578
 (inlined by) multi_heap_internal_lock at /Users/jkk/esp/esp-idf/components/heap/multi_heap.c:152
 (inlined by) multi_heap_malloc_impl at /Users/jkk/esp/esp-idf/components/heap/multi_heap.c:196

After restart loop:

SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x1658
load:0x403b6000,len:0xb7c
load:0x403ba000,len:0x2f74
entry 0x403b6248
I (29) boot: ESP-IDF v4.4-367-gc29343eb94 2nd stage bootloader
I (29) boot: compile time 14:48:50
I (29) boot: chip revision: 0
I (32) boot.esp32s3: Boot SPI Speed : 80MHz
I (37) boot.esp32s3: SPI Mode       : DIO
I (42) boot.esp32s3: SPI Flash Size : 8MB
I (46) boot: Enabling RNG early entropy source...
I (52) boot: Partition Table:
I (55) boot: ## Label            Usage          Type ST Offset   Length
I (63) boot:  0 sec_cert         unknown          3f 06 0000d000 00003000
I (70) boot:  1 nvs              WiFi data        01 02 00010000 00006000
I (77) boot:  2 otadata          OTA data         01 00 00016000 00002000
I (85) boot:  3 phy_init         RF data          01 01 00018000 00001000
I (92) boot:  4 ota_0            OTA app          00 10 00020000 00200000
I (100) boot:  5 ota_1            OTA app          00 11 00220000 00200000
I (107) boot:  6 factory_nvs      WiFi data        01 02 00420000 00007000
I (115) boot:  7 nvs_keys         NVS keys         01 04 00427000 00001000
I (123) boot: End of partition table
I (127) esp_image: segment 0: paddr=00020020 vaddr=3c0d0020 size=2d588h (185736) map
I (169) esp_image: segment 1: paddr=0004d5b0 vaddr=3fc95f10 size=02a68h ( 10856) load
I (171) esp_image: segment 2: paddr=00050020 vaddr=42000020 size=c0104h (786692) map
I (315) esp_image: segment 3: paddr=0011012c vaddr=3fc98978 size=0235ch (  9052) load
I (318) esp_image: segment 4: paddr=00112490 vaddr=40374000 size=11f10h ( 73488) load
I (337) esp_image: segment 5: paddr=001243a8 vaddr=50000000 size=00010h (    16) load
I (345) boot: Loaded app from partition at offset 0x20000
I (345) boot: Disabling RNG early entropy source...
I (358) spiram: Found 16MBit SPI RAM device
I (358) spiram: SPI RAM mode: sram 80m
I (358) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (363) cpu_start: Pro cpu up.
I (366) cpu_start: Starting app cpu, entry point is 0x4037514c
0x4037514c: call_start_cpu1 at /Users/jkk/esp/esp-idf/components/esp_system/port/cpu_start.c:160

I (351) cpu_start: App cpu up.
E (523) spiram: SPI SRAM error@3de00000:22222222/aaaaaaaa 

E (523) spiram: SPI SRAM error@3de00020:22222222/aaaaaaa2 

E (524) spiram: SPI SRAM error@3de00040:22222232/aaaaaaba 

E (610) spiram: SPI SRAM memory test fail. 65536/65536 writes failed, first @ 3D000000

E (611) cpu_start: External RAM failed memory test!

abort() was called at PC 0x403752c8 on core 0
0x403752c8: call_start_cpu0 at /Users/jkk/esp/esp-idf/components/esp_system/port/cpu_start.c:410 (discriminator 3)

Backtrace:0x40375b82:0x3fceb2600x4037d401:0x3fceb280 0x40383d96:0x3fceb2a0 0x403752c8:0x3fceb310 0x403bb0bc:0x3fceb340 0x403bb525:0x3fceb380 0x403b62b1:0x3fceb4b0 0x40045c01:0x3fceb570  |<-CORRUPTED
0x40375b82: panic_abort at /Users/jkk/esp/esp-idf/components/esp_system/panic.c:402

0x4037d401: esp_system_abort at /Users/jkk/esp/esp-idf/components/esp_system/esp_system.c:128

0x40383d96: abort at /Users/jkk/esp/esp-idf/components/newlib/abort.c:46

0x403752c8: call_start_cpu0 at /Users/jkk/esp/esp-idf/components/esp_system/port/cpu_start.c:410 (discriminator 3)

ELF file SHA256: 487eb8f14ae4596f

Rebooting...
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0xc (RTC_SW_CPU_RST),boot:0xb (SPI_FAST_FLASH_BOOT)
Saved PC:0x40375834
0x40375834: esp_restart_noos at /Users/jkk/esp/esp-idf/components/esp_system/port/soc/esp32s3/system_internal.c:143 (discriminator 1)
MacWyznawca commented 2 years ago

ESP32 with SPI SRAM don't have this problem - works good witch 8 (4 visible) MB SPIRAM. With master IDF (5.0) behaves exactly the same way (SPIRAM crashes).