preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.51-06
--------------------------------------------------------------------
 latency: 54 us, #93/93, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: softirq-net-rx/-5 (uid:0 nice:-10 policy:0 rt_prio:0)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
   <...>-3142  0dnh2    0us!: <5f6f696b> (<70747468>)
   <...>-3142  0dnh2    0us : __trace_start_sched_wakeup (try_to_wake_up)
   <...>-3142  0dnh2    0us : __trace_start_sched_wakeup <softirq--5> (69 0)
   <...>-3142  0dnh1    1us+: try_to_wake_up <softirq--5> (69 76)
   <...>-3142  0dnh.    4us : do_IRQ (c0117743 0 0)
   <...>-3142  0dnh.    5us : __local_irq_save (__do_IRQ)
   <...>-3142  0dnh1    5us+: mask_and_ack_8259A (__do_IRQ)
   <...>-3142  0dnh1   12us : preempt_schedule (__do_IRQ)
   <...>-3142  0dnh1   12us : redirect_hardirq (__do_IRQ)
   <...>-3142  0dnh.   13us : preempt_schedule (__do_IRQ)
   <...>-3142  0dnh.   13us : handle_IRQ_event (__do_IRQ)
   <...>-3142  0dnh.   14us : timer_interrupt (handle_IRQ_event)
   <...>-3142  0dnh1   14us : mark_offset_tsc (timer_interrupt)
   <...>-3142  0dnh1   16us : preempt_schedule (mark_offset_tsc)
   <...>-3142  0dnh1   16us : preempt_schedule (mark_offset_tsc)
   <...>-3142  0dnh1   16us : do_timer (timer_interrupt)
   <...>-3142  0dnh1   17us : update_process_times (timer_interrupt)
   <...>-3142  0dnh1   17us : account_system_time (update_process_times)
   <...>-3142  0dnh1   18us : update_mem_hiwater (update_process_times)
   <...>-3142  0dnh1   19us : run_local_timers (update_process_times)
   <...>-3142  0dnh1   19us : raise_softirq (update_process_times)
   <...>-3142  0dnh1   20us : rcu_check_callbacks (update_process_times)
   <...>-3142  0dnh1   21us : idle_cpu (rcu_check_callbacks)
   <...>-3142  0dnh1   21us : __tasklet_schedule (update_process_times)
   <...>-3142  0dnh1   21us : scheduler_tick (update_process_times)
   <...>-3142  0dnh1   22us : sched_clock (scheduler_tick)
   <...>-3142  0dnh1   22us : preempt_schedule (scheduler_tick)
   <...>-3142  0dnh1   23us : softlockup_tick (timer_interrupt)
   <...>-3142  0dnh.   23us : preempt_schedule (timer_interrupt)
   <...>-3142  0dnh1   24us : note_interrupt (__do_IRQ)
   <...>-3142  0dnh1   24us : end_8259A_irq (__do_IRQ)
   <...>-3142  0dnh1   25us+: enable_8259A_irq (__do_IRQ)
   <...>-3142  0dnh1   28us : preempt_schedule (__do_IRQ)
   <...>-3142  0dnh.   28us : preempt_schedule (__do_IRQ)
   <...>-3142  0dnh.   28us : local_irq_restore (__do_IRQ)
   <...>-3142  0dnh.   29us : irq_exit (do_IRQ)
   <...>-3142  0dnh1   29us : do_softirq (irq_exit)
   <...>-3142  0dnh1   29us : __local_irq_save (do_softirq)
   <...>-3142  0dnh1   30us : __do_softirq (do_softirq)
   <...>-3142  0dnh1   30us : trigger_softirqs (do_softirq)
   <...>-3142  0dnh1   30us : wakeup_softirqd (trigger_softirqs)
   <...>-3142  0dnh1   31us : wake_up_process (trigger_softirqs)
   <...>-3142  0dnh1   31us : try_to_wake_up (wake_up_process)
   <...>-3142  0dnh1   31us : activate_task (try_to_wake_up)
   <...>-3142  0dnh1   32us : sched_clock (activate_task)
   <...>-3142  0dnh1   32us : recalc_task_prio (activate_task)
   <...>-3142  0dnh1   33us : effective_prio (recalc_task_prio)
   <...>-3142  0dnh1   33us : activate_task <<...>-3> (69 4)
   <...>-3142  0dnh1   33us : enqueue_task (activate_task)
   <...>-3142  0dnh1   34us : __trace_start_sched_wakeup (try_to_wake_up)
   <...>-3142  0dnh1   34us : preempt_schedule (try_to_wake_up)
   <...>-3142  0dnh1   34us : try_to_wake_up <<...>-3> (69 76)
   <...>-3142  0dnh1   35us : preempt_schedule (try_to_wake_up)
   <...>-3142  0dnh1   35us : wake_up_process (trigger_softirqs)
   <...>-3142  0dnh1   36us : wakeup_softirqd (trigger_softirqs)
   <...>-3142  0dnh1   36us : wakeup_softirqd (trigger_softirqs)
   <...>-3142  0dnh1   36us : wake_up_process (trigger_softirqs)
   <...>-3142  0dnh1   36us : try_to_wake_up (wake_up_process)
   <...>-3142  0dnh1   37us : activate_task (try_to_wake_up)
   <...>-3142  0dnh1   37us : sched_clock (activate_task)
   <...>-3142  0dnh1   38us : recalc_task_prio (activate_task)
   <...>-3142  0dnh1   38us : effective_prio (recalc_task_prio)
   <...>-3142  0dnh1   38us : activate_task <<...>-7> (69 5)
   <...>-3142  0dnh1   38us : enqueue_task (activate_task)
   <...>-3142  0dnh1   39us : __trace_start_sched_wakeup (try_to_wake_up)
   <...>-3142  0dnh1   39us : preempt_schedule (try_to_wake_up)
   <...>-3142  0dnh1   39us : try_to_wake_up <<...>-7> (69 76)
   <...>-3142  0dnh1   40us : preempt_schedule (try_to_wake_up)
   <...>-3142  0dnh1   40us : wake_up_process (trigger_softirqs)
   <...>-3142  0dnh1   40us : local_irq_restore (do_softirq)
   <...>-3142  0dnh.   41us < (2097760)
   <...>-3142  0dn..   42us : preempt_schedule (try_to_wake_up)
   <...>-3142  0dn..   42us : wake_up_process (trigger_softirqs)
   <...>-3142  0dn..   43us : local_irq_restore (netif_rx)
   <...>-3142  0dn..   43us : get_sample_stats (netif_rx)
   <...>-3142  0dn..   43us : local_irq_restore (netif_rx)
   <...>-3142  0Dn..   44us : preempt_schedule (netif_rx)
   <...>-3142  0Dn..   44us : irqs_disabled (preempt_schedule)
   <...>-3142  0Dnh.   44us : __schedule (preempt_schedule)
   <...>-3142  0Dnh.   45us : profile_hit (__schedule)
   <...>-3142  0Dnh1   45us : sched_clock (__schedule)
   <...>-3142  0Dnh2   46us : dequeue_task (__schedule)
   <...>-3142  0Dnh2   46us : recalc_task_prio (__schedule)
   <...>-3142  0Dnh2   47us : effective_prio (recalc_task_prio)
   <...>-3142  0Dnh2   47us : enqueue_task (__schedule)
softirq--5     0Dnh2   49us : __switch_to (__schedule)
softirq--5     0Dnh2   50us : __schedule <<...>-3142> (76 69)
softirq--5     0Dnh2   50us : finish_task_switch (__schedule)
softirq--5     0Dnh1   51us : trace_stop_sched_switched (finish_task_switch)
softirq--5     0Dnh2   51us : trace_stop_sched_switched <softirq--5> (69 0)
softirq--5     0Dnh2   52us : trace_stop_sched_switched (finish_task_switch)


vim:ft=help