uSDFS on Teensy 3.6

spectasaurus · Oct 27, 2016

I am using the uSDFS-master library to write data to the SD card on T3.6. It works for the most part, but I am noticing that occasionally I get very long delays in writing data. As a test, I am writing 32768 byes to an open file. Usually, this process takes about 3000us, but sometimes will take over 650000us. I am unsure why. I have set the Teensy at various speeds and it's always the same result.

My test code is attached. All it does is open a file for writing, then write 32768 bytes to the file, and repeats this process TotalLoops times. It measures the time it takes for each write.

Code:

#include <Arduino.h>
#include <sys/stat.h>
#include "ff.h"
#define NbrEvents 8192
#define BufferSize 32768    // 32768 bytes per read tends to be optimal for SDHC access
#define TotalLoops 50

static uint32_t event_data[NbrEvents];
void die(char *str, FRESULT rc);

FRESULT rc;        /* Result code */
FATFS fatfs;      /* File system object */
FIL fil;        /* File object */
DIR dir;        /* Directory object */
FILINFO fno;      /* File information object */
FATFS *fs;

uint32_t count=0;
uint32_t ifn=0;
uint32_t isFileOpen=0;
char filename[80];
TCHAR wfilename[80];
uint32_t t0=0;
uint32_t t1=0;
UINT wr;
char text[80];

 extern "C" {

        int _write(int fd, const char *ptr, int len) {
                int j;
                for (j = 0; j < len; j++) {
                        if (fd == 1)
                                Serial.write(*ptr++);
                        else if (fd == 2)
                                Serial3.write(*ptr++);
                }
                return len;
        }

        int _read(int fd, char *ptr, int len) {
                if (len > 0 && fd == 0) {
                        while (!Serial.available());
                        *ptr = Serial.read();
                        return 1;
                }
                return 0;
        }

        int _fstat(int fd, struct stat *st) {
                memset(st, 0, sizeof (*st));
                st->st_mode = S_IFCHR;
                st->st_blksize = 1024;
                return 0;
        }

        int _isatty(int fd) {
                return (fd < 3) ? 1 : 0;
        }
} 

void die(char *str, FRESULT rc) 
{ printf_P("%s: Failed with rc=%u.\n", str, rc); for (;;) delay(100); }


TCHAR * char2tchar( char * charString, size_t nn, TCHAR * tcharString)
{ int ii;
  for(ii = 0; ii<nn; ii++) tcharString[ii] = (TCHAR) charString[ii];
  return tcharString;
}

char * tchar2char(  TCHAR * tcharString, size_t nn, char * charString)
{ int ii;
  for(ii = 0; ii<nn; ii++) charString[ii] = (char) tcharString[ii];
  return charString;
}

void setup() {
  uint32_t wt;
  uint32_t start1, start2, end1, end2, start3, end3;
  uint32_t ii;
  uint32_t ib;
  uint32_t event;
  uint8_t TransferBuffer[BufferSize];
  uint32_t TotalBytes=0;
  float bpms;

  for (ii=0; ii < NbrEvents; ii++) {
    event_data[ii] =  (uint32_t) (random(1000))/1000;
  }

  while (!Serial);
  printf_P(PSTR("\r\n\n\n\n\n\n\n\n\n\n\n\n\n\n\nStart\r\n"));
  Serial.flush();
  delay(1);
 
   f_mount (&fatfs, (TCHAR *)_T("/"), 0);  
   sprintf(filename,"Proj_Data_%d.dat",ib);
   char2tchar(filename,80,wfilename);
  
   rc = f_open(&fil, wfilename, FA_WRITE | FA_CREATE_ALWAYS);
   if (rc) die("open", rc);
   printf_P("Filename: %s\n",filename);  
   start3 = micros();       
   for (ib=0;ib<TotalLoops;ib++) {
     start1 = micros();
     while (start1 == micros());
     for (ii=NbrEvents; ii > 0LU; ii--) {
      // Simulate the data acquisition process here with a 1us delay
      delayMicroseconds(1);
     }
     end1 = micros();
     wt = (end1 - start1) - 1;
     bpms = (float)NbrEvents / (float) wt;

     start2 = micros();
     rc = f_write(&fil, event_data, 4*NbrEvents, &wr); 
     if (rc) die("write", rc); 
     end2 = micros();

     bpms = float(4*NbrEvents)/((end2-start2)-1);
     printf_P(PSTR("Time to write %lu bytes to SD: %lu us (%f MBps) \n"), 4*NbrEvents, (end2-start2)-1, bpms);
     bpms = float(NbrEvents)/((end2-start1)-1);
     delay(1);
    }
    rc = f_close(&fil);
    if (rc) die("close", rc);

   end3 = micros();
   bpms = float(TotalLoops*NbrEvents)/((end3-start3)-1);
   printf_P("Total time to transfer %u events = %u us (%f events/second)\n",TotalLoops*NbrEvents, (end3-start3), bpms*1000000),
   

    delay (2000);
    rc = f_opendir(&dir, (TCHAR*)_T(""));
    if (rc) die("Dir",rc);

    printf_P("Directory listing...\n");
    for (;;)   {
      rc = f_readdir(&dir, &fno);   /* Read a directory item */
      if (rc || !fno.fname[0]) break; /* Error or end of dir */
      if (fno.fattrib & AM_DIR) {
         printf_P("   <dir>  %s\r\n", tchar2char(fno.fname,80,text));
      } else {
         printf_P("%8d  %s\r\n", (int)fno.fsize, tchar2char(fno.fname,80,text)); // fsize is QWORD for exFAT
      }
    }

    printf_P("\n\n");
  
    if (rc) die("Listing",rc);
    // Read File size 
    rc = f_open(&fil, wfilename, FA_READ);
    if (rc) die("Opening", rc);
    printf_P("Sending file %s\n", filename);    
    start1 = micros();
        // Send file in chunks of XX bytes
    for (ii=fno.fsize/BufferSize; ii > 0LU; ii--) {
      rc = f_read(&fil, TransferBuffer, BufferSize, &wr);  
      if (rc) die("Reading", rc);
  //    printf_P("Read %d bytes\n", BufferSize);   
      TotalBytes+=BufferSize;
    }

    if (TotalBytes != fno.fsize) {
      rc = f_read(&fil, TransferBuffer, (uint32_t)(fno.fsize)-TotalBytes, &wr);  
      if (rc) die("Reading", rc);

    }

    end1 = micros();
  printf_P("Done in %u s\n\n", ((end1-start1)-1)/1000000);  
    rc = f_close(&fil);
    if (rc) die("close", rc);
     
}



