Всем привет! На связи Вадим Лазовский, SRE-инженер продукта Deckhouse Observability Platform от компании «Флант», и Владимир Гурьянов, solution architect. Сегодня мы поделимся кейсом, который произошёл у нас при работе с Ceph. При этом его решение может быть применимо для любого другого ПО.

Иногда происходит так, что выполняешь привычную последовательность действий, которую уже делал много раз, а результат получается неожиданным. Например, с утра мы кипятим воду, кладём две ложки кофе и две ложки сахара в чашку, заливаем водой и наслаждаемся ароматным кофе. Но одним утром мы делаем глоток и понимаем, что в чашке холодный кофе.

Так однажды произошло и в процессе установки нашего продукта. Мы столкнулись с тем, что привычные действия приводят к совершенно непривычному результату. В этой статье мы разберём проблему с закрытием файловых дескрипторов при выполнении команды на создание пула в Ceph. Расскажем, как её обнаружили, что делали, чтобы определить причину её возникновения, и самое важное — почему это произошло и как решить проблему. Получился настоящий детектив.

Технические составляющие

Начнем с технического контекста — так будет проще понять, что происходило дальше.

Мы разрабатываем систему мониторинга и централизованного хранения логов — Okmeter, который ставится внутрь Kubernetes'а. И один из вариантов его поставки — on-prem. Чтобы упростить установку, мы упаковали все компоненты аналогично модулям Deckhouse (принцип их работы похож на операторов кластера Kubernetes), поэтому достаточно было применить несколько YAML-манифестов в Kubernetes-кластер. В противном случае микросервисная система и инструкция по установке могли бы быть достаточно обширными и сложными.

Один из компонентов нашей системы — программно реализованная, распределённая система хранения данных Ceph, которая используется как S3-хранилище и устанавливается с помощью rook operator.

Мы не раз разворачивали Okmeter в различные среды виртуализации и на разные дистрибутивы Linux: KVM, VMware, Yandex Cloud, Ubuntu, Astra Linux и др., — и всё ставилось без проблем.

Появление проблемы

Однажды мы устанавливали очередную инсталляцию у клиента в закрытом контуре в Deckhouse Kubernetes-кластер на виртуальных машинах VMware и дистрибутиве РЕД ОС. Мы подключили наши модули, и первым должен был запуститься кластер Ceph, для которого создается custom resource CephObjectStore (отвечает за разворачивание S3-совместимого объектного хранилища на базе Ceph). Всё шло как обычно.

В первую очередь оператор выкатил monitors и manager, и здесь начались проблемы. В определённый момент monitors перестал отвечать на liveness-пробу и kubelet рестартит под с monitor. В результате кластер Ceph постоянно находился либо в полной неработоспособности (два или даже три monitor в CrashLoopBackOff), либо в состоянии HEALTH_WARN в связи с потерей одного из monitor.

Проба у monitor — это простой shell-скрипт, который выполняет команду ceph mon_status. При обычной работе ответ на эту пробу приходит всегда, вне зависимости от состояния кластера. Если процесс жив, статус отдается. При этом оказалось, что до следующего шага доходит и rook operator, который выкатывает OSD, хоть и с задержкой. Это значит, что он может сделать запрос в monitor и получить авторизацию для OSD. То есть кластер все же подавал некоторые признаки жизни.

Также при вводе команды ceph -s счетчик пулов имел нулевое значение. А в логах оператора происходили постоянные таймауты на каждый запрос: создание пулов, получение версий статуса и компонентов, что особенно странно, так как операция очень простая. При этом по логам мало что понятно. Monitors работали без ошибок, просто в какой-то момент ловили TERM от kubelet и плавно завершались.

Выявление проблемы

Мы решили отключить liveness-пробу у деплоймента monitor — это позволило остановить рестарты, но лучше не стало. В какой-то момент полезли Slow Ops (класс проблем в Ceph, который говорит, что операции ввода/вывода выполняются медленно), а получение статуса занимало десятки секунд. Как выяснилось позднее, monitors один за другим повисали.

Slow Ops указывают на то, что проблема может быть в инфраструктуре. Нам нужно было убедиться, что мы не упускаем никаких нюансов, о которых не знаем, так как инфраструктура находилась не под нашим управлением, а мы имели только доступ к ВМ. Поэтому проверили следующие компоненты:

диски — на предмет скорости, latency и прочего;
сеть — на предмет файрволов MTU, DPI, KFC, UFC;
overlay-сети с прямыми маршрутами и VXLAN.

В итоге не обнаружили никаких аномалий.

Далее мы решили остановить rook, чтобы он не мешал, пока ищем проблему, и ушли восстанавливать силы. После перерыва мы обнаружили, что кластер перешёл в состояние Health_OK и с одним системным пулом device_health. Это было неожиданно, так как мы временно отключили rook — оператор, отвечающий за развёртывание и управление кластером. Теоретически отключение rook не должно было повлиять на состояние кластера, и тем более работающий оператор не должен приводить к зависанию компонентов в кластере.

Мы включили rook operator обратно, и стало ясно, что лучше не стало. Кластер опять начало лихорадить, а оператор пачками выдавал ошибки по таймаутам. Стали разбираться, как работает rook operator, и выяснили, что команды в кластер он выполняет обычным exec’ом утилит командной строки (ceph, radosgw-admin и так далее), предварительно подготавливая для себя конфиг и ключ.

Дальше мы стали наблюдать за выводом команды ps aux внутри пода оператора. В результате выяснили, что именно команда ceph osd pool create дает начало проблеме. Остальные команды — статус, запрос версий, получение ключей — отрабатывают хорошо, если кластер доступен.

