Measuring time taken by ISR

Hi all,

I'd like to be able to measure how long an ISR takes to execute.

I'm using two quadrature encoders on two 12V DC motors. These.

Encoders are 64 counts per rotation and with a 29:1 gearbox that's 1856 counts per wheel rotation.
In my setup the wheels can spin to about 3 rotations per second. So that's 1856 x 3 (rps) x 2 (wheels) = 11,136 interrupts per second maximum. Let's say 10,000 / s.

I wrote the interrupts to be as short as possible, they basically do only one command (check status on two pins).

However I'm concerned that even if they are short, they will eat up processor time if they are called every 0.1 ms.

My main loop needs to run on a fixed time (10ms).

  1. The way I understand ISR, if I was able to check millis() right before and after an ISR call, it would show the same, even if the ISR took 500ms to run. IS this correct? Or does the counter "catch up" after exiting the ISR and shows the correct millis() again?

  2. Assuming I'm correct with my assumption in 0. If I want my main loop to run every 10 ms, but interrupts take say 10ms every loop, in effect the loop will take 20ms (even if the processor thinks it's been 10ms). I have no idea how I could avoid this. And similarly,

  3. If ISR indeed pause the update of millis() then my main loop time will be dependent on how many interrupts were called during 1 loop cycle, that is, dependent on wheel speed. How can I avoid that?

  4. Is it possible to check the time taken by an ISR? (separate question, just to be able to otpimise my ISR code as much as possible)

Maybe I'm all wrong and I'm inventing a problem, but I just want to make sure I'm not doing anything dumb. Thanks for your help.

If you have an oscilloscope, you can set an output pin HIGH at the start of the ISR, using direct port access to avoid significantly lengthening the ISR. Then set it LOW at the end of the ISR. Then use the oscilloscope to see how long the pin goes high for.

Otherwise, you can call micros() at the start of the ISR, save the result in a local unsigned int variable (no need to use an unsigned long in this case), call micros() again at the end of the ISR, subtract the value you read at the start, and store the result in a global unsigned int, where code in loop() can pick it up and write the value to the serial port or whatever. If the ISR takes more than 1ms then this will give incorrect results. But 1ms is a very long time for an ISR to take.

An ISR running every 100uS will still only be a fairly small percentage if it's as short as you say. I think we decided some time ago that there is a 3-4uS overhead for an interrupt, add say 1uS for your code and round up to 5uS for the heck of it.

So that's 5% of time used in the ISR.

I would normally set a pin on entry and clear it just before exit, but this does not help with the overhead. If there's an external trigger event to look at you can use that to determine the entry preamble time and assume the exit is the same. So with a scope or logic analyser you can get a very good idea.

Another thing to do is look at the assembly output from the compiler and count the cycles.


Rob

Thanks! I understand how that all works a lot better now. I don’t have a scope so I used micros() inside the ISR.

If I understand correctly the micros keep updating inside the ISR; however the overflow interrupt can’t happen so millis() isn’t updated. So you can read micros() but not millis inside an ISR.
Also if I still understand correctly the overflow interrupt will be queued then executed when exiting the ISR so the main loop will catch up to the proper millis() count correct?


I tried different methods for my encoder ISR.

The encoder outputs are plugged to pin 3 and 5 and their output is like this:

Which means when one of the encoder pin changes, if both pins are HIGH or both LOW, then wheel is spinning one direction. If pins are H/L or L/H wheel is spinning other direction. So it’s a XOR condition. (directions are reversed for the other encoder pin)

My main loop is only

void loop() {
  if ((millis() - timerEncoder) >= 10) {
    timerEncoder = millis();

    int speedR = count - last_count;
    last_count = count;

    Serial.print(ISR_time);  Serial.print(", \t"); Serial.println(speedR);
  }
}

Then the encoder ISR looks like

void rencoder()  {
  int ttime = micros();  

  if (digitalRead(3) ^ digitalRead(5))  count++;
  else count--;

  ISR_time = micros() - ttime;
}

I get a display every 10ms of the time spent inside the ISR. I understand micros() is only accurate to 4us. I then tried different methods:

  1. With digitalRead() as above:
if (digitalRead(3) ^ digitalRead(5))  count++;
  else count--;

it’s pretty bad, I get 12 or 16 us

  1. Using direct port reading like this:
if ((PIND & 0b00001000)  ^ ((PIND & 0b00100000) >> 2)) count++;
else count--;

