Closed Sjurinho closed 2 years ago
I state more clearly that a format of the mounted spiffs did NOT fix the problem, as I have seen other forums mention as a solution. The logs of that is attached in spiffs_format_errors.txt
Thanks for the detailed issue description @Sjurinho!
It seems that first it would be nice to solve the issue with failed erase operations. I'm not sure if SPIFFS will continue working correctly after some erase operations fail.
If you run the spiffs
example provided in ESP-IDF, do you get similar errors about failed erase operations? If not, do you think you could reduce your application to some bare minimum amount of code which still reproduces these erase errors?
Another question, could you please upload the sdkconfig
file from your project and your partition table CSV file?
Thanks for the quick reply @igrr. I have tried the spiffs example as you suggested, and when I don't alter the size of the spiffs partition it works just fine. However, to replicate my situation I altered the partitions_table.csv to match the one I described in the problem description above, it started to report that it was unable to delete some addresses in the spiffs. After reaching approximately 10k bytes into Log1.txt (meaning after ~16384 bytes + 10k bytes) it gets the first erase failure. E (79640) SPIFFS: failed to erase addr 00003000, size 00001000, err 258 Then, after a few thousand more bytes it is unable to open the file Log1.txt for appending, and it does not manage to remove it either.
I have attached a zip with a simple application that reproduces the error. spiffs.zip
E (80860) SPIFFS: failed to erase addr 00006000, size 00001000, err 258
D (80870) example: Json stored! 10317
D (81070) example: Json stored! 10384
D (81270) example: Json stored! 10451
D (81470) example: Json stored! 10518
D (81670) example: Json stored! 10585
E (81890) SPIFFS: failed to erase addr 0000b000, size 00001000, err 258
D (81900) example: Json stored! 10652
D (82100) example: Json stored! 10719
D (82300) example: Json stored! 10786
D (82500) example: Json stored! 10853
D (82700) example: Json stored! 10920
D (82900) example: Json stored! 10987
E (83120) SPIFFS: failed to erase addr 0000f000, size 00001000, err 258
D (83130) example: Json stored! 11054
D (83330) example: Json stored! 11121
D (83530) example: Json stored! 11188
D (83730) example: Json stored! 11255
D (83930) example: Json stored! 11322
D (84140) example: Json stored! 11389
W (84350) SPIFFS: Failed to update mtime (-10002)
D (84360) example: Json stored! 11389
W (84570) SPIFFS: Failed to update mtime (-10002)
D (84580) example: Json stored! 11389
W (84790) SPIFFS: Failed to update mtime (-10002)
D (84800) example: Json stored! 11389
W (85010) SPIFFS: Failed to update mtime (-10002)
D (85020) example: Json stored! 11389
E (85220) example: Failed to open file 'Log1.txt' for appending
E (85220) example: Failed to delete file '/spiffs/Log1.txt': I/O error - 5
E (85220) example: Storage failure! Failed to delete file
I'm sorry, clicking the above spiffs.zip link gives me "Not found" error, could you please try again?
Ah, yes, hopefully it works now :) spiffs.zip
The issue is that the spiffs
partition in your partition table is not aligned to 4kB boundary. Currently it is at 0x39fc00.
Since the flash erase size is 4kB, any data partition which has to support erase operations needs to be aligned to 4kB.
We have recently added a warning about this in commit https://github.com/espressif/esp-idf/commit/b56c9aafe46b00456c12b6979ee0c711575a5697 (part of v4.4 release), and starting from v5.0 unaligned data partitions won't be supported.
Please adjust your partition table to make all partitions aligned to 4kB, e.g. by changing the sizes of factory/ota partitions to 1216kB. Then all the partitions will be aligned:
nvs,data,nvs,0x9000,20K,
otadata,data,ota,0xe000,8K,
factory,app,factory,0x10000,1216K,
ota_0,app,ota_0,0x140000,1216K,
ota_1,app,ota_1,0x270000,1216K,
spiffs,data,spiffs,0x3a0000,256K,
coredump,data,coredump,0x3f0000,64K,
You can check the result by running idf.py partition_table
command.
@igrr, Indeed, changing the app partitions seems to have fixed my problem. That makes sense. Thank you very much for your help, you are a lifesaver! :)
That being said, I do miss some warning in the docs about this though.
Thanks for confirming the fix!
Indeed this is an easy mistake to make, and it's a simple thing to add a check/warning for.
We'll backport the commit I have linked to release/v4.3 and release/v4.4 and close this issue afterwards.
I'm having the same problem. And I don't know how to solve it.
This concept of aligning with 4kb?
How do you do this?
`
I (2213) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
I (2233) INFO: Wifi-Conectado
I (2263) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (3223) esp_netif_handlers: sta ip: 192.168.1.24, mask: 255.255.255.0, gw: 192.168.1.254
I (3233) IP:: got ip:192.168.1.24
I (3243) MQTT: (MQTT-IN Usuario) - Other event id:7 - MQTT-IN(Usuario)
I (3253) MQTT: Other event id:7 - MQTT-OUT(Licenca Enervision)
I (3343) NTP:: Sincronizando hora via NTP...
I (3413) CONFIG FILE: Dados Wifi
I (3413) NTP:: Aguardando sincronizacao com NTP...
W (3583) Datalogger: Datalogger Ativado
I (5033) MQTT: MQTT_EVENT_CONNECTED - MQTT-OUT(Licenca Enervision)
I (5033) MQTT: MQTT_EVENT_CONNECTED - MQTT-IN(Usuario)
I (5243) MQTT: Other event id:3 - MQTT-OUT(Licenca Enervision)
I (5443) MQTT: Other event id:3 - MQTT-OUT(Licenca Enervision)
I (5483) NTP:: Sincronização com NTP realizada...
I (13613) main_task: Returned from app_main()
I (52643) wifi:
ERROR A stack overflow in task f_Datalogger has been detected.
Backtrace: 0x40081c16:0x3fff8450 0x4008b225:0x3fff8470 0x4008c18a:0x3fff8490 0x4008d8a3:0x3fff8510 0x4008c294:0x3fff8530 0x4008c246:0xa5a5a5a5 |<-CORRUPTED 0x40081c16: panic_abort at /home/allan/esp32/esp-idf/components/esp_system/panic.c:469 0x4008b225: esp_system_abort at /home/allan/esp32/esp-idf/components/esp_system/port/esp_system_chip.c:92 0x4008c18a: vApplicationStackOverflowHook at /home/allan/esp32/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:553 0x4008d8a3: vTaskSwitchContext at /home/allan/esp32/esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c:3667 (discriminator 7) 0x4008c294: _frxt_dispatch at /home/allan/esp32/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/portasm.S:451 0x4008c246: _frxt_int_exit at /home/allan/esp32/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/portasm.S:246
ELF file SHA256: 0c38c0e7b
Rebooting... 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:2 load:0x3fff0030,len:7172 load:0x40078000,len:15556 load:0x40080400,len:4 0x40080400: _init at ??:?
ho 8 tail 4 room 4 load:0x40080404,len:3904 entry 0x40080640 I (31) boot: ESP-IDF v5.3-dev-1922-g5454d37d49 2nd stage bootloader I (31) boot: compile time Sep 19 2024 01:30:01 I (33) boot: Multicore bootloader I (37) boot: chip revision: v3.1 I (41) boot.esp32: SPI Speed : 40MHz I (45) boot.esp32: SPI Mode : DIO I (50) boot.esp32: SPI Flash Size : 4MB I (54) boot: Enabling RNG early entropy source... I (60) boot: Partition Table: I (63) boot: ## Label Usage Type ST Offset Length I (71) boot: 0 nvs WiFi data 01 02 00009000 00004000 I (78) boot: 1 otadata OTA data 01 00 0000d000 00002000 I (86) boot: 2 phy_init RF data 01 01 0000f000 00001000 I (93) boot: 3 storage Unknown data 01 82 00010000 00080000 I (101) boot: 4 ota_0 OTA app 00 10 00090000 001a9000 I (108) boot: 5 ota_1 OTA app 00 11 00240000 001a9000 I (116) boot: End of partition table I (120) esp_image: segment 0: paddr=00090020 vaddr=3f400020 size=7f210h (520720) map I (307) esp_image: segment 1: paddr=0010f238 vaddr=3ffb0000 size=00de0h ( 3552) load I (309) esp_image: segment 2: paddr=00110020 vaddr=400d0020 size=fc070h (1032304) map I (666) esp_image: segment 3: paddr=0020c098 vaddr=3ffb0de0 size=036e0h ( 14048) load I (672) esp_image: segment 4: paddr=0020f780 vaddr=40080000 size=19e00h (105984) load I (727) boot: Loaded app from partition at offset 0x90000 I (727) boot: Disabling RNG early entropy source... I (738) cpu_start: Multicore app I (747) cpu_start: Pro cpu start user code I (747) cpu_start: cpu freq: 160000000 Hz I (747) cpu_start: Application information: I (750) cpu_start: Project name: Enervision I (755) cpu_start: App version: Enervision Thermal - IDF I (762) cpu_start: Compile time: Sep 27 2024 22:31:33 I (768) cpu_start: ELF file SHA256: 0c38c0e7b... I (773) cpu_start: ESP-IDF: v5.3-dev-1922-g5454d37d49 I (780) cpu_start: Min chip rev: v0.0 I (784) cpu_start: Max chip rev: v3.99 I (789) cpu_start: Chip rev: v3.1 I (794) heap_init: Initializing. RAM available for dynamic allocation: I (801) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM I (807) heap_init: At 3FFC2178 len 0001DE88 (119 KiB): DRAM I (814) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM I (820) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM I (826) heap_init: At 40099E00 len 00006200 (24 KiB): IRAM I (834) spi_flash: detected chip: generic I (837) spi_flash: flash io: dio I (842) main_task: Started on CPU0 I (852) main_task: Calling app_main() I (852) CONFIG FILE: Initializing NVS I (892) CONFIG FILE: NVS initialized successfully I (902) LCD:: Turn off LCD backlight I (902) gpio: GPIO[27]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (902) LCD:: Initialize SPI bus I (912) LCD:: Install panel IO I (912) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (922) LCD:: Install ILI9341 panel driver I (922) ili9341: LCD panel create success, version: 1.2.0 I (1052) gpio: GPIO[36]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (1052) TouchPanel: Touch Inicializado I (1052) TouchPanel: Calibration data loaded from NVS I (1062) LCD:: Turn on LCD backlight I (1062) LCD:: Initialize LVGL library I (1062) LCD:: Register display driver to LVGL I (1082) LCD:: Install LVGL tick timer I (1082) LCD:: Create LVGL task I (1082) Display: Starting LVGL task I (1222) gpio: GPIO[22]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1232) gpio: GPIO[22]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 I (1222) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1242) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1252) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1262) CONFIG FILE: Configuring SPIFFS I (1342) CONFIG FILE: SPIFFS: total: 474641, used: 343368 I (1342) CONFIG FILE: SPIFFS mounted successfully I (1342) LOG: Sistema de log configurado W (1402) SPIFFS: Failed to update mtime (-10001) I (1402) SensorTask: Dispositivo DS18B20 encontrado: 6400000011F5DC28
`
Environment
Development Kit: ESP32-DevKitC Kit version: v1 Module or chip used: ESP32-WROOM-32 IDF version (run git describe --tags to find it): v4.2.2 Build System: idf.py Compiler version (run xtensa-esp32-elf-gcc --version to find it): 8.4.0 Operating System: Linux Using an IDE?: VSCode with the ESP-IDF extension Power Supply: External 5v
Problem Description
I am running a logger on my esp32 microcontroller. The logs are circular and thus consists of 6 files of size 16384 bytes which are deleted as the spiffs fill up. Additionally I have a small file (approx. 1000 bytes) of config values. After a while I saw that the spiffs wasn't able to save new logs, and turning on the debug logs showed that the gc in the spiffs couldn't erase certain memory addresses. This is shown in the attached logs (spiffs_erros.txt). I have tried to search around on the forums, but I have not been able to find the cause of this problem. It does not appear to be the spiffs running out of memory, as the esp_spiffs_info() api shows that only 38905 bytes are used out of 233681. My spiffs partition (see below) is set to be 256k bytes. I think the problem has something to do with the free blocks being equal to 0, but not sure why or how to fix it. To generate the spiffs I use the standard CMake api spiffs_create_partition_image(spiffs spiffs_image FLASH_IN_PROJECT), as shown in storage/examples. Correct me if I'm wrong, but I think this gives a page size of 256 bytes (as in the sdkconfig) and a 4 KiB erase block size. Is anyone familiar with the issue and how to resolve/work around it?
Expected Behavior
Spiffs continue to work as long as there are bytes left (according to esp_spiffs_info), and the circular logs work.
Actual Behavior
Spiffs run out of blocks(?) and therefore stops being able to save new logs.
Steps to reproduce
Partition Table
# Name, Type, SubType, Offset, Size, Flags nvs, data, nvs, 0x9000, 20k, otadata, data, ota, , 8k, factory, app, factory, , 1215k, ota_0, app, ota_0, , 1215k, ota_1, app, ota_1, , 1215k, spiffs, data, spiffs, , 256k, coredump, data, coredump, 0x3F0000, 64k
Initialization of spiffs
I initialize my spiffs accordingly
LogFiles