Interrupt Latency Measurement

Post your cool example code here.
User avatar
RogerClark
Posts: 7433
Joined: Mon Apr 27, 2015 10:36 am
Location: Melbourne, Australia
Contact:

Re: Interrupt Latency Measurement

Post by RogerClark » Fri Aug 25, 2017 9:45 pm

There are some minor improvements I can make to LibMaple to speed up the ISR response time, but I am not sure if I could achieve more than a 25% speed improvement, and only on the shared ISR code.

It would make the code a bit bigger as I would need to unroll the loops etc

victor_pv
Posts: 1737
Joined: Mon Apr 27, 2015 12:12 pm

Re: Interrupt Latency Measurement

Post by victor_pv » Sat Aug 26, 2017 3:22 am

Thanks for testing Pito, seems like it brings down the average a tiny bit ut at the cost of much higher maximum.
What about rising priority for those interrupts? perhaps that brings the max down. I'm just guessing those that take so long are because some other interrupt, for systick or usb or something else, is interrupting them.

User avatar
Pito
Posts: 1626
Joined: Sat Mar 26, 2016 3:26 pm
Location: Rapa Nui

Re: Interrupt Latency Measurement

Post by Pito » Sat Aug 26, 2017 8:33 am

victor_pv wrote:
Sat Aug 26, 2017 3:22 am
..seems like it brings down the average a tiny bit ut at the cost of much higher maximum..
The MAX depends on for how long the measurement runs, as the probability to catch a larger latency grows with time.
You get a good MAX after an hour or so.. :)
What you get fast is the MIN.
Pukao Hats Cleaning Services Ltd.

dannyf
Posts: 167
Joined: Wed May 11, 2016 4:29 pm

Re: Interrupt Latency Measurement

Post by dannyf » Sat Aug 26, 2017 11:22 am

I ran the following:

Code: Select all

   	for (i=0; i<CNT; i++) {
    		tick0=ticks();						//time stamp time0
    		//benchmark here
    		//20 ticks for doing nothing / consecutive read of coreticks()
    		//LED_PORT;							//45 ticks total, 1 tick variation -> 25 ticks net
    		P1IFG |= (1<<0);					//fire the isr. 85 ticks total, 1 tick variation -> 65 ticks net
    		//tick1=ticks() - tick0;			//calculate time elapsed
    		tmp_ticks[i]=tick1;					//save time measurement
    	}
on a MSP432 (CM4F):

65 ticks in isr. a little bit too high in my view - optimization is off.

execution variability is 1 tick - nothing else is running on the chip at the time. so fairly deterministic.

I would expect like behaviors on a CM3.

User avatar
Pito
Posts: 1626
Joined: Sat Mar 26, 2016 3:26 pm
Location: Rapa Nui

Re: Interrupt Latency Measurement

Post by Pito » Sat Aug 26, 2017 11:29 am

@dannyf: the 8/16bitters like pic24 (and all picXX except pic32) and 8/16bit avrs and msp's have got easy to predict number of clocks per instruction.
Thus we constructed clock precise loops, delays, toggling the pins, etc. with it.

ARM (CM3, CM4) and MIPS (ie. pic32) are not such easy to predict stuff as they use ie. multistage pipelines, out of order instruction processing, several internal buses/bus_matrix for cpu/sram/flash/periph, DSP/FPU units, etc.

On Interrupt latency in ARM CM3/4:

https://community.arm.com/processors/b/ ... processors

http://infocenter.arm.com/help/index.js ... 16366.html
Pukao Hats Cleaning Services Ltd.

User avatar
Pito
Posts: 1626
Joined: Sat Mar 26, 2016 3:26 pm
Location: Rapa Nui

Re: Interrupt Latency Measurement

Post by Pito » Sat Aug 26, 2017 12:18 pm

This is with BluePill, older Libmaple F1 (>1y), SerialUSB, wired with:

Code: Select all

#define INTR_IN PB3    // INTERRUPT INPUT PIN
#define SIG_OUT PA15   // RANDOM RISING EDGE

Code: Select all

INTR Latency MIN=472ns MAX=25664ns AVER=521ns OVER=229
INTR Latency MIN=472ns MAX=25664ns AVER=521ns OVER=229
Pukao Hats Cleaning Services Ltd.