I get 4 or 8us (about 50/50)

  1. then I tried fancy stuff :smiley: avoiding IF loops
count = count - 1 + (((PIND & 0b00001000) >> 2) ^ ((PIND & 0b00100000) >> 4));

I get same results as above.
The idea was to avoid the IF loop do count = count -1 + 2*(XOR(pin1, pin2)
shift pin D3 3 bits right, shift D5 5 bits right, XOR them, then multiply by two = shift one bit left
So instead of shifting right then left I just shift 2 and 4 bits

  1. Finally doing the other way, i.e. IF loops but no bit shifting
if (PIND & 0b00001000)  {
  if (PIND & 0b00100000)  count--;
  else count++;
  } else { //if pin3 low
    if (PIND & 0b00100000) count++;
    else count--;
  }

I get the best results, 4us almost always and 8us once in a blue moon.

In the end it looks like IF loops are faster than bit shifts. And the solution I thought was the less “elegant” is actually the fastest.

In total the ISR code itself takes <4us, let’s say 4us. Add the 4us of overhead and a very pessimistic estimate is 8us. So I’ll be fine even with interrupts running every 100us.

Thanks guys, I learned a lot again today :slight_smile:

Dwacito:
If I understand correctly the micros keep updating inside the ISR; however the overflow interrupt can't happen so millis() isn't updated. So you can read micros() but not millis inside an ISR.
Also if I still understand correctly the overflow interrupt will be queued then executed when exiting the ISR so the main loop will catch up to the proper millis() count correct?

Both correct. micros() allows for the possibility that a timer 0 overflow interrupt is pending, which is why you get the correct results when calling it from an ISR - provided that timer 0 has overflowed only once.

Dwacito:
In the end it looks like IF loops are faster than bit shifts. And the solution I thought was the less "elegant" is actually the fastest.

The atmega mcus have no barrel shifter, so for example a shift by 4 bits requires 4 instructions. So your code:

count = count - 1 + (((PIND & 0b00001000) >> 2) ^ ((PIND & 0b00100000) >> 4));

should be rewritten like this:

count = count - 1 + ((((PIND & 0b00100000) >> 2) ^ (PIND & 0b00001000)) >> 2);

to save 2 instructions.

It sounds like your processor time issue may already be settled, but If the processor time taken up by reading the quadrature encoder is an issue, it may be viable to use a different encoder located after the gear train, or alternatively an encoder with lower resolution. A lower pulse count would reduce your resolution, but if you don't need that resolution, then it is a waste of processor time. Of course, the price/availability of a new encoder would be a consideration.

-Joe

[This is a minor niggle BTW]

You shouldn't read PIND twice in the interrupt routine really - you want to get
a snapshot of both pins simultaneously, so copy PIND into a local byte variable
before the comparisons.

In practice the chance of an edge happening between successive reads of PIND is
very slight (perhaps only a 1us window), but its good discipline to sample inputs
simultaneously when interpreting quadrature (because the counting algorithm is
more robust to poor timing or noise if you do this).

MarkT:
You shouldn't read PIND twice in the interrupt routine really - you want to get
a snapshot of both pins simultaneously, so copy PIND into a local byte variable
before the comparisons.

Good point, also reading the pin just once into a local variable may speed up the code. PIND is a volatile variable, so the compiler isn't allowed to optimize the code to read it just once.

MarkT:
You shouldn't read PIND twice in the interrupt routine really - you want to get
a snapshot of both pins simultaneously, so copy PIND into a local byte variable
before the comparisons.

Thanks. So the correct way is to rewrite

count = count - 1 + ((((PIND & 0b00100000) >> 2) ^ (PIND & 0b00001000)) >> 2);

like this:

byte pinState = PIND;
count = count - 1 + ((((pinState & 0b00100000) >> 2) ^ (pinState & 0b00001000)) >> 2);

correct?

Thanks again for the advice, even if it's a 'minor niggle' I'm happy to learn the proper way of doing things, and this is something I'd never have realised by myself. You guys make this forum awesome.

@cadcoke5: thanks for the input. My goal was to be able to get full resolution on the encoders to see what PID update rate I could achieve. In the end, total time spent in the ISR is negligible even at full resolution so everything is all and well :slight_smile: (On a side note, it also turned out that because of motors inertia, there's no point increasing the speed of the PID loop past a certain value. But the whole thing was a good learning experience.)