LittleFS performance issue for QSPI flash from 1.54 beta10 to 1.56?

TeensyDigital

Well-known member
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.

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);
}

Here is the output from 1.54 beta 10:

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
 
TeensyDuino 1.57 Beta 3 just released.

In this post above code was incorporated (mostly) as posted: pjrc.com/threads/68139-Teensyduino-File-System-Integration-including-MTP-and-MSC?p=307790&viewfull=1#post307790

T_4.1 with 16 MB NOR flash gives:
Code:
Completed 100 open/write/close in a total of ... 17418 ms - avg tx/ms = 174
Per Tx in Micros:  Avg open: 4585    Avg print: 167033    Avg close: 2565

The FileSystem code is changing ... not sure what might account for the speed change.

Suggest updating to TD 1.57 to confirm results and perhaps it can be addressed if possible.
 
Yes there were some changes, was kind of a tradeoff process. The main thing was that the blocksizes increased which means you are going to get a performance hit for small files (less than a block). Blokc sizes are now on the order of 32K vs 4k in earlier versions.

If I run a modified version of the SDfat Benchmark sketch I am seeing:
Code:
Bytes Used: 131072, Bytes Total:16777216
FILE_SIZE = 5242880
BUF_SIZE = 512 bytes

Starting write test, please wait.
write speed and latency
speed,max,min,avg
KB/Sec,usec,usec,usec
640.78,3444,780,798
640.70,3444,780,798
640.86,3443,780,798
282.21,174936,780,1814
274.55,143769,780,1864
261.87,172613,780,1955
262.17,166621,780,1952
258.88,173212,780,1977
274.84,143818,780,1862
260.98,177333,780,1961


Starting sequential read test, please wait.
read speed and latency
speed,max,min,avg
KB/Sec,usec,usec,usec
33619.41,72,14,15
33618.98,73,14,15
33618.55,73,14,15
33618.77,73,14,15
33618.77,73,14,15
33618.55,73,14,15
33618.98,73,14,15
33618.77,73,14,15
33618.77,73,14,15
33618.12,73,14,15

Done
Time to Open File for Read (uSecs): 198
Time to Close File(uSecs): 1

Unfortunately I can not find the equivalent results for earlier revisions of LittleFS. not sure why your open and close times are so large to be honest though
 
I'm curious too. Put this on my (very long) list of low priority issues to investigate. But odds are I probably can't do much on this anytime soon. So many other high priority items pending...
 
I installed Aduino 1.55 and TD1.55 (closest I could get) and verified that the LittlFS had the smaller block sizes and earlier revision of LittleFS (0x00020002) running the sketch #1 with 1 minor change:
Code:
  //myfs.remove("stest.txt");
  myfs.lowLevelFormat('.');

RESULTS:
Code:
1.55 w/1.8.15 (verified has old LFS version + old blocksizes)
LittleFS Open Close Write Speed Test
Volume size 16 MByte
Completed 100 open/write/close in a total of  607 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 124    Avg print: 3746    Avg close: 2201
Completed 100 open/write/close in a total of  630 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 117    Avg print: 3971    Avg close: 2210
Completed 100 open/write/close in a total of  652 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 118    Avg print: 4193    Avg close: 2212
Completed 100 open/write/close in a total of  685 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 118    Avg print: 4192    Avg close: 2529
Completed 100 open/write/close in a total of  615 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 115    Avg print: 3797    Avg close: 2242
Completed 100 open/write/close in a total of  637 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 117    Avg print: 4025    Avg close: 2223
Completed 100 open/write/close in a total of  650 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 118    Avg print: 4188    Avg close: 2190

Actually a bit better than in post #1

TEST 2: Use the latest version of LFS (0x00020004) into TD155 LittleFS library and rerun sketch:
Code:
Completed 100 open/write/close in a total of  607 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 124    Avg print: 3739    Avg close: 2210
Completed 100 open/write/close in a total of  630 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 117    Avg print: 3964    Avg close: 2209
Completed 100 open/write/close in a total of  654 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 118    Avg print: 4186    Avg close: 2238
Completed 100 open/write/close in a total of  686 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 118    Avg print: 4185    Avg close: 2554
Completed 100 open/write/close in a total of  614 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 115    Avg print: 3791    Avg close: 2240
Completed 100 open/write/close in a total of  635 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 117    Avg print: 4018    Avg close: 2214
Completed 100 open/write/close in a total of  653 ms - avg tx/ms = 6
Per Tx in Micros:  Avg open: 118    Avg print: 4181    Avg close: 2235

