Re: [Question]page allocation failure: order:2, mode:0x2000d1

From: Vlastimil Babka
Date: Tue Jul 19 2016 - 10:14:33 EST

Next message: kbuild test robot: "security/yama/yama_lsm.o: warning: objtool: report_access()+0x210: function has unreachable instruction"
Previous message: atull: "Re: [PATCH] fpga: zynq: Add hardware dependencies"
In reply to: Xishi Qiu: "Re: [Question]page allocation failure: order:2, mode:0x2000d1"
Next in thread: Yisheng Xie: "Re: [Question]page allocation failure: order:2, mode:0x2000d1"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On 07/19/2016 03:48 PM, Xishi Qiu wrote:

On 2016/7/19 21:17, Vlastimil Babka wrote:

On 07/19/2016 02:43 PM, Yisheng Xie wrote:

hi all,
I'm getting a 2-order page allocation failure problem on 4.1.18.
From the Mem-info, it seems the system have much zero order free pages which can be used for memory compaction.
Is it possible that the memory compacted by current process used by other process soon, which cause page allocation failure of current process ?

It's possible, but an order-2 allocation should retry compaction in such case.

Hi Vlastimil,

mode:0x2000d1 means it expects to alloc from zone_dma, (on arm64 zone_dma is 0-4G)

Yes, but I don't see where the __GFP_DMA comes from. The backtrace suggests it's alloc_thread_info_node() which uses THREADINFO_GFP which is GFP_KERNEL | __GFP_NOTRACK. There shouldn't be __GFP_DMA, even on arm64. Are there some local modifications to the kernel source?

The page cache is very small(active_file:292kB inactive_file:240kB),
so did_some_progress may be zero, and will not retry, right?

Could be, and then __alloc_pages_may_oom() has this:

/* The OOM killer does not needlessly kill tasks for lowmem */
if (ac->high_zoneidx < ZONE_NORMAL)
goto out;

So no oom and no faking progress for non-costly order that would result in retry, because of that mysterious __GFP_DMA...

Thanks,
Xishi Qiu

--- dmesg messages ---
07-13 08:41:51.341 <4>[309805.658142s][pid:1361,cpu5,sManagerService]sManagerService: page allocation failure: order:2, mode:0x2000d1

Geez, these old kernels that can't print the mode human-readably...
#define ___GFP_DMA 0x01
#define ___GFP_WAIT 0x10
#define ___GFP_IO 0x40
#define ___GFP_FS 0x80
#define ___GFP_NOTRACK 0x200000

Compaction indeed should be possible. And it's a non-costly allocation. It shouldn't even be allowed to fail, unless the process was killed?

07-13 08:41:51.346 <4>[309805.658142s][pid:1361,cpu5,sManagerService]CPU: 5 PID: 1361 Comm: sManagerService Tainted: G W 4.1.18-g09f547b #1

There's a W taint flag so there should have been a WARN message/backtrace preceding it. What is it? It could be related.