void loop() {     
  
}

Output looks like the following:

Code:

Start
Filename: Proj_Data_0.dat
Time to write 32768 bytes to SD: 3758 us (8.719532 MBps) 
Time to write 32768 bytes to SD: 3989 us (8.214590 MBps) 
Time to write 32768 bytes to SD: 4126 us (7.941832 MBps) 
Time to write 32768 bytes to SD: 3997 us (8.198149 MBps) 
Time to write 32768 bytes to SD: 4068 us (8.055064 MBps) 
Time to write 32768 bytes to SD: 4001 us (8.189953 MBps) 
Time to write 32768 bytes to SD: 4149 us (7.897807 MBps) 
Time to write 32768 bytes to SD: 3922 us (8.354921 MBps) 
Time to write 32768 bytes to SD: 4177 us (7.844865 MBps) 
Time to write 32768 bytes to SD: 4067 us (8.057044 MBps) 
Time to write 32768 bytes to SD: 4373 us (7.493254 MBps) 
Time to write 32768 bytes to SD: 3516 us (9.319681 MBps) 
Time to write 32768 bytes to SD: 3031 us (10.810953 MBps) 
Time to write 32768 bytes to SD: 3041 us (10.775403 MBps) 
Time to write 32768 bytes to SD: 3031 us (10.810953 MBps) 
Time to write 32768 bytes to SD: 3041 us (10.775403 MBps) 
Time to write 32768 bytes to SD: 3030 us (10.814522 MBps) 
Time to write 32768 bytes to SD: 3042 us (10.771861 MBps) 
Time to write 32768 bytes to SD: 3032 us (10.807388 MBps) 
Time to write 32768 bytes to SD: 3104 us (10.556701 MBps) 
Time to write 32768 bytes to SD: 3031 us (10.810953 MBps) 
Time to write 32768 bytes to SD: 3040 us (10.778948 MBps) 
Time to write 32768 bytes to SD: 3031 us (10.810953 MBps) 
Time to write 32768 bytes to SD: 3041 us (10.775403 MBps) 
Time to write 32768 bytes to SD: 3030 us (10.814522 MBps) 
Time to write 32768 bytes to SD: 3042 us (10.771861 MBps) 
Time to write 32768 bytes to SD: 681527 us (0.048080 MBps) 
Time to write 32768 bytes to SD: 15418 us (2.125308 MBps) 
Time to write 32768 bytes to SD: 3492 us (9.383735 MBps) 
Time to write 32768 bytes to SD: 3590 us (9.127577 MBps) 
Time to write 32768 bytes to SD: 3653 us (8.970161 MBps) 
Time to write 32768 bytes to SD: 3503 us (9.354268 MBps) 
Time to write 32768 bytes to SD: 8725 us (3.755645 MBps) 
Time to write 32768 bytes to SD: 6004 us (5.457695 MBps) 
Time to write 32768 bytes to SD: 3493 us (9.381048 MBps) 
Time to write 32768 bytes to SD: 3445 us (9.511756 MBps) 
Time to write 32768 bytes to SD: 3426 us (9.564507 MBps) 
Time to write 32768 bytes to SD: 3463 us (9.462316 MBps) 
Time to write 32768 bytes to SD: 3445 us (9.511756 MBps) 
Time to write 32768 bytes to SD: 3454 us (9.486972 MBps) 
Time to write 32768 bytes to SD: 3464 us (9.459584 MBps) 
Time to write 32768 bytes to SD: 3412 us (9.603751 MBps) 
Time to write 32768 bytes to SD: 3423 us (9.572889 MBps) 
Time to write 32768 bytes to SD: 3441 us (9.522813 MBps) 
Time to write 32768 bytes to SD: 3485 us (9.402582 MBps) 
Time to write 32768 bytes to SD: 3451 us (9.495219 MBps) 
Time to write 32768 bytes to SD: 3520 us (9.309091 MBps) 
Time to write 32768 bytes to SD: 3474 us (9.432355 MBps) 
Time to write 32768 bytes to SD: 3523 us (9.301164 MBps) 
Time to write 32768 bytes to SD: 3475 us (9.429640 MBps) 
Total time to transfer 409600 events = 1357090 us (301822.500000 events/second)
Directory listing...
 1638400  Proj_Data_0.dat


