Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1310760 > unrolled thread

Re: [PATCH 1/3] mm, oom: rework oom detection

Started byTetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
First post2016-01-16 02:10 +0100
Last post2016-01-20 14:20 +0100
Articles 4 — 3 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: [PATCH 1/3] mm, oom: rework oom detection Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> - 2016-01-16 02:10 +0100
    Re: [PATCH 1/3] mm, oom: rework oom detection David Rientjes <rientjes@google.com> - 2016-01-19 23:50 +0100
      Re: [PATCH 1/3] mm, oom: rework oom detection Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp> - 2016-01-20 12:20 +0100
        Re: [PATCH 1/3] mm, oom: rework oom detection Michal Hocko <mhocko@kernel.org> - 2016-01-20 14:20 +0100

#1310760 — Re: [PATCH 1/3] mm, oom: rework oom detection

FromTetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Date2016-01-16 02:10 +0100
SubjectRe: [PATCH 1/3] mm, oom: rework oom detection
Message-ID<qRnxo-5EP-15@gated-at.bofh.it>
David Rientjes wrote:
> Tetsuo's log of an early oom in this thread shows that this check is 
> wrong.  The allocation in question is an order-2 GFP_KERNEL on a system 
> with only ZONE_DMA and ZONE_DMA32:
> 
> 	zone=DMA32 reclaimable=308907 available=312734 no_progress_loops=0 did_some_progress=50
> 	zone=DMA reclaimable=2 available=1728 no_progress_loops=0 did_some_progress=50
> 
> and the watermarks:
> 
> 	Node 0 DMA free:6908kB min:44kB low:52kB high:64kB ...
> 	lowmem_reserve[]: 0 1714 1714 1714
> 	Node 0 DMA32 free:17996kB min:5172kB low:6464kB high:7756kB  ...
> 	lowmem_reserve[]: 0 0 0 0
> 
> and the scary thing is that this triggers when no_progress_loops == 0, so 
> this is the first time trying the allocation after progress has been made.
> 
> Watermarks clearly indicate that memory is available, the problem is 
> fragmentation for the order-2 allocation.  This is not a situation where 
> we want to immediately call the oom killer to solve since we have no 
> guarantee it is going to free contiguous memory (in fact it wouldn't be 
> used at all for PAGE_ALLOC_COSTLY_ORDER).
> 
> There is order-2 memory available however:
> 
> 	Node 0 DMA32: 1113*4kB (UME) 1400*8kB (UME) 116*16kB (UM) 15*32kB (UM) 1*64kB (M) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 18052kB
> 
> The failure for ZONE_DMA makes sense for the lowmem_reserve ratio, it's 
> oom for this allocation.  ZONE_DMA32 is not, however.
> 
> I'm wondering if this has to do with the z->nr_reserved_highatomic 
> estimate.  ZONE_DMA32 present pages is 2080640kB, so this would be limited 
> to 1%, or 20806kB.  That failure would make sense if free is 17996kB.
> 
> Tetsuo, would it be possible to try your workload with just this match and 
> also show z->nr_reserved_highatomic?

I don't know what "try your workload with just this match" expects, but
zone->nr_reserved_highatomic is always 0.

