Data storage efficiency

[jveitchmichaelis]

I would switch to storing raw data, rather than strings.

There is probably a significant overhead in doing a string conversion, because you're implicitly calling itoa a bunch of times. You'd be better off having three 16-bit arrays to store the accelerations and just putting the raw measurements in there each loop.

projects/accelerometer/sensor_logger.ino

Lines 162 to 172 in a298bcd

	/* Display the results (acceleration is measured in m/s^2) */
	strRow = String(now.unixtime()) + ", ";
	strRow += String(event.acceleration.x) + ", ";
	strRow += String(event.acceleration.y) + ", ";
	strRow += String(event.acceleration.z) + ", ";
	strRow += "m/s^2, ";
	strRow += String(rangeVal) + ", ";
	strRow += String(millis()) + ", ";
	strRow += String(micros()) + ", ";
	strRow += String(measuredvbat);

It will also save a lot of space. This string "m/s^2, " alone contains as much data as a single 3 axis measurement!

The Adafruit library also does a bunch of float calculations which is also going to be a lot of extra cycles, but worry about that when you've optimised as far as you can with their library.

So in principle your max data rate is 3 x 5000 x 16 bits or around 240kbaud. From your writeup it looks like you're capturing at a much lower rate (around 140Hz). I'd be curious to see how much faster you can write to disk just making the changes above.

[erichiggins]

Thank you for the feedback!

There is probably a significant overhead in doing a string conversion, because you're implicitly calling itoa a bunch of times. You'd be better off having three 16-bit arrays to store the accelerations and just putting the raw measurements in there each loop.

I knew that this section of the code was going to be hacky and inefficient, but it was "good enough" to make it usable for the experiment. Would you consider creating a pull request, or just simply providing some guidance on a better way to do it here?

This string "m/s^2, " alone contains as much data as a single 3 axis measurement!

I'd hesitate to remove this from the output since it's important to label the data. Is there another way to do it while maintaining properly formatted CSV?

The Adafruit library also does a bunch of float calculations which is also going to be a lot of extra cycles, but worry about that when you've optimised as far as you can with their library.

That's good to know. Would you mind linking directly to where they are doing that for future reference?

So in principle your max data rate is 3 x 5000 x 16 bits or around 240kbaud. From your writeup it looks like you're capturing at a much lower rate (around 140Hz). I'd be curious to see how much faster you can write to disk just making the changes above.

Wow, that'd be a huge improvement! I'd love to get your help to pull that off -- I'm already a little outside my comfort zone in the Arduino world, so guidance would be greatly appreciated!

Thanks again!

[jveitchmichaelis]

No worries! First thing I would do is profile. Strip out everything extraneous and figure out how fast you can poll the sensor - can you achieve the datasheet 5kHz, for example?

Something like:

// Main Loop
void loop() {

  unsigned long start = micros();
  lis.read();      // get X Y and Z data at once
 
  unsigned long stop = micros();

  DEBUG_PRINTLN(stop-start);
  DEBUG_PRINTLN(lis.x); // print, in case the compiler optimises lis away.
  DEBUG_PRINTLN(lis.y);
  DEBUG_PRINTLN(lis.z);
  DEBUG_PRINTLN("-----");
}

You can check the overhead of using getEvent in a similar way:

// Main Loop
void loop() {
  sensors_event_t event;

  unsigned long start = micros();
  lis.getEvent(&event);
  unsigned long stop = micros();

  DEBUG_PRINTLN(stop-start);
  DEBUG_PRINTLN(event.acceleration.x);
  DEBUG_PRINTLN(event.acceleration.y);
  DEBUG_PRINTLN(event.acceleration.z);
  DEBUG_PRINTLN("-----");
}

The code for getEvent is here:

https://github.com/adafruit/Adafruit_LIS3DH/blob/17017f2d7d6b8cb19befb16168c864efb627b130/Adafruit_LIS3DH.cpp#L309

and here for reference. lis.x is a 16-bit int, whereas event.acceleration.x is a float.

One thing, in your code you're calling read() and then getEvent which calls read() as well - so you're polling twice each loop. You only need to use one or the other.

Once you've done that, you can add other bits like the string conversion and writing to SD to see how much overhead you're adding.

If you want to write as a CSV that's fine, but you don't need to print the units in every row. Just make the first row a header and put the units in there.

[erichiggins]

Strip out everything extraneous and figure out how fast you can poll the sensor - can you achieve the datasheet 5kHz, for example?

That's a great idea! Your examples use the DEBUG_PRINTLN, which is just a reference to Serial.println() when the DEBUG flag is enabled. As I noted in the article, calls to Serial are rather slow which would affect the performance test, but maybe it's good enough to get a sense of the speed difference.

