Problem writing to SD card

I’m using SdCardLogHandlerRK (0.1.0) library along with the SdFat (1.0.16) library on our e-series hardware (2nd gen) and seeing a problem writing to an SD card connected via SPI.

When setting the .withSyncEveryEntry to true, everything works without problem. When setting it to false however, the SPI write’s appear to work, no errors are reported, but nothing is written out to the physical SDHC device (Kingston 16GB SDHC, FAT32 formatted), and any subsequent directory listings show that the file size is not changing.

The first entry in the terminal output shown below demonstrates the working state. See also the ‘SdSpiCardWithSyncEntryTrue MISO MOSO.jpeg’ file attached.

The remaining scope screenshots show the signals in the failure condition. From the terminal log, the SPI driver also appears to be performing correctly (no errors are reported, and a single writeBlock after >512 bytes are collected). As you can see from the directory listing however, the changes are not being committed to the SD. I’ve confirmed this by removing the SD card and taking a look at the files; nothing was in fact written. Any idea what the issue might be?

Cheers,

Paul

Terminal Log - withSyncEveryEntry( true )

SD /logs directory listing:
RB32768
RB32832
2022-01-11 19:05:18 95712 000001.txt

Reference:

  • SdFat/src/SdCard/SdSpiCard.cpp, SdSpiCard::writeBlock(), SdSpiCard::readBlock()
  • SdFat/src/FatLib/FatVolume.cpp, FatCache::sync();

0000325439 [app] TRACE: SENSORS READ STATE
RB32952
FatCache::sync() dirty
WB32952
RB32832
FatCache::sync() dirty
WB32832
0000326747 [app] TRACE: GPS READ STATE: last gps msg sent 0




Terminal Log - withSyncEveryEntry( false ):

0000727429 [app] TRACE: ALARM HANDLER STATE
FatCache::sync() dirty
WB33397
0000727432 [app] TRACE: SLEEP STATE
0000727934 [app] TRACE: ALARM HANDLER STATE
0000727935 [app] TRACE: SLEEP STATE
0000728439 [app] TRACE: ALARM HANDLER STATE
0000728440 [app] TRACE: SLEEP STATE
0000728942 [app] TRACE: ALARM HANDLER STATE
0000728943 [app] TRACE: SLEEP STATE
0000729447 [app] TRACE: ALARM HANDLER STATE
0000729448 [app] TRACE: SLEEP STATE
0000729950 [app] TRACE: ALARM HANDLER STATE
0000729951 [app] TRACE: SLEEP STATE
0000730455 [app] TRACE: update data
0000730455 [app] TRACE: MODBUS READ STATE
FatCache::sync() dirty
WB33398
0000730458 [app] TRACE: SENSORS READ STATE

SD /logs directory listing:
FatCache::sync() dirty
WB33552
RB32768
RB32832
FatCache::sync() dirty
WB3134
WB17951
2022-01-11 21:26:34 344300 000001.txt

SD /logs directory listing:
FatCache::sync() dirty
WB33548
RB32768
RB32832
2022-01-11 21:26:34 344300 000001.txt
0000082659 [app] TRACE: SEND CONFIG MSG STATE
RB33548

1 Like

Can you check whether an explicit writeBuf() does commit the data to SD?
Can you also provide a simple test program that exserts the issue?

The console logging messages beginning with WB and RB are from the SdFat SdSpiCard::writeBlock() and SdSpiCard::readBlock() routines respectively, and this works when the SdCardLogHandlerRK .withSyncEveryEntry value is true.

The problem is reproducible on our hardware with the following loop() code:

void loop() 
{
  static unsigned long count = 0;
  sdLogHandler->loop();

  Log.info("SdSpiCard Testing...\r\n");
  delay(1000);

  if ((count++ % 15) == 0) {
    Serial.printf("SD /logs directory listing\r\n");
    sd.ls("/logs", LS_R|LS_DATE|LS_SIZE);
  }
}

And here’s the console output:

FatCache::sync() dirty
WB33570
0000329860 [app] INFO: SdSpiCard Testing...
0000330860 [app] INFO: SdSpiCard Testing...
SD /logs directory listing
FatCache::sync() dirty
WB33571
RB32768
RB32832
2022-01-12 18:28:34     352326 000001.txt
0000331861 [app] INFO: SdSpiCard Testing...
RB33571
0000332865 [app] INFO: SdSpiCard Testing...
0000333865 [app] INFO: SdSpiCard Testing...
0000334866 [app] INFO: SdSpiCard Testing...
0000335866 [app] INFO: SdSpiCard Testing...
0000336866 [app] INFO: SdSpiCard Testing...
0000337867 [app] INFO: SdSpiCard Testing...
0000338867 [app] INFO: SdSpiCard Testing...
FatCache::sync() dirty
WB33571

0000339869 [app] INFO: SdSpiCard Testing...
0000340870 [app] INFO: SdSpiCard Testing...
0000341870 [app] INFO: SdSpiCard Testing...
0000342870 [app] INFO: SdSpiCard Testing...
0000343871 [app] INFO: SdSpiCard Testing...
0000344871 [app] INFO: SdSpiCard Testing...
0000345871 [app] INFO: SdSpiCard Testing...
SD /logs directory listing
FatCache::sync() dirty
WB33572
RB32768
RB32832
2022-01-12 18:28:34     352326 000001.txt

@rickkas7 - would you mind taking a look?

I’d suggest the next step would be to remove SdCardLogHandlerRK from the simple test cast. I don’t see how it could be the source of the problem, but a simpler example would be desirable if the bug is in SdFat, anyway, so it’s worth a try to see if it can be reproduced with just SdFat directly.

For sure, the problem appears to be with the SdFat library. The code below removes SdCardLogHandler, but is functionally identical to the previous and has the same behaviour.

void loop()
{
    static unsigned count = 0;
    const char *str = "0123456789012345678901234567890123456789";
    boolean syncEveryEntry = false;

    file.println(str);
    if (syncEveryEntry) {
      file.sync();
    }

    delay(500);

    if ((count++ % 15) == 0) {
      Serial.printf("\r\nSD directory listing\r\n");
      sd.ls("/", LS_R|LS_DATE|LS_SIZE);
   }
}

With syncEveryEntry set to true, the contents of SdSpiCardTest.txt are as expected. When set to false, the listing works, but not the writeBlock:


SD directory listing
FatCache::sync() dirty
WB16648
RB16384
2000-01-01 01:00:00       1154 test.txt
2021-12-14 16:44:02          0 logs/
RB16512
  2022-01-10 21:57:02       3404 000001.txt
RB16384
2000-01-01 01:00:00       4242 SdSpiCardTest.txt
RB16648
FatCache::sync() dirty
WB16648

SD directory listing
FatCache::sync() dirty
WB16649
RB16384
2000-01-01 01:00:00       1154 test.txt
2021-12-14 16:44:02          0 logs/
RB16512
  2022-01-10 21:57:02       3404 000001.txt
RB16384
2000-01-01 01:00:00       4242 SdSpiCardTest.txt
RB16649
FatCache::sync() dirty
WB16649
1 Like