----------
[  178.058803] zone=DMA32 reclaimable=367474 available=369923 no_progress_loops=0 did_some_progress=37 nr_reserved_highatomic=0
[  178.061350] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=37 nr_reserved_highatomic=0
[  178.132174] Node 0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:3256kB inactive_anon:172kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:56kB shmem:180kB slab_reclaimable:2056kB slab_unreclaimable:1096kB kernel_stack:192kB pagetables:180kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:4 all_unreclaimable? no
[  178.145589] Node 0 DMA32 free:11532kB min:5564kB low:6952kB high:8344kB active_anon:133896kB inactive_anon:8204kB active_file:1001828kB inactive_file:462944kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2080640kB managed:2021064kB mlocked:0kB dirty:8kB writeback:0kB mapped:8572kB shmem:8468kB slab_reclaimable:57136kB slab_unreclaimable:86380kB kernel_stack:50080kB pagetables:83600kB unstable:0kB bounce:0kB free_pcp:1268kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:356 all_unreclaimable? no
[  198.457718] zone=DMA32 reclaimable=381991 available=386237 no_progress_loops=0 did_some_progress=37 nr_reserved_highatomic=0
[  198.460111] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=37 nr_reserved_highatomic=0
[  198.507204] Node 0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:3088kB inactive_anon:172kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:92kB shmem:180kB slab_reclaimable:976kB slab_unreclaimable:1468kB kernel_stack:672kB pagetables:336kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:4 all_unreclaimable? no
[  198.507209] Node 0 DMA32 free:19992kB min:5564kB low:6952kB high:8344kB active_anon:104176kB inactive_anon:8204kB active_file:905320kB inactive_file:617264kB unevictable:0kB isolated(anon):0kB isolated(file):116kB present:2080640kB managed:2021064kB mlocked:0kB dirty:176kB writeback:0kB mapped:12772kB shmem:8468kB slab_reclaimable:60372kB slab_unreclaimable:77856kB kernel_stack:44144kB pagetables:69180kB unstable:0kB bounce:0kB free_pcp:1104kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  198.647075] zone=DMA32 reclaimable=374429 available=378945 no_progress_loops=0 did_some_progress=61 nr_reserved_highatomic=0
[  198.647076] zone=DMA reclaimable=1 available=1983 no_progress_loops=0 did_some_progress=61 nr_reserved_highatomic=0
[  198.652177] Node 0 DMA free:7928kB min:40kB low:48kB high:60kB active_anon:588kB inactive_anon:172kB active_file:0kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:88kB shmem:180kB slab_reclaimable:1008kB slab_unreclaimable:2576kB kernel_stack:1840kB pagetables:408kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  198.652182] Node 0 DMA32 free:17608kB min:5564kB low:6952kB high:8344kB active_anon:89528kB inactive_anon:8204kB active_file:1025084kB inactive_file:472512kB unevictable:0kB isolated(anon):0kB isolated(file):120kB present:2080640kB managed:2021064kB mlocked:0kB dirty:176kB writeback:0kB mapped:12848kB shmem:8468kB slab_reclaimable:60372kB slab_unreclaimable:86628kB kernel_stack:50880kB pagetables:82336kB unstable:0kB bounce:0kB free_pcp:236kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  207.045450] zone=DMA32 reclaimable=386923 available=392299 no_progress_loops=0 did_some_progress=38 nr_reserved_highatomic=0
[  207.045451] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=38 nr_reserved_highatomic=0
[  207.050241] Node 0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:732kB inactive_anon:336kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:140kB shmem:436kB slab_reclaimable:456kB slab_unreclaimable:3536kB kernel_stack:1584kB pagetables:188kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:4 all_unreclaimable? no
[  207.050246] Node 0 DMA32 free:20092kB min:5564kB low:6952kB high:8344kB active_anon:91600kB inactive_anon:18620kB active_file:921896kB inactive_file:626544kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2080640kB managed:2021064kB mlocked:0kB dirty:964kB writeback:0kB mapped:17016kB shmem:24584kB slab_reclaimable:51908kB slab_unreclaimable:72792kB kernel_stack:40832kB pagetables:67396kB unstable:0kB bounce:0kB free_pcp:472kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  221.034713] zone=DMA32 reclaimable=389283 available=393245 no_progress_loops=0 did_some_progress=40 nr_reserved_highatomic=0
[  221.037103] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=40 nr_reserved_highatomic=0
[  221.105952] Node 0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:416kB inactive_anon:304kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:132kB shmem:436kB slab_reclaimable:424kB slab_unreclaimable:3156kB kernel_stack:2352kB pagetables:212kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:4 all_unreclaimable? no
[  221.119016] Node 0 DMA32 free:7220kB min:5564kB low:6952kB high:8344kB active_anon:74480kB inactive_anon:23544kB active_file:946560kB inactive_file:618900kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2080640kB managed:2021064kB mlocked:0kB dirty:1056kB writeback:0kB mapped:14760kB shmem:32768kB slab_reclaimable:51328kB slab_unreclaimable:75692kB kernel_stack:42960kB pagetables:66732kB unstable:0kB bounce:0kB free_pcp:196kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:248 all_unreclaimable? no
[  224.072875] zone=DMA32 reclaimable=397667 available=401058 no_progress_loops=0 did_some_progress=56 nr_reserved_highatomic=0
[  224.075212] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=56 nr_reserved_highatomic=0
[  224.133813] Node 0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:664kB inactive_anon:296kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:436kB slab_reclaimable:424kB slab_unreclaimable:3760kB kernel_stack:1136kB pagetables:376kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  224.145691] Node 0 DMA32 free:12160kB min:5564kB low:6952kB high:8344kB active_anon:69352kB inactive_anon:23140kB active_file:1191992kB inactive_file:399408kB unevictable:0kB isolated(anon):0kB isolated(file):104kB present:2080640kB managed:2021064kB mlocked:0kB dirty:844kB writeback:0kB mapped:4916kB shmem:32768kB slab_reclaimable:51288kB slab_unreclaimable:68392kB kernel_stack:38560kB pagetables:61820kB unstable:0kB bounce:0kB free_pcp:184kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  234.291285] zone=DMA32 reclaimable=403563 available=407626 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0
[  234.293557] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0
[  234.357091] Node 0 DMA free:7920kB min:40kB low:48kB high:60kB active_anon:312kB inactive_anon:296kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:144kB shmem:436kB slab_reclaimable:424kB slab_unreclaimable:2596kB kernel_stack:2992kB pagetables:204kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:4 all_unreclaimable? no
[  234.370106] Node 0 DMA32 free:6804kB min:5564kB low:6952kB high:8344kB active_anon:77364kB inactive_anon:23140kB active_file:1168356kB inactive_file:454384kB unevictable:0kB isolated(anon):0kB isolated(file):128kB present:2080640kB managed:2021064kB mlocked:0kB dirty:0kB writeback:0kB mapped:11884kB shmem:32768kB slab_reclaimable:51292kB slab_unreclaimable:61492kB kernel_stack:32016kB pagetables:49248kB unstable:0kB bounce:0kB free_pcp:760kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:696 all_unreclaimable? no
[  246.183836] zone=DMA32 reclaimable=405496 available=410200 no_progress_loops=0 did_some_progress=59 nr_reserved_highatomic=0
[  246.186069] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=59 nr_reserved_highatomic=0
[  246.246157] Node 0 DMA free:7920kB min:40kB low:48kB high:60kB active_anon:1144kB inactive_anon:284kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:124kB shmem:436kB slab_reclaimable:424kB slab_unreclaimable:2404kB kernel_stack:1392kB pagetables:660kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  246.260159] Node 0 DMA32 free:11564kB min:5564kB low:6952kB high:8344kB active_anon:74360kB inactive_anon:23036kB active_file:1173248kB inactive_file:456000kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2080640kB managed:2021064kB mlocked:0kB dirty:732kB writeback:0kB mapped:14812kB shmem:32768kB slab_reclaimable:51292kB slab_unreclaimable:59884kB kernel_stack:31824kB pagetables:47960kB unstable:0kB bounce:0kB free_pcp:136kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  258.994846] zone=DMA32 reclaimable=403441 available=407544 no_progress_loops=0 did_some_progress=61 nr_reserved_highatomic=0
[  258.997488] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=61 nr_reserved_highatomic=0
[  259.055818] Node 0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:848kB inactive_anon:284kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:136kB shmem:436kB slab_reclaimable:428kB slab_unreclaimable:2692kB kernel_stack:1872kB pagetables:476kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  259.067950] Node 0 DMA32 free:29136kB min:5564kB low:6952kB high:8344kB active_anon:71476kB inactive_anon:23032kB active_file:1129276kB inactive_file:485324kB unevictable:0kB isolated(anon):0kB isolated(file):112kB present:2080640kB managed:2021064kB mlocked:0kB dirty:0kB writeback:0kB mapped:14340kB shmem:32768kB slab_reclaimable:51312kB slab_unreclaimable:61680kB kernel_stack:34704kB pagetables:44856kB unstable:0kB bounce:0kB free_pcp:1996kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  271.392099] zone=DMA32 reclaimable=399774 available=406049 no_progress_loops=0 did_some_progress=59 nr_reserved_highatomic=0
[  271.394646] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=59 nr_reserved_highatomic=0
[  271.459049] Node 0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:832kB inactive_anon:284kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:124kB shmem:436kB slab_reclaimable:428kB slab_unreclaimable:2824kB kernel_stack:2320kB pagetables:180kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  271.472413] Node 0 DMA32 free:21848kB min:5564kB low:6952kB high:8344kB active_anon:77144kB inactive_anon:23032kB active_file:1148420kB inactive_file:462308kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2080640kB managed:2021064kB mlocked:0kB dirty:664kB writeback:0kB mapped:14700kB shmem:32768kB slab_reclaimable:51312kB slab_unreclaimable:61672kB kernel_stack:32064kB pagetables:50888kB unstable:0kB bounce:0kB free_pcp:848kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  274.428858] zone=DMA32 reclaimable=404186 available=408756 no_progress_loops=0 did_some_progress=52 nr_reserved_highatomic=0
[  274.431146] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=52 nr_reserved_highatomic=0
[  274.487864] Node 0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:600kB inactive_anon:284kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:436kB slab_reclaimable:428kB slab_unreclaimable:3504kB kernel_stack:1120kB pagetables:532kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[  274.499779] Node 0 DMA32 free:17040kB min:5564kB low:6952kB high:8344kB active_anon:60480kB inactive_anon:23032kB active_file:1277956kB inactive_file:339528kB unevictable:0kB isolated(anon):0kB isolated(file):68kB present:2080640kB managed:2021064kB mlocked:0kB dirty:664kB writeback:0kB mapped:5912kB shmem:32768kB slab_reclaimable:51312kB slab_unreclaimable:64216kB kernel_stack:37520kB pagetables:52096kB unstable:0kB bounce:0kB free_pcp:308kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
----------
Complete log is at http://I-love.SAKURA.ne.jp/tmp/serial-20160116.txt.xz .

