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....

Thanks,

Mathieu

Here is my config :


#
# Automatically generated make config: don't edit
# Linux kernel version: 2.6.27-rc3
# Tue Aug 19 18:39:06 2008
#
CONFIG_64BIT=y
# CONFIG_X86_32 is not set
CONFIG_X86_64=y
CONFIG_X86=y
CONFIG_ARCH_DEFCONFIG="arch/x86/configs/x86_64_defconfig"
# CONFIG_GENERIC_LOCKBREAK is not ...
[ message continues ]

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

--

[ message continues ]