Enough memory but OOM killer invoked?
16,181
There's a bunch of things you need to do here.
First, the OOM killer was triggered by apache2 asking for more memory than was available, not by mysqld. But because the mysqld process was using the most memory at the time, it was the process that got killed.
Consider setting the sysctl vm.oom_kill_allocating_task, which will cause the process that asked for the memory to be killed instead.
Second, you most likely have configured Apache with mpm_prefork and are running PHP as an Apache module. This setup is slow, underperforming, not thread safe, and when PHP fails, the failure gets blamed on other components because PHP is well hidden inside of Apache. Modern web server setups use php-fpm and either nginx or Apache with mpm_event. This will give you better performance and visibility into what PHP is doing (as it is most likely what is eating up all your memory).
Finally, your droplet appears to have 1GB RAM and 1GB swap. If you're routinely running out, then your VM just may be too small. Consider adding RAM.
Related videos on Youtube
02 : 14
Ubuntu: OOM-killer is invoked for no reason Ubuntu 16.04
03 : 08
Why does linux out-of-memory (OOM) killer not run automatically, but works upon sysrq-key?
17 : 53
Out of Memory(OOM)
02 : 54
DevOps & SysAdmins: Enough memory but OOM killer invoked? (2 Solutions!!)
23 : 06
LPC2018 - oomd: a userspace OOM killer
Author by
MikeSkril
Updated on September 18, 2022Comments
-
MikeSkril almost 2 years
It has been a long time since my old friend the OOM killer came to visit me. Now it is coming by once a week and I cannot figure out why it’s triggered. It doesn’t seem that I’m missing memory. What is causing that and what can be done to prevent that?
Kernel: 3.13.0-49-generic #83-Ubuntu SMP
Right before the OOM killer was triggered:
Fri Nov 16 01:45:01 EST 2018 COMMAND %MEM mysqld 17.2 apache2 7.2 spamd child 7.0 apache2 7.0 apache2 6.9 apache2 6.8 apache2 6.8 apache2 6.6 apache2 6.6 apache2 6.4 apache2 6.4 /usr/sbin/spamd 6.4 spamd child 6.2 apache2 5.6 opendkim 0.6 horde-alarms 0.5 fail2ban-server 0.5 apache2 0.4 munin-node 0.2 pickup 0.1 cron 0.1 cron 0.1 cron 0.1 mem.sh 0.1 init 0.1 ps 0.1 config 0.0 tlsmgr 0.0 ntpd 0.0 qmgr 0.0 sh 0.0 sh 0.0 sh 0.0 systemd-logind 0.0 dovecot 0.0 auth 0.0 whoopsie 0.0 rsyslogd 0.0 log 0.0 vnstatd 0.0 master 0.0 dbus-daemon 0.0 anvil 0.0 cron 0.0 upstart-file-br 0.0 php5-fpm 0.0 upstart-socket- 0.0 upstart-udev-br 0.0 memcached 0.0 sshd 0.0 shellinaboxd 0.0 getty 0.0 getty 0.0 getty 0.0 getty 0.0 getty 0.0 php5-fpm 0.0 php5-fpm 0.0 /usr/sbin/postg 0.0 getty 0.0 systemd-udevd 0.0 acpid 0.0 opendkim 0.0 kthreadd 0.0 ksoftirqd/0 0.0 kworker/0:0H 0.0 rcu_sched 0.0 rcuos/0 0.0 rcu_bh 0.0 rcuob/0 0.0 migration/0 0.0 watchdog/0 0.0 khelper 0.0 kdevtmpfs 0.0 netns 0.0 writeback 0.0 kintegrityd 0.0 bioset 0.0 kworker/u3:0 0.0 kblockd 0.0 ata_sff 0.0 khubd 0.0 md 0.0 devfreq_wq 0.0 kworker/0:1 0.0 khungtaskd 0.0 kswapd0 0.0 ksmd 0.0 khugepaged 0.0 fsnotify_mark 0.0 ecryptfs-kthrea 0.0 crypto 0.0 kthrotld 0.0 vballoon 0.0 scsi_eh_0 0.0 scsi_eh_1 0.0 deferwq 0.0 charger_manager 0.0 scsi_eh_2 0.0 kpsmoused 0.0 kworker/0:2 0.0 ttm_swap 0.0 qxl_gc 0.0 jbd2/vda1-8 0.0 ext4-rsv-conver 0.0 kvm-irqfd-clean 0.0 atd 0.0 shellinaboxd 0.0 managesieve-log 0.0 kworker/u3:1 0.0 kauditd 0.0 kworker/u2:2 0.0 kworker/u2:0 0.0 Memory Space Details Total Memory space : 2018 MB Used Memory Space : 1055 MB Free Memory : 962 MB Swap memory Details Total Swap space : 1023 MB Used Swap Space : 164 MB Free Swap : 859 MB Node 0, zone DMA 9 12 6 8 7 4 1 2 2 0 0 Node 0, zone DMA32 2202 535 425 464 304 89 26 24 12 1 0Syslog:
Nov 16 01:46:34 foobar kernel: [2269670.312226] apache2 invoked oom-killer: gfp_mask=0x200da, order=0, oom_score_adj=0 Nov 16 01:46:34 foobar kernel: [2269670.312231] apache2 cpuset=/ mems_allowed=0 Nov 16 01:46:34 foobar kernel: [2269670.312234] CPU: 0 PID: 14040 Comm: apache2 Not tainted 3.13.0-49-generic #83-Ubuntu Nov 16 01:46:34 foobar kernel: [2269670.312235] Hardware name: DigitalOcean Droplet, BIOS 20171212 12/12/2017 Nov 16 01:46:34 foobar kernel: [2269670.312237] 0000000000000000 ffff880003f3b988 ffffffff81721b36 ffff8800041f1800 Nov 16 01:46:34 foobar kernel: [2269670.312240] ffff880003f3ba10 ffffffff8171c3f1 ffffffff81067996 ffff880003f3b9e8 Nov 16 01:46:34 foobar kernel: [2269670.312242] ffffffff810c75dc 0000000000000000 ffff88003fff7e28 0000000000000000 Nov 16 01:46:34 foobar kernel: [2269670.312244] Call Trace: Nov 16 01:46:34 foobar kernel: [2269670.312250] [<ffffffff81721b36>] dump_stack+0x45/0x56 Nov 16 01:46:34 foobar kernel: [2269670.312257] [<ffffffff8171c3f1>] dump_header+0x7f/0x1f1 Nov 16 01:46:34 foobar kernel: [2269670.312262] [<ffffffff81067996>] ? put_online_cpus+0x56/0x80 Nov 16 01:46:34 foobar kernel: [2269670.312273] [<ffffffff810c75dc>] ? rcu_oom_notify+0xcc/0xf0 Nov 16 01:46:34 foobar kernel: [2269670.312276] [<ffffffff811529ce>] oom_kill_process+0x1ce/0x330 Nov 16 01:46:34 foobar kernel: [2269670.312280] [<ffffffff812d75f5>] ? security_capable_noaudit+0x15/0x20 Nov 16 01:46:34 foobar kernel: [2269670.312282] [<ffffffff81153104>] out_of_memory+0x414/0x450 Nov 16 01:46:34 foobar kernel: [2269670.312285] [<ffffffff81159470>] __alloc_pages_nodemask+0xa60/0xb80 Nov 16 01:46:34 foobar kernel: [2269670.312289] [<ffffffff81199dda>] alloc_pages_vma+0x9a/0x140 Nov 16 01:46:34 foobar kernel: [2269670.312292] [<ffffffff8118c5ab>] read_swap_cache_async+0xeb/0x160 Nov 16 01:46:34 foobar kernel: [2269670.312294] [<ffffffff8118c6b8>] swapin_readahead+0x98/0xe0 Nov 16 01:46:34 foobar kernel: [2269670.312297] [<ffffffff8117a536>] handle_mm_fault+0xa76/0xf10 Nov 16 01:46:34 foobar kernel: [2269670.312301] [<ffffffff8172db74>] __do_page_fault+0x184/0x570 Nov 16 01:46:34 foobar kernel: [2269670.312305] [<ffffffff811ceb6f>] ? user_path_at_empty+0x5f/0x90 Nov 16 01:46:34 foobar kernel: [2269670.312308] [<ffffffff810a02c5>] ? set_next_entity+0x95/0xb0 Nov 16 01:46:34 foobar kernel: [2269670.312312] [<ffffffff8101260b>] ? __switch_to+0x16b/0x4d0 Nov 16 01:46:34 foobar kernel: [2269670.312314] [<ffffffff8172df7a>] do_page_fault+0x1a/0x70 Nov 16 01:46:34 foobar kernel: [2269670.312316] [<ffffffff8172d5e9>] do_async_page_fault+0x29/0xe0 Nov 16 01:46:34 foobar kernel: [2269670.312320] Mem-Info: Nov 16 01:46:34 foobar kernel: [2269670.312321] Node 0 DMA per-cpu: Nov 16 01:46:34 foobar kernel: [2269670.312323] CPU 0: hi: 0, btch: 1 usd: 0 Nov 16 01:46:34 foobar kernel: [2269670.312324] Node 0 DMA32 per-cpu: Nov 16 01:46:34 foobar kernel: [2269670.312325] CPU 0: hi: 186, btch: 31 usd: 93 Nov 16 01:46:34 foobar kernel: [2269670.312329] active_anon:101755 inactive_anon:101941 isolated_anon:208 Nov 16 01:46:34 foobar kernel: [2269670.312329] active_file:294 inactive_file:309 isolated_file:64 Nov 16 01:46:34 foobar kernel: [2269670.312329] unevictable:0 dirty:0 writeback:63 unstable:0 Nov 16 01:46:34 foobar kernel: [2269670.312329] free:12210 slab_reclaimable:2743 slab_unreclaimable:8287 Nov 16 01:46:34 foobar kernel: [2269670.312329] mapped:2580 shmem:6561 pagetables:20656 bounce:0 Nov 16 01:46:34 foobar kernel: [2269670.312329] free_cma:0 Nov 16 01:46:34 foobar kernel: [2269670.312331] Node 0 DMA free:4596kB min:704kB low:880kB high:1056kB active_anon:4844kB i nactive_anon:5424kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB ma naged:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:92kB shmem:96kB slab_reclaimable:64kB slab_unreclaimable:232kB kernel _stack:40kB pagetables:684kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes Nov 16 01:46:34 foobar kernel: [2269670.312336] lowmem_reserve[]: 0 975 975 975 Nov 16 01:46:34 foobar kernel: [2269670.312338] Node 0 DMA32 free:44244kB min:44348kB low:55432kB high:66520kB active_anon: 402176kB inactive_anon:402340kB active_file:1176kB inactive_file:1236kB unevictable:0kB isolated(anon):832kB isolated(file):25 6kB present:1032172kB managed:1001956kB mlocked:0kB dirty:0kB writeback:252kB mapped:10228kB shmem:26148kB slab_reclaimable:10 908kB slab_unreclaimable:32916kB kernel_stack:2520kB pagetables:81940kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:10612 all_unreclaimable? yes Nov 16 01:46:34 foobar kernel: [2269670.312342] lowmem_reserve[]: 0 0 0 0 Nov 16 01:46:34 foobar kernel: [2269670.312343] Node 0 DMA: 3*4kB (EM) 3*8kB (EM) 3*16kB (UE) 3*32kB (EM) 3*64kB (UMR) 3*12 8kB (UE) 3*256kB (UEM) 2*512kB (EM) 2*1024kB (EM) 0*2048kB 0*4096kB = 4596kB Nov 16 01:46:34 foobar kernel: [2269670.312351] Node 0 DMA32: 297*4kB (EM) 610*8kB (UEM) 406*16kB (UEM) 234*32kB (UEM) 130* 64kB (UEM) 56*128kB (UEM) 20*256kB (UEM) 3*512kB (E) 0*1024kB 1*2048kB (R) 0*4096kB = 44244kB Nov 16 01:46:34 foobar kernel: [2269670.312362] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2 048kB Nov 16 01:46:34 foobar kernel: [2269670.312363] 14604 total pagecache pages Nov 16 01:46:34 foobar kernel: [2269670.312365] 7377 pages in swap cache Nov 16 01:46:34 foobar kernel: [2269670.312366] Swap cache stats: add 2208965, delete 2201588, find 55272636/55445769 Nov 16 01:46:34 foobar kernel: [2269670.312367] Free swap = 0kB Nov 16 01:46:34 foobar kernel: [2269670.312367] Total swap = 1048572kB Nov 16 01:46:34 foobar kernel: [2269670.312368] 262041 pages RAM Nov 16 01:46:34 foobar kernel: [2269670.312369] 0 pages HighMem/MovableOnly Nov 16 01:46:34 foobar kernel: [2269670.312370] 7554 pages reserved Nov 16 01:46:34 foobar kernel: [2269670.312610] Out of memory: Kill process 1047 (mysqld) score 115 or sacrifice child Nov 16 01:46:34 foobar kernel: [2269670.312637] Killed process 1047 (mysqld) total-vm:896532kB, anon-rss:103356kB, file-rss :0kB Nov 16 01:46:34 foobar kernel: [2269670.554632] init: mysql main process (1047) killed by KILL signal Nov 16 01:46:34 foobar kernel: [2269670.554653] init: mysql main process ended, respawning Nov 16 01:46:34 foobar kernel: [2269670.602286] audit_printk_skb: 9 callbacks suppressed Nov 16 01:46:34 foobar kernel: [2269670.602290] type=1400 audit(1542350794.977:14): apparmor="STATUS" operation="profile_re place" profile="unconfined" name="/usr/sbin/mysqld" pid=14117 comm="apparmor_parser" Nov 16 01:46:37 foobar /etc/mysql/debian-start[14200]: Upgrading MySQL tables if necessary. Nov 16 01:46:37 foobar /etc/mysql/debian-start[14204]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored Nov 16 01:46:37 foobar /etc/mysql/debian-start[14204]: Looking for 'mysql' as: /usr/bin/mysql Nov 16 01:46:37 foobar /etc/mysql/debian-start[14204]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck Nov 16 01:46:37 foobar /etc/mysql/debian-start[14204]: This installation of MySQL is already upgraded to 5.5.61, use --forc e if you still need to run mysql_upgrade Nov 16 01:46:37 foobar /etc/mysql/debian-start[14217]: Checking for insecure root accounts. Nov 16 01:46:37 foobar /etc/mysql/debian-start[14223]: Triggering myisam-recover for all MyISAM tables Nov 16 01:46:51 foobar kernel: [2269686.979583] apache2 invoked oom-killer: gfp_mask=0x200da, order=0, oom_score_adj=0 Nov 16 01:46:51 foobar kernel: [2269686.979588] apache2 cpuset=/ mems_allowed=0-
Matthew Ife over 5 yearsIf you dont have it set already set the valuevm.oom_dump_tasksinsysctl. You are definitely using more memory than you're reporting in your output. -
MikeSkril over 5 yearsWill do. I aslo added
vm.panic_on_oom=1andkernel.panic=5so the server will reboot and the website won't be offline for hours. -
Mikko Rantalainen about 4 yearsIn practice, memory usage often has big enough spikes and any logger just doing a snapshot every N seconds rarely gets a look at the biggest spikes. In my experience, the amount of
freeRAM often correlates to the size of spikes. If your memory usage does not have spikes, the amount offreeRAM should be around 5 MB. Your server has 962 MB which suggests that the server has recently run something that took over 900 MB of RAM and that process has already ended. As the server only has 2 GB of RAM that kind of spikes will be problematic.
-
-
MikeSkril over 5 yearsOk, but why does it show that I had lot's of memory left when OOM was invoked? Why do you know that mysql was the cause? It was just the process killed by OOM because it was the biggest user of memory at the time. There was no memory usage spike before OOM was invoked.
-
MikeSkril over 5 yearsThank you for the comment. After some more investigation, I saw that Apache was flooded with requests just before the OOM call. And yes, it's Prefork configured by default in Ubuntu. I don't feel good about switching to Event, I don't want to mess things up. I will have to add some RAM. :-(
-
KonstantinYu over 5 yearsI used to work a lot with mysql servers and their tuning, and this was usual cause in most cases. mysql could try to allocate a lot of memory performing some unoptimized or complex query and gets killed by OOM. So in this case I would start from mysql, then checking all other daemons.
-
MikeSkril over 5 yearsIn this case it was Apache demanding too much memory caused by traffic flooding.
-
Michael Hampton over 5 yearsThat's a ridiculous 20 year old default, and switching isn't very hard. Definitely consider changing it. -
Mikko Rantalainen about 4 yearsDo not set
oom_kill_allocating_taskbecause then any random little script running important system service will get killed if it needs 4KB more. When some process gets out of control and eats lots of memory settingoom_kill_allocating_taskonly causes OOM Killer to kill any random process running. Note that even touching a page in stack may cause memory allocation so there's no way any random app can protect itself from killing in that case.