> 
> This patch would need to at least have knowledge of the heuristics used by 
> __zone_watermark_ok() since it's making an inference on reclaimability 
> based on numbers that include pageblocks that are reserved from usage.
>

[toc] | [next] | [standalone]

#1312570

FromDavid Rientjes <rientjes@google.com>
Date2016-01-19 23:50 +0100
Message-ID<qSNg6-5Mk-23@gated-at.bofh.it>
In reply to#1310760
On Sat, 16 Jan 2016, Tetsuo Handa wrote:

> > Tetsuo's log of an early oom in this thread shows that this check is 
> > wrong.  The allocation in question is an order-2 GFP_KERNEL on a system 
> > with only ZONE_DMA and ZONE_DMA32:
> > 
> > 	zone=DMA32 reclaimable=308907 available=312734 no_progress_loops=0 did_some_progress=50
> > 	zone=DMA reclaimable=2 available=1728 no_progress_loops=0 did_some_progress=50
> > 
> > and the watermarks:
> > 
> > 	Node 0 DMA free:6908kB min:44kB low:52kB high:64kB ...
> > 	lowmem_reserve[]: 0 1714 1714 1714
> > 	Node 0 DMA32 free:17996kB min:5172kB low:6464kB high:7756kB  ...
> > 	lowmem_reserve[]: 0 0 0 0
> > 
> > and the scary thing is that this triggers when no_progress_loops == 0, so 
> > this is the first time trying the allocation after progress has been made.
> > 
> > Watermarks clearly indicate that memory is available, the problem is 
> > fragmentation for the order-2 allocation.  This is not a situation where 
> > we want to immediately call the oom killer to solve since we have no 
> > guarantee it is going to free contiguous memory (in fact it wouldn't be 
> > used at all for PAGE_ALLOC_COSTLY_ORDER).
> > 
> > There is order-2 memory available however:
> > 
> > 	Node 0 DMA32: 1113*4kB (UME) 1400*8kB (UME) 116*16kB (UM) 15*32kB (UM) 1*64kB (M) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 18052kB
> > 
> > The failure for ZONE_DMA makes sense for the lowmem_reserve ratio, it's 
> > oom for this allocation.  ZONE_DMA32 is not, however.
> > 
> > I'm wondering if this has to do with the z->nr_reserved_highatomic 
> > estimate.  ZONE_DMA32 present pages is 2080640kB, so this would be limited 
> > to 1%, or 20806kB.  That failure would make sense if free is 17996kB.
> > 
> > Tetsuo, would it be possible to try your workload with just this match and 
> > also show z->nr_reserved_highatomic?
> 
> I don't know what "try your workload with just this match" expects, but
> zone->nr_reserved_highatomic is always 0.
> 

