## an efficient way to find out the duration of a function or ISR routine

17 posts / 0 new
Author
Message

Lets say I want to calculate the actual time taken by my MCU to run 1 of my function or ISR routine. What would be the best approach to find the actual time? provided oscilloscope is available

I did something like this

```ISR()
{
PORTC |= (1<<5);

//some stuff

PORTC &= ~(1<<5);

}
```

then i checked on oscilloscope I was expecting a square wave and that the duty cycle of that wave would help me to determine the duration of ISR but what I obtained was  .. not at all what I expected ...  Its a high signal with small ripples ... Can anyone help me understand this  ... I have attached the output that i obtained from oscilliscope below

Thanks in advance :)

## Attachment(s):

This topic has a solution.
Last Edited: Fri. Jul 19, 2019 - 09:20 AM
Total votes: 0

So, what is the problem with those "little ripples"? How big are they? What is the logic swing? Hint: they have almost no effect until they are more than about 25% of the logic swing.

That is a good way to do it, EXCEPT, it will not catch all the "register save" stuff at the start nor all the "register restore" stuff at the end. That can vary from a few bytes saved and restored, to quite a few, depending on what the function or ISR does. Whether or not that is significant or not depends on how long the function or ISR is, and how precise you need to know it.

Jim

Until Black Lives Matter, we do not have "All Lives Matter"!

Last Edited: Fri. Jul 19, 2019 - 05:40 AM
Total votes: 0

No the problem is not with the ripples they are below 10% of logic swing , its just that I was expecting it to be a square wave.... at first the ISR was empty except for these 2 statements ... at that time this output was fine.... but then I put a delay of 500us ,1ms then 2ms even 3 ms between these two statements but still the result was same even though the brightness of the LED changed... my interrupt is called after every 3.5 ms

I want the timing to be rounded off by 1 ms ... is it too sensitive of a reading for oscilloscope?

ka7ehk wrote:
EXCEPT, it will not catch all the "register save" stuff at the start nor all the "register restore" stuff at the end. That can vary from a few bytes saved and restored, to quite a few, depending on what the function or ISR does

I am sorry I didnt understand this part

Total votes: 0

I run an unused timer with F_CPU and measure it at the count at the breakpoint.

Total votes: 0

Too little information! The ripples on the scope trace is noise most likely.

Show us ALL the code.

The technique you have used is valid, but as noted, it doesn't measure the isr overhead - the compiler generates code to save and restore the processor state - this is not included in your measurement. How to measure this? It gets a bit tricky - you can examine the compiler's generated code and add up the cycles for isr entry/exit then add it to your scope measurement. A more involved method is to use a 'naked' isr but you need to code the entry/exit for yourself - if you don't do it right, then your code will crash.

Total votes: 0

SufyanRaza26 wrote:

...I did something like this...I was expecting a square wave...not at all what I expected...Its a high signal with small ripples...

Which indicates that your ISR is not being run or your port is not outputting anything because it is not configured correctly.

#1 Hardware Problem? https://www.avrfreaks.net/forum/...

#2 Hardware Problem? Read AVR042.

#3 All grounds are not created equal

#4 Have you proved your chip is running at xxMHz?

#5 "If you think you need floating point to solve the problem then you don't understand the problem. If you really do need floating point then you have a problem you do not understand."

Last Edited: Fri. Jul 19, 2019 - 06:47 AM
Total votes: 0

SufyanRaza26 wrote:

I am sorry I didnt understand this part

Consider this ISR code...

```interrupt [TIM2_OVF] void timer2_ovf_isr(void) {

TIMER2_STOP;
gSlave_timeout = 1;

}```

...simple isn't it? Except the compiler generates this...

Quote:

