А давайте я расскажу вам про необычный баг в своем блоге, на борьбу с которым я потратил не один вечер.
Вс началось с того, что сайт перестал автоматически обновляться при добавлении поста или комментария. Вероятно, это произошло, когда я переехал на другой хостинг. Конечно же, первой мыслью было то, что перестал нормально отрабатывать WebHook на GitHub. Если кто не в курсе, WebHook — это запрос на определённый URL, который GitHub выполняет при коммите. Так вот, из настроек GitHub нужный URL никуда не исчез, да и изучение логов сервера показало, что запросы приходят нормально.
Запустил обновление ручками и увидел в конце консольного вывода строчку «Killed». Запустил на домашней машине — нет ошибок. Посмотрел потребление памяти и загруженность процессора. Показатели были в пределах нормы, да и полная перегенерация сайта (гораздо более долгая и затратная операция) отрабатывала как надо. Но я обнаружил, что swap-раздел отключён. Я его довольно быстро включил обратно, но проблема не исчезла. Swap не использовался, это и укоренило меня в мысли, что проблема не в ресурсах. А раз не в ресурсах, значит что-то не так с самой программой. Не буду рассказывать сколько вариантов компиляции я перепробовал, сколько исходников просмотрел. Ничего не помогало, более того, строка «Killed» нигде не встречалась. На некоторое время я отложил баг в сторону и запускал полную перегенерацию сайта по мере необходимости.
И уже потом я наткнулся на StackOverflow, что «Killed» может выдаваться ядром Linux в случае, если процессу пришёл сигнал SIGKILL (безапелляционное закрытие процесса). Но кто может отправлять этот сигнал моему процессу? Ну конечно, OOM (Out of Memory) Killer! Но ведь ресурсов достаточно, да и swap не используется, какой же тут Out of Memory? А ещё, судя по форумам, в системном логе (cat /var/log/kern.log
или dmesg
) при закрытии процесса OOM Killer’ом должна появляться строчка, что-то вроде:
ruby invoked oom-killer: gfp_mask=0x200da, order=0, oom_adj=0, oom_score_adj=0 ruby cpuset=/ mems_allowed=0 Pid: 27311, comm: ruby Not tainted 2.6.32-279.el6.x86_64 #1
У меня же были совсем другие записи.
Feb 4 02:28:44 dikmax kernel: [1430123.088968] select 1 (init), adj 0, size 146, to kill
Feb 4 02:28:44 dikmax kernel: [1430123.089000] select 378 (rsyslogd), adj 0, size 377, to kill
Feb 4 02:28:44 dikmax kernel: [1430123.089011] select 5584 (dropbox), adj 0, size 21725, to kill
Feb 4 02:28:44 dikmax kernel: [1430123.089018] select 17651 (dikmax-name), adj 0, size 86942, to kill
Feb 4 02:28:44 dikmax kernel: [1430123.089020] send sigkill to 17651 (dikmax-name), adj 0, size 86942
И всё, никаких деталей. Дальнейшие поиски навели на информацию о том, что похожие строчки могут встречаться на Android. И там их выдаёт lowmemorykiller — аналог OOM Killer. Ещё несколько запросов в гугл вывели причину их появления у меня: оказывается, lowmemorykiller был портирован в ядро Ubuntu (возможно, только серверную версию) и некоторое время там уже обитает.
Всё это хорошо, но ведь как показывают замеры, у моего приложения не было проблем с памятью и swap не использовался. Почему же тогда lowmemorykiller так нехорошо себя ведет? Ответ придет, если вспомнить, что Android — система с небольшим количеством памяти и совсем без swap-раздела. И lowmemorykiller ведёт себя соответственно платформе. Зачем ждать, пока память закончится, можно начинать убивать процессы заранее. Вот и у меня в соответствии с настройками первые кандидаты на убийство появлялись, если свободной памяти становилось меньше 64 Мб, а это целых 12.5% от памяти на сервере. Понятное дело, что до swap дело даже не доходило, что, конечно, не так плохо для общей производительности, но плохо для некоторых приложений.
Понимание проблемы позволило заняться поиском решения. Настойки lowmemorykiller можно поменять во время работы сервера с помощью записи в системные файлы /sys/module/lowmemorykiller/parameters
. Например, вот такая команда фактически выключает lowmemorykiller:
sudo echo '9999' > /sys/module/lowmemorykiller/parameters/adj && echo '1' > /sys/module/lowmemorykiller/parameters/minfree
Осталось только добавить команду в автозапуск. Как всегда crontab придёт на помощь. Только не забываем, что конкретно эта команда должна выполняться от имени root-пользователя и редактировать crontab нужно от его же имени (sudo crontab -e
).
@reboot echo '9999' > /sys/module/lowmemorykiller/parameters/adj && echo '1' > /sys/module/lowmemorykiller/parameters/minfree
По итогу 512 Мб оказалось недостаточно для нормального запуска обновления сайта. Но учитывая то, что оно выполняется всего несколько раз в неделю и не продолжается дольше 1-й минуты, использование 50 Мб swap мне не кажется большой проблемой.
Вот такая детективная история. Как обычно, комментарии горячо приветствуются и не оставляются без внимания.