Messages in this thread | | | Date | Tue, 19 Aug 2008 19:13:12 -0400 | From | Steven Rostedt <> | Subject | Re: ftrace bad timings (was: No Subject) |
| |
Mathieu Desnoyers wrote: > Hi Steven, > > I am currently trying to get precise numbers on the interrupt latency > generated by a heavy load on my new writer-biased rwlock (previously > known as fair rwlock). > > However, when trying to use the irqoff tracer, I hit this : > > # tracer: irqsoff > # > irqsoff latency trace v1.1.5 on 2.6.27-rc3-trace > -------------------------------------------------------------------- > latency: 3995 us, #3/3, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:8) > ----------------- > | task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0) > ----------------- > => started at: apic_timer_interrupt > => ended at: __do_softirq > > # _------=> 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.s2 3995us+: __do_softirq (0) > <idle>-0 0d.s3 3997us : trace_hardirqs_on (__do_softirq) > > Is it known/does it have a solution ? I would really like to be able to > see sub 4ms numbers.... > > >
Could you go into kernel/trace/trace.c and search for ftrace_now. Then change cpu_clock to sched_clock. cpu_clock is known to give large inaccurate timings and is not reliable with ftrace. Unfortunately, sched_clock can be bad on various hardware, but should always be fine for preempt and irqs off latency timings since that is always local to a single CPU.
-- Steve
| |