OOM Killer убивает вещи с большим количеством (?) Свободной оперативной памяти

11

Убийца OOM, похоже, убивает вещи, несмотря на то, что в моей системе более чем достаточно свободной оперативной памяти:

График использования памяти (Полное разрешение)

График использования ввода-вывода (Полное разрешение)

Через 27 минут и 408 процессов система снова начала отвечать. Я перезагрузил его примерно через час, и вскоре после этого использование памяти вернулось к норме (для этой машины).

После проверки у меня на компьютере работает несколько интересных процессов:

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
[...snip...]
root      1399 60702042  0.2 482288 1868 ?     Sl   Feb21 21114574:24 /sbin/rsyslogd -i /var/run/syslogd.pid -c 4
[...snip...]
mysql     2022 60730428  5.1 1606028 38760 ?   Sl   Feb21 21096396:49 /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --user=mysql --log-error=/var/log/mysqld.log --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/lib/mysql/mysql.sock
[...snip...]

Этот конкретный сервер работает в течение ок. 8 часов, и это только два процесса, которые имеют такие ... нечетные значения. Я подозреваю, что происходит «что-то еще», потенциально относящееся к этим бессмысленным ценностям. В частности, я думаю, что система считает, что она не хватает памяти, а на самом деле это не так. В конце концов, он считает, что rsyslogd последовательно использует процессор на 55383984%, тогда как теоретический максимум в этой системе составляет 400%.

Это полностью обновленная установка CentOS 6 (6.2) с 768 МБ оперативной памяти. Будем благодарны за любые предложения о том, как выяснить, почему это происходит!

редактировать: прикрепление VM. Настраиваемые параметры sysctl. Я играл с swappiness (это видно по 100), и я также запускаю абсолютно ужасный скрипт, который сбрасывает мои буферы и кэш (это видно по vm.drop_caches, равному 3) + синхронизирует диск каждый раз 15 минут. Вот почему после перезагрузки кэшированные данные выросли до несколько нормального размера, но затем снова быстро сбросились. Я признаю, что наличие кеша - очень хорошая вещь, но пока я не выясню это ...

Также несколько интересным является то, что, хотя мой файл подкачки вырос во время мероприятия, он достиг всего лишь ~ 20% от общего возможного использования, что не характерно для истинных событий OOM. На другом конце спектра за тот же период диск просто сошел с ума, что характерно для события OOM, когда файл подкачки находится в режиме воспроизведения.

sysctl -a 2>/dev/null | grep '^vm':

vm.overcommit_memory = 1
vm.panic_on_oom = 0
vm.oom_kill_allocating_task = 0
vm.extfrag_threshold = 500
vm.oom_dump_tasks = 0
vm.would_have_oomkilled = 0
vm.overcommit_ratio = 50
vm.page-cluster = 3
vm.dirty_background_ratio = 10
vm.dirty_background_bytes = 0
vm.dirty_ratio = 20
vm.dirty_bytes = 0
vm.dirty_writeback_centisecs = 500
vm.dirty_expire_centisecs = 3000
vm.nr_pdflush_threads = 0
vm.swappiness = 100
vm.nr_hugepages = 0
vm.hugetlb_shm_group = 0
vm.hugepages_treat_as_movable = 0
vm.nr_overcommit_hugepages = 0
vm.lowmem_reserve_ratio = 256   256     32
vm.drop_caches = 3
vm.min_free_kbytes = 3518
vm.percpu_pagelist_fraction = 0
vm.max_map_count = 65530
vm.laptop_mode = 0
vm.block_dump = 0
vm.vfs_cache_pressure = 100
vm.legacy_va_layout = 0
vm.zone_reclaim_mode = 0
vm.min_unmapped_ratio = 1
vm.min_slab_ratio = 5
vm.stat_interval = 1
vm.mmap_min_addr = 4096
vm.numa_zonelist_order = default
vm.scan_unevictable_pages = 0
vm.memory_failure_early_kill = 0
vm.memory_failure_recovery = 1