;interrupt [TIM2_OVF] void timer2_ovf_isr(void) {
; 0000 011C interrupt [12] void timer2_ovf_isr(void) {
_timer2_ovf_isr:
; .FSTART _timer2_ovf_isr
ST   -Y,R30
; 0000 011D
; 0000 011E     TIMER2_STOP;
LDI  R30,LOW(0)
STS  177,R30
; 0000 011F     gSlave_timeout = 1;
SBI  0x1E,0
; 0000 0120
; 0000 0121 }
LD   R30,Y+
RETI
; .FEND

...see the extra ST and LD instructions that have nothing to do with the code in the ISR? They are needed to save any registers used in the ISR. Using a port pin to time the ISR will not take those into account. Nor will it take into account the time it takes for RETI to execute and return to your main code, nor the time that the interrupts takes to start running.

If timing is critical then you must inspect any generated code and add those extra times to your measured answer.

#1 Hardware Problem? https://www.avrfreaks.net/forum/...

#2 Hardware Problem? Read AVR042.

#3 All grounds are not created equal

#4 Have you proved your chip is running at xxMHz?

#5 "If you think you need floating point to solve the problem then you don't understand the problem. If you really do need floating point then you have a problem you do not understand."

This reply has been marked as the solution.
Total votes: 0

And just to prove the technique works...

```/*******************************************************
Chip type               : ATmega1284P
Program type            : Application
AVR Core Clock frequency: 16.000000 MHz
Memory model            : Small
External RAM size       : 0
Data Stack size         : 4096
*******************************************************/

#include <mega1284p.h>
#include <delay.h>

// Timer 0 overflow interrupt service routine
interrupt [TIM0_OVF] void timer0_ovf_isr(void) {

PORTA.0 = 0;
TCNT0=0x25;
delay_us(500);
PORTA.0 = 1;
}

void main(void) {

// Crystal Oscillator division factor: 1
#pragma optsize-
CLKPR=(1<<CLKPCE);
CLKPR=(0<<CLKPCE) | (0<<CLKPS3) | (0<<CLKPS2) | (0<<CLKPS1) | (0<<CLKPS0);
#ifdef _OPTIMIZE_SIZE_
#pragma optsize+
#endif

// Input/Output Ports initialization
// Port A initialization
// Function: Bit7=In Bit6=In Bit5=In Bit4=In Bit3=In Bit2=In Bit1=In Bit0=Out
DDRA=(0<<DDA7) | (0<<DDA6) | (0<<DDA5) | (0<<DDA4) | (0<<DDA3) | (0<<DDA2) | (0<<DDA1) | (1<<DDA0);
// State: Bit7=T Bit6=T Bit5=T Bit4=T Bit3=T Bit2=T Bit1=T Bit0=0
PORTA=(0<<PORTA7) | (0<<PORTA6) | (0<<PORTA5) | (0<<PORTA4) | (0<<PORTA3) | (0<<PORTA2) | (0<<PORTA1) | (0<<PORTA0);

// Timer/Counter 0 initialization
// Clock source: System Clock
// Clock value: 62.500 kHz
// Mode: Normal top=0xFF
// OC0A output: Disconnected
// OC0B output: Disconnected
// Timer Period: 3.488 ms
TCCR0A=(0<<COM0A1) | (0<<COM0A0) | (0<<COM0B1) | (0<<COM0B0) | (0<<WGM01) | (0<<WGM00);
TCCR0B=(0<<WGM02) | (1<<CS02) | (0<<CS01) | (0<<CS00);
TCNT0=0x25;
OCR0A=0x00;
OCR0B=0x00;

// Timer/Counter 0 Interrupt(s) initialization
TIMSK0=(0<<OCIE0B) | (0<<OCIE0A) | (1<<TOIE0);

// Globally enable interrupts
#asm("sei")

while (1) {
;
}
}```

#1 Hardware Problem? https://www.avrfreaks.net/forum/...

#2 Hardware Problem? Read AVR042.

#3 All grounds are not created equal

#4 Have you proved your chip is running at xxMHz?

#5 "If you think you need floating point to solve the problem then you don't understand the problem. If you really do need floating point then you have a problem you do not understand."

Total votes: 0

...and the generated ISR code...

```	.CSEG
_timer0_ovf_isr:
; .FSTART _timer0_ovf_isr
ST   -Y,R24
ST   -Y,R25
ST   -Y,R30
IN   R30,SREG
ST   -Y,R30
; 0000 001C
; 0000 001D 	PORTA.0 = 0;
CBI  0x2,0
; 0000 001E 	TCNT0=0x25;
LDI  R30,LOW(37)
OUT  0x26,R30
; 0000 001F 	delay_us(500);
__DELAY_USW 2000
; 0000 0020     PORTA.0 = 1;
SBI  0x2,0
; 0000 0021
; 0000 0022 }
LD   R30,Y+
OUT  SREG,R30
LD   R30,Y+
LD   R25,Y+
LD   R24,Y+
RETI
; .FEND```

#1 Hardware Problem? https://www.avrfreaks.net/forum/...

#2 Hardware Problem? Read AVR042.

#3 All grounds are not created equal

#4 Have you proved your chip is running at xxMHz?

#5 "If you think you need floating point to solve the problem then you don't understand the problem. If you really do need floating point then you have a problem you do not understand."

Total votes: 0

Kartman wrote:
The ripples on the scope trace is noise most likely.
Brian Fairchild wrote:
Which indicates that your ISR is not being run
+1

Either you have failed to set up the trigger conditions for your scope correctly or the ISR simply is not being run.

Pulsing an IO to measure duration is a classic technique for determining the duration of a code sequence.

Try cutting the complexity out of your code and just do something in a main() loop. Maybe something like:

```#include <stdlib.h>
#include <math.h>
#include <avr/io.h>
#include <util/delay.h>

volatile float f;

int main(void) {
DDRC = (1 << 5);
while(1) {
PORTC |= (1 << 5);
f = sin(rand());
PORTC &= ~(1 << 5);
_delay_ms(20);
}
}```

There should be a variable period high pulse on the IO line then 20ms low periods between. If you don't see this then your triggering is not working (or maybe you are even probing the wrong trigger pin?).

Total votes: 0

Brian Fairchild wrote:
Which indicates that your ISR is not being run or your port is not outputting anything because it is not configured correctly.

yes sorry my bad!! but even if it was working i would have made the mistake that you pointed out in your next reply, Thank you !!!

Total votes: 0

You do not have reasonable expectations of what an LED would show.

Any LED that flashes faster than about once every 100ms will appear steadily on, to your eye. It is called "persistence of vision". Instead, depending on the percentage of time the LED is on, it  will appear to have varying brightness, independent of the flash frequency.

Jim

Until Black Lives Matter, we do not have "All Lives Matter"!

Total votes: 0

ka7ehk wrote:
Any LED that flashes faster than about once every 100ms will appear steadily on, to your eye. It is called "persistence of vision". Instead, depending on the percentage of time the LED is on, it  will appear to have varying brightness, independent of the flash frequency.

True, but it does give you a convenient place (LED) to hang the scope or logic analyzer probe.

If I read the thread correctly, the OP failed to make his port pin an output, and that was why they did not get the square wave they were expecting.

FO Jim

(Possum Lodge oath) Quando omni flunkus, moritati.

"I thought growing old would take longer"

Total votes: 0

"When you have eliminated the impossible, whatever remains, however improbable, must be the truth."

-S. Holmes.

Last Edited: Fri. Jul 19, 2019 - 03:43 PM
Total votes: 0

True about providing a connection point. My comment was pointed at the statement:

but then I put a delay of 500us ,1ms then 2ms even 3 ms between these two statements but still the result was same even though the brightness of the LED changed...

Jim

Until Black Lives Matter, we do not have "All Lives Matter"!

Total votes: 0

There are many ways to check how long time some (ISR) code take. And sometimes you don't care about avg. speed but only worst case.

I most often use a timer ISR and have the habit to end a ISR with setting a max variable at the bottom of the code. (and if I fear then RAM is a problem also log min of the stack-pointer).

Total votes: 0

sparrow2 wrote:
There are many ways to check how long time some (ISR) code take. And sometimes you don't care about avg. speed but only worst case.

Using the 'persistence' feature of a scope on the ISR_active bit can also help determine worst case ISR duration.