If your

Seems like something is missing here?

One thing, in your code you're calling read() and then getEvent which calls read() as well - so you're polling twice each loop. You only need to use one or the other.

Great catch!

If you want to write as a CSV that's fine, but you don't need to print the units in every row. Just make the first row a header and put the units in there.

I see what you mean -- have a header row something like the following:

timestamp, accel x (m/s^2), accel y (m/s^2), accel z (m/s^2), millis, micros

That's a good solution, thanks!

[jveitchmichaelis]

The print statements won't affect the timing, you only care about the stuff that happens between start and stop :)

Yeah that's what I meant for the CSV, you can shove that in your setup.

On your timestamp measurement: when you call millis() and micros() you're querying the time since the micro turned on. Micros will only overflow after 70 minutes ish which means there's not much point storing millis as well; it's just micros*1000 though it will overflow at a much longer time. You could save the unix timestamp in the filename and store micros() for every measurement instead.

[erichiggins]

I did a quick test based on your suggestion, here are some results (very promising)!

Timing per-call:

• lis.read(): ~1375 microseconds
• getEvent(): ~1395 microseconds
• rtc.now().unixtime(): ~1000 microseconds

Total samples per second:

• micros(), lis.read(): ~585hz
• micros(), lis.read(), unixtime(): ~350hz
• micros(), lis.read(), unixtime(), getEvent(): ~198hz
• micros(), unixtime(), getEvent(): ~278hz

The print statements won't affect the timing, you only care about the stuff that happens between start and stop :)

Good point!

there's not much point storing millis as well; it's just micros*1000

Also a great point. I didn't find having both to be very useful when doing the data analysis.

You could save the unix timestamp in the filename and store micros() for every measurement instead.

Possibly... The trouble is that the unix timestamp from the RTC isn't synced to when the board was initialized, and therefore it isn't synced to micros(). Having the unix timestamp for each shot is very useful, but it clearly comes with a performance cost.

[erichiggins]

(Adding the following for myself)

References:

• SENSOR_GRAVITY_EARTH
• Raw acceleration conversion and to m/s^2 (on Earth).

[jveitchmichaelis]

Great. The main takeaway from that is that getEvent() is basically as efficient as just doing read(). So you might as well take advantage of the unit conversion because it only costs you a few microseconds.

What's interesting is that your read speed is really quite slow. I2C operates in fast mode at 400kHz. You want to transfer 6 bytes, plus probably another 4 bytes of overhead sending addresses and selecting the register to read. So that's about 72 bits per transaction. It should only take around 180 microseconds to do that. Your call is taking 1300, assuming the timing is accurate.

There are a bunch of float divisions in read(), and a few multiplies in getEvent().

https://github.com/adafruit/Adafruit_LIS3DH/blob/17017f2d7d6b8cb19befb16168c864efb627b130/Adafruit_LIS3DH.cpp#L173-L175

Floating point division is always going to be slower than multiplying. I'm not familiar enough with the ARM M0 to say how many cycles floating point division takes, but you can test this by timing something like (pick some arbitrary numbers):

unsigned long start = micros();
float a = 2000;
float x = 10;
float y = 15;
float z = 20;

x /= a;
y /= a;
z /= a;
unsigned long end = micros();

// print to avoid the compiler optimising the variables out
Serial.println(x);
Serial.println(y);
Serial.println(z);

If you get an answer of around 1ms, then that's your bottleneck.

Compare it to this, which should be lightning fast:

unsigned long start = micros();
uint16_t = 2000;
uint16_t x = 100;
uint16_t y = 150;
uint16_t z = 200;

x /= a;
y /= a;
z /= a;
unsigned long end = micros();

Serial.println(x);
Serial.println(y);
Serial.println(z);

You could call unixtime() and store that value along with the current value of micros(). That gives you your sync. Then every time you call micros() again, you can use that initial value to calculate the time
elapsed since you called unixtime().

I saw you posted in the Adafruit repo, so I guess you realised that the default code sets up the IMU to operate at 400Hz by default. That shoudn't affect your read speed though, the library doesn't wait for the sensor to update, it just reads whatever the last value is.

[erichiggins]

What's interesting is that your read speed is really quite slow. I2C operates in fast mode at 400kHz.

I looked into this a little bit and found some references that lead me to believe that it defaults to 100kHz.

• https://learn.adafruit.com/mcp4725-12-bit-dac-tutorial?view=all#increasing-the-speed-3-5
• https://github.com/adafruit/Adafruit_MCP4725/blob/master/Adafruit_MCP4725.cpp#L69
• https://www.arduino.cc/en/Reference/WireSetClock

