This is a 59GB RAM system that's hitting OOM-Kills with plenty of recoverable memory around. This one is stubborn.
kthreadd invoked oom-killer: gfp_mask=0x26080c0, order=2, oom_score_adj=0
kthreadd cpuset=/ mems_allowed=0
CPU: 3 PID: 2 Comm: kthreadd Not tainted 4.4.0-1083-aws #93-Ubuntu
Hardware name: Xen HVM domU, BIOS 4.2.amazon 08/24/2006
0000000000000286 ecc5681d66b270c1 ffff880f7b54fad0 ffffffff81407501
ffff880f7b54fc88 ffff88010f19e040 ffff880f7b54fb40 ffffffff81214a0a
0000000000000000 ffff880f7884ea80 ffff8804fa62a940 ffff880f7b54fb28
Call Trace:
[<ffffffff81407501>] dump_stack+0x63/0x82
[<ffffffff81214a0a>] dump_header+0x5a/0x1c3
[<ffffffff8139e754>] ? apparmor_capable+0xc4/0x1b0
[<ffffffff81198f7b>] oom_kill_process+0x20b/0x3d0
[<ffffffff811993a9>] out_of_memory+0x219/0x460
[<ffffffff8119f3c3>] __alloc_pages_slowpath.constprop.88+0x943/0xaf0
[<ffffffff8119f7f8>] __alloc_pages_nodemask+0x288/0x2a0
[<ffffffff810b803d>] ? attach_task_cfs_rq+0x3d/0x80
[<ffffffff810a5220>] ? kthread_create_on_node+0x1e0/0x1e0
[<ffffffff8119f8ab>] alloc_kmem_pages_node+0x4b/0xc0
[<ffffffff810a5220>] ? kthread_create_on_node+0x1e0/0x1e0
[<ffffffff81081ab9>] copy_process+0x1d9/0x1c30
[<ffffffff8183c201>] ? __schedule+0x301/0x810
[<ffffffff8183c20d>] ? __schedule+0x30d/0x810
[<ffffffff8183c201>] ? __schedule+0x301/0x810
[<ffffffff8183c20d>] ? __schedule+0x30d/0x810
[<ffffffff810836a0>] _do_fork+0x80/0x360
[<ffffffff8183c241>] ? __schedule+0x341/0x810
[<ffffffff810839a9>] kernel_thread+0x29/0x30
[<ffffffff810a5ce8>] kthreadd+0x148/0x190
[<ffffffff810a5ba0>] ? kthread_create_on_cpu+0x60/0x60
[<ffffffff81841565>] ret_from_fork+0x55/0x80
[<ffffffff810a5ba0>] ? kthread_create_on_cpu+0x60/0x60
Mem-Info:
active_anon:6852345 inactive_anon:67572 isolated_anon:0
active_file:4085952 inactive_file:4062216 isolated_file:32
unevictable:913 dirty:54748 writeback:25758 unstable:0
slab_reclaimable:434984 slab_unreclaimable:13452
mapped:2572311 shmem:164039 pagetables:50287 bounce:0
free:84572 free_pcp:8 free_cma:0
Node 0 DMA free:15900kB min:16kB low:20kB high:24kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
lowmem_reserve[]: 0 1953 61390 61390 61390
Node 0 DMA32 free:255200kB min:2132kB low:2664kB high:3196kB active_anon:1722736kB inactive_anon:0kB active_file:4kB inactive_file:4kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2080768kB managed:2000228kB mlocked:0kB dirty:0kB writeback:0kB mapped:8kB shmem:0kB slab_reclaimable:16304kB slab_unreclaimable:1292kB kernel_stack:128kB pagetables:3640kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 0 59437 59437 59437
Node 0 Normal free:67188kB min:65432kB low:81788kB high:98148kB active_anon:25686644kB inactive_anon:270288kB active_file:16343804kB inactive_file:16248860kB unevictable:3652kB isolated(anon):0kB isolated(file):128kB present:61865984kB managed:60863752kB mlocked:3652kB dirty:218992kB writeback:103032kB mapped:10289236kB shmem:656156kB slab_reclaimable:1723632kB slab_unreclaimable:52516kB kernel_stack:7104kB pagetables:197508kB unstable:0kB bounce:0kB free_pcp:36kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:6116 all_unreclaimable? no
lowmem_reserve[]: 0 0 0 0 0
Node 0 DMA: 1*4kB (U) 1*8kB (U) 1*16kB (U) 0*32kB 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15900kB
Node 0 DMA32: 688*4kB (ME) 522*8kB (UME) 401*16kB (UME) 256*32kB (UM) 147*64kB (UM) 68*128kB (UME) 34*256kB (UME) 18*512kB (UM) 11*1024kB (UME) 7*2048kB (UME) 42*4096kB (M) = 255200kB
Node 0 Normal: 16723*4kB (UMEH) 2*8kB (H) 1*16kB (H) 4*32kB (H) 4*64kB (H) 1*128kB (H) 2*256kB (H) 1*512kB (H) 0*1024kB 0*2048kB 0*4096kB = 68460kB
Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
8312802 total pagecache pages
0 pages in swap cache
Swap cache stats: add 0, delete 0, find 0/0
Free swap = 0kB
Total swap = 0kB
15990685 pages RAM
0 pages HighMem/MovableOnly
270715 pages reserved
0 pages cma reserved
0 pages hwpoisoned
[ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name
[ 450] 0 450 36775 25135 75 3 0 0 systemd-journal
[ 493] 0 493 25742 45 17 4 0 0 lvmetad
[ 522] 0 522 10921 1129 22 3 0 -1000 systemd-udevd
[ 1112] 0 1112 4030 709 11 3 0 0 dhclient
[ 1260] 0 1260 1099 296 8 3 0 0 acpid
[ 1264] 0 1264 68648 596 36 4 0 0 accounts-daemon
[ 1266] 0 1266 1305 28 8 3 0 0 iscsid
[ 1267] 0 1267 1430 877 9 3 0 -17 iscsid
[ 1280] 107 1280 10757 327 25 3 0 -900 dbus-daemon
[ 1291] 0 1291 77264 529 20 3 0 0 lxcfs
[ 1293] 0 1293 6511 396 19 3 0 0 atd
[ 1295] 104 1295 65157 1015 29 4 0 0 rsyslogd
[ 1303] 0 1303 5024 268 14 3 0 0 systemd-logind
[ 1305] 0 1305 6932 506 18 3 0 0 cron
[ 1307] 0 1307 231489 3444 53 6 0 0 amazon-ssm-agen
[ 1344] 0 1344 69278 683 38 4 0 0 polkitd
[ 1406] 0 1406 3343 36 11 3 0 0 mdadm
[ 1468] 0 1468 16378 441 36 3 0 -1000 sshd
[ 1497] 0 1497 4901 283 14 3 0 0 irqbalance
[ 1509] 112 1509 27509 459 26 4 0 0 ntpd
[ 1519] 0 1519 9672 634 23 3 0 0 monit
[ 1637] 0 1637 233876 7156 63 25 0 0 node
[ 3023] 0 3023 1475808 143142 402 9 0 0 java
[ 3117] 0 3117 193826 912 43 4 0 0 collectd
[ 3328] 0 3328 3664 343 11 3 0 0 agetty
[ 3329] 0 3329 3618 392 12 3 0 0 agetty
[ 7107] 114 7107 249623716 9115398 48941 947 0 0 java
[20376] 0 20376 314931 18408 124 34 0 0 node
[20400] 0 20400 36161 1469 50 5 0 0 tsauditd
[20492] 0 20492 77044 8287 52 3 0 0 tsfim
[29823] 0 29823 199481 6601 54 6 0 -900 snapd
Out of memory: Kill process 7107 (java) score 583 or sacrifice child
Killed process 7107 (java) total-vm:998494864kB, anon-rss:26292036kB, file-rss:10168536kB
gfp_mask=0x26080c0
decodes to:
- 2: GFP_KSWAPD_RECLAIM
- 6: GFP_DIRECT_RECLAIM + GFP_NOTRACK
- 0:
- 8: GFP_ZERO
- 0:
- C: GFP_FS + GFP_IO
- 0: Memory zone Normal
Which tells me that the allocation problems are in the Normal memory zone, and I don't have to look at either DMA or DMA32. Nice. Two reclaim flags are used, which should tell the memory allocator to go ahead and reclaim memory to satisfy this request. GFP_FS and GFP_IO might be a hint that this particular request may be mmap somehow, but I can't tell.
The overall Mem-Info
shows a system with about 26GB in active_anon memory (active_anon:6852345), plus another 32GBish in active and inactive caches (active_file:4085952 and inactive_file:4062216 respectively) that should be reclaimable. On the surface, this looks like there is plenty of memory to go around, but we still hit the killer. So we're probably facing a fragmentation issue.
Looking at the zone info...
Node 0 Normal
free:67188kB min:65432kB low:81788kB high:98148kB
active_anon:25686644kB inactive_anon:270288kB
active_file:16343804kB inactive_file:16248860kB
unevictable:3652kB isolated(anon):0kB isolated(file):128kB
present:61865984kB managed:60863752kB mlocked:3652kB
dirty:218992kB writeback:103032kB mapped:10289236kB shmem:656156kB
slab_reclaimable:1723632kB slab_unreclaimable:52516kB
kernel_stack:7104kB pagetables:197508kB unstable:0kB
bounce:0kB free_pcp:36kB local_pcp:0kB free_cma:0kB
writeback_tmp:0kB pages_scanned:6116
all_unreclaimable? no
We get numbers pretty close to the top-line Mem-Info numbers. Which is to be expected. The DMA32 zone has some usage in it, but is much smaller than Normal.
Looking at the page-size info for Normal...
Node 0 Normal:
16723*4kB (UMEH)
2*8kB (H)
1*16kB (H)
4*32kB (H)
4*64kB (H)
1*128kB (H)
2*256kB (H)
1*512kB (H)
0*1024kB 0*2048kB 0*4096kB
= 68460kB
(The decodes for the UMEH characters) I suspect my clue is in here, but I'm not seeing it. Nearly all of the memory usage is in the 4kB bucket, which suggests fragmentation. In this case, the DMA32 bucket is actually larger by a fair piece. I guess I don't understand what these lines are telling me.
Are the gfp mask flags indicating this is a memmapped write of some kind?
Where is the fragmentation here?