Datalogging to an SD card (Teensy 3.6)

Zaite12 · Jun 12, 2017

Hi all,

I am working on a personal RC (remote control) project with Teensy 3.6, datalogging information to the builtin micro SD card. I have encountered a small problem I need to try and fine a way to solve. The datalogger is writing approximately 40 KB of data per second (so roughly 2.5 MB per minute) just to put into context how much data is being written - not a huge amount. It is working very well, however there is one small problem I have noticed, every 20 to 30 seconds there is a very momentary 'block' in execution which lasts roughly 300 to 500ms from what I can tell. I can only imagine there is some sort of flushing going on, or some other issue that is causing execution flow to momentarily pause. This 'blocking' doesn't happen if I disable the SD datalogger part of the update routine.

It is quite essential that execution flow is not blocked for the system to be responsive (as you can imagine for a remote control aircraft). I have included the relevant parts of the code below. Essentially the Initialise() function is called at the start and then 20 times per second the Output() function is called to write new data to the log file.

If anyone can provide some assistance, or advice how to improve the code that would be greatly appreciated. The Micro SD card is a Sandisk Ultra 16GB class 10 card.

Thank you very much in advance

Code:

#include <Arduino.h>
#include <SD.h>
#include <SPI.h>

//
// Initialise
//
void DataLogger::Initialise() {
  if (gc->DATALOG_ENABLED) {
    serialdebug->OutputEarlyMessage(String("SD Datalogger: initialising\n"));
  
    // Attempt to initialise the card (BUILTIN_SDCARD)
    if (!SD.begin(gc->DATALOG_SD_CHIP_SELECT)) {
      serialdebug->OutputEarlyMessage(String("SD Datalogger: card not present or unable to read.\n"));
      return;
    }
  
    serialdebug->OutputEarlyMessage(String("SD Datalogger: card initialised.\n"));
  
    // Find a free file
    datafile = "";
    uint8_t strLen = 0;
    
    for (uint32_t i = 0; i < gc->DATALOG_SD_MAX_LOGFILES; i++) {
      datafile = String(i + 1) + String(".txt");
      strLen = datafile.length() + 1;
      char charBuf[strLen];
      datafile.toCharArray(charBuf, strLen);
      if (!SD.exists(charBuf)) {
        serialdebug->OutputEarlyMessage(String("SD Datalogger: outputting log data to ") + String(datafile) + String("\n"));
        initialised = HIGH;
        break;
      }
    }
  
    if (!initialised) {
      serialdebug->OutputEarlyMessage(String("SD Datalogger: maximum number of log files reached or unable to read filesystem.\n"));
      return;
    }

    serialdebug->OutputEarlyMessage(String("SD Datalogger: initialisation successful\n"));

    // Mark
    mark_out = LOW;
    mark_count = 0;
    marker = 0;

    // Output header
    this->OutputHeader();
  }
}

