Re: [patch] Real-Time Preemption, -RT-2.6.12-rc6-V0.7.48-00

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On Thu, 23 Jun 2005, Ingo Molnar wrote:

> these are all the first type of latencies, which seem to be hardware 
> related. Could you try to boot the UP kernel, do you see these latencies 
> there too? (if yes then please post those too)

On -50-11 UP, the ~200us idle is still showing up in the traces.  This
idle time, however, seems to be at random points within the trace.  Some
of the traces attached are nearly identical except for where the ~200us
jump happens to fall.  Hardware induced latency?

--ww
preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.50-11-up-debug
--------------------------------------------------------------------
 latency: 221 us, #29/29, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: softirq-timer/0-3 (uid:0 nice:-10 policy:0 rt_prio:0)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
     cc1-4654  0Dnh3    0us : <00316363> (<66747200>)
     cc1-4654  0Dnh3    0us : __trace_start_sched_wakeup (try_to_wake_up)
     cc1-4654  0Dnh3    0us : __trace_start_sched_wakeup <<...>-3> (69 0)
     cc1-4654  0Dnh2    0us : try_to_wake_up <<...>-3> (69 7b)
     cc1-4654  0Dnh1    0us : preempt_schedule (try_to_wake_up)
     cc1-4654  0Dnh1    0us : wake_up_process (trigger_softirqs)
     cc1-4654  0Dnh.    0us : __schedule (work_resched)
     cc1-4654  0Dnh.    0us : profile_hit (__schedule)
     cc1-4654  0Dnh1    1us : sched_clock (__schedule)
     cc1-4654  0Dnh2    2us : dequeue_task (__schedule)
     cc1-4654  0Dnh2    2us : recalc_task_prio (__schedule)
     cc1-4654  0Dnh2    2us : effective_prio (recalc_task_prio)
     cc1-4654  0Dnh2    2us : enqueue_task (__schedule)
     cc1-4654  0Dnh2    2us : trace_array (__schedule)
     cc1-4654  0Dnh2    3us : trace_array <<...>-3> (69 6e)
     cc1-4654  0Dnh2    3us : trace_array <cc1-4654> (7b 78)
     cc1-4654  0Dnh2    3us : trace_array <<...>-3592> (7d 82)
     cc1-4654  0Dnh2    4us : trace_array <<...>-3588> (7d 82)
     cc1-4654  0Dnh2    4us : trace_array <<...>-3586> (7d 82)
     cc1-4654  0Dnh2    4us : trace_array <<...>-3587> (7d 82)
     cc1-4654  0Dnh2    4us : trace_array <<...>-3589> (7d 82)
     cc1-4654  0Dnh2    5us : trace_array <<...>-3594> (7e 82)
     cc1-4654  0Dnh2    5us : trace_array (__schedule)
   <...>-3     0Dnh2    7us : __switch_to (__schedule)
   <...>-3     0Dnh2    8us : __schedule <cc1-4654> (7b 69)
   <...>-3     0Dnh1    8us!: trace_stop_sched_switched (__schedule)
   <...>-3     0Dnh2  220us : trace_stop_sched_switched <<...>-3> (69 0)
   <...>-3     0Dnh1  221us : trace_stop_sched_switched (__schedule)


