Re: More latency regressions with 2.6.11-rc4-RT-V0.7.39-02

[Lee Revell <rlrevell@joe-job.com>]

[-- Attachment #1: Type: text/plain, Size: 1106 bytes --]

On Wed, 2005-02-23 at 19:16 +0000, Hugh Dickins wrote:
> On Wed, 23 Feb 2005, Lee Revell wrote:
> > 
> > Did something change recently in the VM that made copy_pte_range and
> > clear_page_range a lot more expensive?  I noticed a reference in the
> > "Page Table Iterators" thread to excessive overhead introduced by
> > aggressive page freeing.  That sure looks like what is going on in
> > trace2.  trace1 and trace3 look like big fork latencies associated with
> > copy_pte_range.
> 
> I'm just about to test this patch below: please give it a try: thanks...
> 
> Ingo's patch to reduce scheduling latencies, by checking for lockbreak
> in copy_page_range, was in the -VP and -mm patchsets some months ago;
> but got preempted by the 4level rework, and not reinstated since.
> Restore it now in copy_pte_range - which mercifully makes it easier.

Aha, that explains why all the latency regressions involve the VM
subsystem. 

Thanks, your patch fixes the copy_pte_range latency.  Now zap_pte_range,
which Ingo also fixed a few months ago, is the worst offender.  Can this
fix be easily ported too?

Lee

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: trace5.txt --]
[-- Type: text/plain; name=trace5.txt; charset=ANSI_X3.4-1968, Size: 12790 bytes --]

preemption latency trace v1.1.4 on 2.6.11-rc4-RT-V0.7.39-02
--------------------------------------------------------------------
 latency: 197 µs, #74/74, 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      
      \   /    |||||   \   |   /           