If you get an answer of around 1ms, then that's your bottleneck.
Compare it to this, which should be lightning fast:

There wasn't a measurable difference between either of the two methods. Each took around 1-2 microseconds.

You could call unixtime() and store that value along with the current value of micros(). That gives you your sync. Then every time you call micros() again, you can use that initial value to calculate the time
elapsed since you called unixtime().

I gave this a try and compared it against calling unixtime() within the loop. It was pretty close, only off by about 30ms or so. The slight tradeoff in precision vs the big performance boost seems pretty reasonable to me.

I saw you posted in the Adafruit repo, so I guess you realised that the default code sets up the IMU to operate at 400Hz by default. That shoudn't affect your read speed though, the library doesn't wait for the sensor to update, it just reads whatever the last value is.

Yeah, it would be nice to get that set faster so that it doesn't become a bottleneck. I don't get the sense that Adafruit spends a lot of resources maintaining these libraries long after release.

Thank you again for all of the help. I'm already seeing a massive performance increase (almost 3x!) and hope that we can get it even faster!

[jveitchmichaelis]

That does make sense, 1500 odd cycles for the divisions at 48Mhz shouldn't take long. So at 100kHz that might go some way to explain it (ie 800us just for the transfer). Without really looking at what the arduino i2c library is doing there might be other things going on in there that's slowing you down. If you have access to an oscilloscope or a logic analyser you can see what's happening on the bus.

Or try wiring it up using the spi interface instead?

Since you can just download the library, you could also try profiling within the read function to see what's going on..

But at this point a 3x speedup is good to get started!

[erichiggins]

Without really looking at what the arduino i2c library is doing there might be other things going on in there that's slowing you down. If you have access to an oscilloscope or a logic analyser you can see what's happening on the bus.

I've read some articles which state that calls like digitalWrite can be slow because of all the safety-checks they include. Here's one reference: https://stackabuse.com/speeding-up-arduino/

I have neither an oscilloscope or logic analyzer.

Or try wiring it up using the spi interface instead?

I know that I can chain multiple devices, but I'm not certain if that's true for SPI. The FeatherWing I'm using adds RTC + microSD -- the latter utilizes the SPI connections.

Since you can just download the library, you could also try profiling within the read function to see what's going on..

Yeah, that might be my next approach.

Do you have any thoughts on buffering the data in memory and writing to the SD card only when acceleration events are detected?

[jveitchmichaelis]

Yeah digital write is much slower than directly using the pin registers. Though the I2C interface ought to be reasonably quick. Saying that I had similar problems on other platforms where there were large delays between SPI transfers.

SPI is mediated with the (well, a) chip select (CS) pin, so you connect all the sck/mosi/miso pins in parallel and each device has a separate CS. When you make the accelerometer object, the constructor takes CS as an input. Should be the same with the SD card. There's a default CS pin, but you don't need to use it, and if you have multiple devices obviously you need other pins.

Buffering is definitely an option, but always a trade off between how much you can store and how often you need to dump it.

[erichiggins]

I made a bit more progress without much effort by setting Wire.setClock(400000L);

This moved me from ~400hz to ~650hz.

It also reduced the call time for getEvent() down to ~430 microseconds.

Edit: Using fast mode plus moved the needle to ~750hz and getEvent() down to ~250 microseconds. I tried 'high speed mode', but it doesn't seem to be supported by this setup.

[erichiggins]

One more update for the day.

Here's a small sample of the new data structure (formatted for readability):

timestamp (s)	start (µs)	delta (µs)	accel x (m/s²)	accel y (m/s²)	accel z (m/s²)
1547749706	123593	223	0.00	0.00	0.00
1547749706	125917	251	-6.32	3.72	7.35
1547749706	126979	252	-6.32	4.52	6.40
1547749706	128040	252	-5.36	4.90	5.67
1547749706	129097	251	-5.06	5.29	4.94
1547749706	130158	252	-4.94	5.55	4.79

I ran the unit with these improvements with DEBUG mode disabled for around 60 seconds. In that time, the resulting file contained 50,400 lines of data and was 2MB. Scaling linearly, I'd expect one hour of data to be 120MB.

Samples were taken approximately every 1-2ms, with a ~10ms delay for writing to the SD card (using SDfat) every 800 iterations.

I have a 600yd match on Saturday, where I'll be firing ~50 rounds. I'll run this code on the unit during that match to collect data for a follow up. If all goes well, I'll create a PR with the changes.