linux-kernel - Re: Pin-pointing the root of unusual application latencies

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [thread-next>] [day] [month] [year] [list]

Message-ID: <20070723095357.GA886@elte.hu>
Date:	Mon, 23 Jul 2007 11:53:57 +0200
From:	Ingo Molnar <mingo@...e.hu>
To:	John Sigler <linux.kernel@...e.fr>
Cc:	linux-rt-users@...r.kernel.org,
	oprofile-list@...ts.sourceforge.net, linux-kernel@...r.kernel.org
Subject: Re: Pin-pointing the root of unusual application latencies

* John Sigler <linux.kernel@...e.fr> wrote:

> Here's a /proc/latency_trace dump. What is there to understand?
> 
> # cat /proc/latency_trace
> preemption latency trace v1.1.5 on 2.6.20.7-rt8
> --------------------------------------------------------------------
>  latency: 26 us, #2/2, CPU#0 | (M:rt VP:0, KP:0, SP:1 HP:1)
>     -----------------
>     | task: softirq-timer/0-4 (uid:0 nice:0 policy:1 rt_prio:50)
>     -----------------
> 
>                  _------=> CPU#
>                 / _-----=> irqs-off
>                | / _----=> need-resched
>                || / _---=> hardirq/softirq
>                ||| / _--=> preempt-depth
>                |||| /
>                |||||     delay
>    cmd     pid ||||| time  |   caller
>       \   /    |||||   \   |   /
>    <...>-4     0D..1   26us : trace_stop_sched_switched 
> (__sched_text_start)

could you try:

 http://redhat.com/~mingo/latency-tracing-patches/trace-it.c

and run it like this:

 ./trace-it 1 > trace.txt

does it produce lots of trace entries? If not then 
CONFIG_FUNCTION_TRACING is not enabled. Once you see lots of output in 
the file, the tracer is up and running and you can start tracing the 
latency in your app.

your above wakeup-tracing output suggests that your app is probably not 
delayed by scheduling latencies, but by some other, higher-level 
latencies.

To track it down, use the method that trace-it.c uses to start/stop 
tracing, i.e. put the prctl(0,1); / prctl(0,0); calls into your app to 
start/stop tracing and the kernel will do the rest once you've set 
/proc/sys/kernel/preempt_max_latency back to 0: /proc/latency_trace will 
always contain the longest latency that your app triggered, of the 
critical path you programmed into it.

also check the cyclictest source of how to do app-driven latency 
tracing. (And please post any latency traces to this list, we might be 
able to pinpoint the source of the latencies.)

	Ingo
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/