Sending file Proj_Data_0.dat
Done in 0 s

WMXZ · Oct 27, 2016

spectasaurus said:
I am using the uSDFS-master library to write data to the SD card on T3.6. It works for the most part, but I am noticing that occasionally I get very long delays in writing data. As a test, I am writing 32768 byes to an open file. Usually, this process takes about 3000us, but sometimes will take over 650000us. I am unsure why. I have set the Teensy at various speeds and it's always the same result.

My test code is attached. All it does is open a file for writing, then write 32768 bytes to the file, and repeats this process TotalLoops times. It measures the time it takes for each write.

These occasional very long delays are due to disk fragmentation and due to uSD internal behaviour.
While the first source can be eliminated with a freshly formatted disk, the latter (internal uSD behaviour) is an intrinsic feature of the uSD. All these disks contain a small CPU that handles bad blocks and carry out wear-levelling to avoid writing always to the same physical location, as this would generate bad blocks or reduce disk lifetime.
So, there is a lot going on inside the disk that from time to time will need a very long time. Obviously, this undesired behaviour depends on the quality of the disk, which itself is a function of the disk capacity. The higher the capacity, the smaller the storage units, the more errors can occur, both in production and during operation.

So, that is something we have to live with. It is not a fault of the filing system. The commodity of using commercial disk has its price. Alternatively, I have some recorders that write directly to flash. first you scan the flash chips for bad blocks, then you write from beginning to the end, so no wear-levelling is necessary. This is faster, more reliable, but not flexible, as flash chips are soldered onto PCB and cannot be changed.

spectasaurus · Oct 27, 2016

Good to know, thank you. I am using the Teensy to acquire high speed data via SPI from a piece of hardware and am looking at ways to save it or send it quickly to a PC. I've previously used Serial USB for transfer, but at 12Mbps, it is not fast enough. I was hoping SD might be faster (and it is), with this caveat. HS USB would be nice, but not sure that's coming very quickly.

PaulStoffregen · Oct 27, 2016

Have you tried different brands of SD cards? Maybe try ones with fast reputations, like Sandisk Ultra/Extreme or Samsung EVO.

spectasaurus · Oct 27, 2016

Haven't looked at other brands yet. I have only a 16 GB Lexar Class 10 on hand, but this might be worth looking into. I'm very impressed with T3.6 so far and very glad I jumped in the KS campaign. Thanks.

linuxgeek · Oct 27, 2016

I imagine you could write to SPI flash buffer (ie in an interrupt), and write that buffer out to uSD when it's less time-sensitive (ie in loop).

Bill Greiman · Oct 27, 2016

Every SD will have long write delays. The spec allows 250 ms for 32GB or smaller cards and 500 ms for 64GB and larger cards.

You will rarely see the max and it depends on the card. The spec assumes you will write a RU, Recording Unit, which is 512 KB as a single contiguous write.

The card has a number of RUs ready but if you run out of ready RUs, fragment an RU, or the wear leveling or ECC algorithm kicks in, a large delay will occur.

Wear leveling requires data to be moved and moving 512 KB can take lots of time even in a fast card. Erasing a number of RUs also takes time.

