interrupt duration

Andrew Maximov amaximus at mail.ru
Fri May 11 17:51:24 UTC 2001


----- Original Message -----
From: "Joel Sherrill" <joel.sherrill at OARcorp.com>
To: "Andrew Maximov" <amaximus at mail.ru>
Cc: "RTEMS User List" <rtems-users at oarcorp.com>
Sent: Friday, May 11, 2001 4:36 PM
Subject: Re: interrupt duration

My configuration:
CPU: Pentium MMX - 125 Mhz
MEMORY: 32M
VIDEO: S3TrioV+

I write simple test. First I change _ISR_Handler in irq_asm.S for for
interrupt duration measurement.

here is a fragment from _ISR_Handler ( full source code attached )

SYM (_ISR_Handler):
        ...
.check_stack_switch:
        pushl   ebp
        movl      esp, ebp                  # ebp = previous stack pointer
        cmpl      $0, SYM (_ISR_Nest_level) # is this the outermost
interrupt?
        jne       nested                    # No, then continue
        movl      SYM (_CPU_Interrupt_stack_high), esp

        /*
         *  We want to insure that the old stack pointer is on the
         *  stack we will be on at the end of the ISR when we restore it.
         *  By saving it on every interrupt, all we have to do is pop it
         *  near the end of every interrupt.
         */

nested:
        incl      SYM (_ISR_Nest_level)     # one nest level deeper
        incl      SYM (_Thread_Dispatch_disable_level) # disable
multitasking
 /*
  * re-enable interrupts at processor level as the current
  * interrupt source is now masked via i8259
  */

       rdtsc                                                       # this is
my patch  EDX:EAX -  number of CPU cycles since power up
       mov       eax,SYM (old_rdtsc) (,ecx,4)    # this is my patch  save
ticks

       sti


        /*
  *  ECX is preloaded with the vector number but it is a scratch register
  *  so we must save it again.
  */

        pushl     ecx                       # push vector number

        mov       SYM (current_irq) (,ecx,4),eax
                                            # eax = Users handler
        call      *eax                      # invoke user ISR
 /*
  * disable interrupts_again
  */
 cli
    popl       ecx                       # ecx = vector number

    rdtsc                                                         # this is
my patch
    sub    SYM (old_rdtsc) (,ecx,4), eax         # this is my patch
    cmp    eax, SYM (max_rdtsc) (,ecx,4)      # this is my patch
    jnb    .dont_update_max_rdtsc                  # this is my patch
    mov    eax, SYM (max_rdtsc) (,ecx,4)      # this is my patch  (store
maximum of interrupt duration)
.dont_update_max_rdtsc:

 /*
  * restore stack
  */
 movl   ebp, esp
 popl   ebp
  ...

BEGIN_DATA                                          # this is my patch

SYM(old_rdtsc):                                        # this is my patch
 .rept 16                                                     # this is my
patch
 .long 0                                                       # this is my
patch
 .endr                                                         # this is my
patch

PUBLIC (max_rdtsc)                                 # this is my patch
SYM(max_rdtsc):                                      # this is my patch
 .rept 16                                                     # this is my
patch
 .long 0                                                       # this is my
patch
 .endr                                                         # this is my
patch

END_DATA                                             # this is my patch

and here is a C fragment

#define CONFIGURE_INIT
#include <rtems.h>

rtems_task Init( rtems_task_argument argument );

/* configuration information */
#include <bsp.h>

#define CONFIGURE_APPLICATION_NEEDS_CONSOLE_DRIVER
#define CONFIGURE_APPLICATION_NEEDS_CLOCK_DRIVER
#define CONFIGURE_MAXIMUM_TASKS              32
#define CONFIGURE_MAXIMUM_TIMERS     32
#define CONFIGURE_RTEMS_INIT_TASKS_TABLE
#define CONFIGURE_USE_MINIIMFS_AS_BASE_FILESYSTEM

#include <confdefs.h>
#include <stdio.h>

rtems_id statistics_timer;
extern unsigned int max_rdtsc[];

rtems_timer_service_routine
statistics_fire_proc( rtems_id timer_id, void *unused )
{
 int i;
 for ( i=0; i<16; i++ ) {
  if ( (i&7) == 0 ) printf("\n");
  printf("t%d:%u ",i,max_rdtsc[i]);
  max_rdtsc[i] = 0;
 }
 printf("\n");
 rtems_timer_reset( timer_id );
}

rtems_task Init(
  rtems_task_argument ignored
)
{
 rtems_status_code status;
 rtems_name name;
 rtems_interval ticks_per_second;

 rtems_clock_get( RTEMS_CLOCK_GET_TICKS_PER_SECOND, &ticks_per_second );

 name = rtems_build_name( 'T', 'E', 'S', 'T' );
 status = rtems_timer_create( name, &statistics_timer );
 if ( status != RTEMS_SUCCESSFUL ) rtems_fatal_error_occurred(status);

 status = rtems_timer_fire_after( statistics_timer,
          ticks_per_second,
          statistics_fire_proc,
          NULL);
 if ( status != RTEMS_SUCCESSFUL ) rtems_fatal_error_occurred(status);
 printf( "\n\ninterrupt measurement start.\n" );
 rtems_task_suspend( RTEMS_SELF );
}


1. After start, IRQ0 - 52313 ( 417 microseconds on my PC )
2. After 20-30 seconds, IRQ0 - 3250835 ticks ( 26 ms !!! on my PC )

What I do wrong ?


> Andrew Maximov wrote:
> >
> > RTEMS: rtems-4.5.0
> > BSP: pc586
> >
> > I have a question about interrupt duration.
> > I change irq_asm.S for interrupt duration measurement.
> > This is a result of interrupt duration measurement.
> >
> > IRQ0  - 4596784 ticks ( rdtsc intstruction )
> > IRQ1  - 0
> > ...
> > IRQ10 - 8321/4601374 ( this is my device )
> > ...
> > IRQ15 - 0
> >
> > By default all IRQs has equal priority, therefore
> > IRQ10 can be interrupted by IRQ0. And process time of
> > IRQ10 is increasing.
> > I solved this problem by increasing priority of IRQ10.
> > But why IRQ0 has such long process time ?
> > IRQ0 handler call rtems_clock_tick().
>
> First doesn't rdtsc read the number of CPU cycles
> since power up?  That means that 8321 is only
> about 8.3 microseconds for a 100 Mhz part or
> 2.1 for a 400 Mhz part.
>
> On the i386, interrupts do not nest unless the handlers
> make special provisions to lower interrupts.  If you
> think you are measuring nested interrupts, then
> my suspicion is that your start/end time marks are
> not matched like you think.
>
> rtems_clock_tick() has a O(n) in it based upon the number
> of time events that fire at the same clock tick.  For example,
> if the delay for 10 tasks ends on the same clock tick, there
> will be 10 unblocking operations.  But I doubt this is
> what you are seeing.
>
>
  ------------------------------------------------------------------------
> >                 Name: irq_asm.S
> >    irq_asm.S    Type: unspecified type (application/octet-stream)
> >             Encoding: quoted-printable
>
> --
> Joel Sherrill, Ph.D.             Director of Research & Development
> joel at OARcorp.com                 On-Line Applications Research
> Ask me about RTEMS: a free RTOS  Huntsville AL 35805
>    Support Available             (256) 722-9985
>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: test.tar.gz
Type: application/x-compressed
Size: 4296 bytes
Desc: not available
URL: <http://lists.rtems.org/pipermail/users/attachments/20010511/c7fc142a/attachment-0001.bin>


More information about the users mailing list