Skip to content

SD vs ExFat - Raw Logging Tests #1

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
adamgarbo opened this issue Jan 12, 2021 · 10 comments
Closed

SD vs ExFat - Raw Logging Tests #1

adamgarbo opened this issue Jan 12, 2021 · 10 comments

Comments

@adamgarbo
Copy link
Contributor

Hi @PaulZC,

I thought I'd create an issue where I can share some of the results of my ongoing tests of the new u-blox library.

My first goal was to determine what kind of performance gains can be achieved using the ExFat classes of v2.0 of the SdFat library. Having read that 7 Hz appeared to be the upper limit for the SD library, I thought I'd start at 10 Hz. While the results below were only for a short period of time, they were quite telling!

Test Configuration:

  • All I2C pull-ups were disabled (ZED-F9P, MMDLCB, Artemis)
  • u-blox library example: DataLoggingExample5_Fast_RXM was used for both tests, with only the library, object instantiation and write command code being modified.
  • A micros() timer was added to the SD write commands to measure latency.

Components

  • Sparkfun Artemis Processor Board
  • SparkFun MicroMod Data Logging Carrier Board (MMDLCB)
  • SparkFun GPS-RTK2 ZED-F9P SMA
  • u-blox ANN-MB antenna

ZED-F9P Configuration:

  • Navigation rate: 10 Hz
  • Constellation: GPS only
  • Messages logged: RAWX/SFRBX

SD Test Configuration:

  • Arduino SD library
  • microSD card: SanDisk Industrial XI 32 GB
    • Formatted using FAT32

ExFat Test Configuration:

  • SdFat library (SdExFat/ExFile classes)
  • microSD card: SanDisk Extreme 64 GB
    • Formatted using ExFat

Results:

  • Figure 1 illustrates just how quickly the file buffer fills up at 10 Hz when using the SD library. It's clear that the 12 ms SD write latency is creating a bottleneck that causes the buffer to overflow.
  • The second SD test filled the buffer quicker likely because the receiver had a better fix at this time.
  • After maxing out the file buffer, eventually the entire system became non-responsible and could not be halted via serial input.
  • By comparison, the ExFat write latency of ~400 μs appears to be sufficient to allow the data to be written to the card and prevent the overflow issue.
  • I also left the ExFat tests run for longer periods of time and never saw the buffer exceed 5000 bytes.

max_buffer
Figure 1. Max buffer size over time

latency
Figure 2. SD write latencies

Conclusion & Next Steps:

  • The performance gains offered by the new SdFat library are significant!
  • The next step will be to see just how far I can push the library when using an ExFat formatted card.
  • I'll also start looking at data integrity after longer duration logging and see if I run into any of the same gremlins you and @nseidle had run into previously.

Cheers,
Adam
@PaulZC
Copy link
Collaborator

PaulZC commented Jan 12, 2021

Excellent work @adamgarbo - sincere thanks,
I think it's clear I need to add an SdFat example to the library!
It will be good to see if the periodic write error has gone away too. Please do let us know how the longer duration tests go.
Thanks again!

@adamgarbo
Copy link
Contributor Author

Hi @PaulZC,

Can you remind me how the periodic write error manifested itself (i.e. how did you reliably identify it?).

Cheers,
Adam

@PaulZC
Copy link
Collaborator

PaulZC commented Jan 13, 2021

@nseidle found that when logging data on the OLA using SdFat BETA, it would rarely and randomly throw an error and the SD writing would stall. IIRC, it was rare and very difficult to capture, but bad enough to make him switch back to 'standard' SdFat.
24 hours of logging should be long enough to see if it is still there...

@PaulZC PaulZC mentioned this issue Jan 14, 2021
Closed
@adamgarbo
Copy link
Contributor Author

adamgarbo commented Jan 14, 2021 •
edited
Loading

Hi @PaulZC,

See below for results of a 24-hour test using v2.0.4 of SdFat, the SdFs and FsFile classes, and a SanDisk 64 GB Extreme microSD card formatted as ExFat. GPS and GLONASS constellations were enabled and logged at a rate of 1 Hz.

max_buffer2

Do you have any requests for specific receiver/logging configurations that I can test?

Cheers,
Adam

@PaulZC
Copy link
Collaborator

PaulZC commented Jan 15, 2021

Nice one @adamgarbo - thank you!
If you have time, a 20Hz GPS-only L1+L2 SFRBX+RAWX test on the ZED-F9P would be a useful benchmark. But only if you can spare the time.
All the best,
Paul