My point about z->nr_reserved_highatomic still stands, specifically that 
pageblocks may be reserved from allocation and __zone_watermark_ok() may 
fail, which would cause a premature oom condition, for this patch's 
calculation of "available".  It may not have caused a problem on your 
specific workload, however.

Are you able to precisely identify why __zone_watermark_ok() is failing 
and triggering the oom in the log you posted January 3?

[  154.829582] zone=DMA32 reclaimable=308907 available=312734 no_progress_loops=0 did_some_progress=50
[  154.831562] zone=DMA reclaimable=2 available=1728 no_progress_loops=0 did_some_progress=50
// here //
[  154.838499] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)
[  154.841167] fork cpuset=/ mems_allowed=0
[  154.842348] CPU: 1 PID: 9599 Comm: fork Tainted: G        W       4.4.0-rc7-next-20151231+ #273
...
[  154.852386] Call Trace:
[  154.853350]  [<ffffffff81398b83>] dump_stack+0x4b/0x68
[  154.854731]  [<ffffffff811bc81c>] dump_header+0x5b/0x3b0
[  154.856309]  [<ffffffff810bdd79>] ? trace_hardirqs_on_caller+0xf9/0x1c0
[  154.858046]  [<ffffffff810bde4d>] ? trace_hardirqs_on+0xd/0x10
[  154.859593]  [<ffffffff81143d36>] oom_kill_process+0x366/0x540
[  154.861142]  [<ffffffff8114414f>] out_of_memory+0x1ef/0x5a0
[  154.862655]  [<ffffffff8114420d>] ? out_of_memory+0x2ad/0x5a0
[  154.864194]  [<ffffffff81149c72>] __alloc_pages_nodemask+0xda2/0xde0
[  154.865852]  [<ffffffff810bdd00>] ? trace_hardirqs_on_caller+0x80/0x1c0
[  154.867844]  [<ffffffff81149e6c>] alloc_kmem_pages_node+0x4c/0xc0
[  154.868726] zone=DMA32 reclaimable=309003 available=312677 no_progress_loops=0 did_some_progress=48
[  154.868727] zone=DMA reclaimable=2 available=1728 no_progress_loops=0 did_some_progress=48
// and also here, if we didn't serialize the oom killer //

