Hi, experts
I am looking for some help on debugging a page allocation failure when there
are many free pages. The kernel is v4.19 with some backported patches. I don't
expect functional difference from upstream.
The request order is 0, and each zone has some free pages. So to me it seems
could get a free page successfully. But maybe I missed something.
Below is the dmesg, and I have manually adjusted to help me understand. If
there would be some suggestion, I would appreciate it a lot.
[1195372.701524] java: page allocation failure: order:0, mode:0x400000(GFP_NOWAIT), nodemask=(null),cpuset=/,mems_allowed=0
[1195373.162873] CPU: 6 PID: 7121 Comm: java Kdump: loaded Not tainted 4.19.95-29 #1
[1195373.164655] Call Trace:
[1195373.164990] dump_stack+0x6d/0x89
[1195373.165626] warn_alloc+0xff/0x170
[1195373.166117] ? wake_all_kswapds+0x58/0x99
[1195373.166842] __alloc_pages_slowpath+0x735/0x8d0
[1195373.167351] __alloc_pages_nodemask+0x2c9/0x2f0
[1195373.167849] alloc_pages_current+0x6a/0xb0
[1195373.168328] new_slab+0x33d/0x400
[1195373.168726] ? __switch_to_asm+0x35/0x70
[1195373.169234] ___slab_alloc+0x38f/0x570
[1195373.169703] ? alloc_vmap_area+0x27c/0x7c0
[1195373.170404] ? __switch_to_asm+0x41/0x70
[1195373.170885] ? __switch_to_asm+0x35/0x70
[1195373.171383] ? __switch_to_asm+0x41/0x70
[1195373.172154] ? __switch_to_asm+0x35/0x70
[1195373.172577] ? __switch_to_asm+0x41/0x70
[1195373.172984] ? __switch_to_asm+0x41/0x70
[1195373.173395] ? __switch_to_asm+0x35/0x70
[1195373.173888] ? __switch_to_asm+0x41/0x70
[1195373.174542] ? alloc_vmap_area+0x27c/0x7c0
[1195373.174962] __slab_alloc+0x45/0x5f
[1195373.175330] ? alloc_vmap_area+0x27c/0x7c0
[1195373.175768] kmem_cache_alloc+0x30c/0x3c0
[1195373.176177] alloc_vmap_area+0x27c/0x7c0
[1195373.176592] __get_vm_area_node+0xb5/0x170
[1195373.177019] __vmalloc_node_range+0x7a/0x290
[1195373.177542] ? _do_fork+0xf6/0x390
[1195373.177907] ? kmem_cache_alloc_node+0x2af/0x390
[1195373.178437] copy_process.part.32+0x816/0x1c10
[1195373.178896] ? _do_fork+0xf6/0x390
[1195373.179268] ? do_tcp_setsockopt.isra.43+0x2fe/0xb90
[1195373.179907] _do_fork+0xf6/0x390
[1195373.180514] __x64_sys_clone+0x27/0x30
[1195373.180907] do_syscall_64+0x60/0x1b0
[1195373.181358] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[1195373.181872] RIP: 0033:0x7f719cca59c1
[1195373.182246] Code: 48 85 ff 74 69 48 85 f6 74 64 48 83 ee 10 48 89 4e 08 48 89 3e 48 89 d7 4c 89 c2 4d 89 c8 4c 8b 54 24 08 b8 38 00 00 00 0f 05 <48> 85 c0 7c 3f 74 01 c3 31 ed 48 f7 c7 00 00 01 00 75 25 48 f7 c7
[1195373.183935] RSP: 002b:00007f7167240758 EFLAGS: 00000202 ORIG_RAX: 0000000000000038
[1195373.184791] RAX: ffffffffffffffda RBX: 00007f714e706700 RCX: 00007f719cca59c1
[1195373.185472] RDX: 00007f714e7069d0 RSI: 00007f714e705fb0 RDI: 00000000003d0f00
[1195373.186245] RBP: 00007f7167240830 R08: 00007f714e706700 R09: 00007f714e706700
[1195373.187164] R10: 00007f714e7069d0 R11: 0000000000000202 R12: 0000000000000000
[1195373.187844] R13: 0000000000100000 R14: 0000000000000003 R15: 00007f714e706700
[1195373.188518] Mem-Info:
[1195373.188784]
Global Info:
active_anon: 416 1.625M inactive_anon:1816625 6.929G isolated_anon:0
active_file:1261763 4.813G inactive_file:4528074 17.273G isolated_file:32
unevictable:0 dirty: 740915 2.826G writeback:2046 unstable:0
slab_reclaimable: 95037 371.238M
slab_unreclaimable:26598 103.898M
mapped:11897 shmem:171 pagetables:4977 bounce:0
free:344490 1.314G
free_pcp:1985 free_cma:0
[1195373.192698]
Node Info:
Node 0
active_anon:1664kB 1.6M inactive_anon:7266500kB 6.9G
active_file:5047052kB 4.8G inactive_file:18112296kB 17.2G
unevictable:0kB isolated(anon):0kB isolated(file):128kB
mapped:47588kB dirty:2963076kB writeback:9060kB
shmem:684kB shmem_thp: 0kB shmem_pmdmapped: 0kB
anon_thp: 6785024kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[1195373.195326]
Zone Info:
Node 0 DMA
free:15908kB 15M
min:508kB
low:632kB
high:756kB
active_anon:0kB
inactive_anon:0kB
active_file:0kB
inactive_file:0kB
unevictable:0kB writepending:0kB
present:15992kB
managed:15908kB 15M
mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[1195373.197666] lowmem_reserve[]: 0 2717 31867 31867 31867
Node 0 DMA32
free:410800kB 401M
min:292196kB
low:314672kB
high:337148kB
active_anon:48kB
inactive_anon:458756kB 448M
active_file:1000096kB 976M
inactive_file:742940kB 725M
unevictable:0kB writepending:947760kB
present:3129156kB 2.98G
managed:2801476kB 2.67G
mlocked:0kB kernel_stack:816kB pagetables:1296kB bounce:0kB free_pcp:4228kB local_pcp:248kB free_cma:0kB
[1195373.323857] lowmem_reserve[]: 0 0 29149 29149 29149
[1195373.428886]
Node 0 Normal
free:1044716kB 0.99G
min:958156kB
low:1197692kB
high:1437228kB
active_anon:1616kB 1.57M
inactive_anon:6808036kB 6.49G
active_file:4067912kB 3.87G
inactive_file:17251456kB 16.45G
unevictable:0kB writepending:2026288kB
present:30408704kB
managed:29855140kB
mlocked:0kB kernel_stack:7408kB pagetables:18612kB bounce:0kB free_pcp:3316kB local_pcp:312kB free_cma:0kB
[1195373.432065] lowmem_reserve[]: 0 0 0 0 0
[1195373.432518]
Node 0 DMA:
1*4kB (U)
0*8kB
0*16kB
1*32kB (U)
2*64kB (U)
1*128kB (U)
1*256kB (U)
0*512kB
1*1024kB (U)
1*2048kB (M)
3*4096kB (M) = 15908kB
Node 0 DMA32:
1*4kB (M)
0*8kB
24850*16kB (U)
348*32kB (UE)
0*64kB
0*128kB
0*256kB
0*512kB
0*1024kB
0*2048kB
0*4096kB = 408740kB
Node 0 Normal:
23516*4kB (UMEH)
1746*8kB (UMEH)
2785*16kB (UMEH)
2699*32kB (UMEH)
1820*64kB (UMEH)
1860*128kB (UMEH)
724*256kB (UME)
445*512kB (UMEH)
30*1024kB (UME)
3*2048kB (M)
0*4096kB = 1043568kB
[1195373.437470] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
[1195373.437472] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[1195373.437474] 5765741 5.49G total pagecache pages
[1195373.437942] 0 pages in swap cache
[1195373.438338] Swap cache stats: add 0, delete 0, find 0/0
[1195373.438922] Free swap = 0kB
[1195373.439276] Total swap = 0kB
[1195373.439630] 8388463 31.999G pages RAM
[1195373.439999] 0 pages HighMem/MovableOnly
[1195373.440445] 220332 860.671M pages reserved
[1195373.440845] 0 pages hwpoisoned
[1195373.441227] SLUB: Unable to allocate memory on node -1, gfp=0x400000(GFP_NOWAIT)
[1195373.442028] cache: vmap_area, object size: 88, buffer size: 88, default order: 0, min order: 0
[1195373.443006] node 0: slabs: 347, objs: 15962, free: 0
--
Wei Yang
Help you, Help me
