lkml.org 
[lkml]   [2012]   [Dec]   [3]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: kswapd craziness in 3.7
Dne 28.11.2012 10:45, Mel Gorman napsal(a):
> (Adding Thorsten to cc)
>
> On Tue, Nov 27, 2012 at 03:48:34PM -0500, Johannes Weiner wrote:
>> Hi everyone,
>>
>> I hope I included everybody that participated in the various threads
>> on kswapd getting stuck / exhibiting high CPU usage. We were looking
>> at at least three root causes as far as I can see, so it's not really
>> clear who observed which problem. Please correct me if the
>> reported-by, tested-by, bisected-by tags are incomplete.
>>
>> One problem was, as it seems, overly aggressive reclaim due to scaling
>> up reclaim goals based on compaction failures. This one was reverted
>> in 9671009 mm: revert "mm: vmscan: scale number of pages reclaimed by
>> reclaim/compaction based on failures".
>>
>
> This particular one would have been made worse by the accounting bug and
> if kswapd was staying awake longer than necessary. As scaling the amount
> of reclaim only for direct reclaim helped this problem a lot, I strongly
> suspect the accounting bug was a factor.
>
> However the benefit for this is marginal -- it primarily affects how
> many THP pages we can allocate under stress. There is already a graceful
> fallback path and a system under heavy reclaim pressure is not going to
> notice the performance benefit of THP.
>
>> Another one was an accounting problem where a freed higher order page
>> was underreported, and so kswapd had trouble restoring watermarks.
>> This one was fixed in ef6c5be fix incorrect NR_FREE_PAGES accounting
>> (appears like memory leak).
>>
>
> This almost certainly also requires the follow-on fix at
> https://lkml.org/lkml/2012/11/26/225 for reasons I explained in
> https://lkml.org/lkml/2012/11/27/190 .
>
>> The third one is a problem with small zones, like the DMA zone, where
>> the high watermark is lower than the low watermark plus compaction gap
>> (2 * allocation size). The zonelist reclaim in kswapd would do
>> nothing because all high watermarks are met, but the compaction logic
>> would find its own requirements unmet and loop over the zones again.
>> Indefinitely, until some third party would free enough memory to help
>> meet the higher compaction watermark. The problematic code has been
>> there since the 3.4 merge window for non-THP higher order allocations
>> but has been more prominent since the 3.7 merge window, where kswapd
>> is also woken up for the much more common THP allocations.
>>
>
> Yes.
>
>> The following patch should fix the third issue by making both reclaim
>> and compaction code in kswapd use the same predicate to determine
>> whether a zone is balanced or not.
>>
>> Hopefully, the sum of all three fixes should tame kswapd enough for
>> 3.7.
>>
>
> Not exactly sure of that. With just those patches it is possible for
> allocations for THP entering the slow path to keep kswapd continually awake
> doing busy work. This was an alternative to the revert that covered that
> https://lkml.org/lkml/2012/11/12/151 but it was not enough because kswapd
> would stay awake due to the bug you identified and fixed.
>
> I went with the __GFP_NO_KSWAPD patch in this cycle because 3.6 was/is
> very poor in how it handles THP after the removal of lumpy reclaim. 3.7
> was shaping up to be even worse with multiple root causes too close to the
> release date. Taking kswapd out of the equation covered some of the
> problems (yes, by hiding them) so it could be revisited but Johannes may
> have finally squashed it.
>
> However, if we revert the revert then I strongly recommend that it be
> replaced with "Avoid waking kswapd for THP allocations when compaction is
> deferred or contended".
>


Ok, bad news - I've been hit by kswapd0 loop again -
my kernel git commit cc19528bd3084c3c2d870b31a3578da8c69952f3 again shown
kswapd0 for couple minutes on CPU.