edit: и вложение первого сообщения OOM ... при ближайшем рассмотрении говорит, что что-то явно пошло не по пути, чтобы съесть все мое пространство подкачки.

Feb 21 17:12:49 host kernel: mysqld invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0
Feb 21 17:12:51 host kernel: mysqld cpuset=/ mems_allowed=0
Feb 21 17:12:51 host kernel: Pid: 2777, comm: mysqld Not tainted 2.6.32-71.29.1.el6.x86_64 #1
Feb 21 17:12:51 host kernel: Call Trace:
Feb 21 17:12:51 host kernel: [<ffffffff810c2e01>] ? cpuset_print_task_mems_allowed+0x91/0xb0
Feb 21 17:12:51 host kernel: [<ffffffff8110f1bb>] oom_kill_process+0xcb/0x2e0
Feb 21 17:12:51 host kernel: [<ffffffff8110f780>] ? select_bad_process+0xd0/0x110
Feb 21 17:12:51 host kernel: [<ffffffff8110f818>] __out_of_memory+0x58/0xc0
Feb 21 17:12:51 host kernel: [<ffffffff8110fa19>] out_of_memory+0x199/0x210
Feb 21 17:12:51 host kernel: [<ffffffff8111ebe2>] __alloc_pages_nodemask+0x832/0x850
Feb 21 17:12:51 host kernel: [<ffffffff81150cba>] alloc_pages_current+0x9a/0x100
Feb 21 17:12:51 host kernel: [<ffffffff8110c617>] __page_cache_alloc+0x87/0x90
Feb 21 17:12:51 host kernel: [<ffffffff8112136b>] __do_page_cache_readahead+0xdb/0x210
Feb 21 17:12:51 host kernel: [<ffffffff811214c1>] ra_submit+0x21/0x30
Feb 21 17:12:51 host kernel: [<ffffffff8110e1c1>] filemap_fault+0x4b1/0x510
Feb 21 17:12:51 host kernel: [<ffffffff81135604>] __do_fault+0x54/0x500
Feb 21 17:12:51 host kernel: [<ffffffff81135ba7>] handle_pte_fault+0xf7/0xad0
Feb 21 17:12:51 host kernel: [<ffffffff8103cd18>] ? pvclock_clocksource_read+0x58/0xd0
Feb 21 17:12:51 host kernel: [<ffffffff8100f951>] ? xen_clocksource_read+0x21/0x30
Feb 21 17:12:51 host kernel: [<ffffffff8100fa39>] ? xen_clocksource_get_cycles+0x9/0x10
Feb 21 17:12:51 host kernel: [<ffffffff8100c949>] ? __raw_callee_save_xen_pmd_val+0x11/0x1e
Feb 21 17:12:51 host kernel: [<ffffffff8113676d>] handle_mm_fault+0x1ed/0x2b0
Feb 21 17:12:51 host kernel: [<ffffffff814ce503>] do_page_fault+0x123/0x3a0
Feb 21 17:12:51 host kernel: [<ffffffff814cbf75>] page_fault+0x25/0x30
Feb 21 17:12:51 host kernel: Mem-Info:
Feb 21 17:12:51 host kernel: Node 0 DMA per-cpu:
Feb 21 17:12:51 host kernel: CPU    0: hi:    0, btch:   1 usd:   0
Feb 21 17:12:51 host kernel: CPU    1: hi:    0, btch:   1 usd:   0
Feb 21 17:12:51 host kernel: CPU    2: hi:    0, btch:   1 usd:   0
Feb 21 17:12:51 host kernel: CPU    3: hi:    0, btch:   1 usd:   0
Feb 21 17:12:51 host kernel: Node 0 DMA32 per-cpu:
Feb 21 17:12:51 host kernel: CPU    0: hi:  186, btch:  31 usd:  47
Feb 21 17:12:51 host kernel: CPU    1: hi:  186, btch:  31 usd:   0
Feb 21 17:12:51 host kernel: CPU    2: hi:  186, btch:  31 usd:   0
Feb 21 17:12:51 host kernel: CPU    3: hi:  186, btch:  31 usd: 174
Feb 21 17:12:51 host kernel: active_anon:74201 inactive_anon:74249 isolated_anon:0
Feb 21 17:12:51 host kernel: active_file:120 inactive_file:276 isolated_file:0
Feb 21 17:12:51 host kernel: unevictable:0 dirty:0 writeback:2 unstable:0
Feb 21 17:12:51 host kernel: free:1600 slab_reclaimable:2713 slab_unreclaimable:19139
Feb 21 17:12:51 host kernel: mapped:177 shmem:84 pagetables:12939 bounce:0
Feb 21 17:12:51 host kernel: Node 0 DMA free:3024kB min:64kB low:80kB high:96kB active_anon:5384kB inactive_anon:5460kB active_file:36kB inactive_file:12kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:14368kB mlocked:0kB dirty:0kB writeback:0kB mapped:16kB shmem:0kB slab_reclaimable:16kB slab_unreclaimable:116kB kernel_stack:32kB pagetables:140kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:8 all_unreclaimable? no
Feb 21 17:12:51 host kernel: lowmem_reserve[]: 0 741 741 741
Feb 21 17:12:51 host kernel: Node 0 DMA32 free:3376kB min:3448kB low:4308kB high:5172kB active_anon:291420kB inactive_anon:291536kB active_file:444kB inactive_file:1092kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:759520kB mlocked:0kB dirty:0kB writeback:8kB mapped:692kB shmem:336kB slab_reclaimable:10836kB slab_unreclaimable:76440kB kernel_stack:2520kB pagetables:51616kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:2560 all_unreclaimable? yes
Feb 21 17:12:51 host kernel: lowmem_reserve[]: 0 0 0 0
Feb 21 17:12:51 host kernel: Node 0 DMA: 5*4kB 4*8kB 2*16kB 0*32kB 0*64kB 1*128kB 1*256kB 1*512kB 0*1024kB 1*2048kB 0*4096kB = 3028kB
Feb 21 17:12:51 host kernel: Node 0 DMA32: 191*4kB 63*8kB 9*16kB 2*32kB 0*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB = 3396kB
Feb 21 17:12:51 host kernel: 4685 total pagecache pages
Feb 21 17:12:51 host kernel: 4131 pages in swap cache
Feb 21 17:12:51 host kernel: Swap cache stats: add 166650, delete 162519, find 1524867/1527901
Feb 21 17:12:51 host kernel: Free swap  = 0kB
Feb 21 17:12:51 host kernel: Total swap = 523256kB
Feb 21 17:12:51 host kernel: 196607 pages RAM
Feb 21 17:12:51 host kernel: 6737 pages reserved
Feb 21 17:12:51 host kernel: 33612 pages shared
Feb 21 17:12:51 host kernel: 180803 pages non-shared
Feb 21 17:12:51 host kernel: Out of memory: kill process 2053 (mysqld_safe) score 891049 or a child
Feb 21 17:12:51 host kernel: Killed process 2266 (mysqld) vsz:1540232kB, anon-rss:4692kB, file-rss:128kB
Кайл Брантли
источник
Можете ли вы предоставить вывод sysctl -a 2>/dev/null | grep '^vm'?
Патрик
Добавлен. Надеюсь, вы (или кто-то) можете найти то, что я пропустил.
Кайл Брантли
Единственное, что бросается в глаза, это overcommit_memoryобстановка. Установка его в 1 не должна вызывать такое поведение, но у меня никогда не было необходимости устанавливать его всегда «overcommit», так что опыта там немного. Глядя на другие заметки, которые вы добавили, вы сказали, что своп использовался только на 20%. Однако , по мнению журнала отвала OOM, Free swap = 0kB. Это определенно думал, что своп был использован на 100%.
Патрик