vim:ft=help
preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.50-11-up-debug
--------------------------------------------------------------------
 latency: 217 us, #29/29, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: softirq-timer/0-3 (uid:0 nice:-10 policy:0 rt_prio:0)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
       X-2790  0Dnh3    0us : <2d6d0058> (<616e6962>)
       X-2790  0Dnh3    0us : __trace_start_sched_wakeup (try_to_wake_up)
       X-2790  0Dnh3    0us : __trace_start_sched_wakeup <<...>-3> (69 0)
       X-2790  0Dnh2    0us : try_to_wake_up <<...>-3> (69 74)
       X-2790  0Dnh1    0us!: preempt_schedule (try_to_wake_up)
       X-2790  0Dnh1  211us : wake_up_process (trigger_softirqs)
       X-2790  0Dnh.  211us : preempt_schedule_irq (need_resched)
       X-2790  0Dnh.  211us : __schedule (preempt_schedule_irq)
       X-2790  0Dnh.  212us : profile_hit (__schedule)
       X-2790  0Dnh1  212us : sched_clock (__schedule)
       X-2790  0Dnh2  212us : dequeue_task (__schedule)
       X-2790  0Dnh2  212us : recalc_task_prio (__schedule)
       X-2790  0Dnh2  212us : effective_prio (recalc_task_prio)
       X-2790  0Dnh2  212us : enqueue_task (__schedule)
       X-2790  0Dnh2  212us : trace_array (__schedule)
       X-2790  0Dnh2  213us : trace_array <<...>-3> (69 6e)
       X-2790  0Dnh2  213us : trace_array <X-2790> (74 78)
       X-2790  0Dnh2  214us : trace_array <<...>-3588> (7d 82)
       X-2790  0Dnh2  214us : trace_array <<...>-3586> (7d 82)
       X-2790  0Dnh2  214us : trace_array <<...>-3587> (7d 82)
       X-2790  0Dnh2  214us : trace_array <<...>-3589> (7d 82)
       X-2790  0Dnh2  214us : trace_array (__schedule)
       X-2790  0Dnh2  215us : trace_array <<...>-6004> (7d 78)
   <...>-3     0Dnh2  216us : __switch_to (__schedule)
   <...>-3     0Dnh2  216us : __schedule <X-2790> (74 69)
   <...>-3     0Dnh1  216us : trace_stop_sched_switched (__schedule)
   <...>-3     0Dnh2  217us : trace_stop_sched_switched <<...>-3> (69 0)
   <...>-3     0Dnh1  217us : trace_stop_sched_switched (__schedule)


vim:ft=help
preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.50-11-up-debug
--------------------------------------------------------------------
 latency: 208 us, #30/30, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: softirq-timer/0-3 (uid:0 nice:-10 policy:0 rt_prio:0)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
     vlc-8511  0Dnh3    0us : <00636c76> (<6f000000>)
     vlc-8511  0Dnh3    0us : __trace_start_sched_wakeup (try_to_wake_up)
     vlc-8511  0Dnh3    0us : __trace_start_sched_wakeup <<...>-3> (69 0)
     vlc-8511  0Dnh2    0us : try_to_wake_up <<...>-3> (69 73)
     vlc-8511  0Dnh1    0us!: preempt_schedule (try_to_wake_up)
     vlc-8511  0Dnh1  200us : wake_up_process (trigger_softirqs)
     vlc-8511  0Dnh.  201us : __schedule (work_resched)
     vlc-8511  0Dnh.  201us : profile_hit (__schedule)
     vlc-8511  0Dnh1  201us : sched_clock (__schedule)
     vlc-8511  0Dnh2  201us : dequeue_task (__schedule)
     vlc-8511  0Dnh2  201us : recalc_task_prio (__schedule)
     vlc-8511  0Dnh2  202us : effective_prio (recalc_task_prio)
     vlc-8511  0Dnh2  202us : enqueue_task (__schedule)
     vlc-8511  0Dnh2  202us : trace_array (__schedule)
     vlc-8511  0Dnh2  203us : trace_array <<...>-3> (69 6e)
     vlc-8511  0Dnh2  203us : trace_array <<...>-2790> (73 78)
     vlc-8511  0Dnh2  203us : trace_array <vlc-8511> (73 78)
     vlc-8511  0Dnh2  203us : trace_array <<...>-8766> (7d 78)
     vlc-8511  0Dnh2  203us : trace_array <<...>-3592> (7d 82)
     vlc-8511  0Dnh2  204us : trace_array <<...>-3588> (7d 82)
     vlc-8511  0Dnh2  204us : trace_array <<...>-3587> (7d 82)
     vlc-8511  0Dnh2  204us : trace_array <<...>-3586> (7d 82)
     vlc-8511  0Dnh2  204us : trace_array <<...>-3589> (7d 82)
     vlc-8511  0Dnh2  205us : trace_array (__schedule)
   <...>-3     0Dnh2  206us : __switch_to (__schedule)
   <...>-3     0Dnh2  207us : __schedule <vlc-8511> (73 69)
   <...>-3     0Dnh1  207us : trace_stop_sched_switched (__schedule)
   <...>-3     0Dnh2  208us : trace_stop_sched_switched <<...>-3> (69 0)
   <...>-3     0Dnh1  208us : trace_stop_sched_switched (__schedule)