07-13 08:41:51.347 <4>[309805.658142s][pid:1361,cpu5,sManagerService]TGID: 981 Comm: system_server
07-13 08:41:51.347 <4>[309805.658172s][pid:1361,cpu5,sManagerService]Hardware name: hi3650 (DT)
07-13 08:41:51.347 <0>[309805.658172s][pid:1361,cpu5,sManagerService]Call trace:
07-13 08:41:51.347 <4>[309805.658203s][pid:1361,cpu5,sManagerService][<ffffffc00008a0a4>] dump_backtrace+0x0/0x150
07-13 08:41:51.347 <4>[309805.658203s][pid:1361,cpu5,sManagerService][<ffffffc00008a214>] show_stack+0x20/0x28
07-13 08:41:51.347 <4>[309805.658203s][pid:1361,cpu5,sManagerService][<ffffffc000fc4034>] dump_stack+0x84/0xa8
07-13 08:41:51.347 <4>[309805.658203s][pid:1361,cpu5,sManagerService][<ffffffc00018af54>] warn_alloc_failed+0x10c/0x164
07-13 08:41:51.347 <4>[309805.658233s][pid:1361,cpu5,sManagerService][<ffffffc00018e778>] __alloc_pages_nodemask+0x5b4/0x888
07-13 08:41:51.347 <4>[309805.658233s][pid:1361,cpu5,sManagerService][<ffffffc00018eb84>] alloc_kmem_pages_node+0x44/0x50
07-13 08:41:51.347 <4>[309805.658233s][pid:1361,cpu5,sManagerService][<ffffffc00009fa78>] copy_process.part.46+0x140/0x15ac
07-13 08:41:51.347 <4>[309805.658233s][pid:1361,cpu5,sManagerService][<ffffffc0000a10a0>] do_fork+0xe8/0x444
07-13 08:41:51.347 <4>[309805.658264s][pid:1361,cpu5,sManagerService][<ffffffc0000a14e8>] SyS_clone+0x3c/0x48
07-13 08:41:51.347 <4>[309805.658264s][pid:1361,cpu5,sManagerService]Mem-Info:
07-13 08:41:51.347 <4>[309805.658264s][pid:1361,cpu5,sManagerService]active_anon:491074 inactive_anon:118072 isolated_anon:0
07-13 08:41:51.347 <4>[309805.658264s] active_file:19087 inactive_file:9843 isolated_file:0
07-13 08:41:51.347 <4>[309805.658264s] unevictable:322 dirty:20 writeback:0 unstable:0
07-13 08:41:51.347 <4>[309805.658264s] slab_reclaimable:11788 slab_unreclaimable:28068
07-13 08:41:51.347 <4>[309805.658264s] mapped:20633 shmem:4038 pagetables:10865 bounce:72
07-13 08:41:51.347 <4>[309805.658264s] free:118678 free_pcp:58 free_cma:0
07-13 08:41:51.347 <4>[309805.658294s][pid:1361,cpu5,sManagerService]DMA free:470628kB min:6800kB low:29116kB high:30816kB active_anon:1868540kB inactive_anon:376100kB active_file:292kB inactive_file:240kB unevictable:1080kB isolated(anon):0kB isolated(file):0kB present:3446780kB managed:3307056kB mlocked:1080kB dirty:80kB writeback:0kB mapped:7604kB shmem:14380kB slab_reclaimable:47152kB slab_unreclaimable:112268kB kernel_stack:28224kB pagetables:43460kB unstable:0kB bounce:288kB free_pcp:204kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
07-13 08:41:51.347 <4>[309805.658294s][pid:1361,cpu5,sManagerService]lowmem_reserve[]: 0 415 415
07-13 08:41:51.347 <4>[309805.658294s][pid:1361,cpu5,sManagerService]Normal free:4084kB min:872kB low:3740kB high:3960kB active_anon:95756kB inactive_anon:96188kB active_file:76056kB inactive_file:39132kB unevictable:208kB isolated(anon):0kB isolated(file):0kB present:524288kB managed:425480kB mlocked:208kB dirty:0kB writeback:0kB mapped:74928kB shmem:1772kB slab_reclaimable:0kB slab_unreclaimable:4kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:28kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
07-13 08:41:51.347 <4>[309805.658294s][pid:1361,cpu5,sManagerService]lowmem_reserve[]: 0 0 0
07-13 08:41:51.347 <4>[309805.658325s][pid:1361,cpu5,sManagerService]DMA: 68324*4kB (UEM) 24706*8kB (UER) 2*16kB (U) 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 470976kB

Indeed compaction should be doing something with this...

07-13 08:41:51.347 <4>[309805.658355s][pid:1361,cpu5,sManagerService]Normal: 270*4kB (UMR) 82*8kB (UMR) 48*16kB (MR) 25*32kB (R) 12*64kB (R) 2*128kB (R) 1*256kB (R) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 4584kB
07-13 08:41:51.347 <4>[309805.658386s][pid:1361,cpu5,sManagerService]38319 total pagecache pages
07-13 08:41:51.347 <4>[309805.658386s][pid:1361,cpu5,sManagerService]5384 pages in swap cache
07-13 08:41:51.347 <4>[309805.658386s][pid:1361,cpu5,sManagerService]Swap cache stats: add 628084, delete 622700, find 2187699/2264909
07-13 08:41:51.347 <4>[309805.658386s][pid:1361,cpu5,sManagerService]Free swap = 0kB
07-13 08:41:51.348 <4>[309805.658416s][pid:1361,cpu5,sManagerService]Total swap = 524284kB
07-13 08:41:51.348 <4>[309805.658416s][pid:1361,cpu5,sManagerService]992767 pages RAM
07-13 08:41:51.348 <4>[309805.658416s][pid:1361,cpu5,sManagerService]0 pages HighMem/MovableOnly
07-13 08:41:51.348 <4>[309805.658416s][pid:1361,cpu5,sManagerService]51441 pages reserved
07-13 08:41:51.348 <4>[309805.658416s][pid:1361,cpu5,sManagerService]8192 pages cma reserved
07-13 08:41:51.767 <6>[309806.068298s][pid:2247,cpu6,notification-sq][I/sensorhub] shb_release ok

.

Next message: kbuild test robot: "security/yama/yama_lsm.o: warning: objtool: report_access()+0x210: function has unreachable instruction"
Previous message: atull: "Re: [PATCH] fpga: zynq: Add hardware dependencies"
In reply to: Xishi Qiu: "Re: [Question]page allocation failure: order:2, mode:0x2000d1"
Next in thread: Yisheng Xie: "Re: [Question]page allocation failure: order:2, mode:0x2000d1"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]