Repeated slow writes to microSD card

18 Nov 2012

Hi,

I'm trying to put together a data logger for my motorcycle for next year and I'm running into a problem with writing data to a microSD card. It seems that on a repeated basis there is one write that takes a disproportionately long time and this is causing me to miss data. I've tried: - setting the setvbuf for the opened file and all appropriate options http://www.cplusplus.com/reference/clibrary/cstdio/setvbuf/ - using fflush to make sure that everything is written to the card on each write cycle - using different cards

#include "mbed.h"
#include "string"
#include "SDHCFileSystem.h"

Serial pc(USBTX, USBRX); // tx, rx
SDFileSystem sd(p5, p6, p7, p8, "sd"); // mosi, miso, sclk, cs
Serial serialGPS(p9, p10);  // tx, rx

Timer t;
Timer t1;
int reset = 0;
FILE *can;

DigitalOut led1(LED1);
DigitalOut led2(LED2);

int a = 0;
int printLine = 0;
int readLine = 0;
char gpsTEMP[100][100];

char gpsWRITEbuffer[100];
char canWRITEbuffer[10000];

char directory[20];
char dirText[20];
int randomNumber = 0;

void printGPS(int index)
{
    //fflush(can);
    t.start();
    //fflush(can);
    fprintf(can, gpsTEMP[index]);
    t.stop();
        if(t.read_us() < 200) {
            pc.printf("w");
        } else {
            pc.printf("\n\rTIME T0: %d\n\r", t.read_us());
        }
    t.reset();
}

void gpsREADchar()
{
    //pc.printf("I");
    if (serialGPS.getc() == '$') {
        //pc.printf("\n\n\n IN!!!! \n\n\n");
        //t.start();
        //memset(gpsTEMP[printLine],' ',strlen(gpsTEMP[printLine]));
        a=1;
        gpsTEMP[printLine][0] = '$';
        while (1) {
            gpsTEMP[printLine][a]= serialGPS.getc();
            // pc.putc(gpsTEMP[printLine][a]);
            if (gpsTEMP[printLine][a]== '\n') {
                gpsTEMP[printLine][a] = '\0';    //overwrite newline with end-of-string char
               // printGPS(printLine);
                break;
            }
            a++;
        }
        printLine++;
        //t.stop();
        // printf("TIME: %d\n\r", t.read_us());
        //  t.reset();
        if (printLine == 10) {
            printLine = 0;
        }
    }
}

void closeCanFiles()
{

    pc.printf("\n\n\rPRESS 'q' to stop recording\n");

    while (1) {
        if (pc.readable()) {
            if (pc.getc() == 'q') {
                fclose(can);
                //fclose(gps);

                pc.printf("ALL FILES CLOSED");
            }
        }
    }
}

void printTEST()
{
    while(1) {

        t.start();
        fprintf(can,"255,255,255,255,255,255,255,255\n");
        t.stop();
        if(t.read_us() < 3) {
            pc.printf("w");
        } else {
            pc.printf("TIME T0: %d\n\r", t.read_us());
        }
        t.reset();
        wait_ms(50);
    }
}

int main()
{

    pc.baud(115200);
    serialGPS.baud(115200);
    pc.attach(&closeCanFiles);

    can = fopen("/sd/my18.txt", "w");
    setvbuf ( can , NULL , _IOLBF , 1024);
    if (can == NULL) {
        pc.printf("\n\rERROR\n\r");
        while(1);
    }
    
    // printTEST();

    serialGPS.attach(&gpsREADchar);

    while(1) {
        if(printLine - readLine > 3 || readLine - printLine < 6) {
            //pc.printf("\n\r");
            //pc.printf(gpsTEMP[readLine]);
            printGPS(readLine);
            readLine++;
        }
        
        if(readLine == 10)
        {
        readLine = 0;
        }

    }
}

Sample output

Init: SDCARD_V2
init card = 2

CSD_STRUCT = 0

