Forum Rule: Always post complete source code & details to reproduce any issue!
Page 1 of 2 1 2 LastLast
Results 1 to 25 of 31

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

  1. #1

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

    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

  2. #2
    Senior Member+ defragster's Avatar
    Join Date
    Feb 2015
    Posts
    16,202
    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.

  3. #3
    Senior Member+ mjs513's Avatar
    Join Date
    Jul 2014
    Location
    New York
    Posts
    8,274
    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

  4. #4
    Senior Member PaulStoffregen's Avatar
    Join Date
    Nov 2012
    Posts
    26,553
    Didn't we upgrade the internal littlefs code to a newer version?

  5. #5
    Senior Member+ mjs513's Avatar
    Join Date
    Jul 2014
    Location
    New York
    Posts
    8,274
    Quote Originally Posted by PaulStoffregen View Post
    Didn't we upgrade the internal littlefs code to a newer version?
    Yes we did but when we tested the changes we didn't see much difference. I am still going to do some more testing because I am now curious.

  6. #6
    Senior Member PaulStoffregen's Avatar
    Join Date
    Nov 2012
    Posts
    26,553
    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...

  7. #7
    Senior Member+ mjs513's Avatar
    Join Date
    Jul 2014
    Location
    New York
    Posts
    8,274
    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.

  8. #8
    Senior Member+ mjs513's Avatar
    Join Date
    Jul 2014
    Location
    New York
    Posts
    8,274
    Quote Originally Posted by PaulStoffregen View Post
    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

  9. #9
    Senior Member+ mjs513's Avatar
    Join Date
    Jul 2014
    Location
    New York
    Posts
    8,274
    @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

  10. #10
    Quote Originally Posted by mjs513 View Post
    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

  11. #11
    Senior Member+ mjs513's Avatar
    Join Date
    Jul 2014
    Location
    New York
    Posts
    8,274
    @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

  12. #12
    Senior Member+ mjs513's Avatar
    Join Date
    Jul 2014
    Location
    New York
    Posts
    8,274
    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
    Click image for larger version. 

Name:	Capture.PNG 
Views:	4 
Size:	5.6 KB 
ID:	28696
    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 by mjs513; 06-15-2022 at 06:25 PM.

  13. #13
    Senior Member+ defragster's Avatar
    Join Date
    Feb 2015
    Posts
    16,202
    Quote Originally Posted by mjs513 View Post
    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?

  14. #14
    Senior Member+ mjs513's Avatar
    Join Date
    Jul 2014
    Location
    New York
    Posts
    8,274
    Quote Originally Posted by defragster View Post
    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.

  15. #15
    Senior Member+ defragster's Avatar
    Join Date
    Feb 2015
    Posts
    16,202
    Quote Originally Posted by mjs513 View Post
    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?

  16. #16
    Senior Member+ mjs513's Avatar
    Join Date
    Jul 2014
    Location
    New York
    Posts
    8,274
    Quote Originally Posted by defragster View Post
    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.

  17. #17
    Senior Member+ defragster's Avatar
    Join Date
    Feb 2015
    Posts
    16,202
    Quote Originally Posted by mjs513 View Post
    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 }

  18. #18
    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.

  19. #19
    Senior Member PaulStoffregen's Avatar
    Join Date
    Nov 2012
    Posts
    26,553
    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

  20. #20
    Quote Originally Posted by PaulStoffregen View Post
    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.

  21. #21
    Senior Member PaulStoffregen's Avatar
    Join Date
    Nov 2012
    Posts
    26,553
    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.

  22. #22
    Senior Member+ defragster's Avatar
    Join Date
    Feb 2015
    Posts
    16,202
    Quote Originally Posted by PaulStoffregen View Post
    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 by defragster; 06-16-2022 at 07:10 AM. Reason: link to new code post

  23. #23
    Quote Originally Posted by defragster View Post
    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

  24. #24
    @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!

  25. #25
    Senior Member+ defragster's Avatar
    Join Date
    Feb 2015
    Posts
    16,202
    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.

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •