Re: [patch] Real-Time Preemption, -RT-2.6.11-rc3-V0.7.38-01

[Lee Revell]

On Fri, 2005-02-04 at 11:03 +0100, Ingo Molnar wrote:
>   http://redhat.com/~mingo/realtime-preempt/
> 

Testing on an all SCSI 1.3Ghz Athlon XP system, I am seeing very long
latencies in the journalling code with 2.6.11-rc4-RT-V0.7.39-02.

preemption latency trace v1.1.4 on 2.6.11-rc4-RT-V0.7.39-02
--------------------------------------------------------------------
 latency: 713 µs, #3455/3455, CPU#0 | (M:preempt VP:0, KP:1, SP:1 HP:1 #P:1)
    -----------------
    | task: ksoftirqd/0-2 (uid:0 nice:-10 policy:0 rt_prio:0)
    -----------------

                 _------=> CPU#        
                / _-----=> irqs-off        
               | / _----=> need-resched    
               || / _---=> hardirq/softirq 
               ||| / _--=> preempt-depth   
               |||| /        
               |||||     delay        
   cmd     pid ||||| time  |   caller      
      \   /    |||||   \   |   /        
kjournal-2478  0dn.4    0µs!: <756f6a6b> (<6c616e72>)
kjournal-2478  0dn.4    0µs : __trace_start_sched_wakeup (try_to_wake_up)
kjournal-2478  0dn.3    0µs : preempt_schedule (try_to_wake_up)
kjournal-2478  0dn.3    0µs : try_to_wake_up <<...>-2> (69 73): 
kjournal-2478  0dn.2    0µs : preempt_schedule (try_to_wake_up)
kjournal-2478  0dn.2    0µs : wake_up_process (do_softirq)
kjournal-2478  0dn.1    1µs < (1)

The repeating pattern is 8 of these:

kjournal-2478  0.n.1    1µs : inverted_lock (journal_commit_transaction)
kjournal-2478  0.n.1    1µs : __journal_unfile_buffer (journal_commit_transaction)
kjournal-2478  0.n.1    1µs : journal_remove_journal_head (journal_commit_transaction)
kjournal-2478  0.n.1    1µs : __journal_remove_journal_head (journal_remove_journal_head)
kjournal-2478  0.n.1    1µs : __brelse (__journal_remove_journal_head)
kjournal-2478  0.n.1    1µs : journal_free_journal_head (journal_remove_journal_head)
kjournal-2478  0.n.1    2µs : kmem_cache_free (journal_free_journal_head)

and one of these:

kjournal-2478  0dn.1    9µs : cache_flusharray (kmem_cache_free)
kjournal-2478  0dn.2    9µs : free_block (cache_flusharray)
kjournal-2478  0dn.1   11µs : preempt_schedule (cache_flusharray)
kjournal-2478  0dn.1   11µs : memmove (cache_flusharray)
kjournal-2478  0dn.1   11µs : memcpy (memmove)

etc.  Finally:

kjournal-2478  0dn.1  704µs : cache_flusharray (kmem_cache_free)
kjournal-2478  0dn.2  704µs+: free_block (cache_flusharray)
kjournal-2478  0dn.1  707µs : preempt_schedule (cache_flusharray)
kjournal-2478  0dn.1  707µs : memmove (cache_flusharray)
kjournal-2478  0dn.1  707µs : memcpy (memmove)
kjournal-2478  0.n.1  708µs : inverted_lock (journal_commit_transaction)
kjournal-2478  0.n.1  708µs : __journal_unfile_buffer (journal_commit_transaction)
kjournal-2478  0.n.1  709µs : journal_remove_journal_head (journal_commit_transaction)
kjournal-2478  0.n.1  709µs : __journal_remove_journal_head (journal_remove_journal_head)
kjournal-2478  0.n.1  709µs : __brelse (__journal_remove_journal_head)
kjournal-2478  0.n.1  709µs : journal_free_journal_head (journal_remove_journal_head)
kjournal-2478  0.n.1  709µs : kmem_cache_free (journal_free_journal_head)
kjournal-2478  0.n..  710µs : preempt_schedule (journal_commit_transaction)
kjournal-2478  0dn..  710µs : __schedule (preempt_schedule)
kjournal-2478  0dn..  710µs : profile_hit (__schedule)
kjournal-2478  0dn.1  710µs : sched_clock (__schedule)
kjournal-2478  0dn.2  711µs : dequeue_task (__schedule)
kjournal-2478  0dn.2  711µs : recalc_task_prio (__schedule)
kjournal-2478  0dn.2  711µs : effective_prio (recalc_task_prio)
kjournal-2478  0dn.2  711µs : enqueue_task (__schedule)
   <...>-2     0d..2  712µs : __switch_to (__schedule)
   <...>-2     0d..2  712µs : __schedule <kjournal-2478> (73 69):
   <...>-2     0d..2  712µs : finish_task_switch (__schedule)
   <...>-2     0d..1  712µs : trace_stop_sched_switched (finish_task_switch)
   <...>-2     0d..1  712µs : trace_stop_sched_switched <<...>-2> (69 0):
   <...>-2     0d..1  713µs : trace_stop_sched_switched (finish_task_switch)

Lee

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/