@adamgarbo
Copy link
Contributor Author

Hi @PaulZC,

No dice on the 20 Hz GPS test, I'm afraid!

From a cold start, it took about 30 seconds before there was a buffer overflow. The three numbers you see below are: microSD write time (μs), bytes written and max buffer size. I haven't delved into the library yet, but do you reckon this caused by simply too much I2C traffic?

Cheers,
Adam

20:03:48.149 -> SparkFun u-blox Example
20:03:48.149 -> Initializing SD card...
20:03:48.323 -> SD card initialized.
20:03:50.710 -> Press any key to stop logging.
20:03:51.780 -> 671,512,528
20:03:52.875 -> 315,1024,528
20:03:53.901 -> 316,1536,528
20:03:55.008 -> 316,2048,528
20:03:55.109 -> 316,2560,528
20:03:56.214 -> 316,3072,528
20:03:57.244 -> 316,3584,528
20:03:58.315 -> 315,4096,528
20:03:59.421 -> 316,4608,528
20:04:00.111 -> 316,5120,528
20:04:01.079 -> 316,5632,720
20:04:01.428 -> 316,6144,720
20:04:02.517 -> 316,6656,720
20:04:03.553 -> 316,7168,720
20:04:04.612 -> 316,7680,720
20:04:05.716 -> 316,8192,720
20:04:05.918 -> 316,8704,720
20:04:06.924 -> 315,9216,720
20:04:07.850 -> 316,9728,720
20:04:08.922 -> 316,10240,720
20:04:09.963 -> 316,10752,720
20:04:11.070 -> 316,11264,720
20:04:11.887 -> 316,11776,880
20:04:12.130 -> 316,12288,880
20:04:13.058 -> 316,12800,880
20:04:13.717 -> 315,13312,880
20:04:13.853 -> 316,13824,1120
20:04:13.988 -> 353,14336,1360
20:04:14.132 -> 353,14848,1976
20:04:14.308 -> 353,15360,2968
20:04:14.589 -> 353,15872,4336
20:04:14.901 -> 353,16384,6456
20:04:15.383 -> 353,16896,9328
20:04:15.969 -> 352,17408,13328
20:04:16.764 -> 352,17920,18832
20:04:17.798 -> 352,18432,25840
20:04:19.115 -> 352,storePacket: insufficient space available! Data will be lost!
20:04:20.523 -> storePacket: insufficient space available! Data will be lost!
20:04:20.627 -> storePacket: insufficient space available! Data will be lost!
20:04:20.702 -> storePacket: insufficient space available! Data will be lost!
20:04:20.803 -> storePacket: insufficient space available! Data will be lost!
20:04:20.905 -> storePacket: insufficient space available! Data will be lost!
20:04:21.006 -> storePacket: insufficient space available! Data will be lost!
20:04:21.077 -> storePacket: insufficient space available! Data will be lost!
20:04:21.182 -> storePacket: insufficient space available! Data will be lost!
20:04:21.248 -> storePacket: insufficient space available! Data will be lost!
20:04:21.349 -> storePacket: insufficient space available! Data will be lost!
20:04:21.452 -> storePacket: insufficient space available! Data will be lost!
20:04:21.452 -> 18944,32544
20:04:21.452 -> 353,storePacket: insufficient space available! Data will be lost!
20:04:21.727 -> storePacket: insufficient space available! Data will be lost!
20:04:21.798 -> storePacket: insufficient space available! Data will be lost!
20:04:21.903 -> storePacket: insufficient space available! Data will be lost!
20:04:22.005 -> storePacket: insufficient space available! Data will be lost!
20:04:22.073 -> storePacket: insufficient space available! Data will be lost!
20:04:22.182 -> storePacket: insufficient space available! Data will be lost!
20:04:22.252 -> storePacket: insufficient space available! Data will be lost!
20:04:22.354 -> storePacket: insufficient space available! Data will be lost!
20:04:22.458 -> storePacket: insufficient space available! Data will be lost!
20:04:22.560 -> storePacket: insufficient space available! Data will be lost!
20:04:22.632 -> storePacket: insufficient space available! Data will be lost!
20:04:22.732 -> storePacket: insufficient space available! Data will be lost!
20:04:22.834 -> storePacket: insufficient space available! Data will be lost!
20:04:22.903 -> storePacket: insufficient space available! Data will be lost!
20:04:23.007 -> storePacket: insufficient space available! Data will be lost!
20:04:23.081 -> storePacket: insufficient space available! Data will be lost!
20:04:23.186 -> storePacket: insufficient space available! Data will be lost!
20:04:23.286 -> storePacket: insufficient space available! Data will be lost!
20:04:23.355 -> storePacket: insufficient space available! Data will be lost!
20:04:23.457 -> storePacket: insufficient space available! Data will be lost!
20:04:23.561 -> storePacket: insufficient space available! Data will be lost!
20:04:23.632 -> storePacket: insufficient space available! Data will be lost!
20:04:23.735 -> storePacket: insufficient space available! Data will be lost!
20:04:23.836 -> storePacket: insufficient space available! Data will be lost!
20:04:23.904 -> storePacket: insufficient space available! Data will be lost!
20:04:24.006 -> storePacket: insufficient space available! Data will be lost!
20:04:24.106 -> storePacket: insufficient space available! Data will be lost!
20:04:24.179 -> storePacket: insufficient space available! Data will be lost!
20:04:24.286 -> storePacket: insufficient space available! Data will be lost!
20:04:24.353 -> storePacket: insufficient space available! Data will be lost!
20:04:24.455 -> storePacket: insufficient space available! Data will be lost!
20:04:24.556 -> storePacket: insufficient space available! Data will be lost!
20:04:24.661 -> storePacket: insufficient space available! Data will be lost!
20:04:24.733 -> storePacket: insufficient space available! Data will be lost!
20:04:24.833 -> storePacket: insufficient space available! Data will be lost!
20:04:24.933 -> storePacket: insufficient space available! Data will be lost!
20:04:25.037 -> storePacket: insufficient space available! Data will be lost!
20:04:25.138 -> storePacket: insufficient space available! Data will be lost!
20:04:25.240 -> storePacket: insufficient space available! Data will be lost!
20:04:25.316 -> storePacket: insufficient space available! Data will be lost!
20:04:25.420 -> storePacket: insufficient space available! Data will be lost!
20:04:25.521 -> storePacket: insufficient space available! Data will be lost!
20:04:25.621 -> storePacket: insufficient space available! Data will be lost!
20:04:25.692 -> storePacket: insufficient space available! Data will be lost!
20:04:25.728 -> 19456,32568
20:04:25.728 -> 353,storePacket: insufficient space available! Data will be lost!
20:04:26.007 -> storePacket: insufficient space available! Data will be lost!
20:04:26.116 -> storePacket: insufficient space available! Data will be lost!
20:04:26.218 -> storePacket: insufficient space available! Data will be lost!
20:04:26.286 -> storePacket: insufficient space available! Data will be lost!
20:04:26.386 -> storePacket: insufficient space available! Data will be lost!
20:04:26.487 -> storePacket: insufficient space available! Data will be lost!
20:04:26.591 -> storePacket: insufficient space available! Data will be lost!
20:04:26.694 -> storePacket: insufficient space available! Data will be lost!
20:04:26.800 -> storePacket: insufficient space available! Data will be lost!
20:04:26.868 -> storePacket: insufficient space available! Data will be lost!
20:04:26.974 -> storePacket: insufficient space available! Data will be lost!
20:04:27.083 -> storePacket: insufficient space available! Data will be lost!
20:04:27.184 -> storePacket: insufficient space available! Data will be lost!
20:04:27.287 -> storePacket: insufficient space available! Data will be lost!
20:04:27.357 -> storePacket: insufficient space available! Data will be lost!
20:04:27.461 -> storePacket: insufficient space available! Data will be lost!
20:04:27.568 -> storePacket: insufficient space available! Data will be lost!
20:04:27.669 -> storePacket: insufficient space available! Data will be lost!
20:04:27.738 -> storePacket: insufficient space available! Data will be lost!
20:04:27.840 -> storePacket: insufficient space available! Data will be lost!
20:04:27.945 -> storePacket: insufficient space available! Data will be lost!
20:04:28.049 -> storePacket: insufficient space available! Data will be lost!
20:04:28.149 -> storePacket: insufficient space available! Data will be lost!
20:04:28.216 -> storePacket: insufficient space available! Data will be lost!
20:04:28.253 -> storePacket: insufficient space available! Data will be lost!
20:04:28.253 -> storePacket: insufficient space available! Data will be lost!
20:04:28.289 -> storePacket: insufficient space available! Data will be lost!
20:04:28.289 -> storePacket: insufficient space available! Data will be lost!
20:04:28.289 -> storePacket: insufficient space available! Data will be lost!
20:04:28.289 -> storePacket: insufficient space available! Data will be lost!
20:04:28.327 -> storePacket: insufficient space available! Data will be lost!
20:04:28.433 -> storePacket: insufficient space available! Data will be lost!
20:04:28.503 -> storePacket: insufficient space available! Data will be lost!
20:04:28.605 -> storePacket: insufficient space available! Data will be lost!
20:04:28.706 -> storePacket: insufficient space available! Data will be lost!
20:04:28.808 -> storePacket: insufficient space available! Data will be lost!
20:04:28.916 -> storePacket: insufficient space available! Data will be lost!
20:04:28.984 -> storePacket: insufficient space available! Data will be lost!
20:04:29.086 -> storePacket: insufficient space available! Data will be lost!
20:04:29.187 -> storePacket: insufficient space available! Data will be lost!
20:04:29.292 -> storePacket: insufficient space available! Data will be lost!
20:04:29.362 -> storePacket: insufficient space available! Data will be lost!
20:04:29.469 -> storePacket: insufficient space available! Data will be lost!
20:04:29.571 -> storePacket: insufficient space available! Data will be lost!
20:04:29.673 -> storePacket: insufficient space available! Data will be lost!
20:04:29.779 -> storePacket: insufficient space available! Data will be lost!
20:04:29.851 -> storePacket: insufficient space available! Data will be lost!
20:04:29.988 -> storePacket: insufficient space available! Data will be lost!
20:04:30.091 -> storePacket: insufficient space available! Data will be lost!
20:04:30.192 -> storePacket: insufficient space available! Data will be lost!
20:04:30.266 -> storePacket: insufficient space available! Data will be lost!
20:04:30.266 -> 19968,32736