SDCard
c_size: 0EE5
capacity: 999817216
sectors: 1952768
wwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 13016
wwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 13127
wwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 13219
wwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 12649
wwwwwwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 12438
wwwwwwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 12583
wwwwwwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 12565
wwwwwwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 12620
wwwwwwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 45678
wwwwwwwwwwwwwwwwwww
TIME T0: 30371
wwwwwwwwwwwwwwwwwww
TIME T0: 13155
wwwwwwwwwwwwwwwwww
TIME T0: 37606
wwwwwwwwwwwwwwwwwwwwwwwww
TIME T0: 12884
wwwwwwwwwwwwwwwww
TIME T0: 227353
wwwwwwwwwwwwwwww
TIME T0: 28424
wwwwwwwwwwwwwww
TIME T0: 36319
wwwwwwwwwwwwwwww
TIME T0: 17836
wwwwwwwwwwwwwww
TIME T0: 12678
wwwwwwwwwwwwww
TIME T0: 12475
wwwwwwwwwwwwwww
TIME T0: 13259
wwwwwwwwwwwwwww
TIME T0: 36894
wwwwwwwwwwwwww
TIME T0: 29402
wwwwwwwwwwwwwww
TIME T0: 13290
wwwwwwwwwwwwwww
TIME T0: 13019
wwwwwwwwwwwwwwwwww
TIME T0: 12614
wwwwwwwwwwwwww
TIME T0: 12677
wwwwwwwwwwwwww
TIME T0: 12750
wwwwwwwwwwwwww
TIME T0: 12305
wwwwwwwwwwwwww
TIME T0: 36853
wwwwwwwwwwwwwww
TIME T0: 30537
wwwwwwwwwwwww
TIME T0: 13212
wwwwwwwwwwwwwww
TIME T0: 13275
wwwwwwwwwwwwww
TIME T0: 36514
wwwwwwwwwwwwww
TIME T0: 28852
wwwwwwwwwwwwww
TIME T0: 12541
wwwwwwwwwwwwww
TIME T0: 12614
wwwwwww
TIME T0: 11708
wwwwwwwwwwwwwww
TIME T0: 12377
wwwwwwwwwwwwww
TIME T0: 13188
wwwwwwwwwwwwwww
TIME T0: 13192
wwwwwwwwwwwwwww
TIME T0: 13183
wwwwwwwwwwwwww
TIME T0: 36277
wwwwwwwwwwwwww
TIME T0: 29965
wwwwwwwwwwwwwww
TIME T0: 12549
wwwwwwwwwwwwww
TIME T0: 12549
wwwwwwwwwwwwwww
TIME T0: 36264
wwwwwwwwwwwwww
TIME T0: 28511
wwwwwwwwwwwwwww
TIME T0: 12377
wwwwwwwwwwwwww
TIME T0: 25213
w
TIME T0: 11875
w
TIME T0: 11866
wwwwwwwwwwwwww
TIME T0: 18299
wwwwwwwwwwwwww
TIME T0: 13120
wwwwwwwwwwwwww
TIME T0: 13184
wwwwwwwwwwwwww
TIME T0: 13020
wwwwwwwwwwwwww
TIME T0: 36572
wwwwwwwwwwwww
TIME T0: 28361
wwwwwwwwwwwwww
TIME T0: 12621
wwwwwwwwwwwwww
TIME T0: 12675
wwwwwwwwwwwwww
TIME T0: 12403
wwwwwwwwwwwwww
TIME T0: 13225
wwwwwwwwwwwwww
TIME T0: 13183
wwwwwwwwwwwwww
TIME T0: 13183
wwwwwwwwwwwwww
TIME T0: 36911
wwwwwwww
TIME T0: 11523
wwwwwwwwwwwwww
TIME T0: 12638
wwwwwwwwwwwwwww
TIME T0: 12511
wwwwwwwwwwwwww
TIME T0: 12611
wwwwwwwwwwwwwww
TIME T0: 12638
wwwwwwwwwwwwww

So the "w" are the write that take less than 200us and the ones with the printed time are those long ones that I'm trying to get rid of. Does anyone have any ideas or did I make an implementation mistake?

Cheers

19 Nov 2012

Hi,

I too am working on a data logger, if you are using the same libraries as me then this may work:

In the "SDHCFileSystem.cpp" there is a line that reads:

_spi.frequency(1000000); // Set to 1MHz for data transfer

I have set this to "_spi.frequency(5000000);", this seems fine with my card. I think it depends on the quality of the card you are using.

It's simple enough to try and may solve your problem.

N.B. do not confuse this line with the first one that reads

// Set to 100kHz for initialisation, and clock card with cs = 1
_spi.frequency(100000);

Regards,

Phil

19 Nov 2012

Hi Phil,

Yes I already changed the SPI speed, but it made no difference if it was 1, 5, 10, 20 MHz. Have you actually timed your writes like I did above to see if they are all ballpark the same time?

Cheers

19 Nov 2012

Hi Sebastian,

No I haven't timed my writes. I was recording CANBUS messages and needed to ensure that I did not miss any. My problem was the delay in opening a file to write to (which was only done on receipt of the first CAN message), so I employed a ring buffer of size 256 which is filled by a CANBUS interrupt and emptied (written to SD card) in a while loop that constantly monitors to see if the buffer write position has moved away from the buffer read position.

I found that the difference in the read and write positions of the buffer could get as large as 150, and assume that there is some variation in write speeds, but not enough to cause a buffer overrun in my case.

I can not follow my own code very well ;-), so I have not really studied yours, but am I right in thinking that you employ a buffer but only of size 10?

Regards,

Phil

26 Sep 2013

Hi Sebastian,

I am Jose Escalona, from Spain. I'm having exactly the same problem as you showed in the first message (18 Nov 2012) but I'm trying to write accelarometer's data in a USB stick. I get a data acquisition velocity of 300 Hz but I need 1000 Hz.

Did you already solve the problem? Thanks

Jose