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

[Ingo Molnar <mingo@elte.hu>]

* Steven Rostedt <rostedt@goodmis.org> wrote:

> 
> 
> On Wed, 25 Feb 2009, Ingo Molnar wrote:
> 
> > 
> > * Steven Rostedt <rostedt@goodmis.org> wrote:
> > 
> > > > #                _------=> 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.
> > > 
> > > 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.

That is something that is sane to have as a default anyway. It 
always annoys me that i have to start looking at a trace by 
subtracting the first timestamp from the last timestamp.

	Ingo