I have been using LittleFS for a QSPI data logging application for the last year on a T4.1 with a 64Mb W25Q512JVEIQ NOR chip. This is being used to log flight telemetry on amateur test rockets, so it is a very volatile environment. To get reliable crash data I need to open, write, and close the files each time, otherwise I risk losing whatever has not been "saved" by a close. I have an old Mac that was running 1.54 beta10 and Little FS to this chip was consistently opening-writing 100 characters-and-closing about 6.5 times a second (150ms). But I recently bought a new Mac and dropped in Teensyduino 1.56 and my LittleFS logging performance completely tanked, causing other processes on my flight computer to back-up. So, I created a simple benchmark program to open, write, and close and I compiled it under the old computer and the new computer with the same T4.1 hardware. Under 1.56 the performance is about 2-3X slower and very erratic. Under 1.54 beta10 it is consistent and fast.
Did something significant change in LittleFS when it went GA? Is it possible I am missing something else in the environment or board settings? (CPU speed and optimize settings are the same for both). Any insight would be appreciated. I will likely be re-writing my logging handler to queue write requests in memory and keep the file open with fast write speeds and then close-and-reopen it every 750ms to "save" intervals. This would only put at risk 750ms worth of data, but would complicate the logging thread.
Here is the code I am running to benchmark 1.54b10 vs. 1.56.
Here is the output from 1.54 beta 10:Code:// measure the time to open, print/write, and close to a file #include <LittleFS.h> LittleFS_QSPIFlash myfs; void setup() { Serial.begin(115200); Serial.println("LittleFS Open Close Write Speed Test"); if (!myfs.begin()) { Serial.printf("Error starting %s\n", "SPI FLASH"); while (1) ; // stop here } Serial.printf("Volume size %d MByte\n", myfs.totalSize() / 1048576); myfs.remove("stest.txt"); } void loop() { unsigned long startTime = 0; unsigned long goTime = 0; int openTime = 0; int printTime = 0; int closeTime = 0; int totalTime = 0; startTime = millis(); for(int n=0; n < 100; n++) { goTime = micros(); File myfile = myfs.open("stest.txt", FILE_WRITE); if(myfile) { openTime += (micros() - goTime); goTime = micros(); myfile.println("12345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890"); printTime += (micros() - goTime); goTime = micros(); myfile.close(); closeTime += (micros() - goTime); } } totalTime = millis() - startTime; Serial.print("Completed 100 open/write/close in a total of "); Serial.print(totalTime); Serial.print(" ms - avg tx/ms = "); Serial.println(totalTime/100); Serial.print("Per Tx in Micros: Avg open: ");Serial.print(openTime/100);Serial.print(" Avg print: ");Serial.print(printTime/100);Serial.print(" Avg close: ");Serial.println(closeTime/100); openTime = 0; printTime = 0; closeTime = 0; totalTime = 0; delay(2000); }
LittleFS Open Close Write Speed Test
Volume size 64 MByte
Completed 100 open/write/close in a total of 15400 ms - avg tx/ms = 154
Per Tx in Micros: Avg open: 555 Avg print: 153443 Avg close: 0
Completed 100 open/write/close in a total of 15400 ms - avg tx/ms = 154
Per Tx in Micros: Avg open: 555 Avg print: 153442 Avg close: 0
Completed 100 open/write/close in a total of 15400 ms - avg tx/ms = 154
Per Tx in Micros: Avg open: 555 Avg print: 153442 Avg close: 0
Completed 100 open/write/close in a total of 15400 ms - avg tx/ms = 154
Per Tx in Micros: Avg open: 555 Avg print: 153441 Avg close: 0
Completed 100 open/write/close in a total of 15400 ms - avg tx/ms = 154
Per Tx in Micros: Avg open: 555 Avg print: 153442 Avg close: 0
Completed 100 open/write/close in a total of 15400 ms - avg tx/ms = 154
Per Tx in Micros: Avg open: 555 Avg print: 153443 Avg close: 0
Completed 100 open/write/close in a total of 15400 ms - avg tx/ms = 154
Per Tx in Micros: Avg open: 555 Avg print: 153442 Avg close: 0
Completed 100 open/write/close in a total of 15399 ms - avg tx/ms = 153
Per Tx in Micros: Avg open: 555 Avg print: 153442 Avg close: 0
Completed 100 open/write/close in a total of 15400 ms - avg tx/ms = 154
Per Tx in Micros: Avg open: 555 Avg print: 153442 Avg close: 0
Here is the output from 1.56
LittleFS Open Close Write Speed Test
Volume size 64 MByte
Completed 100 open/write/close in a total of 27255 ms - avg tx/ms = 272
Per Tx in Micros: Avg open: 5580 Avg print: 258644 Avg close: 8332
Completed 100 open/write/close in a total of 31456 ms - avg tx/ms = 314
Per Tx in Micros: Avg open: 14013 Avg print: 296760 Avg close: 3785
Completed 100 open/write/close in a total of 34387 ms - avg tx/ms = 343
Per Tx in Micros: Avg open: 14306 Avg print: 325879 Avg close: 3685
Completed 100 open/write/close in a total of 36042 ms - avg tx/ms = 360
Per Tx in Micros: Avg open: 6094 Avg print: 353692 Avg close: 625
Completed 100 open/write/close in a total of 39877 ms - avg tx/ms = 398
Per Tx in Micros: Avg open: 13057 Avg print: 382008 Avg close: 3710
Completed 100 open/write/close in a total of 40901 ms - avg tx/ms = 409
Per Tx in Micros: Avg open: 13323 Avg print: 392006 Avg close: 3679
Completed 100 open/write/close in a total of 29031 ms - avg tx/ms = 290
Per Tx in Micros: Avg open: 13867 Avg print: 272617 Avg close: 3815
Completed 100 open/write/close in a total of 31994 ms - avg tx/ms = 319
Per Tx in Micros: Avg open: 14309 Avg print: 301904 Avg close: 3730
Completed 100 open/write/close in a total of 33423 ms - avg tx/ms = 334
Per Tx in Micros: Avg open: 6376 Avg print: 327193 Avg close: 660
Reply With Quote
Originally Posted by PaulStoffregen
As you said you have enough on your plate