Don't see much of a change between LFS versions used in the LittleFS library.
 
I'm curious too. Put this on my (very long) list of low priority issues to investigate. But odds are I probably can't do much on this anytime soon. So many other high priority items pending...

Understood - going to see how much I can isolate it down without breaking things :) As you said you have enough on your plate
 
@PaulStoffregen
Think I got it isolated. Using 1.8.15 + TD155 plus the following changes to LittleFS Libary
  1. Updated LFS library to 0x00020004
  2. Updated the LittleFS for change blocksize and blockerase (equivalent to what is in 1.8.19 less the code we added to support MTP (file dates, etc)

the results show a dramatic hit to file write and open times as in post #1:
Code:
Completed 100 open/write/close in a total of  1312 ms - avg tx/ms = 13
Per Tx in Micros:  Avg open: 586    Avg print: 12196    Avg close: 345
Completed 100 open/write/close in a total of  3421 ms - avg tx/ms = 34
Per Tx in Micros:  Avg open: 1539    Avg print: 32327    Avg close: 343
Completed 100 open/write/close in a total of  12602 ms - avg tx/ms = 126
Per Tx in Micros:  Avg open: 1366    Avg print: 122593    Avg close: 2059
Completed 100 open/write/close in a total of  21440 ms - avg tx/ms = 214
Per Tx in Micros:  Avg open: 943    Avg print: 213115    Avg close: 342
Completed 100 open/write/close in a total of  24498 ms - avg tx/ms = 244
Per Tx in Micros:  Avg open: 1894    Avg print: 242738    Avg close: 346
Completed 100 open/write/close in a total of  25150 ms - avg tx/ms = 251
Per Tx in Micros:  Avg open: 684    Avg print: 248803    Avg close: 2014
Completed 100 open/write/close in a total of  15822 ms - avg tx/ms = 158
Per Tx in Micros:  Avg open: 1368    Avg print: 156494    Avg close: 357
Completed 100 open/write/close in a total of  19593 ms - avg tx/ms = 195
Per Tx in Micros:  Avg open: 1514    Avg print: 192349    Avg close: 2064
Completed 100 open/write/close in a total of  19873 ms - avg tx/ms = 198
Per Tx in Micros:  Avg open: 829    Avg print: 197545    Avg close: 356
Completed 100 open/write/close in a total of  22739 ms - avg tx/ms = 227
 
I installed Aduino 1.55 and TD1.55 (closest I could get) and verified that the LittlFS had the smaller block sizes and earlier revision of LittleFS (0x00020002) running the sketch #1 with 1 minor change:

Oh wow! The low level format brought back the old screaming fast performance I used to see, but performance is still an issue under 1.56.

With a low level format using 1.54beta10 my open-print-close time dropped to an average of 8ms. using the same code on 1.56 it starts out faster (20ms), but is back up to 350ms within a few minutes. Again very inconsistent with 1.56. I have not yet installed the 1.57 beta, but I will.

Here are my results when initiating with the low level format first...

1.56 with a low level format

...............................................................................................................................
Completed 100 open/write/close in a total of 2080 ms - avg tx/ms = 20
Per Tx in Micros: Avg open: 4078 Avg print: 16102 Avg close: 618
Completed 100 open/write/close in a total of 5016 ms - avg tx/ms = 50
Per Tx in Micros: Avg open: 4421 Avg print: 42004 Avg close: 3738
Completed 100 open/write/close in a total of 7977 ms - avg tx/ms = 79
Per Tx in Micros: Avg open: 4937 Avg print: 71172 Avg close: 3662
Completed 100 open/write/close in a total of 10657 ms - avg tx/ms = 106
Per Tx in Micros: Avg open: 5492 Avg print: 97410 Avg close: 3662
Completed 100 open/write/close in a total of 12695 ms - avg tx/ms = 126
Per Tx in Micros: Avg open: 5043 Avg print: 121299 Avg close: 605
Completed 100 open/write/close in a total of 14016 ms - avg tx/ms = 140
Per Tx in Micros: Avg open: 4076 Avg print: 132501 Avg close: 3581
Completed 100 open/write/close in a total of 2836 ms - avg tx/ms = 28
Per Tx in Micros: Avg open: 4620 Avg print: 20018 Avg close: 3724
Completed 100 open/write/close in a total of 5605 ms - avg tx/ms = 56
Per Tx in Micros: Avg open: 5172 Avg print: 47314 Avg close: 3560
Completed 100 open/write/close in a total of 8407 ms - avg tx/ms = 84
Per Tx in Micros: Avg open: 5729 Avg print: 74614 Avg close: 3726
Completed 100 open/write/close in a total of 10501 ms - avg tx/ms = 105
Per Tx in Micros: Avg open: 4200 Avg print: 100174 Avg close: 631
Completed 100 open/write/close in a total of 34924 ms - avg tx/ms = 349
Per Tx in Micros: Avg open: 4311 Avg print: 341312 Avg close: 3617
Completed 100 open/write/close in a total of 38463 ms - avg tx/ms = 384
Per Tx in Micros: Avg open: 4858 Avg print: 376040 Avg close: 3736
Completed 100 open/write/close in a total of 29614 ms - avg tx/ms = 296
Per Tx in Micros: Avg open: 5407 Avg print: 287247 Avg close: 3479



1.54 beta10 with low level format

.........................................................................................................................
Completed 100 open/write/close in a total of 856 ms - avg tx/ms = 8
Per Tx in Micros: Avg open: 126 Avg print: 4892 Avg close: 3548
Completed 100 open/write/close in a total of 882 ms - avg tx/ms = 8
Per Tx in Micros: Avg open: 118 Avg print: 5148 Avg close: 3552
Completed 100 open/write/close in a total of 911 ms - avg tx/ms = 9
Per Tx in Micros: Avg open: 119 Avg print: 5438 Avg close: 3543
Completed 100 open/write/close in a total of 961 ms - avg tx/ms = 9
Per Tx in Micros: Avg open: 119 Avg print: 5442 Avg close: 4053
Completed 100 open/write/close in a total of 863 ms - avg tx/ms = 8
Per Tx in Micros: Avg open: 116 Avg print: 4947 Avg close: 3563
Completed 100 open/write/close in a total of 888 ms - avg tx/ms = 8
Per Tx in Micros: Avg open: 118 Avg print: 5226 Avg close: 3533
Completed 100 open/write/close in a total of 906 ms - avg tx/ms = 9
Per Tx in Micros: Avg open: 119 Avg print: 5445 Avg close: 3500
Completed 100 open/write/close in a total of 953 ms - avg tx/ms = 9
Per Tx in Micros: Avg open: 119 Avg print: 5328 Avg close: 4078
Completed 100 open/write/close in a total of 872 ms - avg tx/ms = 8
Per Tx in Micros: Avg open: 116 Avg print: 5038 Avg close: 3559
Completed 100 open/write/close in a total of 892 ms - avg tx/ms = 8
Per Tx in Micros: Avg open: 118 Avg print: 5222 Avg close: 3578
Completed 100 open/write/close in a total of 926 ms - avg tx/ms = 9
Per Tx in Micros: Avg open: 119 Avg print: 5613 Avg close: 3535
Completed 100 open/write/close in a total of 940 ms - avg tx/ms = 9
Per Tx in Micros: Avg open: 119 Avg print: 5244 Avg close: 4027
 
@PaulStoffregen - @KurtE - @TeensyDigital
Using Arduino IDE 1.8.19 and TD1.57beta3 I switched back to using the smaller blocksizes that we originally had in LittleFS (4096 versus 32/64K) and reran the sketch in post #1 with the change I mention ed in Post #7 and the times improved dramatically:
Code:
Completed 100 open/write/close in a total of  815 ms - avg tx/ms = 8
Per Tx in Micros:  Avg open: 498    Avg print: 3518    Avg close: 4132
Completed 100 open/write/close in a total of  869 ms - avg tx/ms = 8
Per Tx in Micros:  Avg open: 493    Avg print: 3730    Avg close: 4470
Completed 100 open/write/close in a total of  855 ms - avg tx/ms = 8
Per Tx in Micros:  Avg open: 487    Avg print: 3940    Avg close: 4117
Completed 100 open/write/close in a total of  889 ms - avg tx/ms = 8
Per Tx in Micros:  Avg open: 493    Avg print: 3938    Avg close: 4455
Completed 100 open/write/close in a total of  820 ms - avg tx/ms = 8
Per Tx in Micros:  Avg open: 488    Avg print: 3566    Avg close: 4146
Completed 100 open/write/close in a total of  872 ms - avg tx/ms = 8
Per Tx in Micros:  Avg open: 494    Avg print: 3780    Avg close: 4447
Completed 100 open/write/close in a total of  853 ms - avg tx/ms = 8
Per Tx in Micros:  Avg open: 488    Avg print: 3934    Avg close: 4107

The changes to avg open times are probably due to us adding in date/time functions using setattr in LFS, etc. Formatting seems to be working on Flash chips without an issue with the smaller block sizes.

This is the change I made to the chipinfo structure:
Code:
known_chips[] = {
{{0xEF, 0x40, 0x15}, 24, 256, 4096, 0x20, 2097152, 3000, 1600000, "W25Q16JV*Q/W25Q16FV"},  // Winbond W25Q16JV*Q/W25Q16FV
{{0xEF, 0x40, 0x16}, 24, 256, 4096, 0x20, 4194304, 3000, 1600000, "W25Q32JV*Q/W25Q32FV"},  // Winbond W25Q32JV*Q/W25Q32FV
{{0xEF, 0x40, 0x17}, 24, 256, 4096, 0x20, 8388608, 3000, 2000000, "W25Q64JV*Q/W25Q64FV"},  // Winbond W25Q64JV*Q/W25Q64FV
{{0xEF, 0x40, 0x18}, 24, 256, 4096, 0x20, 16777216, 3000, 2000000, "W25Q128JV*Q/W25Q128FV"}, // Winbond W25Q128JV*Q/W25Q128FV
{{0xEF, 0x40, 0x19}, 32, 256, 4096, 0x21, 33554432, 3000, 2000000, "W25Q256JV*Q"}, // Winbond W25Q256JV*Q
{{0xEF, 0x40, 0x20}, 32, 256, 4096, 0x21, 67108864, 3500, 2000000, "W25Q512JV*Q"}, // Winbond W25Q512JV*Q
{{0xEF, 0x40, 0x21}, 32, 256, 4096, 0x21, 134217728, 3500, 2000000, "W25Q01JV*Q"},// Winbond W25Q01JV*Q
{{0xEF, 0x70, 0x17}, 24, 256, 4096, 0x20, 8388608, 3000, 2000000, "W25Q64JV*M (DTR)"},  // Winbond W25Q64JV*M (DTR)
{{0xEF, 0x70, 0x18}, 24, 256, 4096, 0x20, 16777216, 3000, 2000000, "W25Q128JV*M (DTR)"}, // Winbond W25Q128JV*M (DTR)
{{0xEF, 0x70, 0x19}, 32, 256, 4096, 0x21, 33554432, 3000, 2000000, "W25Q256JV*M (DTR)"}, // Winbond W25Q256JV*M (DTR)
{{0xEF, 0x80, 0x19}, 32, 256, 4096, 0x21, 33554432, 3000, 2000000, "W25Q256JW*M"}, // Winbond (W25Q256JW*M)
{{0xEF, 0x70, 0x20}, 32, 256, 4096, 0x21, 67108864, 3500, 2000000, "W25Q512JV*M (DTR)"}, // Winbond W25Q512JV*M (DTR)
{{0x1F, 0x84, 0x01}, 24, 256,  4096, 0x20, 524288, 2500, 300000, "AT25SF041"},    // Adesto/Atmel AT25SF041
{{0x01, 0x40, 0x14}, 24, 256,  4096, 0x20, 1048576, 5000, 300000, "S25FL208K"},   // Spansion S25FL208K
 
Using @defragster MakeFiles sketch running the 't' and 'b' options it created 1,151 Files in 49 Folders on the Builtin SDCard. I copied the files from SD Card to the PC using MTP and then copied the files to the W25Q512JV*Q flash chip (all with MTP) and then back to the PC.

1. Coping from PC to flash:
1 directory of 5 files did not [sic] copy when I did the transfer from the flash to the PC
Capture.PNG
but the files are on the flash.

2. Just a note
sampling files on the PC/SDCard/flash they all look to be correct

UPDATE:
A couple more tests
1. Copied a 7.8Mbyte pdf to both the W25Q512JV and the W25Q512JV spi flash and the W25Q128JV QSPI Flash showed no transfer issues. PDF copied and the opened from the drives.
2. No issues with formatting the flash chips either.
 
Last edited:
Using @defragster MakeFiles sketch running the 't' and 'b' options it created 1,151 Files in 49 Folders on the Builtin SDCard. I copied the files from SD Card to the PC using MTP and then copied the files to the W25Q512JV*Q flash chip (all with MTP) and then back to the PC.

1. Coping from PC to flash:
1 directory of 5 files did copy when I did the transfer from the flash to the PC
...
but the files are on the flash.

2. Just a note
sampling files on the PC/SDCard/flash they all look to be correct

UPDATE:
A couple more tests
1. Copied a 7.8Mbyte pdf to both the W25Q512JV and the W25Q512JV spi flash and the W25Q128JV QSPI Flash showed no transfer issues. PDF copied and the opened from the drives.
2. No issues with formatting the flash chips either.

Should that be: " 1 directory of 5 files did NOT copy when I did the transfer from the flash to the PC"
> CodeCompare looks to show them missing

Don't forget the fun - but, perhaps useless here - given the files are known to be on Flash: "C - Copy LFS media content to SD"
> when the DISK is LFS, it can move all LFS media content to folder on SD card

Suppose I should add option for 'formatting LFS media' when active, but the 'W'ipe will delete everything.
> both low level and 'unused'

Cool that Makefiles.ino is useful ... anything else it could put in one place for reference testing?
 
Should that be: " 1 directory of 5 files did NOT copy when I did the transfer from the flash to the PC"
> CodeCompare looks to show them missing

Don't forget the fun - but, perhaps useless here - given the files are known to be on Flash: "C - Copy LFS media content to SD"
> when the DISK is LFS, it can move all LFS media content to folder on SD card

Suppose I should add option for 'formatting LFS media' when active, but the 'W'ipe will delete everything.
> both low level and 'unused'

Cool that Makefiles.ino is useful ... anything else it could put in one place for reference testing?

Yep should be DID NOT transfer - typed it too fast

Probably formatting would be good.

Of course makefiles is useful. In comes in handy for certain testing.
 
Yep should be DID NOT transfer - typed it too fast

Probably formatting would be good.

Of course makefiles is useful. In comes in handy for certain testing.

Odd they did not copy ... Assume makefiles: 'l'ist shows them so they are properly findable and the "C"opy would put them on SD. Also 'v'erify.

Done minimal testing on Flash - SD no fun transferring the card all the time - but that was important for verification of function.

Wonder if it is a mismatch of mtpindex.dat not having those files recorded?

Could the Teensy walk the mtpindex.dat file and compare to actual file list as a confirmation test?
 
Odd they did not copy ... Assume makefiles: 'l'ist shows them so they are properly findable and the "C"opy would put them on SD. Also 'v'erify.

Done minimal testing on Flash - SD no fun transferring the card all the time - but that was important for verification of function.

Wonder if it is a mismatch of mtpindex.dat not having those files recorded?

Could the Teensy walk the mtpindex.dat file and compare to actual file list as a confirmation test?

Well they copied from the PC to the flash. I did verify that they were on the flash via MTP of course. Yet they did not copy down from the flash to PC - not sure why when everything else did.
 
Well they copied from the PC to the flash. I did verify that they were on the flash via MTP of course. Yet they did not copy down from the flash to PC - not sure why when everything else did.

That is puzzling that whole files got missed. That was showing before on SD card, but it went away. All recent SD copies had at worst a missing packet or so, but all files were present after MTP read from T_4.1.
> Wonder if it repro's the same and goes away with the LFS PROGRAM disk for the index.dat file? { with rebuild and the #ifdef enabled }
 
I've found one more strange performance issue with LittleFS doing the open-print-close cycle to my QSPI flash chip. If I run the code in post #1 with @mjs513's low level format first, using TD 1.55 it is screaming fast (the same as 1.54b10) at about 9ms per open-print-close. But... after a few minutes when the chip has about 2Mb of data written (same file or different files) the performance drops to 50-70ms per transaction. This is consistent and repeatable every time. I thought it might be a bad QSPI chip, so I pulled a brand new T4.1 and soldered in a new W25Q512JVEIQ chip and I get the same result. Odd, since it is only used 2Mb of 64Mb. I have not let it go much longer, but there might be other performance break points higher up.
 
I'm pretty sure this problem is you're running out pre-erased sectors and LittleFS is having to do slow erase operations.

That sounds right, but it is odd that it happens in exactly the same spot/time on two different chips. One that has been used for a year and one brand new. That would imply that something about a LittleFS low-level format consistently pre-erases the first 2Mb of space.
 
Brand new flash chips usually start in fully erased condition, so you could expect to see the same behavior on all chips of the same size.
 
I'm pretty sure this problem is you're running out pre-erased sectors and LittleFS is having to do slow erase operations.

Sadly, LittleFS doesn't have any way to allow us to pre-erase the sectors. It's been requested...

https://github.com/littlefs-project/littlefs/issues/493

This is exactly what .formatUnused() does. It does take 'user code' "during Down Time ... or before Active Time" when write speed needs to be optimal.

Usage was included in the integrity test code for LFS and I just wrote it into MakeFiles.ino I'll be noting on the MTP/MSC thread shortly. <edit>: See https://forum.pjrc.com/threads/68139-Teensyduino-File-System-Integration-including-MTP-and-MSC?p=307922&viewfull=1#post307922

My loop looks like this:
Code:
        uint32_t nextBlock = 0;

        Serial.print("Starting SAFE Format of unused blocks:\n\t>");
        do {
          nextBlock = DISK.formatUnused( 10, nextBlock ); // COUNT, where to start
          Serial.print('.');
        } while ( 0 != nextBlock );
        Serial.println();

That says start at the beginning of the media ( uint32_t nextBlock = 0; ) and find 10 blocks "unused and in need of formatting" and return, when it returns it says what block it stopped on, and in this case it shows a progress '.' and repeats until it returns '0' saying it ran off the end of the media.

> Each call to .formatUnused() has to create a new bitmap of the used media and this can be time consuming to make repeat small calls - especially on huge NAND flash holding lots of files (it can take over 20 seconds just to ask LFS for the 'used' bitmap info)
> To have it run HEAD down on a single pass read of the bitmap call with: DISK.formatUnused( 0,0 );
- that starts at the beginning and stops when all blocks are tested to be in use, and formatted if needed when not in use.
- it is SAFE in that it won't format USED blocks, when data preservation is needed, to add files (after some may have been deleted or normal LFS activity may have abandoned blocks as DIR data grew/moved).
- Unlike the DISK.lowLevelFormat('.'); it won't delete and format ALL existing data blocks.
 
Last edited:
This is exactly what .formatUnused() does. It does take 'user code' "during Down Time ... or before Active Time" when write speed needs to be optimal.

@defragster how would you implement this in practice? I've reverted back to TD1.55, since the LittleFS performance is better than 1.56, but this switch in performance after writing about 2Mb to my QSPI flash is really messing with me. After a low-level format my open-write-close cycle time is about 98 per second. I get this performance up to about 2Mb and then it drops as low as 10 per second. I would happily pre-process before writing, like I need to do a 16 minute low level format first. If I do the low-level format and then run your code above it finishes immediately (no unused to format?). Should I be invoking your code above after I've written 1Mb, but before I've reached the "problem space"?

thanks,

Mike
 
@defragster you can disregard the previous post. I got the LFS formatUnused to work. To work it has to be invoked after you start writing to flash. It does improve performance, but it is too (time) expensive for my application. I am going to rewrite what I am doing and use a flush() every one second without closing the file to "burn in". This will give me the high speed logging I need and will only create one second of risk. Thanks!
 
If I understand what you are hitting ...
LFS on FLASH does have drawbacks. Each committed update has to make an updated DIR entry - which leaves behind a dirty set of flash blocks from the prior DIR info.
So limiting the DIR data updates will limit the dirty blocks needing format before use.

The formatUnused is nice in that it does not destroy Used data like lowLevelFormat. The problem is there is only one way to track blocks in use and that is a full walk of the dir data as provided by LFS code. LFS does not expose a way to know when a block is discarded.

If that dirty and now unused block were known it could be targeted to pre-format without having to walk the entire media for used blocks.
 
Back
Top