From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1761556AbZBYWsV (ORCPT ); Wed, 25 Feb 2009 17:48:21 -0500 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1752882AbZBYWsK (ORCPT ); Wed, 25 Feb 2009 17:48:10 -0500 Received: from hrndva-omtalb.mail.rr.com ([71.74.56.123]:48172 "EHLO hrndva-omtalb.mail.rr.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751788AbZBYWsJ (ORCPT ); Wed, 25 Feb 2009 17:48:09 -0500 Date: Wed, 25 Feb 2009 17:48:06 -0500 (EST) From: Steven Rostedt X-X-Sender: rostedt@gandalf.stny.rr.com To: Ingo Molnar cc: Andrew Morton , Pekka Enberg , LKML , Thomas Gleixner , Peter Zijlstra , Frederic Weisbecker , Theodore Tso , Arjan van de Ven , Pekka Paalanen , Arnaldo Carvalho de Melo , Jason Baron , Martin Bligh , Mathieu Desnoyers , "Frank Ch. Eigler" , KOSAKI Motohiro , Jens Axboe , Masami Hiramatsu , Steven Rostedt Subject: Re: [PATCH 2/4] tracing: add event trace infrastructure In-Reply-To: <20090225155709.GA12732@elte.hu> Message-ID: References: <20090225025608.956691460@goodmis.org> <20090225025753.798204550@goodmis.org> <20090224194548.3effb746.akpm@linux-foundation.org> <20090224203308.8d623e0b.akpm@linux-foundation.org> <20090225081118.GC15303@elte.hu> <20090225002852.5ef5b869.akpm@linux-foundation.org> <84144f020902250100k41e55dd7w8a9c8d2ca96908ea@mail.gmail.com> <20090225012250.db68e480.akpm@linux-foundation.org> <20090225155709.GA12732@elte.hu> User-Agent: Alpine 2.00 (DEB 1167 2008-08-23) MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Wed, 25 Feb 2009, Ingo Molnar wrote: > > * Steven Rostedt wrote: > > > > # _------=> CPU# > > > # / _-----=> irqs-off > > > # | / _----=> need-resched > > > # || / _---=> hardirq/softirq > > > # ||| / _--=> preempt-depth > > > # |||| / > > > # ||||| delay > > > # cmd pid ||||| time | caller > > > # \ / ||||| \ | / > > > -0 0d..1 0us+: trace_hardirqs_off_thunk (apic_timer_interrupt) > > > -0 0d.s. 97us : __do_softirq (do_softirq) > > > -0 0d.s1 98us : trace_hardirqs_on (do_softirq) > [...] > > > > > > your time starts now. > > > > Note, that is a legacy format, that works great for the > > latency tracers. Those include (the example you used) irqsoff, > > the preempt off, wake up latencies. This gives us a nice > > listing of why we are hitting a latency. All other plugins > > generally use the trace file, although they could also use > > that file too. > > > > As for your English comment. I showed the header to my wife, > > and she had no idea what irqs-off means, nor need-resched, nor > > preempt-depth ;-) They are not quite English as they are > > technical terms. Most of the names are hard coded into the > > kernel too. > > > > Yeah, maybe that file (latency_trace) is a bit too much. I for > > one love it. It is great to load a kernel on some remote box, > > and run the irqs off latency tracer to see where the > > interrupts are disabled for the longest time. This format is > > really nice because it shows me when we are in an interrupt, > > or interrupts are disabled, and when the task should have been > > rescheduled. > > > > This has help find places that we miss a preemption check too. > > Could we get that, as PeterZ has suggested, as a trace_option > column in the 'trace' file? It would be default off for > non-latency tracers, with latency tracing plugins turning it on > by default. Would that work? I guess adding options will be a high priority for me now. I can't parse irqsoff output anymore :-( Besides the information of the ..... area, the times were all based off of the start of the trace, not global. This allowed you to see the latency in the trace. -- Steve