victor_pv
Posts: 1737
Joined: Mon Apr 27, 2015 12:12 pm

Re: Interrupt Latency Measurement

Post by victor_pv » Sat Aug 26, 2017 12:45 pm

To compare apples to apples you have to use a lower pin for the IN in the newer libmaple too, since only the lines 0 to 4 have their own interrupt vector.
From 5 up, they share vector among several lines, that's the code Roger posted above and he commented that can be optimized to some degree.
Looks like the first tests you ran on libmaple were on PA14 and 15, so that's the longer path.
BTW not sure if possible, but I think it is: to set the interrupt on toggle in a pin, and then toggle that same pin to trip the interrupt.

dannyf
Posts: 167
Joined: Wed May 11, 2016 4:29 pm

Re: Interrupt Latency Measurement

Post by dannyf » Sat Aug 26, 2017 3:00 pm

just to add what I wrote earlier.

the following code:

Code: Select all

		for (i=0; i<CNT; i++) {
			tick0=ticks();						//time stamp
			//benchmark here
			//nothing here / base line -> 17 ticks
			//tmp=LEDG_PORT;						//31 ticks
			EXTI->SWIER |= (1<<0);				//fire the isr - 76 ticks gross -> 59 ticks net
			//tick1=ticks() - tick0;				//calculate time elapsed
			tmp_ticks[i]=tick1;
		}
on a stm32f103c8t6, yielded a calculated isr latency of 59 ticks, zero variability (there is nothing else on that chip running).

inline with the CM4F numbers - as they are basically the same chip, for purposes of this test.

seemed a little bit too long.

victor_pv
Posts: 1737
Joined: Mon Apr 27, 2015 12:12 pm

Re: Interrupt Latency Measurement

Post by victor_pv » Sat Aug 26, 2017 4:15 pm

dannyf wrote:
Sat Aug 26, 2017 3:00 pm
on a stm32f103c8t6, yielded a calculated isr latency of 59 ticks, zero variability (there is nothing else on that chip running).
That's the difference, there are other things running in the libmaple and Generic cores when PIto run his tests. For one, the USB TX and RX which use interrupts, then there is the systick timer, using interrupts also.
Then the EXTI interrupt handling is done by the core, which reads some things form flash and/or RAM, among others a pointer to the the function that saves the stop time.
So when the interrupt triggers the path the CPU takes is very different than in your code, and then it can get interrupted multiple times for multiple reasons, even between the moment the start time is measured and the moment in which the GPIO register is written to set the pin level and trigger the interrupt.

User avatar
Pito
Posts: 1626
Joined: Sat Mar 26, 2016 3:26 pm
Location: Rapa Nui

Re: Interrupt Latency Measurement

Post by Pito » Sat Aug 26, 2017 5:04 pm

This is with an "interrupt latencies histogram", the latency bins are 1000ns wide, 31 bins from 0..31000ns.
After about 150k interrupts (BPill as above, Libmaple, INT_IN PB3) - the majority of latencies fall into first 0..1000ns bin, then into the second bin 1000..2000ns.
There is a latency peak in the bin 4000..5000ns, and in the bin 28000..29000ns.

Code: Select all

INTR Latency MIN=472ns MAX=28954ns AVER=492ns OVER=407
150286
193
16
4
58
8
1
0
0
0
0
0
0
0
0
2
0
4
9
6
5
1
3
4
4
3
0
3
55
0
0
.
Histogram: Black F407ZE, Libmaple, INT_IN PB3, 31bins (1us each):

Code: Select all

INTR Latency MIN=214ns MAX=7667ns AVER=312ns OVER=32198
150131
23
20
3
1
0
9
29
0
0
0
0
0
0
0
0
0
0
0
0
0
0
0
0
0
0
0
0
0
0
0
Histogram: MapleMini, Libmaple, INT_IN PA14, 35 bins (1us each):

Code: Select all

INTR Latency MIN=1681ns MAX=32083ns AVER=1707ns OVER=460
0
150221
149
102
1
55
8
3
0
5
3
12
5
5
2
0
0
0
0
0
0
0
0
1
2
0
0
0
2
2
0
101
2
0
0
Pukao Hats Cleaning Services Ltd.

Post Reply