sched/irq: Monitor the irq execution time. This is very useful for measuring the interrupt latency.

This commit is contained in:
Xiang Xiao 2018-08-25 07:10:11 -06:00 committed by Gregory Nutt
parent 3bf96c8e7e
commit c9b24615a6
4 changed files with 69 additions and 8 deletions

View File

@ -82,6 +82,9 @@ struct irq_info_s
uint32_t mscount; /* Number of interrupts on this IRQ (MS) */
uint32_t lscount; /* Number of interrupts on this IRQ (LS) */
#endif
#ifdef CONFIG_SCHED_TICKLESS
uint32_t time; /* Maximum execution time on this IRQ */
#endif
#endif
};

View File

@ -45,11 +45,14 @@
#include <nuttx/random.h>
#include "irq/irq.h"
#include "clock/clock.h"
/****************************************************************************
* Pre-processor Definitions
****************************************************************************/
/* INCR_COUNT - Increment the count of interrupts taken on this IRQ number */
#ifdef CONFIG_SCHED_IRQMONITOR
# ifdef CONFIG_HAVE_LONG_LONG
# define INCR_COUNT(ndx) \
@ -73,6 +76,32 @@
# define INCR_COUNT(ndx)
#endif
/* CALL_VECTOR - Call the interrupt service routine attached to this interrupt
* request
*/
#if defined(CONFIG_SCHED_IRQMONITOR) && defined(CONFIG_SCHED_TICKLESS)
# define CALL_VECTOR(ndx, vector, irq, context, arg) \
do \
{ \
struct timespec start; \
struct timespec end; \
struct timespec delta; \
clock_systimespec(&start); \
vector(irq, context, arg); \
clock_systimespec(&end); \
clock_timespec_subtract(&end, &start, &delta); \
if (delta.tv_nsec > g_irqvector[ndx].time) \
{ \
g_irqvector[ndx].time = delta.tv_nsec; \
} \
} \
while (0)
#else
# define CALL_VECTOR(ndx, vector, irq, context, arg) \
vector(irq, context, arg)
#endif
/****************************************************************************
* Public Functions
****************************************************************************/
@ -127,5 +156,5 @@ void irq_dispatch(int irq, FAR void *context)
/* Then dispatch to the interrupt handler */
vector(irq, context, arg);
CALL_VECTOR(ndx, vector, irq, context, arg);
}

View File

@ -97,6 +97,9 @@ void irq_initialize(void)
g_irqvector[i].mscount = 0;
g_irqvector[i].lscount = 0;
#endif
#ifdef CONFIG_SCHED_TICKLESS
g_irqvector[i].time = 0;
#endif
#endif
}

View File

@ -59,6 +59,16 @@
* Pre-processor Definitions
****************************************************************************/
/* Output format:
*
* In Tickless mode (where IRQ timing is available):
*
* 1111111111222222222233333333334444444444
* 1234567890123456789012345678901234567890123456789
*
* IRQ HANDLER ARGUMENT COUNT RATE TIME
* DDD XXXXXXXX XXXXXXXX DDDDDDDDDD DDDD.DDD DDDD
*
* In other modes:
*
* 11111111112222222222333333333344
* 12345678901234567890123456789012345678901
@ -71,15 +81,24 @@
* may not be wide enough.
*/
#ifdef CONFIG_SCHED_TICKLESS
# define HDR_FMT "IRQ HANDLER ARGUMENT COUNT RATE TIME\n"
# define IRQ_FMT "%3u %08lx %08lx %10lu %4lu.%03lu %4lu\n"
#else
# define HDR_FMT "IRQ HANDLER ARGUMENT COUNT RATE\n"
# define IRQ_FMT "%3u %08lx %08lx %10lu %4lu.%03lu\n"
#endif
/* Determines the size of an intermediate buffer that must be large enough
* to handle the longest line generated by this logic (plus a couple of
* bytes).
*/
#ifdef CONFIG_SCHED_TICKLESS
# define IRQ_LINELEN 50
#else
# define IRQ_LINELEN 44
#endif
/****************************************************************************
* Private Types
@ -178,6 +197,9 @@ static int irq_callback(int irq, FAR struct irq_info_s *info,
#else
info->mscount = 0;
info->lscount = 0;
#endif
#ifdef CONFIG_SCHED_TICKLESS
info->time = 0;
#endif
leave_critical_section(flags);
@ -251,7 +273,11 @@ static int irq_callback(int irq, FAR struct irq_info_s *info,
(unsigned int)irq,
(unsigned long)((uintptr_t)copy.handler),
(unsigned long)((uintptr_t)copy.arg),
#ifdef CONFIG_SCHED_TICKLESS
count, intpart, fracpart, copy.time / 1000);
#else
count, intpart, fracpart);
#endif
copysize = procfs_memcpy(irqfile->line, linesize, irqfile->buffer,
irqfile->remaining, &irqfile->offset);