Timing the little things

I have stumbled several times now by poorly guessing how long a function takes. I suspect others have as well. For example, I see people looking for help debugging code that measures a couple of microseconds between digitalWrite() calls, neglecting that these calls take something near 10 microseconds each.

Here is a way to very accurately time how many clock cycles a tiny operation takes without an oscilloscope.

void setup()

void loop()
  unsigned long loops = 0;

  // TCNT0 is the timer used to compute milliseconds and drive PWM0.
  // It is an 8 bit value that increments every 64 clock cycles and
  // rolls over from 255 to 0.
  // We repeatedly run the test code as the timer goes from 156 through 255
  // which gives use 64*100 clock cycles.
  // In practice this works for timing operations that take from 1 to 
  // hundreds of clock cycles. The results get a little chunky after that
  // since the last one will have gone a fair bit past the end period.
  while( TCNT0 != 155);        // wait for 155 to start
  while( TCNT0 == 155);        // wait until 155 ends
  cli(); // turn off interrupts
  while( TCNT0 > 150 ) {       // that 150 acknowledges we may miss 0
    // vvvvvv---- your code to be timed
    // ^^^^^^---- your code to be timed
  sei(); // turn interrupts back on
  Serial.print("loops: ");
  Serial.print(" clocks: ");
  Serial.print( (int) (( 100UL*64UL) / loops) - 8 /* empty loop cost */, DEC);


Run that and watch your serial monitor at 9600 bps and you will see how many clock cycles a digitalWrite() takes.

The interesting section is where I have a digitalWrite(). You would replace that line with something you cared to time. If it is a simple computation you will have to be careful that it doesn't get optimized away. Assigning the result to a "volatile" variable and using "volatile" variables as inputs is a good tactic, but it can still do tricky things with your constants.

(I made this because I was dismayed at how slow digitalWrite() was. I've recoded it and it is now much faster, smaller, and saves 100+ bytes of RAM. I'll write about that in another entry.)