Saturday, November 29, 2014

Debugging Interrupt Service Routines

I have been spending some time writing AVR Interrupt Service Routines of late and have decided to share some debugging techniques that I have found useful.

When writing ISRs, especially those used to service timer interrupts, as the timer period shortens, it becomes necessary to be especially prudent about the amount of code you place in the ISR.

Obviously, the ISR routine cannot execute longer than the timer period or timer interrupts will be missed.  When an ISR is entered, interrupts are disabled so that the ISR itself cannot be interrupted unless interrupts are explicitly re-enabled in the ISR itself.  This is something that should be done very carefully (if at all) after understanding all the ramifications.

It is a mistake to put Serial.print() code in your ISR code as such code takes a very long time to complete when interrupts are disabled.  It may appear to work for a while with very short output messages, but you are fooling yourself as to the usefulness of this output.

So, how does one debug ISR code?  I find it very useful to use an oscilloscope connected to a digital pin and to toggle that pin when events of interest are seen.  For example I might set the pin high when entering the ISR and low when exiting the ISR.  Along with allowing me to see that my interrupt service routine is in fact being called, I can see how often it is called by measuring the time between pin transitions from low to high.  Additionally, I can see how long the ISR itself is taking to run by measuring the time between the pin going high and it going low again.

By way of example, I have set up timer2 on an ATMega2560 to interrupt every 32 microseconds. 

// Setup timer2 with prescaler = 1, PWM mode to phase correct PWM
// Timer will count to maximum and then back down again (effectively a divide by
// 512 since timer2 is an 8 bit counter.  This will generate an interrupt every
// 32 us.  16000000 / 512 = 31250 = 32 us (.000032 seconds)
// See the ATMega datasheet for all the gory details
void timer2Setup()

  TIMSK2 = 0;
  TCCR2A = _BV(COM2A1) | _BV(COM2B1) | _BV(WGM20);
  TCCR2B = _BV(CS20);

And then enable timer2 when I am ready for the timer to start.

  // Useful macros for setting and resetting bits
  #define cbi(sfr, bit) (_SFR_BYTE(sfr) &= ~_BV(bit))
  #define sbi(sfr, bit) (_SFR_BYTE(sfr) |= _BV(bit))

  sbi (TIMSK2, TOIE2);      // Enable timer 2.

To handle the ISR, I have created a trivial handler that merely sets digital pin 8 high and then sets it back low.

  // Timer 2 interrupt service routine (ISR).
    digitalWrite(8, HIGH);
    digitalWrite(8, LOW);

Now, looking at this on the scope, we see a positive going pulse on pin 8 every 32us indicating that the ISR is being entered at that rate.

But another very interesting fact is revealed by this scope trace.  The amount of time it takes the ISR to simply toggle a pin high and then low is an amazing 7.6us.  This is a freaking eternity in the relative scheme of things.  Out of 32us I have to perform all of my ISR code, just toggling a pin high then low takes 23% of the available time.

If your ISR code is very short and sweet, this may be a non-issue.  However, everything you can do to shorten ISR code length should be done because the ISR runs with interrupts disabled.  Nothing else can run until you return from your ISR.

A silly example would be an ISR that runs every 32us and takes nearly 100% of the available 32us to complete.  This would mean that precious little time would be available for your main loop to run in your Arduino sketch.  In this particular example, there is no code in the main loop, so it is of no consequence.  However, this is not the norm and you want to minimize the time spent with interrupts disabled as much as possible as a general rule so some time spent on optimizing your ISR code can pay big dividends on overall performance.  Any section of you code can be timed quite accurately using this method allowing experimentation of different techniques to speed up your code or at least understand the effect on performance of any code change.

So, what can we do to optimize this simple two line ISR routine?  Ditch the use of digitalWrite and manipulate the port directly.  The beauty of digitalWrite is that it allows you to abstract the notion of "digital pin 8" from the particular hardware you are running on.  If you are running on a Arduino UNO (or any ATMega328 device) then digital pin 8 is PORTB bit 0 (PB0).  However, if you are running on an ATMega2560 as I am, then this same digital pin 8 is PORTH bit 5.  The digitalWrite implementation hides all of this mess from you very nicely, but at the expense of code speed.

So, let's take the knowledge we have of what processor we are running on and what port and bit the digital pin is assigned to and optimize this code a little.  I am running on an ATMega2560, so digital pin 8 is PH5.  Modifying the code to manipulate the desired bit directly means the code is hardware specific, but we gain a significant speed improvement in the code.  This code is for the ATMega2560.

  // Timer 2 interrupt service routine (ISR).

Now looking at the scope, we see that the setting and resetting of the pin only takes 320ns to execute, a significant savings.

If running on an ATMega328 such as found in the UNO, change the ISR as follows:

  // Timer 2 interrupt service routine (ISR).

Hopefully you will find this technique useful in your general debugging as well as when debugging ISR code in particular.  As always if you need assistance, drop me a line at ko7m at arrl dot net and I will be happy to assist in any way I can.

No comments:

Post a Comment