preemption latency trace v1.0.6 on 2.6.9-rc1-bk12-VP-R6
--------------------------------------------------
 latency: 945 us, entries: 54 (54)  [VP:1 KP:1 SP:1 HP:1 #CPUS:1]
    -----------------
    | task: X/3030, uid:0 nice:0 policy:0 rt_prio:0
    -----------------
 => started at: cond_resched+0x13/0x80
 => ended at:   sys_ioctl+0x104/0x2c0
=======>
00000001 0.000ms (+0.001ms): touch_preempt_timing (cond_resched)
00000001 0.001ms (+0.000ms): generic_get_mtrr (mtrr_del_page)
00000001 0.002ms (+0.001ms): generic_get_mtrr (mtrr_del_page)
00000001 0.003ms (+0.001ms): generic_get_mtrr (mtrr_del_page)
00000001 0.005ms (+0.000ms): set_mtrr (mtrr_del_page)
00000001 0.005ms (+0.000ms): generic_set_mtrr (set_mtrr)
00000001 0.006ms (+0.867ms): prepare_set (generic_set_mtrr)
00000002 0.874ms (+0.018ms): post_set (set_mtrr)
00010002 0.892ms (+0.000ms): do_IRQ (post_set)
00010002 0.893ms (+0.001ms): do_IRQ (<00000000>)
00010003 0.894ms (+0.003ms): mask_and_ack_8259A (do_IRQ)
00010003 0.897ms (+0.000ms): generic_redirect_hardirq (do_IRQ)
00010002 0.898ms (+0.000ms): generic_handle_IRQ_event (do_IRQ)
00010002 0.899ms (+0.001ms): timer_interrupt (generic_handle_IRQ_event)
00010003 0.900ms (+0.008ms): mark_offset_tsc (timer_interrupt)
00010003 0.908ms (+0.000ms): do_timer (timer_interrupt)
00010003 0.909ms (+0.000ms): update_process_times (do_timer)
00010003 0.909ms (+0.000ms): update_one_process (update_process_times)
00010003 0.910ms (+0.000ms): run_local_timers (update_process_times)
00010003 0.911ms (+0.000ms): raise_softirq (update_process_times)
00010003 0.912ms (+0.000ms): scheduler_tick (update_process_times)
00010003 0.912ms (+0.004ms): sched_clock (scheduler_tick)
00010004 0.916ms (+0.001ms): task_timeslice (scheduler_tick)
00010004 0.918ms (+0.000ms): dequeue_task (scheduler_tick)
00010004 0.919ms (+0.000ms): effective_prio (scheduler_tick)
00010004 0.919ms (+0.000ms): enqueue_task (scheduler_tick)
00010003 0.920ms (+0.001ms): preempt_schedule (scheduler_tick)
00010003 0.921ms (+0.000ms): update_wall_time (do_timer)
00010003 0.922ms (+0.001ms): update_wall_time_one_tick (update_wall_time)
00010003 0.923ms (+0.000ms): profile_tick (timer_interrupt)
00010003 0.924ms (+0.000ms): profile_hook (profile_tick)
00010004 0.924ms (+0.000ms): notifier_call_chain (profile_hook)
00010003 0.925ms (+0.000ms): preempt_schedule (profile_tick)
00010003 0.925ms (+0.000ms): profile_hit (timer_interrupt)
00010002 0.926ms (+0.001ms): preempt_schedule (timer_interrupt)
00010003 0.927ms (+0.000ms): generic_note_interrupt (do_IRQ)
00010003 0.928ms (+0.000ms): end_8259A_irq (do_IRQ)
00010003 0.928ms (+0.001ms): enable_8259A_irq (do_IRQ)
00010003 0.930ms (+0.000ms): preempt_schedule (do_IRQ)
00010002 0.930ms (+0.000ms): preempt_schedule (do_IRQ)
00000003 0.931ms (+0.000ms): do_softirq (do_IRQ)
00000003 0.932ms (+0.001ms): __do_softirq (do_softirq)
00000003 0.933ms (+0.000ms): wake_up_process (do_softirq)
00000003 0.933ms (+0.000ms): try_to_wake_up (wake_up_process)
00000003 0.933ms (+0.000ms): task_rq_lock (try_to_wake_up)
00000004 0.934ms (+0.000ms): activate_task (try_to_wake_up)
00000004 0.934ms (+0.000ms): sched_clock (activate_task)
00000004 0.935ms (+0.001ms): recalc_task_prio (activate_task)
00000004 0.936ms (+0.000ms): effective_prio (recalc_task_prio)
00000004 0.937ms (+0.000ms): enqueue_task (activate_task)
00000003 0.937ms (+0.001ms): preempt_schedule (try_to_wake_up)
00000001 0.939ms (+0.006ms): preempt_schedule (set_mtrr)
00000001 0.946ms (+0.000ms): sub_preempt_count (sys_ioctl)
00000001 0.947ms (+0.000ms): update_max_trace (check_preempt_timing)