How to use latency trace

How to use latency trace

[Gerrit Binnenmars]

Hello,

Below is a latency trace from cyclictest at a pentm4 1.8G with cyclictest stopping the
latency tracer at a latency of 25us.
The disknoise script is running in the background together with a self made loadgen appl.
The latency is in the 5th line from the bottom in clockevents_program_events, a function 
which in most cases only takes one us.
Why is it now taking 40us? Or is sys_getdents64() causing the problem?

Another question: can you ever guarantee a max. latency if a user has access to the system?

> preemption latency trace v1.1.5 on 2.6.22.1-rt4
> --------------------------------------------------------------------
> latency: 1832319 us, #65536/3501832508, CPU#0 | (M:rt VP:0, KP:0, SP:1
> HP:1)
> -----------------
> | task: cyclictest-647 (uid:0 nice:0 policy:1 rt_prio:80)
> -----------------
> => started at: sys_prctl+0x21/0x1a4 
> => ended at: 0
> 
> loadgen-738 0D..2 439508us!: __schedule+0x3c4/0x4f3 (150 0)
> loadgen-738 0D.h. 439745us : do_IRQ+0x96/0xfb (8048563 17 0)
> loadgen-738 0D.h1 439745us : try_to_wake_up+0x19/0x188 (c0115f37 0 0)
> loadgen-738 0D.h2 439746us : activate_task+0x83/0xce (150 1)
> loadgen-738 0DN.1 439747us : __schedule+0xb7/0x4f3 (c0102afa 0 0)
> IRQ-17-294 0D..2 439748us : __schedule+0x3c4/0x4f3 (0 150)
> IRQ-17-294 0D.h. 439748us+: do_IRQ+0x96/0xfb (c035c1aa 17 0)
> IRQ-17-294 0D..1 439763us : __schedule+0xb7/0x4f3 (c035c18c 0 0)
> IRQ-17-294 0D..2 439763us : deactivate_task+0x83/0xce (150 2)
> loadgen-738 0D..2 439764us+: __schedule+0x3c4/0x4f3 (150 0)
> loadgen-738 0D.h. 439795us : do_IRQ+0x96/0xfb (8048563 17 0)
> loadgen-738 0D.h1 439795us : try_to_wake_up+0x19/0x188 (c0115f37 0 0)
> loadgen-738 0D.h2 439796us : activate_task+0x83/0xce (150 1)
> loadgen-738 0DN.1 439797us : __schedule+0xb7/0x4f3 (c0102afa 0 0)
> IRQ-17-294 0D..2 439798us : __schedule+0x3c4/0x4f3 (0 150)
> IRQ-17-294 0D.h. 439798us+: do_IRQ+0x96/0xfb (c01487e3 17 0)
> IRQ-17-294 0.... 439819us : try_to_wake_up+0x19/0x188 (c0115e57 0 0)
> IRQ-17-294 0D..1 439819us+: activate_task+0x83/0xce (0 2)
> IRQ-17-294 0D..1 439825us : __schedule+0xb7/0x4f3 (c035c18c 0 0)
> IRQ-17-294 0D..2 439825us : deactivate_task+0x83/0xce (150 3)
> find-742 0D..2 439826us!: __schedule+0x3c4/0x4f3 (150 0)
> find-742 0.... 440000us > sys_getdents64+0x0/0xb2 (00000004 080cc054 00000000)
> find-742 0D..1 440000us : smp_apic_timer_interrupt+0x2d/0x97 (c02329c9 1 0)
> find-742 0D.h1 440001us : hrtimer_interrupt+0x60/0x20a (54040878530431 0)
> find-742 0D.h2 440001us : hrtimer_interrupt+0xef/0x20a (54040878529874 -134680768)
> find-742 0D.h2 440002us : try_to_wake_up+0x19/0x188 (c0115f37 0 0)
> find-742 0D.h3 440002us : activate_task+0x83/0xce (180 2)
> find-742 0DNh3 440003us : try_to_wake_up+0x15a/0x188 (180 0)
> find-742 0DNh1 440003us+: clockevents_program_event+0x33/0xb2 (54040879000000 467212)
> find-742 0DN.1 440043us : __schedule+0xb7/0x4f3 (c035bffe 0 0)
> cyclicte-647 0D..2 440045us : __schedule+0x3c4/0x4f3 (0 180)
> cyclicte-647 0.... 440046us > sys_clock_gettime+0x0/0x9c (00000001 b7f2c448 00000000)
> cyclicte-647 0.... 440047us > sys_prctl+0x0/0x1a4 (00000000 00000000 00000000)