@PaulZC
Copy link
Collaborator

PaulZC commented Jan 18, 2021

Humm. That is 'unfortunate'... I was expecting SdFat to be able to cope - given the success we've had with the OLA GNSS Logger.
I wonder if the exFAT implementation is slower than 'standard' SdFat (using FAT32). It would be really useful to have a side-by-side comparison of the write latency using SdFat exFAT and SdFat FAT32.
Thanks again for all the hard work here,
Paul

PaulZC pushed a commit that referenced this issue Mar 31, 2021
@UT2UH
Merge pull request #1 from sparkfun/release_candidate
beb707a 
Release candidate update
@adam515 adam515 mentioned this issue Oct 13, 2021
Closed
@adamgarbo
Copy link
Contributor Author

Hi @PaulZC,

Is there still interest in benchmarking the write latencies of SdFat exFAT vs FAT32? There's been a few updates of SdFat since this issue was opened. I'd be curious to see if there have been any performance improvements.

Cheers,
Adam

@PaulZC
Copy link
Collaborator

PaulZC commented Feb 2, 2022

Hi Adam (@adamgarbo ),

This issue is pretty old - and possibly stale - but I'm happy to leave it open. This is still something I'd like to "get around to" - but I have a ton of other stuff to do first...

I do have secret plans to try and write a dual-SPI-bus example: streaming data from a ZED-F9n to microSD using two separate SPI busses for maximum throughput. I think ESP32 (SparkFun Thing Plus C) could do it, and it should provide a very significant increase in throughput, but I don't have time to do it right now... Humm. I think I'll open a "help wanted" issue and see if anyone fancies having a go.

All the best,
Paul

PaulZC pushed a commit that referenced this issue Feb 28, 2022
@nabelekt
Merge pull request #1 from sparkfun/main
6318127 
merge in SparkFun's main
@PaulZC
Copy link
Collaborator

PaulZC commented Oct 17, 2022

Hi Adam (@adamgarbo ),

It's clear that for logging at (very) high data rates, full 4-bit SDIO is the way forward. OpenLog ESP32 is able to log at close to 1MByte/sec using SD_MMC, writing to a cheap 1GB SD card. I've left myself a note to write an SPI to SDIO logger example for OpenLog ESP32 ( #105 ).

Closing in favour of #105... After only ~20 months! ;-)

All the best,
Paul

@PaulZC PaulZC closed this as completed Oct 17, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@PaulZC @adamgarbo