Hello,
We had this strange OOM trace, with low value for
[51381.921936] xmlrpcphone-sta invoked oom-killer: gfp_mask=0x201d2, order=0, oom_score_adj=0
[51381.921945] CPU: 0 PID: 25443 Comm: xmlrpcphone-sta Tainted: G W O 3.10.40-gde7aafa-dirty #59
[51381.921961] [<c0016418>] (unwind_backtrace+0x0/0x140) from [<c0012f48>] (show_stack+0x18/0x1c)
[51381.921971] [<c0012f48>] (show_stack+0x18/0x1c) from [<c07f4fe0>] (dump_header.isra.13+0x74/0xb0)
[51381.921980] [<c07f4fe0>] (dump_header.isra.13+0x74/0xb0) from [<c07f5070>] (oom_kill_process.part.15+0x54/0x394)
[51381.921988] [<c07f5070>] (oom_kill_process.part.15+0x54/0x394) from [<c0106f84>] (out_of_memory+0x12c/0x1cc)
[51381.921996] [<c0106f84>] (out_of_memory+0x12c/0x1cc) from [<c010b7f4>] (__alloc_pages_nodemask+0x8e0/0x90c)
[51381.922003] [<c010b7f4>] (__alloc_pages_nodemask+0x8e0/0x90c) from [<c0105cac>] (filemap_fault+0x19c/0x3c8)
[51381.922010] [<c0105cac>] (filemap_fault+0x19c/0x3c8) from [<c0124a28>] (__do_fault+0x88/0x4c4)
[51381.922026] [<c0124a28>] (__do_fault+0x88/0x4c4) from [<c01282ac>] (handle_pte_fault+0xb8/0x1d8)
[51381.922033] [<c01282ac>] (handle_pte_fault+0xb8/0x1d8) from [<c0128430>] (__handle_mm_fault+0x64/0x90)
[51381.922040] [<c0128430>] (__handle_mm_fault+0x64/0x90) from [<c001e628>] (do_page_fault+0xcc/0x318)
[51381.922046] [<c001e628>] (do_page_fault+0xcc/0x318) from [<c0008434>] (do_PrefetchAbort+0x3c/0xa4)
[51381.922053] [<c0008434>] (do_PrefetchAbort+0x3c/0xa4) from [<c000ee14>] (ret_from_exception+0x0/0x10)
[51381.922057] Exception stack(0xd7e87fb0 to 0xd7e87ff8)
[51381.922061] 7fa0: 7727a4bc 00000000 7727a4dc 7727a4bc
[51381.922066] 7fc0: b6feee70 7727b050 7727b050 7727aa48 7727ab90 00000000 7727b284 7727a4c4
[51381.922070] 7fe0: b6fef0dc 7727a4b8 b6f28b04 b654a714 60070030 ffffffff
[51381.922073] Mem-info:
[51381.922077] Normal per-cpu:
[51381.922080] CPU 0: hi: 186, btch: 31 usd: 0
[51381.922084] CPU 1: hi: 186, btch: 31 usd: 0
[51381.922087] CPU 2: hi: 186, btch: 31 usd: 30
[51381.922090] CPU 3: hi: 186, btch: 31 usd: 30
[51381.922093] HighMem per-cpu:
[51381.922096] CPU 0: hi: 186, btch: 31 usd: 32
[51381.922099] CPU 1: hi: 186, btch: 31 usd: 105
[51381.922101] CPU 2: hi: 186, btch: 31 usd: 2
[51381.922104] CPU 3: hi: 186, btch: 31 usd: 30
[51381.922111] active_anon:426022 inactive_anon:12256 isolated_anon:0
[51381.922111] active_file:233 inactive_file:1359 isolated_file:17
[51381.922111] unevictable:48 dirty:5 writeback:0 unstable:0
[51381.922111] free:15991 slab_reclaimable:1844 slab_unreclaimable:4940
[51381.922111] mapped:19162 shmem:21918 pagetables:1133 bounce:0
[51381.922111] free_cma:4024
[51381.922124] Normal free:63676kB min:2712kB low:3388kB high:4068kB active_anon:343020kB inactive_anon:25460kB active_file:396kB inactive_file:2256kB unevictable:0kB isolated(anon):0kB isolated(file):68kB present:507904kB managed:460160kB mlocked:0kB dirty:16kB writeback:0kB mapped:6792kB shmem:56832kB slab_reclaimable:7376kB slab_unreclaimable:19760kB kernel_stack:1312kB pagetables:4532kB unstable:0kB bounce:0kB free_cma:16096kB writeback_tmp:0kB pages_scanned:3553 all_unreclaimable? yes
[51381.922127] lowmem_reserve[]: 0 11416 11416
[51381.922182] HighMem free:288kB min:512kB low:2664kB high:4816kB active_anon:1361068kB inactive_anon:23564kB active_file:536kB inactive_file:3180kB unevictable:192kB isolated(anon):0kB isolated(file):0kB present:1461248kB managed:1461248kB mlocked:192kB dirty:4kB writeback:0kB mapped:69856kB shmem:30840kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:5728 all_unreclaimable? yes
[51381.922185] lowmem_reserve[]: 0 0 0
[51381.922192] Normal: 844*4kB (UE) 336*8kB (UEM) 185*16kB (UEM) 98*32kB (UEMC) 68*64kB (UEMC) 31*128kB (UEC) 15*256kB (U) 3*512kB (UC) 3*1024kB (UC) 1*2048kB (C) 8*4096kB (MRC) = 63744kB
[51381.922224] HighMem: 23*4kB (M) 22*8kB (UM) 5*16kB (U) 1*32kB (M) 1*64kB (M) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 444kB
[51381.922247] 23645 total pagecache pages
[51381.922250] 0 pages in swap cache
[51381.922253] Swap cache stats: add 0, delete 0, find 0/0
[51381.922256] Free swap = 0kB
[51381.922258] Total swap = 0kB
[51381.931635] 515840 pages of RAM
[51381.931692] 16904 free pages
[51381.931695] 31265 reserved pages
[51381.931697] 6806 slab pages
[51381.931700] 282708 pages shared
[51381.931703] 0 pages swap cached
[51381.931707] [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name
[51381.931724] [ 272] 0 272 656 154 4 0 0 upstart-udev-br
[51381.931729] [ 284] 0 284 521 41 4 0 0 rpc.idmapd
[51381.931734] [ 292] 103 292 853 125 4 0 0 dbus-daemon
[51381.931739] [ 304] 0 304 2361 189 5 0 -1000 systemd-udevd
[51381.931743] [ 368] 0 368 841 96 4 0 0 systemd-logind
[51381.931748] [ 402] 101 402 7619 153 8 0 0 rsyslogd
[51381.931752] [ 933] 0 933 506 78 4 0 0 rpcbind
[51381.931757] [ 965] 118 965 544 126 3 0 0 rpc.statd
[51381.931761] [ 1023] 0 1023 726 273 4 0 0 upstart-file-br
[51381.931766] [ 1026] 0 1026 519 79 3 0 0 upstart-socket-
[51381.931770] [ 1163] 0 1163 12699 292 15 0 0 NetworkManager
[51381.931775] [ 1165] 0 1165 964 48 5 0 0 getty
[51381.931779] [ 1167] 0 1167 964 48 4 0 0 getty
[51381.931784] [ 1172] 0 1172 964 48 5 0 0 getty
[51381.931788] [ 1173] 0 1173 964 48 5 0 0 getty
[51381.931792] [ 1176] 0 1176 964 48 5 0 0 getty
[51381.931797] [ 1197] 0 1197 1471 140 5 0 -1000 sshd
[51381.931801] [ 1210] 0 1210 565 67 4 0 0 cron
[51381.931805] [ 1245] 0 1245 8675 153 10 0 0 polkitd
[51381.931810] [ 1246] 119 1246 483 53 3 0 0 dnsproxy
[51381.931814] [ 1425] 0 1425 964 48 5 0 0 getty
[51381.931818] [ 1426] 0 1426 1349 168 5 0 0 login
[51381.931835] [ 1477] 1000 1477 1150 60 4 0 0 bash
[51381.931840] [ 1550] 0 1550 2763 236 7 0 0 sshd
[51381.931844] [ 1593] 1000 1593 2763 214 6 0 0 sshd
[51381.931849] [ 1596] 1000 1596 1149 105 4 0 0 bash
[51381.931853] [ 1666] 117 1666 1069 121 4 0 0 ntpd
[51381.931857] [ 1786] 0 1786 1889 157 5 0 0 sudo
[51381.931861] [ 1793] 0 1793 1777 145 6 0 0 su
[51381.932085] [ 1802] 0 1802 1168 123 5 0 0 bash
[51381.932092] [ 1835] 0 1835 381360 347823 721 0 0 xmlrpcphone-sta
[51381.932096] [ 1852] 0 1852 567 86 3 0 0 tmux
[51381.932100] [ 1854] 0 1854 1409 881 5 0 0 tmux
[51381.932104] [ 1855] 0 1855 1176 133 4 0 0 bash
[51381.932109] [ 2573] 0 2573 1176 131 5 0 0 bash
[51381.932114] [14079] 0 14079 2804 239 8 0 0 sshd
[51381.932118] [14144] 1000 14144 2804 218 7 0 0 sshd
[51381.932123] [14147] 1000 14147 1152 107 4 0 0 bash
[51381.932127] [14159] 0 14159 1889 157 6 0 0 sudo
[51381.932131] [14167] 0 14167 1777 145 6 0 0 su
[51381.932135] [14176] 0 14176 1170 110 5 0 0 bash
[51381.932141] [25193] 0 25193 2797 239 7 0 0 sshd
[51381.932146] [25246] 1000 25246 2797 234 6 0 0 sshd
[51381.932150] [25249] 1000 25249 1149 104 5 0 0 bash
[51381.932154] [25289] 0 25289 1889 157 6 0 0 sudo
[51381.932158] [25296] 0 25296 1777 145 6 0 0 su
[51381.932163] [25306] 0 25306 1167 123 5 0 0 bash
[51381.932167] [25442] 0 25442 82201 81784 163 0 0 perf
[51381.932172] Out of memory: Kill process 1835 (xmlrpcphone-sta) score 697 or sacrifice child
[51381.940857] Killed process 1835 (xmlrpcphone-sta) total-vm:1525440kB, anon-rss:1321632kB, file-rss:69660kB
Our appliaction appears as “xmlrpcphone-sta” process and only consums 381M of RSS and there is almost no other threads running.
How a 2GBytes linux system could be oom with only using 500Mbytes of RAM ?
The only clue we have is : 44kkB of Free High Mem
HighMem: 23*4kB (M) 22*8kB (UM) 5*16kB (U) 1*32kB (M) 1*64kB (M) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 444kB
Did we miss some important information ?
The system is started with vmalloc=512M at boot time, and our application mmap about 200Mbytes of V4L2 buffer.
When running the system ay have the following buddy info :
cat /proc/buddyinfo
Node 0, zone Normal 64 34 156 96 71 14 15 6 3 2 17
Node 0, zone HighMem 6 0 0 1 0 0 0 1 0 1 0
Again some low values for HighMem.
Is this normal ?