vim:ft=help
preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.50-11-up-debug
--------------------------------------------------------------------
 latency: 229 us, #32/32, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: IRQ 10-1010 (uid:0 nice:-5 policy:1 rt_prio:41)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
     vlc-8510  0dnh3    0us : <00636c76> (<6f000000>)
     vlc-8510  0dnh3    0us : __trace_start_sched_wakeup (try_to_wake_up)
     vlc-8510  0dnh3    0us : __trace_start_sched_wakeup <<...>-1010> (3a 0)
     vlc-8510  0dnh2    0us : try_to_wake_up <<...>-1010> (3a 73)
     vlc-8510  0dnh1    0us : preempt_schedule (try_to_wake_up)
     vlc-8510  0dnh1    0us : wake_up_process (redirect_hardirq)
     vlc-8510  0dnh1    0us!: disable_8259A_irq (__do_IRQ)
     vlc-8510  0dnh1  223us : preempt_schedule (__do_IRQ)
     vlc-8510  0dnh.  223us : preempt_schedule (__do_IRQ)
     vlc-8510  0dnh.  223us : local_irq_restore (__do_IRQ)
     vlc-8510  0dnh.  223us : check_soft_flags (local_irq_restore)
     vlc-8510  0Dnh.  223us : preempt_schedule (__do_IRQ)
     vlc-8510  0Dnh.  224us : irq_exit (do_IRQ)
     vlc-8510  0Dnh.  224us : __schedule (work_resched)
     vlc-8510  0Dnh.  224us : profile_hit (__schedule)
     vlc-8510  0Dnh1  224us : sched_clock (__schedule)
     vlc-8510  0Dnh2  224us : trace_array (__schedule)
     vlc-8510  0Dnh2  225us : trace_array <<...>-1010> (3a 3a)
     vlc-8510  0Dnh2  225us : trace_array <vlc-8510> (73 78)
     vlc-8510  0Dnh2  226us : trace_array <<...>-8790> (7c 78)
     vlc-8510  0Dnh2  226us : trace_array <<...>-3592> (7d 82)
     vlc-8510  0Dnh2  226us : trace_array <<...>-3588> (7d 82)
     vlc-8510  0Dnh2  226us : trace_array <<...>-3587> (7d 82)
     vlc-8510  0Dnh2  226us : trace_array <<...>-3586> (7d 82)
     vlc-8510  0Dnh2  226us : trace_array <<...>-3589> (7d 82)
     vlc-8510  0Dnh2  226us : trace_array (__schedule)
   <...>-1010  0Dnh2  228us : __switch_to (__schedule)
   <...>-1010  0Dnh2  228us : __schedule <vlc-8510> (73 3a)
   <...>-1010  0Dnh1  228us : trace_stop_sched_switched (__schedule)
   <...>-1010  0Dnh2  228us : trace_stop_sched_switched <<...>-1010> (3a 0)
   <...>-1010  0Dnh1  229us : trace_stop_sched_switched (__schedule)


vim:ft=help
preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.50-11-up-debug
--------------------------------------------------------------------
 latency: 208 us, #33/33, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: IRQ 10-1010 (uid:0 nice:-5 policy:1 rt_prio:41)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
     vlc-8511  0dnh3    0us : <00636c76> (<6f000000>)
     vlc-8511  0dnh3    0us : __trace_start_sched_wakeup (try_to_wake_up)
     vlc-8511  0dnh3    0us : __trace_start_sched_wakeup <<...>-1010> (3a 0)
     vlc-8511  0dnh2    0us : try_to_wake_up <<...>-1010> (3a 73)
     vlc-8511  0dnh1    0us : preempt_schedule (try_to_wake_up)
     vlc-8511  0dnh1    0us : wake_up_process (redirect_hardirq)
     vlc-8511  0dnh1    0us : disable_8259A_irq (__do_IRQ)
     vlc-8511  0dnh1    1us : preempt_schedule (__do_IRQ)
     vlc-8511  0dnh.    1us : preempt_schedule (__do_IRQ)
     vlc-8511  0dnh.    1us : local_irq_restore (__do_IRQ)
     vlc-8511  0dnh.    1us : check_soft_flags (local_irq_restore)
     vlc-8511  0Dnh.    2us : preempt_schedule (__do_IRQ)
     vlc-8511  0Dnh.    2us : irq_exit (do_IRQ)
     vlc-8511  0Dnh.    2us : __schedule (work_resched)
     vlc-8511  0Dnh.    2us : profile_hit (__schedule)
     vlc-8511  0Dnh1    2us : sched_clock (__schedule)
     vlc-8511  0Dnh2    2us : trace_array (__schedule)
     vlc-8511  0Dnh2    3us : trace_array <<...>-1010> (3a 3a)
     vlc-8511  0Dnh2    3us : trace_array <<...>-8039> (73 78)
     vlc-8511  0Dnh2    3us : trace_array <vlc-8511> (73 78)
     vlc-8511  0Dnh2    4us : trace_array <<...>-9298> (7b 78)
     vlc-8511  0Dnh2    4us : trace_array <<...>-3588> (7d 82)
     vlc-8511  0Dnh2    4us : trace_array <<...>-3592> (7d 82)
     vlc-8511  0Dnh2    4us : trace_array <<...>-3586> (7d 82)
     vlc-8511  0Dnh2    4us : trace_array <<...>-3587> (7d 82)
     vlc-8511  0Dnh2    4us : trace_array <<...>-3589> (7d 82)
     vlc-8511  0Dnh2    4us!: trace_array (__schedule)
   <...>-1010  0Dnh2  207us : __switch_to (__schedule)
   <...>-1010  0Dnh2  208us : __schedule <vlc-8511> (73 3a)
   <...>-1010  0Dnh1  208us : trace_stop_sched_switched (__schedule)
   <...>-1010  0Dnh2  208us : trace_stop_sched_switched <<...>-1010> (3a 0)
   <...>-1010  0Dnh1  208us : trace_stop_sched_switched (__schedule)


