I’ve got a headless ARM-based Linux (v3.10.53-1.1.1) system with no swap space enabled, and I occasionally see processes get killed by the OOM-killer even though there is plenty of RAM available.
Running echo 1 > /proc/sys/vm/compact_memory periodically seems to keep the OOM-killer at bay, which makes me think that memory fragmentation is the culprit, but I don’t understand why a user process would ever need physically-contiguous blocks anyway; as I understand it, even in the worst-case scenario (complete fragmentation, with only individual 4K blocks available), the kernel could simply allocate the necessary number of individual 4K blocks and then use the Magic of Virtual Memory ™ to make them look contiguous to the user-process.
Can someone explain why the OOM-killer would be invoked in response to memory fragmentation? Is it just a buggy kernel or is there a genuine reason? (And even if the kernel did need to de-frag memory in order to satisfy a request, shouldn’t it do that automatically rather than giving up and OOM’ing?)
I’ve pasted an example OOM-killer invocation below, in case it sheds any light on things. I can reproduce the fault at will; this invocation occurred while the computer still had ~120MB of RAM available (according to free), in response to my test-program allocating memory, 10000 400-byte allocations at a time.
May 28 18:51:34 g2 user.warn kernel: [ 4228.307769] cored invoked oom-killer: gfp_mask=0x2084d0, order=0, oom_score_adj=0 May 28 18:51:35 g2 user.warn kernel: [ 4228.315295] CPU: 2 PID: 19687 Comm: cored Tainted: G O 3.10.53-1.1.1_ga+gf57416a #1 May 28 18:51:35 g2 user.warn kernel: [ 4228.323843] Backtrace: May 28 18:51:35 g2 user.warn kernel: [ 4228.326340] [<c0011c54>] (dump_backtrace+0x0/0x10c) from [<c0011e68>] (show_stack+0x18/0x1c) May 28 18:51:35 g2 user.warn kernel: [ 4228.334804] r6:00000000 r5:00000000 r4:c9784000 r3:00000000 May 28 18:51:35 g2 user.warn kernel: [ 4228.340566] [<c0011e50>] (show_stack+0x0/0x1c) from [<c04d0dd8>] (dump_stack+0x24/0x28) May 28 18:51:35 g2 user.warn kernel: [ 4228.348684] [<c04d0db4>] (dump_stack+0x0/0x28) from [<c009b474>] (dump_header.isra.10+0x84/0x19c) May 28 18:51:35 g2 user.warn kernel: [ 4228.357616] [<c009b3f0>] (dump_header.isra.10+0x0/0x19c) from [<c009ba3c>] (oom_kill_process+0x288/0x3f4) May 28 18:51:35 g2 user.warn kernel: [ 4228.367230] [<c009b7b4>] (oom_kill_process+0x0/0x3f4) from [<c009bf8c>] (out_of_memory+0x208/0x2cc) May 28 18:51:35 g2 user.warn kernel: [ 4228.376323] [<c009bd84>] (out_of_memory+0x0/0x2cc) from [<c00a0278>] (__alloc_pages_nodemask+0x8f8/0x910) May 28 18:51:35 g2 user.warn kernel: [ 4228.385921] [<c009f980>] (__alloc_pages_nodemask+0x0/0x910) from [<c00b6c34>] (__pte_alloc+0x2c/0x158) May 28 18:51:35 g2 user.warn kernel: [ 4228.395263] [<c00b6c08>] (__pte_alloc+0x0/0x158) from [<c00b9fe0>] (handle_mm_fault+0xd4/0xfc) May 28 18:51:35 g2 user.warn kernel: [ 4228.403914] r6:c981a5d8 r5:cc421a40 r4:10400000 r3:10400000 May 28 18:51:35 g2 user.warn kernel: [ 4228.409689] [<c00b9f0c>] (handle_mm_fault+0x0/0xfc) from [<c0019a00>] (do_page_fault+0x174/0x3dc) May 28 18:51:35 g2 user.warn kernel: [ 4228.418575] [<c001988c>] (do_page_fault+0x0/0x3dc) from [<c0019dc0>] (do_translation_fault+0xb4/0xb8) May 28 18:51:35 g2 user.warn kernel: [ 4228.427824] [<c0019d0c>] (do_translation_fault+0x0/0xb8) from [<c00083ac>] (do_DataAbort+0x40/0xa0) May 28 18:51:35 g2 user.warn kernel: [ 4228.436896] r6:c0019d0c r5:00000805 r4:c06a33d0 r3:103ffea8 May 28 18:51:35 g2 user.warn kernel: [ 4228.442643] [<c000836c>] (do_DataAbort+0x0/0xa0) from [<c000e138>] (__dabt_usr+0x38/0x40) May 28 18:51:35 g2 user.warn kernel: [ 4228.450850] Exception stack(0xc9785fb0 to 0xc9785ff8) May 28 18:51:35 g2 user.warn kernel: [ 4228.455918] 5fa0: 103ffea8 00000000 b6d56708 00000199 May 28 18:51:35 g2 user.warn kernel: [ 4228.464116] 5fc0: 00000001 b6d557c0 0001ffc8 b6d557f0 103ffea0 b6d55228 10400038 00000064 May 28 18:51:35 g2 user.warn kernel: [ 4228.472327] 5fe0: 0001ffc9 beb04990 00000199 b6c95d84 600f0010 ffffffff May 28 18:51:35 g2 user.warn kernel: [ 4228.478952] r8:103ffea0 r7:b6d557f0 r6:ffffffff r5:600f0010 r4:b6c95d84 May 28 18:51:35 g2 user.warn kernel: [ 4228.485759] Mem-info: May 28 18:51:35 g2 user.warn kernel: [ 4228.488038] DMA per-cpu: May 28 18:51:35 g2 user.warn kernel: [ 4228.490589] CPU 0: hi: 90, btch: 15 usd: 5 May 28 18:51:35 g2 user.warn kernel: [ 4228.495389] CPU 1: hi: 90, btch: 15 usd: 13 May 28 18:51:35 g2 user.warn kernel: [ 4228.500205] CPU 2: hi: 90, btch: 15 usd: 17 May 28 18:51:35 g2 user.warn kernel: [ 4228.505003] CPU 3: hi: 90, btch: 15 usd: 65 May 28 18:51:35 g2 user.warn kernel: [ 4228.509823] active_anon:92679 inactive_anon:47 isolated_anon:0 May 28 18:51:35 g2 user.warn kernel: [ 4228.509823] active_file:162 inactive_file:1436 isolated_file:0 May 28 18:51:35 g2 user.warn kernel: [ 4228.509823] unevictable:0 dirty:0 writeback:0 unstable:0 May 28 18:51:35 g2 user.warn kernel: [ 4228.509823] free:28999 slab_reclaimable:841 slab_unreclaimable:2103 May 28 18:51:35 g2 user.warn kernel: [ 4228.509823] mapped:343 shmem:89 pagetables:573 bounce:0 May 28 18:51:35 g2 user.warn kernel: [ 4228.509823] free_cma:29019 May 28 18:51:35 g2 user.warn kernel: [ 4228.541416] DMA free:115636kB min:1996kB low:2492kB high:2992kB active_anon:370716kB inactive_anon:188kB active_file:752kB inactive_file:6040kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:524288kB managed:2 May 28 18:51:35 g2 user.warn kernel: [ 4228.583833] lowmem_reserve[]: 0 0 0 0 May 28 18:51:35 g2 user.warn kernel: [ 4228.587577] DMA: 2335*4kB (UMC) 1266*8kB (UMC) 1034*16kB (UMC) 835*32kB (UC) 444*64kB (C) 28*128kB (C) 103*256kB (C) 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB 0*32768kB = 121100kB May 28 18:51:35 g2 user.warn kernel: [ 4228.604979] 502 total pagecache pages May 28 18:51:35 g2 user.warn kernel: [ 4228.608649] 0 pages in swap cache May 28 18:51:35 g2 user.warn kernel: [ 4228.611979] Swap cache stats: add 0, delete 0, find 0/0 May 28 18:51:35 g2 user.warn kernel: [ 4228.617210] Free swap = 0kB May 28 18:51:35 g2 user.warn kernel: [ 4228.620110] Total swap = 0kB May 28 18:51:35 g2 user.warn kernel: [ 4228.635245] 131072 pages of RAM May 28 18:51:35 g2 user.warn kernel: [ 4228.638394] 30575 free pages May 28 18:51:35 g2 user.warn kernel: [ 4228.641293] 3081 reserved pages May 28 18:51:35 g2 user.warn kernel: [ 4228.644437] 1708 slab pages May 28 18:51:35 g2 user.warn kernel: [ 4228.647239] 265328 pages shared May 28 18:51:35 g2 user.warn kernel: [ 4228.650399] 0 pages swap cached May 28 18:51:35 g2 user.info kernel: [ 4228.653546] [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name May 28 18:51:35 g2 user.info kernel: [ 4228.661408] [ 115] 0 115 761 128 5 0 -1000 udevd May 28 18:51:35 g2 user.info kernel: [ 4228.669347] [ 237] 0 237 731 98 5 0 -1000 udevd May 28 18:51:35 g2 user.info kernel: [ 4228.677278] [ 238] 0 238 731 100 5 0 -1000 udevd May 28 18:51:35 g2 user.info kernel: [ 4228.685224] [ 581] 0 581 1134 78 5 0 -1000 sshd May 28 18:51:35 g2 user.info kernel: [ 4228.693074] [ 592] 0 592 662 15 4 0 0 syslogd May 28 18:51:35 g2 user.info kernel: [ 4228.701184] [ 595] 0 595 662 19 4 0 0 klogd May 28 18:51:35 g2 user.info kernel: [ 4228.709113] [ 633] 0 633 6413 212 12 0 0 g2d May 28 18:51:35 g2 user.info kernel: [ 4228.716877] [ 641] 0 641 663 16 3 0 0 getty May 28 18:51:35 g2 user.info kernel: [ 4228.724827] [ 642] 0 642 663 16 5 0 0 getty May 28 18:51:35 g2 user.info kernel: [ 4228.732770] [ 646] 0 646 6413 215 12 0 0 g2d May 28 18:51:35 g2 user.info kernel: [ 4228.740540] [ 650] 0 650 10791 572 10 0 0 avbd May 28 18:51:35 g2 user.info kernel: [ 4228.748385] [ 651] 0 651 9432 2365 21 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.756322] [ 652] 0 652 52971 4547 42 0 0 g2d May 28 18:51:35 g2 user.info kernel: [ 4228.764104] [ 712] 0 712 14135 2458 24 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.772053] [ 746] 0 746 1380 248 6 0 0 dhclient May 28 18:51:35 g2 user.info kernel: [ 4228.780251] [ 779] 0 779 9419 2383 21 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.788187] [ 780] 0 780 9350 2348 21 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.796127] [ 781] 0 781 9349 2347 21 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.804074] [ 782] 0 782 9353 2354 21 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.812012] [ 783] 0 783 18807 2573 27 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.819955] [ 784] 0 784 17103 3233 28 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.827882] [ 785] 0 785 13990 2436 24 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.835819] [ 786] 0 786 9349 2350 21 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.843764] [ 807] 0 807 13255 4125 25 0 0 cored May 28 18:51:35 g2 user.info kernel: [ 4228.851702] [ 1492] 999 1492 512 27 5 0 0 avahi-autoipd May 28 18:51:35 g2 user.info kernel: [ 4228.860334] [ 1493] 0 1493 433 14 5 0 0 avahi-autoipd May 28 18:51:35 g2 user.info kernel: [ 4228.868955] [ 1494] 0 1494 1380 246 7 0 0 dhclient May 28 18:51:35 g2 user.info kernel: [ 4228.877163] [19170] 0 19170 1175 131 6 0 0 sshd May 28 18:51:35 g2 user.info kernel: [ 4228.885022] [19183] 0 19183 750 70 4 0 0 sh May 28 18:51:35 g2 user.info kernel: [ 4228.892701] [19228] 0 19228 663 16 5 0 0 watch May 28 18:51:35 g2 user.info kernel: [ 4228.900636] [19301] 0 19301 1175 131 5 0 0 sshd May 28 18:51:35 g2 user.info kernel: [ 4228.908475] [19315] 0 19315 751 69 5 0 0 sh May 28 18:51:35 g2 user.info kernel: [ 4228.916154] [19365] 0 19365 663 16 5 0 0 watch May 28 18:51:35 g2 user.info kernel: [ 4228.924099] [19443] 0 19443 1175 153 5 0 0 sshd May 28 18:51:35 g2 user.info kernel: [ 4228.931948] [19449] 0 19449 750 70 5 0 0 sh May 28 18:51:35 g2 user.info kernel: [ 4228.939626] [19487] 0 19487 1175 132 5 0 0 sshd May 28 18:51:35 g2 user.info kernel: [ 4228.947467] [19500] 0 19500 750 70 3 0 0 sh May 28 18:51:35 g2 user.info kernel: [ 4228.955148] [19540] 0 19540 662 17 5 0 0 tail May 28 18:51:35 g2 user.info kernel: [ 4228.963002] [19687] 0 19687 63719 56396 127 0 0 cored May 28 18:51:35 g2 user.err kernel: [ 4228.970936] Out of memory: Kill process 19687 (cored) score 428 or sacrifice child May 28 18:51:35 g2 user.err kernel: [ 4228.978513] Killed process 19687 (cored) total-vm:254876kB, anon-rss:225560kB, file-rss:24kB
Also here is my test-program I use to stress the system and invoke the OOM-killer (with the echo 1 > /proc/sys/vm/compact_memory command being run every so often, the OOM-killer appears when free reports system RAM close to zero, as expected; without it, the OOM-killer appears well before that, when free reports 130+MB of RAM available but after cat /proc/buddyinfo shows the RAM becoming fragmented):
#include <stdio.h>
#include <stdlib.h>
int main(int argc, char ** argv)
{
while(1)
{
printf("PRESS RETURN TO ALLOCATE BUFFERSn");
const int numBytes = 400;
char buf[64]; fgets(buf, sizeof(buf), stdin);
for (int i=0; i<10000; i++)
{
void * ptr = malloc(numBytes); // yes, a deliberate memory leak
if (ptr)
{
memset(ptr, 'J', numBytes); // force the virtual memory system to actually allocate the RAM, and not only the address space
}
else printf("malloc() failed!n");
}
fprintf(stderr, "Deliberately leaked 10000*%i bytes!n", numBytes);
}
return 0;
}
Advertisement
Answer
You are on the right track, Jeremy. The identical thing happened to me on my CentOS desktop system. I am a computer consultant, and I have worked with Linux since 1995. And I pound my Linux systems mercilessly with many file downloads and all sorts of other activities that stretch them to their limits. After my main desktop had been up for about 4 days, it got real slow (like slower than 1/10 of normal speed), the OOM killed kicked in, and I was sitting there wondering why my system was acting that way. It had plenty of RAM, but the OOM killer was kicking when it had no business doing so. So I rebooted it, and it acted fine…for about 4 days, then the problem returned. Bugged the snot out of me not knowing why.
So I put on my test engineer hat and ran all sorts of stress tests on the machine to see if I could reproduce the symptoms on purpose. After several months of this, I was able to recreate the problem at will and prove that my solution for it would work every time.
“Cache turnover” in this context is when a system has to tear down existing cache to create more cache space to support new file writes. Since the system is in a hurry to redeploy the RAM, it does not take the time to defragment the memory it is freeing. So over time, as more and more file writes occur, the cache turns over repeatedly. And the memory in which it resides keeps getting more and more fragmented. In my tests, I found that after the disk cache has turned over about 15 times, the memory becomes so fragmented that the system cannot tear down and then allocate the memory fast enough to keep the OOM killer from being triggered due to lack of free RAM in the system when a spike in memory demand occurs. Such a spike could be caused by executing something as simple as
find /dev /etc /home /opt /tmp /usr -xdev > /dev/null
On my system, that command creates a demand for about 50MB of new cache. That was what
free -mt
shows, anyway.
The solution for this problem involves expanding on what you already discovered.
/bin/echo 3 > /proc/sys/vm/drop_caches export CONFIG_COMPACTION=1 echo 1 > /proc/sys/vm/compact_memory
And yes, I totally agree that dropping cache will force your system to re-read some data from disk. But at a rate of once per day or even once per hour, the negative effect of dropping cache is absolutely negligible compared to everything else your system is doing, no matter what that might be. The negative effect is so small that I cannot even measure it, and I made my living as a test engineer for 5+ years figuring out how to measure things like that.
If you set up a cron job to execute those once a day, that should eliminate your OOM killer problem. If you still see problems with the OOM killer after that, consider executing them more frequently. It will vary depending on how much file writing you do compared to the amount of system RAM your unit has.