Messages in this thread | | | Date | Mon, 23 Jul 2007 18:44:21 +0200 | From | John Sigler <> | Subject | Re: Pin-pointing the root of unusual application latencies |
| |
Ingo Molnar wrote:
> add 'notrace' to the definition of read_tsc in arch/i386/kernel/tsc.c
OK.
> (or do echo 1 > /proc/sys/kernel/trace_use_raw_cycles > if you are using recent enough -rt)
Is patch-2.6.20-rt8 recent enough?
# ./trace-it 1 >trace # cat trace preemption latency trace v1.1.5 on 2.6.20.7-rt8 -------------------------------------------------------------------- latency: 1000034 us, #10083/10083, CPU#0 | (M:rt VP:0, KP:0, SP:1 HP:1) ----------------- | task: trace-it-939 (uid:0 nice:0 policy:0 rt_prio:0) -----------------
_------=> CPU# / _-----=> irqs-off | / _----=> need-resched || / _---=> hardirq/softirq ||| / _--=> preempt-depth |||| / ||||| delay cmd pid ||||| time | caller \ / ||||| \ | / trace-it-939 0D... 0us : user_trace_start (sys_prctl) trace-it-939 0.... 0us : rt_up (user_trace_start) trace-it-939 0...1 1us : rt_mutex_unlock (rt_up) trace-it-939 0D... 1us+< (0) trace-it-939 0.... 4us > sys_rt_sigprocmask (00000000 bfadff4c 000000d8) trace-it-939 0.... 5us : sys_rt_sigprocmask (sysenter_past_esp) trace-it-939 0.... 5us : copy_from_user (sys_rt_sigprocmask) trace-it-939 0.... 5us : __copy_from_user_ll (copy_from_user) trace-it-939 0.... 5us : sigprocmask (sys_rt_sigprocmask) trace-it-939 0.... 5us : __lock_text_start (sigprocmask) trace-it-939 0.... 6us : recalc_sigpending (sigprocmask) [...] <idle>-0 0DN.. 1000027us : __sched_text_start (cpu_idle) <idle>-0 0DN.1 1000027us : __sched_text_start (c0100f30 0 0) <idle>-0 0DN.1 1000027us : sched_clock (__sched_text_start) <idle>-0 0D..2 1000028us : __switch_to (__sched_text_start) trace-it-939 0D..2 1000028us : __sched_text_start <<idle>-0> (20 -2) trace-it-939 0D..1 1000029us : trace_stop_sched_switched (__sched_text_start) trace-it-939 0.... 1000029us : hrtimer_cancel (do_nanosleep) trace-it-939 0.... 1000030us : hrtimer_try_to_cancel (hrtimer_cancel) trace-it-939 0D... 1000031us < (0) trace-it-939 0.... 1000032us > sys_prctl (00000000 00000000 000000d8) trace-it-939 0.... 1000032us : sys_prctl (sysenter_past_esp) trace-it-939 0.... 1000032us : user_trace_stop (sys_prctl) trace-it-939 0D... 1000033us : user_trace_stop (sys_prctl)
This looks better.
I will let my test program run overnight.
Regards. - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
| |