vim:ft=help
preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.50-11-up-debug
--------------------------------------------------------------------
 latency: 231 us, #32/32, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: softirq-timer/0-3 (uid:0 nice:-10 policy:0 rt_prio:0)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
     tee-10092 0Dnh3    0us!: <00656574> (<6f000000>)
     tee-10092 0Dnh3  222us : __trace_start_sched_wakeup (try_to_wake_up)
     tee-10092 0Dnh3  222us : __trace_start_sched_wakeup <<...>-3> (69 0)
     tee-10092 0Dnh2  222us : try_to_wake_up <<...>-3> (69 73)
     tee-10092 0Dnh1  222us : preempt_schedule (try_to_wake_up)
     tee-10092 0Dnh1  222us : wake_up_process (trigger_softirqs)
     tee-10092 0Dnh.  223us : preempt_schedule_irq (need_resched)
     tee-10092 0Dnh.  223us : __schedule (preempt_schedule_irq)
     tee-10092 0Dnh.  223us : profile_hit (__schedule)
     tee-10092 0Dnh1  224us : sched_clock (__schedule)
     tee-10092 0Dnh2  224us : dequeue_task (__schedule)
     tee-10092 0Dnh2  224us : recalc_task_prio (__schedule)
     tee-10092 0Dnh2  224us : effective_prio (recalc_task_prio)
     tee-10092 0Dnh2  224us : enqueue_task (__schedule)
     tee-10092 0Dnh2  224us : trace_array (__schedule)
     tee-10092 0Dnh2  226us : trace_array <<...>-3> (69 6e)
     tee-10092 0Dnh2  226us : trace_array <tee-10092> (73 78)
     tee-10092 0Dnh2  226us : trace_array <<...>-4794> (73 78)
     tee-10092 0Dnh2  226us : trace_array <<...>-8283> (73 78)
     tee-10092 0Dnh2  227us : trace_array <<...>-4659> (74 78)
     tee-10092 0Dnh2  227us : trace_array <<...>-10089> (7b 78)
     tee-10092 0Dnh2  227us : trace_array <<...>-3592> (7d 82)
     tee-10092 0Dnh2  227us : trace_array <<...>-3588> (7d 82)
     tee-10092 0Dnh2  228us : trace_array <<...>-3586> (7d 82)
     tee-10092 0Dnh2  228us : trace_array <<...>-3587> (7d 82)
     tee-10092 0Dnh2  228us : trace_array (__schedule)
   <...>-3     0Dnh2  230us : __switch_to (__schedule)
   <...>-3     0Dnh2  230us : __schedule <tee-10092> (73 69)
   <...>-3     0Dnh1  230us : trace_stop_sched_switched (__schedule)
   <...>-3     0Dnh2  231us : trace_stop_sched_switched <<...>-3> (69 0)
   <...>-3     0Dnh1  231us : trace_stop_sched_switched (__schedule)


