lkml.org 
[lkml]   [2009]   [Feb]   [25]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: [PATCH 2/4] tracing: add event trace infrastructure

    * 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


    \
     
     \ /
      Last update: 2009-02-26 04:23    [W:4.131 / U:0.100 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site