Ответы:

13

Я только что посмотрел на дамп журнала OOM, и я ставлю под сомнение точность этого графика. Обратите внимание на первую строку «Узел 0 DMA32». Он говорит free:3376kB, min:3448kBи low:4308kB. Всякий раз, когда свободное значение опускается ниже минимального значения, kswapd должен начинать меняться, пока это значение не поднимется выше верхнего значения. Всякий раз, когда free падает ниже min, система в основном останавливается до тех пор, пока ядро ​​не восстановит его выше значения min. Это сообщение также указывает, что подкачка была полностью использована там, где говорится Free swap = 0kB.
Таким образом, в основном kswapd сработал, но swap был полон, поэтому он ничего не мог сделать, и значение pages_free было все еще ниже значения pages_min, поэтому единственный вариант состоял в том, чтобы начать убивать вещи до тех пор, пока он не сможет создать резервную копию pages_free.
Вы определенно исчерпали память.

http://web.archive.org/web/20080419012851/http://people.redhat.com/dduval/kernel/min_free_kbytes.html имеет действительно хорошее объяснение того, как это работает. Смотрите раздел «Реализация» внизу.

Патрик
источник
1
Так что ОП действительно просто нужно больше оперативной памяти ...
'11
побольше баранов, или узнай что кушает.
Патрик
Я очень точно расположил линии на этом графике. Он прекратил регистрацию данных ~ 1-2м до того, как был завершен первый процесс, и возобновил регистрацию данных ~ 4-5м после того, как последний был убит. На данный момент я держу пари, что какой-то процесс стал совершенно бесполезным и начал перебивать мой файл подкачки - как только он, наконец, получил все, он также убил процессы, которые функционально заканчивались из файла подкачки, поэтому, когда данные возвращались, файл подкачки был поднят, но не заполнен. Предложения о том, как определить, что делает это будет приветствоваться!
Кайл Брантли
@KyleBrantley Какие значения вы тянете для создания графика? Одним из недостатков системы виртуальной памяти Linux является то, что нет конкретного определения «свободный». Есть дюжина способов определения «свободной памяти». То, что имеет значение для kswapd, это значение pages_free. Что касается бесплатного обмена, я не знаю, какую ценность вы могли бы прочитать, что было бы так далеко. Единственный способ по-настоящему увидеть, что съедает память, - записывать непрерывные снимки всех процессов на коробке и видеть, что израсходует всю память, когда убийца начинает сходить с ума.
Патрик
2
Да, у меня закончилась память. Я просмотрел журналы и обнаружил, что мои дочерние процессы apache неоднократно убивались, что привело меня к выводу, что у меня есть функционально бесконечные дочерние процессы, которые он может запустить. Все, что для этого потребовалось, - это автоматические боты блогов, которые выдают много запросов в секунду на хост, чтобы он упал. Тонкая настройка apache решила все.
Кайл Брантли
3