I think that would help in fixing the issue you reported.

[toc] | [prev] | [next] | [standalone]

#1313133

FromTetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Date2016-01-20 12:20 +0100
Message-ID<qSYXU-5Aj-15@gated-at.bofh.it>
In reply to#1312570
David Rientjes wrote:
> Are you able to precisely identify why __zone_watermark_ok() is failing 
> and triggering the oom in the log you posted January 3?
> 
> [  154.829582] zone=DMA32 reclaimable=308907 available=312734 no_progress_loops=0 did_some_progress=50
> [  154.831562] zone=DMA reclaimable=2 available=1728 no_progress_loops=0 did_some_progress=50
> // here //
> [  154.838499] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)
> [  154.841167] fork cpuset=/ mems_allowed=0
> [  154.842348] CPU: 1 PID: 9599 Comm: fork Tainted: G        W       4.4.0-rc7-next-20151231+ #273
> ...
> [  154.852386] Call Trace:
> [  154.853350]  [<ffffffff81398b83>] dump_stack+0x4b/0x68
> [  154.854731]  [<ffffffff811bc81c>] dump_header+0x5b/0x3b0
> [  154.856309]  [<ffffffff810bdd79>] ? trace_hardirqs_on_caller+0xf9/0x1c0
> [  154.858046]  [<ffffffff810bde4d>] ? trace_hardirqs_on+0xd/0x10
> [  154.859593]  [<ffffffff81143d36>] oom_kill_process+0x366/0x540
> [  154.861142]  [<ffffffff8114414f>] out_of_memory+0x1ef/0x5a0
> [  154.862655]  [<ffffffff8114420d>] ? out_of_memory+0x2ad/0x5a0
> [  154.864194]  [<ffffffff81149c72>] __alloc_pages_nodemask+0xda2/0xde0
> [  154.865852]  [<ffffffff810bdd00>] ? trace_hardirqs_on_caller+0x80/0x1c0
> [  154.867844]  [<ffffffff81149e6c>] alloc_kmem_pages_node+0x4c/0xc0
> [  154.868726] zone=DMA32 reclaimable=309003 available=312677 no_progress_loops=0 did_some_progress=48
> [  154.868727] zone=DMA reclaimable=2 available=1728 no_progress_loops=0 did_some_progress=48
> // and also here, if we didn't serialize the oom killer //
> 
> I think that would help in fixing the issue you reported.
> 
Does "why __zone_watermark_ok() is failing" mean "which 'return false;' statement
in __zone_watermark_ok() I'm hitting on my specific workload"? Then, answer is
the former for DMA zone and the latter for DMA32 zone.