//
// Outputs all logged data to the SD card
//
void DataLogger::Output(uint32_t cycle_time, uint32_t cpu_timer, uint32_t perf_cycles) {
  // Output latest datalog data to the SD card

  // Don't attempt to perform any operations unless the card is initialised and datalogging is enabled
  if (initialised && gc->DATALOG_ENABLED) {
    sd_file = this->OpenFile();

    if (!sd_file) {
      // Error while opening the datalog file
      this->DisableDatalogging();
      return;
    }

    // Log marking
    if (mark_out) {
      marker = 1;
      mark_count += 1;
      if (mark_count >= _DATALOG_MARK_COUNT) {
        // Disable mark, counter is reset on next event
        mark_out = LOW;
      }
    }
    else {
      marker = 0;
    }
    
    String t_str;   // Temporary working string
    
    // System
    t_str = String("SYS,") + String(cycle_time, DEC) + String(",") + String(cpu_timer, DEC) + String(",") + String(perf_cycles, DEC);
    t_str = t_str + String("\r\n");

    // Input PWMs
    t_str = t_str + String("RX_PWM,");
    t_str = t_str + String(marker, DEC);
    for (uint8_t i = 0; i < _RX_NUM_CHANNELS; i++) {
      t_str = t_str + String(",") + String(rx->GetPWM(i), DEC);
    }
    t_str = t_str + String("\r\n");

    // Input PWM PCT
    t_str = t_str + String("RX_PCT,");
    t_str = t_str + String(marker, DEC);
    for (uint8_t i = 0; i < _RX_NUM_CHANNELS; i++) {
      t_str = t_str + String(",") + String(rx->GetPWM_PCT(i), 4);
    }
    t_str = t_str + String("\r\n");

    // SBUS raw
    #ifdef _RX_USE_SBUS
      float *chdata = rx->GetSBUSChRaw();

      t_str = t_str + String("SBUS,");
      t_str = t_str + String(marker, DEC);
      for (uint8_t i = 0; i < _RX_NUM_CHANNELS; i++) {
        t_str = t_str + String(",") + String(chdata[i], 4);
      }
      t_str = t_str + String("\r\n");
    #endif // _RX_USE_SBUS
  
    // Engine data
    t_str = t_str + String("ENG,");
    t_str = t_str + String(marker, DEC) + String(",");
    t_str = t_str + String(LEngine->GetRPM(), DEC) + String(",") + String(REngine->GetRPM(), DEC) + String(",");
    t_str = t_str + String(LEngine->GetRPMAcqErrorFlag(), DEC) + String(",") + String(REngine->GetRPMAcqErrorFlag(), DEC) + String(",");
    t_str = t_str + String(LEngine->GetCMD_PWMPct(), 3) + String(",") + String(REngine->GetCMD_PWMPct(), 4) + String(",");
    t_str = t_str + String(LEngine->GetSyncTrim(), DEC) + String(",") + String(REngine->GetSyncTrim(), DEC) + String(",");
    t_str = t_str + String(LEngine->GetOutPWM(), DEC) + String(",") + String(REngine->GetOutPWM(), DEC);
    t_str = t_str + String("\r\n");

    // Flight Management
    t_str = t_str + String("FM,");
    t_str = t_str + String(marker, DEC) + String(",");
    t_str = t_str + String(fm->GetFlightMode(), DEC) + String(",");
    t_str = t_str + String(fm->GetSystemStatus(), DEC) + String(",");
    t_str = t_str + String(fm->GetATHRStatus(), DEC) + String(",");
    t_str = t_str + String(fm->GetSYNCStatus(), DEC) + String(",");
    t_str = t_str + String(fm->GetGearDown(), DEC) + String(",");
    t_str = t_str + String(fm->GetFailsafe(), DEC) + String(",");
    t_str = t_str + String(fm->GetFlightPhase(), DEC) + String(",");
    t_str = t_str + String(fm->GetDataSourceState(_FM_DATA_I2C_PROX), DEC) + String(",");
    t_str = t_str + String(fm->GetDataSourceState(_FM_DATA_I2C_RPM_L), DEC) + String(",");
    t_str = t_str + String(fm->GetDataSourceState(_FM_DATA_I2C_RPM_R), DEC) + String(",");
    t_str = t_str + String(datalink->GetLimCount(_FM_DATA_I2C_PROX), DEC) + String(",");
    t_str = t_str + String(datalink->GetLimCount(_FM_DATA_I2C_RPM_L), DEC) + String(",");
    t_str = t_str + String(datalink->GetLimCount(_FM_DATA_I2C_RPM_R), DEC);
    t_str = t_str + String("\r\n");

    // Prop Syncho
    t_str = t_str + String("SYNC,");
    t_str = t_str + String(marker, DEC) + String(",");
    t_str = t_str + String(fm->GetSYNCStatus(), DEC) + String(",");
    t_str = t_str + String(fm->GetPropSyncPIDDuty(), DEC) + String(",");
    t_str = t_str + String(LEngine->GetSyncTrim(), DEC) + String(",");
    t_str = t_str + String(REngine->GetSyncTrim(), DEC) + String(",");
    t_str = t_str + String(LEngine->GetSyncTrimOvershoot(), DEC) + String(",");
    t_str = t_str + String(REngine->GetSyncTrimOvershoot(), DEC);
    t_str = t_str + String("\r\n");

    // ASI
    t_str = t_str + String("ASI,");
    t_str = t_str + String(marker, DEC) + String(",");
    t_str = t_str + String(asi->GetSpeedKt(), 3) + String(",");
    t_str = t_str + String(asi->GetSpeedMs(), 3) + String(",");
    t_str = t_str + String(asi->GetADCRaw(), DEC) + String(",");
    t_str = t_str + String(asi->GetVRaw(), 4) + String(",");
    t_str = t_str + String(asi->GetPRaw(), DEC);
    t_str = t_str + String("\r\n");

    // Fuel
    t_str = t_str + String("FUEL,");
    t_str = t_str + String(marker, DEC) + String(",");
    t_str = t_str + String(fuelm->GetTankState(), DEC) + String(",");
    t_str = t_str + String(fuelm->GetLowSensor(), DEC) + String(",");
    t_str = t_str + String(fuelm->GetHighSensor(), DEC);
    t_str = t_str + String("\r\n");
    
    // Proximity
    t_str = t_str + String("PROX,");
    t_str = t_str + String(marker, DEC) + String(",");
    t_str = t_str + String(datalink->GetProximity(), DEC) + String(",");
    t_str = t_str + String(fm->GetProxOnGround(), DEC);
    t_str = t_str + String("\r\n");
    
    // Write line to file
    this->WriteLine(t_str);

    // Close the file
    sd_file.close();
  }
}

