preemption latency trace v1.0.7 on 2.6.9-rc1-bk12-VP-S0
-------------------------------------------------------
 latency: 218 us, entries: 35 (35)   |   [VP:1 KP:1 SP:1 HP:1 #CPUS:1]
    -----------------
    | task: gnome-panel/3036, uid:0 nice:0 policy:0 rt_prio:0
    -----------------
 => started at: __spin_lock_irqsave+0x2b/0xa2
 => ended at:   _spin_unlock_irqrestore+0x1c/0x36
=======>
00000001 0.000ms (+0.204ms): __spin_lock_irqsave (add_wait_queue)
00010001 0.204ms (+0.000ms): do_IRQ (add_preempt_count)
00010001 0.204ms (+0.000ms): do_IRQ (<00000000>)
00010001 0.205ms (+0.000ms): spin_lock (do_IRQ)
00010002 0.205ms (+0.000ms): spin_lock (<00000000>)
00010002 0.205ms (+0.000ms): ack_edge_ioapic_irq (do_IRQ)
00010002 0.205ms (+0.000ms): redirect_hardirq (do_IRQ)
00010002 0.205ms (+0.000ms): _spin_unlock (do_IRQ)
00010001 0.206ms (+0.000ms): handle_IRQ_event (do_IRQ)
00010001 0.206ms (+0.000ms): timer_interrupt (handle_IRQ_event)
00010001 0.206ms (+0.000ms): spin_lock (timer_interrupt)
00010002 0.206ms (+0.000ms): spin_lock (<00000000>)
00010002 0.206ms (+0.000ms): mark_offset_tsc (timer_interrupt)
00010002 0.206ms (+0.000ms): spin_lock (mark_offset_tsc)
00010003 0.207ms (+0.000ms): spin_lock (<00000000>)
00010003 0.207ms (+0.000ms): spin_lock (mark_offset_tsc)
00010004 0.207ms (+0.005ms): spin_lock (<00000000>)
00010004 0.213ms (+0.000ms): _spin_unlock (mark_offset_tsc)
00010003 0.213ms (+0.000ms): _spin_unlock (mark_offset_tsc)
00010002 0.213ms (+0.000ms): spin_lock (timer_interrupt)
00010003 0.213ms (+0.001ms): spin_lock (<00000000>)
00010003 0.215ms (+0.000ms): _spin_unlock (timer_interrupt)
00010002 0.215ms (+0.000ms): do_timer (timer_interrupt)
00010002 0.215ms (+0.000ms): update_wall_time (do_timer)
00010002 0.215ms (+0.000ms): update_wall_time_one_tick (update_wall_time)
00010002 0.216ms (+0.000ms): _spin_unlock (timer_interrupt)
00010001 0.216ms (+0.000ms): spin_lock (do_IRQ)
00010002 0.216ms (+0.000ms): spin_lock (<00000000>)
00010002 0.216ms (+0.000ms): note_interrupt (do_IRQ)
00010002 0.216ms (+0.000ms): end_edge_ioapic_irq (do_IRQ)
00010002 0.217ms (+0.000ms): _spin_unlock (do_IRQ)
00000001 0.217ms (+0.000ms): __spin_lock_irqsave (<00000000>)
00000001 0.217ms (+0.000ms): _spin_unlock_irqrestore (add_wait_queue)
00000001 0.218ms (+0.000ms): sub_preempt_count (_spin_unlock_irqrestore)
00000001 0.218ms (+0.000ms): update_max_trace (check_preempt_timing)