Re: [PATCH 2/4] tracing: add event trace infrastructure [LWN.net]

From:		Andrew Morton <akpm-AT-linux-foundation.org>
To:		Pekka Enberg <penberg-AT-cs.helsinki.fi>
Subject:		Re: [PATCH 2/4] tracing: add event trace infrastructure
Date:		Wed, 25 Feb 2009 01:44:42 -0800
Message-ID:		<20090225014442.7b7b7726.akpm@linux-foundation.org>
Cc:		Ingo Molnar <mingo-AT-elte.hu>, Steven Rostedt <rostedt-AT-goodmis.org>, LKML <linux-kernel-AT-vger.kernel.org>, Thomas Gleixner <tglx-AT-linutronix.de>, Peter Zijlstra <peterz-AT-infradead.org>, Frederic Weisbecker <fweisbec-AT-gmail.com>, Theodore Tso <tytso-AT-mit.edu>, Arjan van de Ven <arjan-AT-infradead.org>, Pekka Paalanen <pq-AT-iki.fi>, Arnaldo Carvalho de Melo <acme-AT-redhat.com>, Jason Baron <jbaron-AT-redhat.com>, Martin Bligh <mbligh-AT-google.com>, Mathieu Desnoyers <compudj-AT-krystal.dyndns.org>, "Frank Ch. Eigler" <fche-AT-redhat.com>, KOSAKI Motohiro <kosaki.motohiro-AT-jp.fujitsu.com>, Jens Axboe <jens.axboe-AT-oracle.com>, Masami Hiramatsu <mhiramat-AT-redhat.com>, Steven Rostedt <srostedt-AT-redhat.com>
Archive-link:		Article, Thread

On Wed, 25 Feb 2009 11:33:07 +0200 Pekka Enberg <penberg@cs.helsinki.fi> wrote:

> Hi Andrew,
> 
> On Wed, 2009-02-25 at 01:22 -0800, Andrew Morton wrote:
> > irqsoff latency trace v1.1.5 on 2.6.26-rc8
> > --------------------------------------------------------------------
> >  latency: 97 us, #3/3, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:2)
> >     -----------------
> >     | task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0)
> >     -----------------
> >  => started at: apic_timer_interrupt
> >  => ended at:   do_softirq
> 
> <the header seems broken here, should have # at the beginning of the line>
> 
> > 
> > #                _------=> CPU#
> > #               / _-----=> irqs-off
> > #              | / _----=> need-resched
> > #              || / _---=> hardirq/softirq
> > #              ||| / _--=> preempt-depth
> > #              |||| /
> > #              |||||     delay
> > #  cmd     pid ||||| time  |   caller
> > #     \   /    |||||   \   |   /
> >   <idle>-0     0d..1    0us+: trace_hardirqs_off_thunk (apic_timer_interrupt)
> >   <idle>-0     0d.s.   97us : __do_softirq (do_softirq)
> >   <idle>-0     0d.s1   98us : trace_hardirqs_on (do_softirq)
> > 
> > your time starts now.
> 
> Well, what do you want to know? The first thing to do here is to:
> 
> $ grep -v "#" trace 
>   <idle>-0     0d..1    0us+: trace_hardirqs_off_thunk (apic_timer_interrupt)
>   <idle>-0     0d.s.   97us : __do_softirq (do_softirq)
>   <idle>-0     0d.s1   98us : trace_hardirqs_on (do_softirq)
> 
> after which you have access to the raw data. This particular trace seems
> to be somewhat hard to parse (because not all fields are whitespace
> delimited) but I can assure you that any format I rely on is not.

yes, but now you need to think about how this interface would have been
designed if we'd decided to access it with something smarter than
`cat'.

I mean, look at it.  All the multi-space column lining upping, the
unnecessary "us" annotation, the strange symbol(symbol) thing, etc. 
Plus it would have been more self-describing.  Right now, your parser
has to either assume that the second character of "0d..1" is
"irqs-off", or it has to learn how to follow ascii art lines.

Plus...  it's all English-only.

> So if you're arguing against specific ftrace plugins, go ahead (you
> probably have a fair point there). But please don't dismiss the while
> _concept_ of ftrace because of them.

Where on earth did that come from?

What I'm arguing against is putting English-only pretty-printers and
pretty-parsers on wrong side of int 80.  That's all.

(Log in to post comments)