manitou · Jun 13, 2017

there have been several threads on low latency data logging to SD, searching the forum revealed:
https://forum.pjrc.com/threads/43834-Real-low-latency-logging-for-Teensy-3-5-3-6-SDIO-SD
https://forum.pjrc.com/threads/43621-Low-latency-data-logger

see low latency examples in https://github.com/greiman/SdFat/tree/master/examples

Zaite12 · Jun 14, 2017

Thanks, I have implemented it with SdFatSdioEX (have also tried SdFatSdio) which are working well. I have noticed that if the SD card is removed while the Teensy is running, it freezes up for long periods of time. It's quite essential there are no significant blocks to execution in the event this could happen. I've searched the documentation but can't seem to find reference to timeouts. Any assistance in that regard would be also appreciated.

Thanks again

UhClem · Jun 14, 2017

It appears that this could be the result of the file system software and cluster allocation. Default cluster size for FAT32 on that size drive is 8KB and with 128 clusters/block that is about 1MB. So the timing of your stalls is consistent with that.

When the free clusters in one block are exhausted the software has to read in a new block. But that shouldn't take that much time so perhaps it is postponing some other activity. If it is postponing writes when a cluster is allocated then it could be doing a lot: write dirty buffer with FAT entry, twice. read new FAT block, and perhaps even update the directory entry. That should be fast but it is disconcerting that the SD card standard only limits the maximum time for this to 750ms.

You could avoid that by using the createContiguous() call to preallocate the entire file.

thanos · Sep 2, 2017

Hello, i've make a quadcopter with teensy 3.6 and i would like now with the sd card to have a data log.
I used the example "data logger" from the library sd and i noticed that to write one value it wanted 12.000 us.
Τhis is prohibitive because i run the main loop in 400Hz(2.5us),what can i do so as to reduce the time?There is some solution?

WMXZ · Sep 2, 2017

thanos said:
Hello, i've make a quadcopter with teensy 3.6 and i would like now with the sd card to have a data log.
I used the example "data logger" from the library sd and i noticed that to write one value it wanted 12.000 us.
Τhis is prohibitive because i run the main loop in 400Hz(2.5us),what can i do so as to reduce the time?There is some solution?

I suspect you have your numbers wrong : 400 Hz equiv to 2.5 ms.
If you wanted to write single values to SD card, you should use Bill's newest SdFs. It will cache the values and write efficiently.

Now, if your 12000 us or 12 ms is correct measurement, please keep in mind a single access to SD card is in that order, more or less independent of data quantity.
In fact, efficient usages of SD cards writes data in chunks of (say 16, or 32) kB, and ALWAYS multiples of 512 bytes.

thanos · Sep 2, 2017

WMXZ said:
I suspect you have your numbers wrong : 400 Hz equiv to 2.5 ms.

Correctly.

What choices i have so as to record the values in the sd card in until the ~100us??
With the library that you proposed me i can do it?

Datalogging to an SD card (Teensy 3.6)

Zaite12

Member

manitou

Senior Member+

Zaite12

Member

UhClem

Well-known member

thanos

Well-known member

WMXZ

Well-known member

thanos

Well-known member