В итоге мы удалили CephObjectStore, и rook operator перестал создавать пулы, а кластер снова пришел в норму.

Причина проблемы

Мы сделали предположение, что проблема кроется именно в создании пулов и начали дебажить этот процесс: включили debug-лог у monitor’ов, повесили kubectl logs -f на каждый monitor и отправили команду на создание пула. В этот момент большой поток логов в одной из консолей прекратился. Зайдя в под с этим monitor, мы увидели, что его процесс забирает 100% CPU в треде ms_dispatch. Одновременно в репозитарии rook operator мы нашли issue, которое всё объяснило, а конкретно вот этот коммент:

Проблема вызвана коммитом в systemd 240: systemd/systemd@a8b627a. До systemd v240 systemd просто оставлял fs.nr_open как есть, потому что отсутствовал механизм для установки безопасного верхнего предела. По умолчанию в ядре максимальное количество открытых файлов равно 1048576. Начиная с systemd v240, если задать LimitNOFILE=infinity в dockerd.service или containerd.service, это значение в большинстве случаев вырастет до ~1073741816 (INT_MAX для x86_64, деленное на два). Начиная с коммита, упомянутого @gpl (containerd/containerd@c691c36), containerd использует «бесконечность», то есть ~1073741816. Следовательно, файловых дескрипторов, которые потенциально открыты, на три порядка больше. А каждый из них необходимо перебрать и попытаться закрыть или просто установить на них бит CLOEXEC, чтобы они закрывались автоматически при вызове fork() / exec(). Именно из-за этого в некоторых случаях кластеры rook возвращались к жизни через несколько дней.
Проще всего избавиться от этой проблемы, если установить LimitNOFILE в сервисе systemd, скажем, на 1048576 или любое другое число, оптимизированное для конкретного случая использования.

Разберём причины возникновения проблемы по шагам:

Ceph при получении команды на создание пула делает fork.
Fork клонирует процесс. Этот процесс получает доступ ко всем файловым дескрипторам родительского процесса, что может быть небезопасным. Поэтому в коде child’а принято закрывать все открытые дескрипторы.
Долгое время в Linux не было возможности или нужды определить, какие дескрипторы нужно закрывать, а какие — нет. Обычно просто в цикле вызывают close() на всём подряд.
В коде ceph закрытие дескрипторов происходит в диапазоне от 0 до sysconf(_SC_OPEN_MAX);.
В systemd v240 увеличили значение по умолчанию для fs.nr_open в 1000 раз с миллиона до миллиарда.
А в containerd перешли с константы в один миллион на infinity для директивы LimitNOFILE в systemd unit-файле.
Теперь Ceph при выполнении fork закрывает не миллион, а миллиард дескрипторов. Время выполнения выросло на три порядка. Это уже десятки секунд (точное значение зависит от характеристик системы). А из-за того, что monitor при этом полностью теряет какую-либо отзывчивость, его прибивает по livenessProbe.

Так несколько несвязанных коммитов в разные проекты в итоге приводят к непредсказуемому поведению.

Решение проблемы

Существует открытый PR в Ceph, который должен решить эту проблему. Суть патча заключается в использовании вызова close_range (доступен начиная с ядра Linux 5.9 и libc 2.34) для всего диапазона. Это позволит выполнять задачу за один syscall вместо миллиарда.

Но пока этот PR не принят, так что мы вернули всё назад и добавили override для сервиса containerd.service со значением LimitNOFILE=1048576. Его можно использовать как временное решение проблемы.

Почему это работало в Ubuntu

В начале статьи мы писали, что многократно тестировали установку Okmeter и всё работало. Также мы рассмотрели проблему при запуске на РЕД ОС. Но почему, если systemd и containerd последних версий, это не проявляется, например, в Ubuntu? Дело в том, что разработчики Ubuntu заметили эту проблему и сделали дополнительный патч для systemd. Ниже приведён перевод их комментария к этому патчу:

Не увеличивайте fs.nr_open для главного процесса (PID 1). В версии v240 systemd задрала параметр fs.nr_open для процесса с PID 1 до максимального возможного значения. У процессов, порождаемых непосредственно systemd, RLIMIT_NOFILE будет (жёстко) установлен на 512K. В Debian pam_limits по умолчанию установлен на «set_all», то есть, если лимиты явно не заданы в /etc/security/limits.conf, будет использоваться значение для PID 1. Это означает, что для логин-сессий RLIMIT_NOFILE вместо 512K будет равен максимальному возможному значению. Не каждое ПО способно нормально работать с таким высоким RLIMIT_NOFILE.
Такое значение pam_limits, установленное по умолчанию в Debian, безусловно, вызывает вопросы. Однако обойти его можно, не повышая значение fs.nr_open для процесса с PID 1.

Заключение

Итак, ранее в Linux просто закрывались все дескрипторы в цикле, но в нашем случае количество закрываемых дескрипторов увеличилось до миллиарда, что значительно замедлило выполнение программы и привело к потере отзывчивости monitor. Причина заключалась в том, что в systemd и containerd были внесены несвязанные изменения: в версии systemd v240 было увеличено значение fs.nr_open по умолчанию в 1000 раз — с миллиона до миллиарда, а в containerd изменили значение директивы LimitNOFILE в systemd unit-файле с константы в один миллион на infinity.

Как временное решение можно использовать override и дождаться, пока PR будет принят и ядро в вашей ОС обновится, так как количество файловых дескрипторов к закрытию определяется по умолчанию на основании переменной, а изменение в ядре позволит не зависеть от значения этой переменной.

P. S.

Читайте также в нашем блоге:

Как несвязанные коммиты в пакетах Linux привели к неожиданным проблемам. Практические истории из SRE-будней. Часть 7