pellepl / spiffs

Wear-leveled SPI flash file system for embedded devices
MIT License
1.52k stars 402 forks source link

Performance when opening large file in append mode #185

Open pjsg opened 7 years ago

pjsg commented 7 years ago

My app logs events and for each event it does

open( APPEND) write write write close

This can take 250 milliseconds or more once the file gets to 1MB. When the file is small, then it only takes 15 milliseconds.

I'm using 256 byte page with 8k blocks. (This is part of the lua nodemcu).

Is this expected behavior or can I fix this? Would increasing the size of the read cache help?

Actually, I did some more experiments, and doubling the cache from 2 pages to 4 pages made no difference. However, it turns out that the write time jumps from 15ms to 250ms when the file size reaches around 26k bytes.

everslick commented 7 years ago

I can confirm. Opening a 1MB file can take several seconds on an ESP32.

pjsg commented 7 years ago

I added a performance test to the tests: https://github.com/pjsg/spiffs/tree/write_perf

This displays:

$ build/linux_spiffs_test -f slow_file_open_large
adding suites...
adding test slow_file_open_large
1 tests added
running tests...
TEST 1/1 : running test slow_file_open_large
Read 557 bytes (3 reads), writes 1290 bytes (18 writes) to open/write/close file of size 21000.
Read 557 bytes (3 reads), writes 1290 bytes (18 writes) to open/write/close file of size 22000.
Read 557 bytes (3 reads), writes 1290 bytes (18 writes) to open/write/close file of size 23000.
Read 557 bytes (3 reads), writes 1290 bytes (18 writes) to open/write/close file of size 24000.
Read 557 bytes (3 reads), writes 1290 bytes (18 writes) to open/write/close file of size 25000.
Read 813 bytes (4 reads), writes 1290 bytes (18 writes) to open/write/close file of size 26000.
Read 1069 bytes (5 reads), writes 1815 bytes (26 writes) to open/write/close file of size 27000.
Read 5165 bytes (21 reads), writes 1546 bytes (19 writes) to open/write/close file of size 28000.
Read 5165 bytes (21 reads), writes 1546 bytes (19 writes) to open/write/close file of size 29000.
Read 5165 bytes (21 reads), writes 1546 bytes (19 writes) to open/write/close file of size 30000.
  .. ok

You can see that something happens at around the 27k byte mark in the file. Why this causes so much impact is unclear.