----------
diff --git a/mm/page_alloc.c b/mm/page_alloc.c
index 9d70a80..dd36f01 100644
--- a/mm/page_alloc.c
+++ b/mm/page_alloc.c
@@ -2390,7 +2390,7 @@ static inline bool should_fail_alloc_page(gfp_t gfp_mask, unsigned int order)
  */
 static bool __zone_watermark_ok(struct zone *z, unsigned int order,
 			unsigned long mark, int classzone_idx, int alloc_flags,
-			long free_pages)
+				long free_pages, bool *no_free)
 {
 	long min = mark;
 	int o;
@@ -2423,6 +2423,7 @@ static bool __zone_watermark_ok(struct zone *z, unsigned int order,
 	 * are not met, then a high-order request also cannot go ahead
 	 * even if a suitable page happened to be free.
 	 */
+	*no_free = false;
 	if (free_pages <= min + z->lowmem_reserve[classzone_idx])
 		return false;
 
@@ -2453,26 +2454,30 @@ static bool __zone_watermark_ok(struct zone *z, unsigned int order,
 		}
 #endif
 	}
+	*no_free = true;
 	return false;
 }
 
 bool zone_watermark_ok(struct zone *z, unsigned int order, unsigned long mark,
 		      int classzone_idx, int alloc_flags)
 {
+	bool unused;
+
 	return __zone_watermark_ok(z, order, mark, classzone_idx, alloc_flags,
-					zone_page_state(z, NR_FREE_PAGES));
+				   zone_page_state(z, NR_FREE_PAGES), &unused);
 }
 
 bool zone_watermark_ok_safe(struct zone *z, unsigned int order,
 			unsigned long mark, int classzone_idx)
 {
+	bool unused;
 	long free_pages = zone_page_state(z, NR_FREE_PAGES);
 
 	if (z->percpu_drift_mark && free_pages < z->percpu_drift_mark)
 		free_pages = zone_page_state_snapshot(z, NR_FREE_PAGES);
 
 	return __zone_watermark_ok(z, order, mark, classzone_idx, 0,
-								free_pages);
+				   free_pages, &unused);
 }
 
 #ifdef CONFIG_NUMA
@@ -3014,7 +3019,7 @@ static inline bool is_thp_gfp_mask(gfp_t gfp_mask)
 static inline bool
 should_reclaim_retry(gfp_t gfp_mask, unsigned order,
 		     struct alloc_context *ac, int alloc_flags,
-		     bool did_some_progress,
+		     unsigned long did_some_progress,
 		     int no_progress_loops)
 {
 	struct zone *zone;
@@ -3024,8 +3029,10 @@ should_reclaim_retry(gfp_t gfp_mask, unsigned order,
 	 * Make sure we converge to OOM if we cannot make any progress
 	 * several times in the row.
 	 */
-	if (no_progress_loops > MAX_RECLAIM_RETRIES)
+	if (no_progress_loops > MAX_RECLAIM_RETRIES) {
+		printk(KERN_INFO "Reached MAX_RECLAIM_RETRIES.\n");
 		return false;
+	}
 
 	/* Do not retry high order allocations unless they are __GFP_REPEAT */
 	if (order > PAGE_ALLOC_COSTLY_ORDER && !(gfp_mask & __GFP_REPEAT))
@@ -3039,6 +3046,7 @@ should_reclaim_retry(gfp_t gfp_mask, unsigned order,
 	 */
 	for_each_zone_zonelist_nodemask(zone, z, ac->zonelist,
 			ac->high_zoneidx, ac->nodemask) {
+		bool no_free;
 		unsigned long available;
 		unsigned long reclaimable;
 
@@ -3052,7 +3060,7 @@ should_reclaim_retry(gfp_t gfp_mask, unsigned order,
 		 * available?
 		 */
 		if (__zone_watermark_ok(zone, order, min_wmark_pages(zone),
-				ac->high_zoneidx, alloc_flags, available)) {
+					ac->high_zoneidx, alloc_flags, available, &no_free)) {
 			unsigned long writeback;
 			unsigned long dirty;
 
@@ -3086,6 +3094,8 @@ should_reclaim_retry(gfp_t gfp_mask, unsigned order,
 
 			return true;
 		}
+		printk(KERN_INFO "zone=%s reclaimable=%lu available=%lu no_progress_loops=%u did_some_progress=%lu nr_reserved_highatomic=%lu no_free=%u\n",
+		       zone->name, reclaimable, available, no_progress_loops, did_some_progress, zone->nr_reserved_highatomic, no_free);
 	}
 
 	return false;
@@ -3273,7 +3283,7 @@ retry:
 		no_progress_loops++;
 
 	if (should_reclaim_retry(gfp_mask, order, ac, alloc_flags,
-				 did_some_progress > 0, no_progress_loops))
+				 did_some_progress, no_progress_loops))
 		goto retry;
 
 	/* Reclaim has failed us, start killing things */
----------

Complete log is at http://I-love.SAKURA.ne.jp/tmp/serial-20160120.txt.xz .
----------
[  141.987548] zone=DMA32 reclaimable=367085 available=371232 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0 no_free=1
[  141.990091] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0 no_free=0
[  141.997360] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  142.055908] Node 0 DMA free:7920kB min:40kB low:48kB high:60kB active_anon:3208kB inactive_anon:188kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB\
 dirty:0kB writeback:0kB mapped:60kB shmem:188kB slab_reclaimable:2792kB slab_unreclaimable:360kB kernel_stack:224kB pagetables:260kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:4 all_\
unreclaimable? no
[  142.066690] lowmem_reserve[]: 0 1970 1970 1970

[  142.914557] zone=DMA32 reclaimable=345975 available=348821 no_progress_loops=0 did_some_progress=58 nr_reserved_highatomic=0 no_free=1
[  142.914558] zone=DMA reclaimable=2 available=1980 no_progress_loops=0 did_some_progress=58 nr_reserved_highatomic=0 no_free=0
[  142.921113] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  153.615466] zone=DMA32 reclaimable=385567 available=389678 no_progress_loops=0 did_some_progress=36 nr_reserved_highatomic=0 no_free=1
[  153.615467] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=36 nr_reserved_highatomic=0 no_free=0
[  153.620507] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  153.658621] zone=DMA32 reclaimable=384064 available=388833 no_progress_loops=0 did_some_progress=37 nr_reserved_highatomic=0 no_free=1
[  153.658623] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=37 nr_reserved_highatomic=0 no_free=0
[  153.663401] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  159.614894] zone=DMA32 reclaimable=356635 available=361925 no_progress_loops=0 did_some_progress=32 nr_reserved_highatomic=0 no_free=1
[  159.614895] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=32 nr_reserved_highatomic=0 no_free=0
[  159.622374] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  164.781516] zone=DMA32 reclaimable=393457 available=397561 no_progress_loops=0 did_some_progress=40 nr_reserved_highatomic=0 no_free=1
[  164.781518] zone=DMA reclaimable=1 available=1983 no_progress_loops=0 did_some_progress=40 nr_reserved_highatomic=0 no_free=0
[  164.786560] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  171.006952] zone=DMA32 reclaimable=405821 available=410137 no_progress_loops=0 did_some_progress=34 nr_reserved_highatomic=0 no_free=1
[  171.006954] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=34 nr_reserved_highatomic=0 no_free=0
[  171.010690] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  171.030121] zone=DMA32 reclaimable=405016 available=409801 no_progress_loops=0 did_some_progress=34 nr_reserved_highatomic=0 no_free=1
[  171.030123] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=34 nr_reserved_highatomic=0 no_free=0
[  171.033530] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  184.631660] zone=DMA32 reclaimable=356652 available=359338 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0 no_free=1
[  184.634207] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0 no_free=0
[  184.642800] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  190.499877] zone=DMA32 reclaimable=382152 available=384996 no_progress_loops=0 did_some_progress=32 nr_reserved_highatomic=0 no_free=1
[  190.499878] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=32 nr_reserved_highatomic=0 no_free=0
[  190.504901] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  196.146728] zone=DMA32 reclaimable=371941 available=374605 no_progress_loops=0 did_some_progress=61 nr_reserved_highatomic=0 no_free=1
[  196.146730] zone=DMA reclaimable=1 available=1982 no_progress_loops=0 did_some_progress=61 nr_reserved_highatomic=0 no_free=0
[  196.152546] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  201.837825] zone=DMA32 reclaimable=364569 available=370359 no_progress_loops=0 did_some_progress=59 nr_reserved_highatomic=0 no_free=1
[  201.837826] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=59 nr_reserved_highatomic=0 no_free=0
[  201.844879] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  212.862325] zone=DMA32 reclaimable=381542 available=387785 no_progress_loops=0 did_some_progress=39 nr_reserved_highatomic=0 no_free=1
[  212.862327] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=39 nr_reserved_highatomic=0 no_free=0
[  212.866857] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)