(T1/#0)            dmesg  3249 0 9 00000002 00000000 [0000163455166655] 0.000ms (+886841.090ms): <73656d64> (<61700067>)
(T1/#2)            dmesg  3249 0 9 00000002 00000002 [0000163455167105] 0.000ms (+0.000ms): __trace_start_sched_wakeup+0x96/0xc0 <c012cbe6> (try_to_wake_up+0x81/0x150 <c010f911>)
(T1/#3)            dmesg  3249 0 9 00000000 00000003 [0000163455167685] 0.001ms (+0.001ms): wake_up_process+0x1c/0x30 <c010f9fc> (do_softirq+0x4b/0x60 <c01042fb>)
(T6/#4)    dmesg-3249  0dn.2    2µs < (1)
(T1/#5)            dmesg  3249 0 2 00000002 00000005 [0000163455168677] 0.003ms (+0.000ms): page_remove_rmap+0x8/0x40 <c0149f78> (zap_pte_range+0x13a/0x250 <c0142f4a>)
(T1/#6)            dmesg  3249 0 2 00000002 00000006 [0000163455168975] 0.003ms (+0.000ms): __mod_page_state+0xa/0x30 <c013a09a> (page_remove_rmap+0x2c/0x40 <c0149f9c>)
(T1/#7)            dmesg  3249 0 2 00000002 00000007 [0000163455169390] 0.004ms (+0.000ms): free_page_and_swap_cache+0x9/0x70 <c014bbb9> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#8)            dmesg  3249 0 2 00000002 00000008 [0000163455169687] 0.005ms (+0.001ms): __page_cache_release+0xb/0xc0 <c013ed4b> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#9)            dmesg  3249 0 2 00000002 00000009 [0000163455170314] 0.006ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (__page_cache_release+0xad/0xc0 <c013eded>)
(T1/#10)            dmesg  3249 0 2 00000002 0000000a [0000163455170636] 0.006ms (+0.000ms): free_hot_page+0x8/0x10 <c0139608> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#11)            dmesg  3249 0 2 00000002 0000000b [0000163455170944] 0.007ms (+0.000ms): free_hot_cold_page+0xe/0x130 <c01394de> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#12)            dmesg  3249 0 2 00000002 0000000c [0000163455171314] 0.007ms (+0.001ms): __mod_page_state+0xa/0x30 <c013a09a> (free_hot_cold_page+0x2a/0x130 <c01394fa>)
(T1/#13)            dmesg  3249 0 2 00000002 0000000d [0000163455172090] 0.009ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#14)            dmesg  3249 0 2 00000002 0000000e [0000163455172432] 0.009ms (+0.000ms): set_page_dirty+0x8/0x60 <c013b428> (zap_pte_range+0x168/0x250 <c0142f78>)
(T1/#15)            dmesg  3249 0 2 00000002 0000000f [0000163455172774] 0.010ms (+0.000ms): page_remove_rmap+0x8/0x40 <c0149f78> (zap_pte_range+0x13a/0x250 <c0142f4a>)
(T1/#16)            dmesg  3249 0 2 00000002 00000010 [0000163455173040] 0.010ms (+0.000ms): __mod_page_state+0xa/0x30 <c013a09a> (page_remove_rmap+0x2c/0x40 <c0149f9c>)
(T1/#17)            dmesg  3249 0 2 00000002 00000011 [0000163455173421] 0.011ms (+0.000ms): free_page_and_swap_cache+0x9/0x70 <c014bbb9> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#18)            dmesg  3249 0 2 00000002 00000012 [0000163455173704] 0.011ms (+0.001ms): __page_cache_release+0xb/0xc0 <c013ed4b> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#19)            dmesg  3249 0 2 00000002 00000013 [0000163455174397] 0.012ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (__page_cache_release+0xad/0xc0 <c013eded>)
(T1/#20)            dmesg  3249 0 2 00000002 00000014 [0000163455174687] 0.013ms (+0.000ms): free_hot_page+0x8/0x10 <c0139608> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#21)            dmesg  3249 0 2 00000002 00000015 [0000163455175101] 0.014ms (+0.000ms): free_hot_cold_page+0xe/0x130 <c01394de> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#22)            dmesg  3249 0 2 00000002 00000016 [0000163455175436] 0.014ms (+0.001ms): __mod_page_state+0xa/0x30 <c013a09a> (free_hot_cold_page+0x2a/0x130 <c01394fa>)
(T1/#23)            dmesg  3249 0 2 00000002 00000017 [0000163455176191] 0.015ms (+0.001ms): preempt_schedule+0xa/0x70 <c027d0fa> (zap_pte_range+0x14c/0x250 <c0142f5c>)
(T1/#24)            dmesg  3249 0 2 00000002 00000018 [0000163455176892] 0.017ms (+0.007ms): clear_page_range+0xe/0x1d0 <c01426fe> (exit_mmap+0xa3/0x1b0 <c0148013>)
(T1/#25)            dmesg  3249 0 2 00000002 00000019 [0000163455181331] 0.024ms (+0.000ms): __mod_page_state+0xa/0x30 <c013a09a> (clear_page_range+0x183/0x1d0 <c0142873>)
(T1/#26)            dmesg  3249 0 2 00000002 0000001a [0000163455181781] 0.025ms (+0.000ms): free_page_and_swap_cache+0x9/0x70 <c014bbb9> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#27)            dmesg  3249 0 2 00000002 0000001b [0000163455182166] 0.025ms (+0.000ms): __page_cache_release+0xb/0xc0 <c013ed4b> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#28)            dmesg  3249 0 2 00000002 0000001c [0000163455182746] 0.026ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (__page_cache_release+0xad/0xc0 <c013eded>)
(T1/#29)            dmesg  3249 0 2 00000002 0000001d [0000163455183036] 0.027ms (+0.000ms): free_hot_page+0x8/0x10 <c0139608> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#30)            dmesg  3249 0 2 00000002 0000001e [0000163455183293] 0.027ms (+0.000ms): free_hot_cold_page+0xe/0x130 <c01394de> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#31)            dmesg  3249 0 2 00000002 0000001f [0000163455183557] 0.028ms (+0.001ms): __mod_page_state+0xa/0x30 <c013a09a> (free_hot_cold_page+0x2a/0x130 <c01394fa>)
(T1/#32)            dmesg  3249 0 2 00000002 00000020 [0000163455184330] 0.029ms (+0.042ms): preempt_schedule+0xa/0x70 <c027d0fa> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#33)            dmesg  3249 0 2 00000002 00000021 [0000163455210040] 0.072ms (+0.000ms): __mod_page_state+0xa/0x30 <c013a09a> (clear_page_range+0x183/0x1d0 <c0142873>)
(T1/#34)            dmesg  3249 0 2 00000002 00000022 [0000163455210487] 0.072ms (+0.000ms): free_page_and_swap_cache+0x9/0x70 <c014bbb9> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#35)            dmesg  3249 0 2 00000002 00000023 [0000163455210867] 0.073ms (+0.001ms): __page_cache_release+0xb/0xc0 <c013ed4b> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#36)            dmesg  3249 0 2 00000002 00000024 [0000163455211481] 0.074ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (__page_cache_release+0xad/0xc0 <c013eded>)
(T1/#37)            dmesg  3249 0 2 00000002 00000025 [0000163455211846] 0.075ms (+0.000ms): free_hot_page+0x8/0x10 <c0139608> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#38)            dmesg  3249 0 2 00000002 00000026 [0000163455212103] 0.075ms (+0.000ms): free_hot_cold_page+0xe/0x130 <c01394de> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#39)            dmesg  3249 0 2 00000002 00000027 [0000163455212367] 0.076ms (+0.001ms): __mod_page_state+0xa/0x30 <c013a09a> (free_hot_cold_page+0x2a/0x130 <c01394fa>)
(T1/#40)            dmesg  3249 0 2 00000002 00000028 [0000163455213164] 0.077ms (+0.088ms): preempt_schedule+0xa/0x70 <c027d0fa> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#41)            dmesg  3249 0 2 00000002 00000029 [0000163455266176] 0.165ms (+0.000ms): __mod_page_state+0xa/0x30 <c013a09a> (clear_page_range+0x183/0x1d0 <c0142873>)
(T1/#42)            dmesg  3249 0 2 00000002 0000002a [0000163455266536] 0.166ms (+0.000ms): free_page_and_swap_cache+0x9/0x70 <c014bbb9> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#43)            dmesg  3249 0 2 00000002 0000002b [0000163455267095] 0.167ms (+0.000ms): __page_cache_release+0xb/0xc0 <c013ed4b> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#44)            dmesg  3249 0 2 00000002 0000002c [0000163455267667] 0.168ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (__page_cache_release+0xad/0xc0 <c013eded>)
(T1/#45)            dmesg  3249 0 2 00000002 0000002d [0000163455268033] 0.168ms (+0.000ms): free_hot_page+0x8/0x10 <c0139608> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#46)            dmesg  3249 0 2 00000002 0000002e [0000163455268375] 0.169ms (+0.000ms): free_hot_cold_page+0xe/0x130 <c01394de> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#47)            dmesg  3249 0 2 00000002 0000002f [0000163455268717] 0.169ms (+0.001ms): __mod_page_state+0xa/0x30 <c013a09a> (free_hot_cold_page+0x2a/0x130 <c01394fa>)
(T1/#48)            dmesg  3249 0 2 00000002 00000030 [0000163455269434] 0.171ms (+0.006ms): preempt_schedule+0xa/0x70 <c027d0fa> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#49)            dmesg  3249 0 2 00000002 00000031 [0000163455273343] 0.177ms (+0.000ms): __mod_page_state+0xa/0x30 <c013a09a> (clear_page_range+0x183/0x1d0 <c0142873>)
(T1/#50)            dmesg  3249 0 2 00000002 00000032 [0000163455273779] 0.178ms (+0.000ms): free_page_and_swap_cache+0x9/0x70 <c014bbb9> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#51)            dmesg  3249 0 2 00000002 00000033 [0000163455274128] 0.178ms (+0.000ms): __page_cache_release+0xb/0xc0 <c013ed4b> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#52)            dmesg  3249 0 2 00000002 00000034 [0000163455274724] 0.179ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (__page_cache_release+0xad/0xc0 <c013eded>)
(T1/#53)            dmesg  3249 0 2 00000002 00000035 [0000163455275084] 0.180ms (+0.000ms): free_hot_page+0x8/0x10 <c0139608> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#54)            dmesg  3249 0 2 00000002 00000036 [0000163455275413] 0.180ms (+0.000ms): free_hot_cold_page+0xe/0x130 <c01394de> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#55)            dmesg  3249 0 2 00000002 00000037 [0000163455275677] 0.181ms (+0.001ms): __mod_page_state+0xa/0x30 <c013a09a> (free_hot_cold_page+0x2a/0x130 <c01394fa>)
(T1/#56)            dmesg  3249 0 2 00000002 00000038 [0000163455276470] 0.182ms (+0.001ms): preempt_schedule+0xa/0x70 <c027d0fa> (clear_page_range+0x1a0/0x1d0 <c0142890>)
(T1/#57)            dmesg  3249 0 2 00000002 00000039 [0000163455277321] 0.184ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (exit_mmap+0x190/0x1b0 <c0148100>)
(T1/#58)            dmesg  3249 0 2 00000001 0000003a [0000163455277715] 0.184ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (exit_mmap+0x164/0x1b0 <c01480d4>)
(T1/#59)            dmesg  3249 0 2 00000000 0000003b [0000163455278192] 0.185ms (+0.000ms): preempt_schedule+0xa/0x70 <c027d0fa> (exit_mmap+0x15d/0x1b0 <c01480cd>)
(T1/#60)            dmesg  3249 0 3 00000000 0000003c [0000163455278638] 0.186ms (+0.000ms): __schedule+0xe/0x630 <c027c9be> (preempt_schedule+0x4f/0x70 <c027d13f>)
(T1/#61)            dmesg  3249 0 3 00000000 0000003d [0000163455278977] 0.186ms (+0.000ms): profile_hit+0x9/0x50 <c0115749> (__schedule+0x3a/0x630 <c027c9ea>)
(T1/#62)            dmesg  3249 0 3 00000001 0000003e [0000163455279418] 0.187ms (+0.001ms): sched_clock+0xe/0xe0 <c010c3ae> (__schedule+0x62/0x630 <c027ca12>)
(T1/#63)            dmesg  3249 0 3 00000002 0000003f [0000163455280259] 0.189ms (+0.000ms): dequeue_task+0xa/0x50 <c010f4ea> (__schedule+0x1ab/0x630 <c027cb5b>)
(T1/#64)            dmesg  3249 0 3 00000002 00000040 [0000163455280596] 0.189ms (+0.000ms): recalc_task_prio+0xc/0x1a0 <c010f64c> (__schedule+0x1c5/0x630 <c027cb75>)
(T1/#65)            dmesg  3249 0 3 00000002 00000041 [0000163455280988] 0.190ms (+0.000ms): effective_prio+0x8/0x50 <c010f5f8> (recalc_task_prio+0xa6/0x1a0 <c010f6e6>)
(T1/#66)            dmesg  3249 0 3 00000002 00000042 [0000163455281297] 0.190ms (+0.000ms): enqueue_task+0xa/0x80 <c010f53a> (__schedule+0x1cc/0x630 <c027cb7c>)
(T4/#67) [ =>            dmesg ] 0.191ms (+0.000ms)
(T1/#68)            <...>     2 0 1 00000002 00000044 [0000163455282330] 0.192ms (+0.000ms): __switch_to+0xb/0x1a0 <c0100f5b> (__schedule+0x2bd/0x630 <c027cc6d>)
(T3/#69)    <...>-2     0d..2  193µs : __schedule+0x2ea/0x630 <c027cc9a> <dmesg-3249> (75 69): 
(T1/#70)            <...>     2 0 1 00000002 00000046 [0000163455283124] 0.193ms (+0.000ms): finish_task_switch+0xc/0x90 <c010fdec> (__schedule+0x2f6/0x630 <c027cca6>)
(T1/#71)            <...>     2 0 1 00000001 00000047 [0000163455283506] 0.194ms (+0.000ms): trace_stop_sched_switched+0xa/0x150 <c012cc1a> (finish_task_switch+0x43/0x90 <c010fe23>)
(T3/#72)    <...>-2     0d..1  194µs : trace_stop_sched_switched+0x42/0x150 <c012cc52> <<...>-2> (69 0): 
(T1/#73)            <...>     2 0 1 00000001 00000049 [0000163455284627] 0.196ms (+0.000ms): trace_stop_sched_switched+0xfe/0x150 <c012cd0e> (finish_task_switch+0x43/0x90 <c010fe23>)


vim:ft=help