Re: How to use latency trace

[Jaswinder Singh]

hello Gerrit Binnenmars,


On 11/2/07, Gerrit Binnenmars <gerritbinnenmars@wanadoo.nl> wrote:
>
> Another question: can you ever guarantee a max. latency if a user has access
> to the system?
>

I do not think so. this shows this is soft real time.

It best example is :

http://rt.wiki.kernel.org/index.php/Cyclictest

you can request for interval for 1000 so it should come 1000 all the
time, but it is not.

Thank you,

Jaswinder Singh.

Re: How to use latency trace

[Sven-Thorsten Dietrich]

On Fri, 2007-11-02 at 17:23 +0530, Jaswinder Singh wrote:
> hello Gerrit Binnenmars,
> 
> 
> On 11/2/07, Gerrit Binnenmars <gerritbinnenmars@wanadoo.nl> wrote:
> >
> > Another question: can you ever guarantee a max. latency if a user has access
> > to the system?
> >
> 

The user could trip over the power chord!

Seriously, users cannot use the high priorities, so apps running above
the user's MAX_PRIO should be safe from whatever the user does.

> I do not think so. this shows this is soft real time.
> 

> It best example is :
> 
> http://rt.wiki.kernel.org/index.php/Cyclictest
> 
> you can request for interval for 1000 so it should come 1000 all the
> time, but it is not.

Its should come CLOSE to 1000. What errors have you seen?

Have you run latency trace on your workload to identify any long
code-paths that need to be cleaned up?

Sven

Re: How to use latency trace

[Jaswinder Singh]

hello Sven,


On Nov 7, 2007 2:43 AM, Sven-Thorsten Dietrich
<sven@thebigcorporation.com> wrote:
> >
> > you can request for interval for 1000 so it should come 1000 all the
> > time, but it is not.
>
> Its should come CLOSE to 1000. What errors have you seen?
>

My errors are min and avg are not equal to ZERO.
And I will be more happy If max is also ZERO :)

> Have you run latency trace on your workload to identify any long
> code-paths that need to be cleaned up?
>

Yes, I need to do it.

Thanks,

Jaswinder Singh.

Re: How to use latency trace

[Gregory Haskins]

>>> On Tue, Nov 13, 2007 at  8:22 AM, in message
<1985e0f60711130522k4ac274d1o42d63abc2c92b83d@mail.gmail.com>, "Jaswinder
Singh" <jaswinderlinuxrt@gmail.com> wrote: 
> hello Sven,
> 
> 
> On Nov 7, 2007 2:43 AM, Sven-Thorsten Dietrich
> <sven@thebigcorporation.com> wrote:
>> >
>> > you can request for interval for 1000 so it should come 1000 all the
>> > time, but it is not.
>>
>> Its should come CLOSE to 1000. What errors have you seen?
>>
> 
> My errors are min and avg are not equal to ZERO.
> And I will be more happy If max is also ZERO :)

Jaswinder,
  As we recently discussed on IRC, this is not an error per se, but a status report of your OS/HW combo.  You will never see zero in cyclictest because the resolution off cyclictest/hrt is higher than the jitter specification of your chosen platform.

There is not an RT system in the world that has zero jitter to my knowledge.  Rather, each OS/HW combo will have some arbitrary jitter specification.   It is then up to the application designer to pick the platform where the specified jitter is lower than the apps tolerances.  Some dedicated hardware and/or RTOS's might spec out in picoseconds or nanoseconds.  Others might in microseconds, milliseconds, etc.

In the case of linux-rt on a modern x86 PC, this spec is generally in the range of 10us-100us.  For instance, an application that needs hard-realtime latencies with no more than 500us jitter, it would probably work great on linux-rt/x86.  Conversely, if you require no more than 500ns jitter, you need to look elsewhere.

So if you are seeing latency spikes> 100us, they should probably be investigated (using latency-trace) as potential bugs in -rt.  However, numbers below that range are probably normal for your system.  We are, of course, always looking to improve these numbers...but as of right now 10us-100us is state of the art.

I hope this helps.
-Greg