[  212.866914] Node 0 DMA free:7920kB min:40kB low:48kB high:60kB active_anon:440kB inactive_anon:196kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB \
dirty:8kB writeback:0kB mapped:0kB shmem:280kB slab_reclaimable:480kB slab_unreclaimable:3856kB kernel_stack:1776kB pagetables:240kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_u\
nreclaimable? no
[  212.866915] lowmem_reserve[]: 0 1970 1970 1970
----------

[toc] | [prev] | [next] | [standalone]

#1313219

FromMichal Hocko <mhocko@kernel.org>
Date2016-01-20 14:20 +0100
Message-ID<qT0Q2-6YG-13@gated-at.bofh.it>
In reply to#1313133
On Wed 20-01-16 20:13:32, Tetsuo Handa wrote:
[...]
> Complete log is at http://I-love.SAKURA.ne.jp/tmp/serial-20160120.txt.xz .

> [  141.987548] zone=DMA32 reclaimable=367085 available=371232 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0 no_free=1

Ok, so we really do not have _any_ pages on the order 2+ free lists and
that is why __zone_watermark_ok failed.

> [  141.990091] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0 no_free=0

DMA zone is not even interesting because it is fully protected by the
lowmem reserves.

> [  141.997360] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)
[...]
> [  142.086897] Node 0 DMA32: 1796*4kB (M) 763*8kB (UM) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 13288kB