vim:ft=help
preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.50-11-up-debug
--------------------------------------------------------------------
 latency: 208 us, #28/28, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: softirq-timer/0-3 (uid:0 nice:-10 policy:0 rt_prio:0)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
     cc1-11149 0Dnh3    0us : <00316363> (<66747200>)
     cc1-11149 0Dnh3    0us : __trace_start_sched_wakeup (try_to_wake_up)
     cc1-11149 0Dnh3    0us : __trace_start_sched_wakeup <<...>-3> (69 0)
     cc1-11149 0Dnh2    0us : try_to_wake_up <<...>-3> (69 78)
     cc1-11149 0Dnh1    0us : preempt_schedule (try_to_wake_up)
     cc1-11149 0Dnh1    0us : wake_up_process (trigger_softirqs)
     cc1-11149 0Dnh.    0us : __schedule (work_resched)
     cc1-11149 0Dnh.    1us : profile_hit (__schedule)
     cc1-11149 0Dnh1    1us : sched_clock (__schedule)
     cc1-11149 0Dnh2    1us!: dequeue_task (__schedule)
     cc1-11149 0Dnh2  202us : recalc_task_prio (__schedule)
     cc1-11149 0Dnh2  202us : effective_prio (recalc_task_prio)
     cc1-11149 0Dnh2  202us : enqueue_task (__schedule)
     cc1-11149 0Dnh2  203us : trace_array (__schedule)
     cc1-11149 0Dnh2  204us : trace_array <<...>-3> (69 6e)
     cc1-11149 0Dnh2  204us : trace_array <cc1-11149> (78 78)
     cc1-11149 0Dnh2  204us : trace_array <<...>-3592> (7d 82)
     cc1-11149 0Dnh2  204us : trace_array <<...>-3588> (7d 82)
     cc1-11149 0Dnh2  204us : trace_array <<...>-3587> (7d 82)
     cc1-11149 0Dnh2  205us : trace_array <<...>-3586> (7d 82)
     cc1-11149 0Dnh2  205us : trace_array <<...>-3589> (7d 82)
     cc1-11149 0Dnh2  205us : trace_array (__schedule)
   <...>-3     0Dnh2  207us : __switch_to (__schedule)
   <...>-3     0Dnh2  207us : __schedule <cc1-11149> (78 69)
   <...>-3     0Dnh1  207us : trace_stop_sched_switched (__schedule)
   <...>-3     0Dnh2  208us : trace_stop_sched_switched <<...>-3> (69 0)
   <...>-3     0Dnh1  208us : trace_stop_sched_switched (__schedule)


vim:ft=help
preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.50-11-up-debug
--------------------------------------------------------------------
 latency: 213 us, #32/32, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: IRQ 14-254 (uid:0 nice:-5 policy:1 rt_prio:45)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
softirq--7     0dnh3    0us : <74666f73> (<2d717269>)
softirq--7     0dnh3    0us : __trace_start_sched_wakeup (try_to_wake_up)
softirq--7     0dnh3    0us : __trace_start_sched_wakeup <<...>-254> (36 0)
softirq--7     0dnh2    0us : try_to_wake_up <<...>-254> (36 3a)
softirq--7     0dnh1    0us : preempt_schedule (try_to_wake_up)
softirq--7     0dnh1    0us : wake_up_process (redirect_hardirq)
softirq--7     0dnh1    0us : disable_8259A_irq (__do_IRQ)
softirq--7     0dnh1    1us : preempt_schedule (__do_IRQ)
softirq--7     0dnh.    1us : preempt_schedule (__do_IRQ)
softirq--7     0dnh.    1us : local_irq_restore (__do_IRQ)
softirq--7     0dnh.    1us : check_soft_flags (local_irq_restore)
softirq--7     0Dnh.    1us : preempt_schedule (__do_IRQ)
softirq--7     0Dnh.    1us!: irq_exit (do_IRQ)
softirq--7     0Dnh.  209us : preempt_schedule_irq (need_resched)
softirq--7     0Dnh.  209us : __schedule (preempt_schedule_irq)
softirq--7     0Dnh.  209us : profile_hit (__schedule)
softirq--7     0Dnh1  209us : sched_clock (__schedule)
softirq--7     0Dnh2  210us : trace_array (__schedule)
softirq--7     0Dnh2  210us : trace_array <<...>-254> (36 36)
softirq--7     0Dnh2  210us : trace_array <softirq--7> (3a 6e)
softirq--7     0Dnh2  211us : trace_array <<...>-11476> (7b 78)
softirq--7     0Dnh2  211us : trace_array <<...>-3588> (7d 82)
softirq--7     0Dnh2  211us : trace_array <<...>-3592> (7d 82)
softirq--7     0Dnh2  211us : trace_array <<...>-3586> (7d 82)
softirq--7     0Dnh2  211us : trace_array <<...>-3587> (7d 82)
softirq--7     0Dnh2  211us : trace_array (__schedule)
   <...>-254   0Dnh2  213us : __switch_to (__schedule)
   <...>-254   0Dnh2  213us : __schedule <softirq--7> (3a 36)
   <...>-254   0Dnh1  213us : trace_stop_sched_switched (__schedule)
   <...>-254   0Dnh2  213us : trace_stop_sched_switched <<...>-254> (36 0)
   <...>-254   0Dnh1  213us : trace_stop_sched_switched (__schedule)


