Re: rt20 scheduling latency testcase and failure data

["Sébastien Dugué" <sebastien.dugue@bull.net>]

On Mon, 2006-05-15 at 18:30 -0700, Darren Hart wrote:
> Following Ingo's example I have included the modified test case (please see 
> the original mail for librt.h) that starts the trace before each sleep and 
> disables it after we wake up.  If we have missed a period, we print the 
> trace.
> 
 <snip>
>   The very first run 
> failed, (I've noticed that the first iteration seems to always hit PERIOD 
> MISSED! while the second usually passes fine).

  I've noticed also that, on some occasions, the first run would fail,
but subsequent runs would be fine. Strange!

  I finally managed to hit a missed period under heavy heavy load:

Running 100000 iterations with a period of 5 ms
Expected running time: 500 s

ITERATION DELAY(US) MAX_DELAY(US) FAILURES
--------- --------- ------------- --------
      211        70            97        0

PERIOD MISSED!
     scheduled delta:     3128 us
        actual delta:     3191 us
             latency:       62 us
---------------------------------------
      previous start:  1055070 us
                 now:  1060172 us
     scheduled start:  1060000 us
next scheduled start is in the past!


Start Latency:  198 us: FAIL
Min Latency:      6 us: PASS
Avg Latency:      0 us: PASS
Max Latency:     97 us: PASS
Failed Iterations: 0


  I'll try to trace it now.

>   It's still running a 1M 
> iteration run with no more failures so far (100K so far).
> 
> The latency tracer is a very interesting tool.  I have a few 
> questions/assumptions I'd like to run by you to make sure I understand the 
> output of the latency trace:
> 
> o ! in the delay column means there is a long latency here?

  ! means latency > 100 us

> o + in the delay column means there is a > 1us latency here?

  + means latency > 1 us

> o > means entering the kernel from a sys_call?

  yep

> o < means returning from the sys_call?

  or from interrupt

> o : is not < or >

  yep


  Sébastien.