And indeed we still do not have any order-2+ available. OOM seems
reasonable.

> [  142.914557] zone=DMA32 reclaimable=345975 available=348821 no_progress_loops=0 did_some_progress=58 nr_reserved_highatomic=0 no_free=1
> [  142.914558] zone=DMA reclaimable=2 available=1980 no_progress_loops=0 did_some_progress=58 nr_reserved_highatomic=0 no_free=0
> [  142.921113] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)
[...]
> [  142.921192] Node 0 DMA32: 1794*4kB (UME) 464*8kB (UM) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 10888kB

Ditto

> [  153.615466] zone=DMA32 reclaimable=385567 available=389678 no_progress_loops=0 did_some_progress=36 nr_reserved_highatomic=0 no_free=1
> [  153.615467] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=36 nr_reserved_highatomic=0 no_free=0
> [  153.620507] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)
[...]
> [  153.620582] Node 0 DMA32: 1241*4kB (UME) 1280*8kB (UM) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 15204kB

Ditto

> [  153.658621] zone=DMA32 reclaimable=384064 available=388833 no_progress_loops=0 did_some_progress=37 nr_reserved_highatomic=0 no_free=1
> [  153.658623] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=37 nr_reserved_highatomic=0 no_free=0
> [  153.663401] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)
[...]
> [  153.663480] Node 0 DMA32: 554*4kB (UME) 2148*8kB (UM) 3*16kB (M) 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 19448kB

Now we have __zone_watermark_ok claiming no order 2+ blocks available
but oom report little bit later sees 3 blocks. This would suggest that
this is just a matter of timing when the children exit and free their
stacks which are order-2.

> [  159.614894] zone=DMA32 reclaimable=356635 available=361925 no_progress_loops=0 did_some_progress=32 nr_reserved_highatomic=0 no_free=1
> [  159.614895] zone=DMA reclaimable=2 available=1983 no_progress_loops=0 did_some_progress=32 nr_reserved_highatomic=0 no_free=0
> [  159.622374] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)
[...]
> [  159.622451] Node 0 DMA32: 2141*4kB (UM) 1435*8kB (UM) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 20044kB

Again no high order pages.

> [  164.781516] zone=DMA32 reclaimable=393457 available=397561 no_progress_loops=0 did_some_progress=40 nr_reserved_highatomic=0 no_free=1
> [  164.781518] zone=DMA reclaimable=1 available=1983 no_progress_loops=0 did_some_progress=40 nr_reserved_highatomic=0 no_free=0
> [  164.786560] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)
[...]
> [  164.786643] Node 0 DMA32: 2961*4kB (UME) 432*8kB (UM) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 15300kB

Ditto

> [  184.631660] zone=DMA32 reclaimable=356652 available=359338 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0 no_free=1
> [  184.634207] zone=DMA reclaimable=2 available=1982 no_progress_loops=0 did_some_progress=60 nr_reserved_highatomic=0 no_free=0
> [  184.642800] fork invoked oom-killer: order=2, oom_score_adj=0, gfp_mask=0x27000c0(GFP_KERNEL|GFP_NOTRACK|0x100000)
[...]
> [  184.728695] Node 0 DMA32: 3144*4kB (UME) 971*8kB (UME) 43*16kB (UM) 3*32kB (M) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 21128kB

Again we have order >=2 pages available here after the allocator has
seen none earlier. And the pattern repeats later on. So I would say
that in this particular load it is a timing which plays the role. I
am not sure we can tune for such a load beause any difference in the
timing would result in a different behavior and basically breaking such
a tuning.

The current heuristic is based on an assumption that retrying for high
order allocations only makes sense if they are hidden behind the min
watermark and the currently reclaimable pages would get us above the
watermark. We cannot assume that the order-0 reclaimable pages will form
the required high order blocks because there is no such guarantee.  I
think such a heuristic makes sense because we have passed the direct
reclaim and also compaction at the time when we check for the retry
so chances to get the required block from the reclaim are not that high.

So I am not really sure what to do here now. On one hand the previous
heuristic would happen to work here probably better because we would be
looping in the allocator, exiting processes would rest the counter and
keep the retries and sooner or later the fork would be lucky and see its
order-2 block and continue. We could starve in this state for basically
unbounded amount of time though which is excatly what I would like to
get rid of. I guess we might want to give few attempts to retry for
all order>0. Let me think about it some more.

Thanks!
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web