vim:ft=help
preemption latency trace v1.1.4 on 2.6.12-RT-V0.7.50-11-up-debug
--------------------------------------------------------------------
 latency: 224 us, #33/33, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: IRQ 10-1010 (uid:0 nice:-5 policy:1 rt_prio:41)
    -----------------

                 _------=> CPU#            
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /                      
               |||||     delay             
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /           
     vlc-8039  0dnh3    0us : <00636c76> (<6f000000>)
     vlc-8039  0dnh3    0us : __trace_start_sched_wakeup (try_to_wake_up)
     vlc-8039  0dnh3    0us : __trace_start_sched_wakeup <<...>-1010> (3a 0)
     vlc-8039  0dnh2    0us : try_to_wake_up <<...>-1010> (3a 73)
     vlc-8039  0dnh1    0us : preempt_schedule (try_to_wake_up)
     vlc-8039  0dnh1    0us : wake_up_process (redirect_hardirq)
     vlc-8039  0dnh1    0us : disable_8259A_irq (__do_IRQ)
     vlc-8039  0dnh1    1us : preempt_schedule (__do_IRQ)
     vlc-8039  0dnh.    1us : preempt_schedule (__do_IRQ)
     vlc-8039  0dnh.    1us : local_irq_restore (__do_IRQ)
     vlc-8039  0dnh.    2us : check_soft_flags (local_irq_restore)
     vlc-8039  0Dnh.    2us : preempt_schedule (__do_IRQ)
     vlc-8039  0Dnh.    2us : irq_exit (do_IRQ)
     vlc-8039  0Dnh.    2us : __schedule (work_resched)
     vlc-8039  0Dnh.    2us : profile_hit (__schedule)
     vlc-8039  0Dnh1    2us : sched_clock (__schedule)
     vlc-8039  0Dnh2    3us : trace_array (__schedule)
     vlc-8039  0Dnh2    3us!: trace_array <<...>-1010> (3a 3a)
     vlc-8039  0Dnh2  219us : trace_array <vlc-8039> (73 78)
     vlc-8039  0Dnh2  219us : trace_array <<...>-7919> (74 78)
     vlc-8039  0Dnh2  220us : trace_array <<...>-11600> (7c 78)
     vlc-8039  0Dnh2  220us : trace_array <<...>-3592> (7d 82)
     vlc-8039  0Dnh2  220us : trace_array <<...>-3588> (7d 82)
     vlc-8039  0Dnh2  220us : trace_array <<...>-3586> (7d 82)
     vlc-8039  0Dnh2  220us : trace_array <<...>-3587> (7d 82)
     vlc-8039  0Dnh2  220us : trace_array <<...>-3589> (7d 82)
     vlc-8039  0Dnh2  221us : trace_array (__schedule)
   <...>-1010  0Dnh2  222us : __switch_to (__schedule)
   <...>-1010  0Dnh2  223us : __schedule <vlc-8039> (73 3a)
   <...>-1010  0Dnh1  224us : trace_stop_sched_switched (__schedule)
   <...>-1010  0Dnh2  224us : trace_stop_sched_switched <<...>-1010> (3a 0)
   <...>-1010  0Dnh1  224us : trace_stop_sched_switched (__schedule)


vim:ft=help

[Index of Archives]     [Kernel Newbies]     [Netfilter]     [Bugtraq]     [Photo]     [Stuff]     [Gimp]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Video 4 Linux]     [Linux for the blind]     [Linux Resources]
  Powered by Linux