It seemed to go instantly away when I've drop caches
(echo 3 >/proc/sys/vm/drop_cache)
(After that I've had over 1G free memory)

Here are some stats before drop while kswapd0 was running:

kswapd0 R running task 0 30 2 0x00000000
ffff880133207b08 0000000000000082 ffff880133207b18 0000000000000246
ffff880135b92340 ffff880133207fd8 ffff880133207fd8 ffff880133207fd8
ffff880103098000 ffff880135b92340 0000000000000000 ffff880133206000
Call Trace:
[<ffffffff815566b2>] preempt_schedule+0x42/0x60
[<ffffffff81558555>] _raw_spin_unlock+0x55/0x60
[<ffffffff81193b3c>] grab_super_passive+0x3c/0x90
[<ffffffff81193bd6>] prune_super+0x46/0x1b0
[<ffffffff81141eda>] shrink_slab+0xba/0x510
[<ffffffff81185c3a>] ? mem_cgroup_iter+0x17a/0x2e0
[<ffffffff81185b8a>] ? mem_cgroup_iter+0xca/0x2e0
[<ffffffff81145141>] balance_pgdat+0x621/0x7e0
[<ffffffff81145474>] kswapd+0x174/0x640
[<ffffffff8106fd40>] ? __init_waitqueue_head+0x60/0x60
[<ffffffff81145300>] ? balance_pgdat+0x7e0/0x7e0
[<ffffffff8106f52b>] kthread+0xdb/0xe0
[<ffffffff8106f450>] ? kthread_create_on_node+0x140/0x140
[<ffffffff815604dc>] ret_from_fork+0x7c/0xb0
[<ffffffff8106f450>] ? kthread_create_on_node+0x140/0x140

runnable tasks:
task PID tree-key switches prio exec-runtime
sum-exec sum-sleep
----------------------------------------------------------------------------------------------------------
kswapd0 30 8087056.792356 30543 120 8087056.792356
158938.479290 137131605.711862 /
kworker/0:3 29833 8087050.792356 526664 120 8087050.792356
24710.527691 24775203.529553 /
R bash 24767 43813.836355 121 120 43813.836355
40.855087 10579.107486 /autogroup-392

----

Showing all locks held in the system:
1 lock held by bash/10668:
#0: (&tty->atomic_read_lock){+.+.+.}, at: [<ffffffff813b3dc0>]
n_tty_read+0x610/0x990
1 lock held by bash/10756:
#0: (&tty->atomic_read_lock){+.+.+.}, at: [<ffffffff813b3dc0>]
n_tty_read+0x610/0x990
1 lock held by bash/26989:
#0: (&tty->atomic_read_lock){+.+.+.}, at: [<ffffffff813b3dc0>]
n_tty_read+0x610/0x990
1 lock held by less/10268:
#0: (&tty->atomic_read_lock){+.+.+.}, at: [<ffffffff813b3dc0>]
n_tty_read+0x610/0x990
1 lock held by less/19112:
#0: (&tty->atomic_read_lock){+.+.+.}, at: [<ffffffff813b3dc0>]
n_tty_read+0x610/0x990
1 lock held by bash/13774:
#0: (&tty->atomic_read_lock){+.+.+.}, at: [<ffffffff813b3dc0>]
n_tty_read+0x610/0x990
1 lock held by less/32444:
#0: (&tty->atomic_read_lock){+.+.+.}, at: [<ffffffff813b3dc0>]
n_tty_read+0x610/0x990
2 locks held by bash/24767:
#0: (sysrq_key_table_lock){......}, at: [<ffffffff813bb553>]
__handle_sysrq+0x33/0x190
#1: (tasklist_lock){.+.+..}, at: [<ffffffff810ad973>]
debug_show_all_locks+0x43/0x2a0

=============================================

SysRq : HELP : loglevel(0-9) reBoot Crash show-all-locks(D)
terminate-all-tasks(E) memory-full-oom-kill(F) kill-all-tasks(I)
thaw-filesystems(J) saK show-backtrace-all-active-cpus(L) show-memory-usage(M)
nice-all-RT-tasks(N) powerOff show-registers(P) show-all-timers(Q) unRaw Sync
show-task-states(T) Unmount force-fb(V) show-blocked-tasks(W)
dump-ftrace-buffer(Z)
SysRq : Show Memory
Mem-Info:
DMA per-cpu:
CPU 0: hi: 0, btch: 1 usd: 0
CPU 1: hi: 0, btch: 1 usd: 0
DMA32 per-cpu:
CPU 0: hi: 186, btch: 31 usd: 147
CPU 1: hi: 186, btch: 31 usd: 157
Normal per-cpu:
CPU 0: hi: 186, btch: 31 usd: 154
CPU 1: hi: 186, btch: 31 usd: 182
active_anon:610014 inactive_anon:16551 isolated_anon:0
active_file:83258 inactive_file:151927 isolated_file:0
unevictable:16 dirty:12 writeback:0 unstable:0
free:72021 slab_reclaimable:18685 slab_unreclaimable:13682
mapped:23445 shmem:29913 pagetables:7689 bounce:0
free_cma:0
DMA free:15892kB min:260kB low:324kB high:388kB active_anon:0kB
inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB present:15644kB mlocked:0kB dirty:0kB
writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:8kB
kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB
writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
lowmem_reserve[]: 0 2982 3927 3927
DMA32 free:251976kB min:51124kB low:63904kB high:76684kB active_anon:1738128kB
inactive_anon:58108kB active_file:316652kB inactive_file:591328kB
unevictable:16kB isolated(anon):0kB isolated(file):0kB present:3054528kB
mlocked:16kB dirty:40kB writeback:0kB mapped:58684kB shmem:108216kB
slab_reclaimable:38888kB slab_unreclaimable:15988kB kernel_stack:1416kB
pagetables:8684kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB
pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 0 945 945
Normal free:20216kB min:16196kB low:20244kB high:24292kB active_anon:701928kB
inactive_anon:8096kB active_file:16380kB inactive_file:16380kB
unevictable:48kB isolated(anon):0kB isolated(file):0kB present:967680kB
mlocked:48kB dirty:8kB writeback:0kB mapped:35096kB shmem:11436kB
slab_reclaimable:35852kB slab_unreclaimable:38732kB kernel_stack:3200kB
pagetables:22072kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB
pages_scanned:42 all_unreclaimable? no
lowmem_reserve[]: 0 0 0 0
DMA: 1*4kB 0*8kB 1*16kB 0*32kB 2*64kB 1*128kB 1*256kB 0*512kB 1*1024kB
1*2048kB 3*4096kB = 15892kB
DMA32: 56*4kB 577*8kB 754*16kB 1192*32kB 713*64kB 484*128kB 223*256kB 57*512kB
1*1024kB 1*2048kB 0*4096kB = 251976kB
Normal: 526*4kB 350*8kB 181*16kB 152*32kB 66*64kB 18*128kB 2*256kB 1*512kB
0*1024kB 0*2048kB 0*4096kB = 20216kB
265099 total pagecache pages
0 pages in swap cache
Swap cache stats: add 0, delete 0, find 0/0
Free swap = 0kB
Total swap = 0kB
1032176 pages RAM
42790 pages reserved
672981 pages shared
820401 pages non-shared

vmstat:

nr_free_pages 72360
nr_inactive_anon 16501
nr_active_anon 609811
nr_inactive_file 151932
nr_active_file 83212
nr_unevictable 16
nr_mlock 16
nr_anon_pages 503314
nr_mapped 23443
nr_file_pages 264982
nr_dirty 234
nr_writeback 0
nr_slab_reclaimable 18685
nr_slab_unreclaimable 13682
nr_page_table_pages 7690
nr_kernel_stack 577
nr_unstable 0
nr_bounce 0
nr_vmscan_write 0
nr_vmscan_immediate_reclaim 29
nr_writeback_temp 0
nr_isolated_anon 0
nr_isolated_file 0
nr_shmem 29838
nr_dirtied 2206202
nr_written 2066654
nr_anon_transparent_hugepages 182
nr_free_cma 0
nr_dirty_threshold 13870
nr_dirty_background_threshold 6935
pgpgin 3224666
pgpgout 9329522
pswpin 0
pswpout 0
pgalloc_dma 2
pgalloc_dma32 100605413
pgalloc_normal 25009399
pgalloc_movable 0
pgfree 126647271
pgactivate 1185101
pgdeactivate 214747
pgfault 106494704
pgmajfault 9834
pgrefill_dma 0
pgrefill_dma32 99747
pgrefill_normal 232841
pgrefill_movable 0
pgsteal_kswapd_dma 0
pgsteal_kswapd_dma32 208294
pgsteal_kswapd_normal 162100
pgsteal_kswapd_movable 0
pgsteal_direct_dma 0
pgsteal_direct_dma32 11942
pgsteal_direct_normal 91155
pgsteal_direct_movable 0
pgscan_kswapd_dma 0
pgscan_kswapd_dma32 211693
pgscan_kswapd_normal 182157
pgscan_kswapd_movable 0
pgscan_direct_dma 0
pgscan_direct_dma32 12129
pgscan_direct_normal 96028
pgscan_direct_movable 0
pgscan_direct_throttle 0
pginodesteal 77546
slabs_scanned 784384
kswapd_inodesteal 47090
kswapd_low_wmark_hit_quickly 57
kswapd_high_wmark_hit_quickly 275
kswapd_skip_congestion_wait 0
pageoutrun 1636173
allocstall 175
pgrotated 73
compact_blocks_moved 80209
compact_pages_moved 345293
compact_pagemigrate_failed 64875
compact_stall 736
compact_fail 314
compact_success 422
htlb_buddy_alloc_success 0
htlb_buddy_alloc_fail 0
unevictable_pgs_culled 2848
unevictable_pgs_scanned 0
unevictable_pgs_rescued 3330
unevictable_pgs_mlocked 3346
unevictable_pgs_munlocked 3330
unevictable_pgs_cleared 0
unevictable_pgs_stranded 0
thp_fault_alloc 53631
thp_fault_fallback 1682
thp_collapse_alloc 13390
thp_collapse_alloc_failed 643
thp_split 2387


Zdenek




\
 
 \ /
  Last update: 2012-12-03 17:01    [W:1.816 / U:0.112 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site