Избавьтесь от сценария drop_caches. Кроме того, вы должны опубликовать соответствующие части вашего dmesgи /var/log/messagesвыходной, показывая сообщения OOM.

Чтобы остановить это поведение, я бы порекомендовал попробовать эту sysctlнастройку. Это система RHEL / CentOS 6, которая явно работает на ограниченных ресурсах. Это виртуальная машина?

Попробуйте изменить /proc/sys/vm/nr_hugepagesи посмотреть, если проблемы не устранены. Это может быть проблемой фрагментации памяти, но посмотрите, если этот параметр имеет значение. Чтобы сделать изменение постоянным, добавьте vm.nr_hugepages = valueего /etc/sysctl.confи запустите, sysctl -pчтобы перечитать файл конфигурации ...

См. Также: Интерпретация загадочных сообщений ядра "ошибка выделения страницы"

ewwhite
источник
Добавлено первое сообщение oom-killer. Несмотря на то, что MySQL является самой интенсивно используемой оперативной памятью, я настроил ее так, чтобы не перегружать коробку, поэтому, за исключением сумасшедших ценностей, которые я вижу сверху, я не подозреваю об этом (5.1% использование памяти в порядке, учитывая все обстоятельства). Это VPS, с 768 МБ оперативной памяти. Я прочитаю на nr_hugepages и попробую, спасибо!
Кайл Брантли
@ewwhite, выделяя столько огромных страниц, чтобы убить коробку. Коробка имеет только 768 МБ оперативной памяти, а при значении defaultpagesp, равном 2 МБ, выделяется 2 ГБ огромных страниц. Коробка не сможет с этим справиться и немедленно умрет.
Патрик
Обновлено. Однако значение должно быть увеличено с нуля.
ewwhite
Это все еще сложнее, чем это. Вы должны установить огромные разрешения для страниц, и mysql должен быть настроен на использование огромных страниц, в противном случае вы просто распределяете их без всякой причины.
Патрик
2

