Freesteel Blog » SD card logging issues

SD card logging issues

Thursday, May 5th, 2016 at 4:29 pm Written by:

I must have changed cards for one in an old camera or something, because the data files went bad on the hang glider logger.

What started out as an effort to plot a timeline of the holes in my data has turned into a simple SD card write benchmarking experiment which allows me to see the slippage.

The code sort of goes like this:

int multiple = 200; 
long biggaptime = multiple*2; 
long sumnormaltimes = 0; 
long nnormaltimes = 0; 
long flushmultiple = 1000; 
void loop()
{
    // wait for the next 200microsecond moment
    long mstamp; 
    long mstampnext = ((int)(mstampprev/multiple + 1))*multiple; 
    do {
        mstamp = micros(); 
    } while (mstamp <= mstampnext); 
    
    // output the microsecond value in 8 hex characters
    for (int i = 32-4; i >= 0; i -= 4)
        sdfile.write(hexchar((mstamp>>i)&0x0f)); 

    // if that write took longer than expected, record how long
    long mwritetime = micros() - mstamp; 
    if (mwritetime > biggaptime) {
        if (ngapsline < ngapslineP) {
            PRINT(" ", mwritetime, ".", nbytessincegap); 
        }
        nbytessincegap = 0; 
        ngapsline++; 

    // otherwise keep track of the average time
    } else {
        sumnormaltimes += mwritetime; 
        nnormaltimes++; 
    }
    nbytessincegap += 8; 
    
    // flush at a defined multiple of looks
    n++; 
    if ((n % flushmultiple) == 0) {
        sumnormaltimes = 0; 
        nnormaltimes = 0; 
        long mstamppreflush = micros(); 
        sdfile.flush(); 
        long mstampflushtime = micros() - mstamppreflush; 
        P(" F", mstampflushtime); 
    }
    mstampprev = mstamp; 
}

This produces output like this:

1085.0 17500.320 2926.512 2906.512 2912.512 3574.512 2925.512 2914.512 2912.512… (33.89)
10000 215737 F7575 994.320 407194.192 4632.512 2915.512 2943.512 2920.512… (33.89)
15000 407211 F7601 1104.384 3279.128 4400.512 205153.512 2916.512 2920.512… (33.82)
20000 207194 F7576 1018.448 3255.64 4535.512 2915.512 2916.512 204380.512… (33.80)

One can interpret it as taking on average 34microseconds per 8 byte write block, with a pause of 3milliseconds after every 512 bytes, and then an enormous 205millisecond pause after every 8*512=4096 bytes. The call to flush() takes 7.6milliseconds.

We can plot the timeline of writes with this function:

ftext = open(“SPEED.TXT”).read()
ts = [ int(ftext[i:i+8], 16) for i in range(0, len(ftext), 8) ]
t0 = ts[-20000]
sendactivity(points=[((t-t0)*1e-6, y) for t in ts[-20000:]])

to get the green series of points labelled 1 in the diagram below (where the yellow vertical lines represent one second increments):
badsdcards

Here it is again, zoomed in (with 0.1second increments in the green vertical lines) to show the gaps between the 512 blocks, showing that it is two tenths of a second:
badsdcardsz1

An even deeper zoom resolves the individual points in the sequence which should have 512/8=64 points each:
badsdcardsz2

This card was unacceptable, with its 1/5 of a second stall after every 4kB of data. This is likely to throw off all the different streaming sets of sensor values by some margin.

Luckily I worked out the problem in time to salvage some data from my second flight by using the SD card from my phone, which is the 16GB class(4) one labeled #4:
cards8

You can see in the drawing above that the data logging into it was pretty smooth in comparison. In all ways this was the most superior, with the following output:

450352.0 6763.512 4847.512 1440.512 1438.512 1433.512 1434.512 (33.78)
5000 2069946 F3547 608.64 1431.448 4424.512 1438.512 1437.512 1438.512 (33.77)
10000 8823 F3543 605.128 1431.384 1436.512 1436.512 4436.512 1438.512 (33.76)
15000 14536 F3575 608.192 1431.320 1460.512 1461.512 1460.512 1462.512 (33.80)
20000 8934 F3567 605.256 1429.256 1459.512 1461.512 1459.512 1461.512 (33.75)

Once it settles down, the average 8byte write is 34microseconds, the 512block takes 1.5milliseconds, and the flush takes 3.5milliseconds, which is almost adequate when I’ve got sensors coming in at the rate of every 10milliseconds.

Someone suggested I use the SdFat library rather than the default out-of-date Arduino SD library, and the results are plotted in red above the green for all the cards which worked.

Bad card 1 changed the most, with some intermittent 15millisecond delays, but a whopping 2 time 105millisecond delay every time flush() is called. I do not know what the correct rate is for calling the flush() function, but I do know that if you don’t call it at all you don’t get a file written. Maybe the blocks get marked as to delete.

Card 8 is a 4GB class(10) one I just bought thisafternoon, and it’s not a lot better.

If I stack its results vertically with every row being 20000*8=160000 bytes of streaming by plotting it with this code:

cC = 20000
for i in range(int(len(ts)/cC)):
    y = 0.1*i
    c0 = i*cC
    t0 = ts[c0]
    sendactivity(points=[((t-t0)*1e-6, y)  for t in ts[c0:c0+cC]])

I get this diagram:

badsdcardstack8
So it seems to take to rows to warm up to speed (this is reproducible), and then there’s this unexplained 6 sequence gap between the 512byte blocks about every 800kB or so. (The missing lines are timing errors in the micros() function, and the other gaps are probably the flush() every 15 or 80 512blocks.

Meanwhile, here’s the same stacked drawing from my 16GB class(4) phone SD card:

badsdcardstack4

That probably explains why it worked so well. Unfortunately it’s got a whole lot of stuff I want on it. Maybe I should fork out for yet another 16GB card, copy it over, and mark this one as to be used in future.

I never thought about looking at this unit before. I had thought it would have its own processors and buffers within it to handle this kind of nonsense. It’s not something that can be solved by inserting another microcontroller to relay the data through a serial port, because (a) even a 115200baud serial port is too slow, and (b) that second controller would itself get grabbed and stalled by this SD card system and therefore drop the incoming data without there being a humongous serial input buffer.

There has to be another solution where this doesn’t happen and the data can buffer up in RAM temporarily until the card sorts itself out.

This is getting too much like real engineering, where the strength of every single ball-bearing and hinge needs to be verified that it won’t crack under the defined load.

Leave a comment

XHTML: You can use these tags: <a href="" title=""> <abbr title=""> <acronym title=""> <blockquote cite=""> <code> <em> <strong>