Measuring the Interrupt Latency

[xcp]

Hello,

I wrote an application with a main() routine and a postix thread. The main() triggers an interrupt pin on my system which is delayed due to a delay element.

The pthread uses a event.sigev_notify = SIGEV_INTR;and InterruptAttachEvent() call to attach the IRQ to the specific thread. The application and the measurement works fine, but when I generate load on the system with the stress tool (http://weather.ou.edu/~apw/projects/stress/) my latencys goes from 25-35 microseconds up to 100 milli seconds. Even when I change the Scheduler or the priority over the IDE for my application or directly for the thread in the sourceode to SCHED_FIFO and Priority 255, the latency doesn't drop.

Latency goes up too, when starting the photon environment from the console.

Anyone got a suggestion?

Thanks.

[mario]

100 milliseconds ?? Something is very wrong. Either it's the way you measure the latency or you aren't setting the priority properly. Can you post code?

[xcp]

Code: Select all

/*
 * Diplomarbeit "Charakterisierung des Echtzeitverhaltens diverser Embedded Betriebssysteme"
 *
 * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * *
 * This application is intended to measure the response time from triggering an interrupt until
 * a thread reacts to the incoming interrupt.
 *
 * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * *
 * NOTE:
 * The ClockCycles() kernel call returns the current value of a free-running 64-bit cycle
 * counter. This is implemented on each processor as a high-performance mechanism for timing
 * short intervals.
 *
 */

#include <inttypes.h>
#include <pthread.h>
#include <stdlib.h>
#include <stdio.h>
#include <stdint.h>
#include <time.h>
#include <unistd.h>

#include <sys/neutrino.h>
#include <sys/mman.h>
#include <sys/syspage.h>

#include <hw/inout.h>

/* ************************* DEFINES ****************************************** */
#define MY_DEBUG

#define MY_SCHEDULER   SCHED_FIFO   /* Use this scheduler for the thread */
#define MY_PRIORITY      255         /* Threadpriority */

#define NUM_MEASURE      200
#define DELAY_TIME_NS   100000      /* 50 us in ns */

/* The Neutrino parallel IO port used, corresponds to a single register, with one byte length */
#define PPT_PORT_LENGTH   1
#define PPT1_DATA      0x378
#define PPT1_CTRL      0x37a
#define PPT1_INIT      0x4    /* bit 2 = printer initialisation (high to initialise) bit 4 = hardware IRQ (high to enable) */
#define PPT1_IRQ      0x7
#define PPT1_INTR      0x10 /* bit 2 = printer initialisation (high to initialise) bit 4 = hardware IRQ (high to enable) */
#define PPT1_VAL      0x14

/* High Low values */
#define HIGH         0xff
#define LOW            0x0

/* ************************* GLOBAL VARIABLES ********************************* */
uintptr_t   pptCtrlHdl;
uintptr_t   pptDataHdl;

pthread_t*   p_workThread;

uint64_t   ui64_cc_start = 0;
uint64_t   ui64_cc_stop = 0;
uint64_t   ui64_cc_diff = 0;
uint64_t   ui64_us_diff = 0;

int         i_intID;

struct sigevent event;


/* ************************** PROTOTYPES ************************************** */
void* funcWorkThread(void* arg);




/* * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * */

void* funcWorkThread(void* arg)
{   
   int err;
   int i;
   uint64_t ccpus;
   FILE* file;
   file = fopen( "values.txt" , "a+" );
   
   #ifdef MY_DEBUG
      printf("DEBUG: entered funcWorkThread\n");
   #endif
   
   err = ThreadCtl( _NTO_TCTL_IO, NULL );
   if ( -1 == err )
   {
      printf( "Can't get root permission for triggerThread!\n" );
   }
   
   /* Determine ClockCycles() per micro second */
   ccpus = ((SYSPAGE_ENTRY(qtime)->cycles_per_sec) / 1000000);
   
    #ifdef MY_DEBUG
       printf( "DEBUG: This system has %lld cycles/usec\n" , ccpus );
    #endif
       
   /* Tell the kernel to attach an interrupt signal event to this thread */
   event.sigev_notify = SIGEV_INTR;
   
   i_intID = InterruptAttachEvent( PPT1_IRQ , &event , 0 );
   if ( i_intID == -1 )
   {
      printf( "Couldn't attach event to IRQ %d\n", PPT1_IRQ );
   }

   for ( i = 1 ; i <= NUM_MEASURE ; i++)
   {
      /* Sleep until the next interrupt */
      InterruptWait( 0, NULL );

      /* Record the time */
      ui64_cc_stop = ClockCycles();
      /* Calculate the ClockClycle difference between start and stop and substract the delay */
      ui64_cc_diff = (ui64_cc_stop - ui64_cc_start - (DELAY_TIME_NS * ccpus));
      /* Convert ClockCycles to micro seconds */
      ui64_us_diff = (ui64_cc_diff/ccpus);
      
      #ifdef MY_DEBUG
         printf("ID: %i, latency: %lld ClockCycles or %lld us\n" , i , ui64_cc_diff , ui64_us_diff);
      #endif
      
      #ifndef MY_DEBUG
         fprintf(file,"ID: %i, latency: %lld ClockCycles or %lld us\n" , i , ui64_cc_diff , ui64_us_diff);
      #endif
      
      /* Reenable this interrupt */
      InterruptUnmask( PPT1_IRQ, i_intID );
   }
   
   InterruptDetach( i_intID );
   return EXIT_SUCCESS;
}

int main()
{
   int err;
   int i;
   pthread_attr_t attr;
   struct sched_param param;

   printf("\nDiplomarbeit Christian Poessinger <poessinger@mixed-mode.de>\n"); 
   printf("\tCharakterisierung des Echtzeitverhaltens diverser Embedded Betriebssysteme\n\n"); 
       
   err = ThreadCtl( _NTO_TCTL_IO, NULL );
   if ( -1 == err )
   {
      printf( "Can't get root permission for triggerThread!\n" );
      return EXIT_FAILURE;
   }
   
    param.sched_priority = MY_PRIORITY;
    pthread_attr_init( &attr );
   pthread_attr_setschedpolicy( &attr , MY_SCHEDULER);
   pthread_attr_setschedparam( &attr , &param );
   
   /* Create Handle for parallel port 1 CTRL register */   
   pptCtrlHdl = mmap_device_io( PPT_PORT_LENGTH , PPT1_CTRL );
   /* Create Handle for parallel port 1 DATA register */
   pptDataHdl = mmap_device_io( PPT_PORT_LENGTH , PPT1_DATA );
   /* Initialise parallel port */
   out8( pptCtrlHdl , PPT1_INIT );
   /* Activate Interrupts on parallel port */
   out8( pptCtrlHdl , PPT1_INTR );
   
   pthread_create( p_workThread, &attr, &funcWorkThread, NULL );

   printf("\n\t=> Beginne Messung!\n");

   for ( i = 0 ; i <= (NUM_MEASURE+1) ; i++)
   {
      out8( pptDataHdl , LOW );      /* send LOW bit on PPT1 */
      out8( pptDataHdl , HIGH );     /* send HIGH bit on PPT1 */
      ui64_cc_start = ClockCycles(); /* get the current system clockcycles */
      delay(30);                     /* delay in milli seconds */
      out8( pptDataHdl , LOW );      /* send LOW bit on PPT1 */
      delay(200);                    /* delay in milli seconds */
   }
   
   printf("\t=> Messung beendet!\n");
      
   return EXIT_SUCCESS;
}


[mario]

You can't really measure latency like that. The problem is that the interrupt might occurs in between out8() and ui64_cc_start = ClockCycles(), throwing the calculation off. I'm assuming the interrupt gets trigger when setting the bit on PPT1 to HIGH.

The (f)printf in the irq is not a good idea, although the process is high priority, if there is a request currently being performed by the related driver ( devc-con/devb-eide), they are queue. Hence these calls could make the ISR block longer then you might expect.

[xcp]

The IRQ can't occur between out8() and ui84_cc_start because the out8 triggers a delay device which delays the signal for 100 milliseconds. Hence the CPU has enough time to get the ClockCycles.

[mario]

The IRQ can't occur between out8() and ui84_cc_start because the out8 triggers a delay device which delays the signal for 100 milliseconds. Hence the CPU has enough time to get the ClockCycles.

Isn't odd that you say that latency goes up to 100 milliseconds...

[xcp]

No, it keeps at those high latencys even when changing the delay time from 100 to 50 milli seconds.

Actually I had an error in the latency calculation. The real latencys are between 5 to 8 microseconds when system is idle. When doing a "stress --cpu 2", having two workers on the cpu doint sqrt(), i get latencys from 8 to 9 milliseconds.

[mario]

Then there is something that you aren`t telling us. Remember, the thread is running at high priority the main() isn`t...

[xcp]

Thanks for the main() tip. Adding a "setprio( getpid() , 254 );" to the main() did the trick. Thanks.

[mario]

setprio(0, 254 ) would work fine. The fact you need to raise the process's priority at 254 show your method of measurement is flawed.

[cburgess]

rather than 254 you should consider using sched_get_priority_max() to get the largest valid priority for your userid/scheduling policy.

[hemanth]

I am also measuring the interrupt latency on X86 target with QNX RTOS. Could someone explain more about this ?? I need a code for this.

[hemanth]

Could someone explain : How to analyze the interrupt latency on embedded PC target (X86) ??
If its possible then please update the code also.
looking forward for your reply.