It's a lot easier to cope with this problem with a RTOS. Use the I/O queue features to buffer data for a lower priority thread.

The rest of this post is just a repeat of my wish for Arduino to natively support a modern RTOS which will never happen.

I don't use the Arduino IDE for complex projects. I started using an RTOS on micro-controllers in the mid 1980s.

I currently use ChibiOS/RT with its HAL for complex or high performance projects. I tried to use ChibiOS/RT as a library on Teensy but it is too messy.

Paul's attempts to address Arduino IDE shortcomings just don't fit well with modern RTOSes.

Paul has fixed many problems but Arduino is still close to 1960s software use in the Apollo lander

I would love to see a ChibiOS/RT HAL for Teensy 3.6 but it would mean scrapping much of the current Teensy software.

Too bad hardware types think an RTOS has too much overhead. A Modern tickless RTOS has less overhead than the Arduino IDE.

kkiokio · Mar 28, 2017

I found that It sometimes takes 480000000 ms to close the file. usually the whole process of storing the data in SD card takes around 200ms but randomly it would take me the above mentioned time for closing the file.

Did anyone find a solution to it?

Why does closing a file take that much time?

WMXZ · Mar 28, 2017

kkiokio said:
I found that It sometimes takes 480000000 ms to close the file. usually the whole process of storing the data in SD card takes around 200ms but randomly it would take me the above mentioned time for closing the file.

Did anyone find a solution to it?

Why does closing a file take that much time?

are you sure about the numbers ? 480000000 ms = 480000 s > 5 days 13 h

BJB · Mar 28, 2017

Bill Greiman said:
Too bad hardware types think an RTOS has too much overhead. A Modern tickless RTOS has less overhead than the Arduino IDE.

Perhaps getting too old and slow, but do not understand comparison of a rtos to an ide. And dunno about any rtos needed for ardy stuff in general. In particular, have done some complex stuff with teensys using none other than my simple scheduler, where each task is typically always running and is essentially static. And only the ghost of Chesty Puller knows how many ardy schedulers have already been written. If you need true dynamic scheduling, methinks one does not use arduino libs.

As for SD stuff, generally buffer the crap out of it and use only sandisk cards, but do not do any fancy audio streaming where latency would bite my butt, which is probably why my stuff does not see these issues.

kkiokio · Mar 29, 2017

WMXZ said:
are you sure about the numbers ? 480000000 ms = 480000 s > 5 days 13 h

I checked again and corrected some mistakes I was making.

It now shows that some times (randomly 3-4 consecutive values) it takes 450-500ms to close the file.
Which is usually 5-8ms.
Can anyone tell me what might be the problem?

heppjs · Aug 11, 2017

very useful thread - helps clarify some seemingly random problems with my cascaded AD7768 logging. Any advice on managing the SD "housekeeping" functions aside from using just-formatted media?

BTW, what's the story on Bill's SDFormatter (takes a few seconds to format 32GB on T36) vs the Tuxera SDCardFormatter v5.0 (takes nearly 30 minutes via USB-connected card reader on my PC)?

firehopper · Aug 11, 2017

heppjs said:
very useful thread - helps clarify some seemingly random problems with my cascaded AD7768 logging. Any advice on managing the SD "housekeeping" functions aside from using just-formatted media?

BTW, what's the story on Bill's SDFormatter (takes a few seconds to format 32GB on T36) vs the Tuxera SDCardFormatter v5.0 (takes nearly 30 minutes via USB-connected card reader on my PC)?

I suspect bills formatter is just doing a quick format, the tux one is doing a full format. just a guess though

Bill Greiman · Aug 13, 2017

firehopper said:
I suspect bills formatter is just doing a quick format, the tux one is doing a full format. just a guess though

No I do a full format if you use the F option. SD cards have an internal erase option so all flash is cleared. Modern SD cards have huge flash pages, they only emulate 512 byte sectors. A high end 64GB Samsung card takes about 30 seconds to erase.

Doing a "full format" with most utilities is a total waste of time. Since SD cards do wear leveling you won't access the same blocks when you use the card. There is a free heap of flash pages and a virtual to physical map.

The card uses huge ECC codes and fixes bad spots until they get past a threshold then they are not used any more. So you can't find marginal blocks with a format utility.

uSDFS on Teensy 3.6

spectasaurus

Active member

Attachments

WMXZ

Well-known member

spectasaurus

Active member

PaulStoffregen

Well-known member

spectasaurus

Active member

linuxgeek

Well-known member

Bill Greiman

Well-known member

kkiokio

Active member

WMXZ

Well-known member

BJB

Well-known member

kkiokio

Active member

heppjs

Member

firehopper

Well-known member

Bill Greiman

Well-known member