На графике нет доступных данных с момента начала убийцы OOM до его окончания. Я верю во временные рамки, в которых график прерывается, что на самом деле потребление памяти резко возрастает и памяти больше нет. В противном случае убийца OOM не будет использоваться. Если вы посмотрите график свободной памяти после остановки OOM killer, вы увидите, что он падает с более высокого значения, чем раньше. По крайней мере, он сделал свою работу правильно, освободив память.

Обратите внимание, что ваше пространство подкачки почти полностью используется до перезагрузки. Это почти никогда не бывает хорошо, и верным признаком остается мало свободной памяти.

Причина, по которой нет данных для этого конкретного периода времени, заключается в том, что система слишком занята другими вещами. «Забавные» значения в вашем списке процессов могут быть просто результатом, а не причиной. Это не неслыханно.

Проверьте /var/log/kern.log и / var / log / messages, какую информацию вы можете найти там?

Если ведение журнала также остановлено, попробуйте выполнить другие действия, каждую секунду выводите список процессов в файл, так же как и в случае с информацией о производительности системы. Запустите его с высоким приоритетом, чтобы он мог выполнять свою работу (будем надеяться), когда пики нагрузки. Хотя если у вас нет предустановленного ядра (иногда обозначаемого как «серверное»), вам может не повезти в этом отношении.

Я думаю, вы обнаружите, что причиной является (ые) процесс (ы), который использует (и) больше всего процессорного времени во время запуска ваших проблем. Я никогда не видел ни rsyslogd, ни mysql, ведущих себя таким образом. Более вероятными виновниками являются Java-приложения и приложения с графическим интерфейсом, такие как браузер.

aseq
источник
В этом промежутке нет данных, потому что нагрузка на коробку пикирует настолько нелепо, что все, включая агент мониторинга, полностью останавливается. Сам агент никогда не был фактически убит в период почти смерти, но он также не мог сообщить никаких данных. Мое пространство подкачки было на самом деле хорошо. До перезагрузки использовалось всего ~ 130/512 МБ. rsyslogd сконфигурирован так, чтобы сообщать о журналах в сетевом расположении, где все, что происходило, было зарегистрировано - и, кроме того, убивало 408 процессов (некоторые из которых были дочерними элементами apache, которые были перезапущены), ничего не выделялось.
Кайл Брантли
Я могу закончить выгрузкой полного списка процессов в файл (или сеть) каждые несколько секунд, если не могу понять, что здесь происходит, так что спасибо за хорошую идею.
Кайл Брантли
Да, вы должны это сделать, убедитесь, что вы также записываете использование процессора каждым процессом, посмотрите на "top -b" (пакетный режим). Процесс, который всплески может быть виновником.
aseq