Праздник «день программиста» отмечается в 256-й день года, а это 2⁸, т.е. два в степени восемь. Это не просто так — на степенях двойки многое завязано в компьютерах и программировании, они повсюду. Настолько повсюду, что иногда даже слишком.

Благодаря празднику я вспомнил, что давно хотел написать эту статью, и поделиться несколькими техническими байками, где числа, являющиеся степенями двойки, вставляли «палки в колёса» мне или моим коллегам.

Вводная

Я расскажу про ряд технических проблем, с которыми пришлось столкнуться в работе. Все проблемы связаны с запуском большого числа docker контейнеров, но суть не только в них. Главное, везде фигурирует число, которое является степенью двойки, причём как ключевое звено истории. Это мне и кажется, как минимум, забавным.

В общем, пробуем запустить кучу docker контейнеров в рамках одного сервера, но что-то постоянно идёт не так...

2⁸ = 256

Первый барьер случился на отметке ~256 контейнеров. Сразу оговорюсь, что проблема воспроизводилась в маленькой окрестности этого числа, так что, это небольшое художественное преувеличение ради упорядочивания повествования. Но! Точная степень двойки тут всё же возникнет и сыграет свою ключевую роль, просто чуть позже.

Выглядело это так. Есть управляющее приложение, которое написано на C#. С помощью него запускались docker контейнеры на сервере. При достижении ~256 запущенных контейнеров, процесс этого управляющего приложения просто «падал». Всё, что оставалось после падения, это ошибка *** buffer overflow detected ***: /bin/dotnet terminated. Больше в логах не оставалось никаких подсказок о причинах. Но что это за буфер и почему он переполнился?

Усугублялось всё тем, что и .NET не оставлял crashdump, в котором можно было бы что-то подглядеть. На руках был только Linux core dump, который содержит исключительно нативные стектрейсы и ничего не знает о managed коде на C#.

Что ж, будем работать с тем, что есть. Вооружаемся gdb, смотрим core dump, видим такой трейс:

======= Backtrace: =========
/lib64/libc.so.6(__fortify_fail+0x37)[0x7f2d1abf7697]
/lib64/libc.so.6(+0x116812)[0x7f2d1abf5812]
/lib64/libc.so.6(+0x1185f7)[0x7f2d1abf75f7]
/lib64/libteamdctl.so.0(+0x2acf)[0x7f0cd427dacf]
/lib64/libteamdctl.so.0(+0x1b63)[0x7f0cd427cb63]
/lib64/libteamdctl.so.0(+0x1cf2)[0x7f0cd427ccf2]
/lib64/libteamdctl.so.0(teamdctl_refresh+0x12)[0x7f0cd427d012]
/lib64/libteamdctl.so.0(teamdctl_connect+0x101)[0x7f0cd427d151]

всё сводится к библиотеке libteamdctl.so.0 и функции teamdctl_connect.

Это была хорошая подсказка. В этот момент вспомнилось, что на серверах настроен тиминг. Было известно, что в коде управляющего приложения, которое запускает контейнеры, точно нет прямого взаимодействия с чем-то подобным. Но внутри использовалась отдельная библиотека для сбора метрик, в том числе про сеть. В голову сразу пришла мысль проверить, а нет ли в этой библиотеке использования чего-то подобного?

В коде этой зависимости сразу же нашлось использование libteamdctl.so.0:

        [DllImport("libteamdctl.so.0")]
        private static extern int teamdctl_connect(
            [In] IntPtr ctl,
            [In] string teamName,
            [In] string addr,
            [In] string ctlType);

Ура, повезло, похоже идём в правильном направлении! Отключаем сбор метрик про сеть и всё начинает работать, контейнеры запускаются. Только вот до сих пор непонятно, в чём конкретно проблема, почему всё ломалось? Но хотя бы понятно, где нужно копать.

Пристальным изучением исходников libteamdctl.so.0 библиотеки, которая написана на языке Си, выяснилось: функция teamdctl_connect внутри использует клиента, который может быть поверх usock, или d-bus, или zmq. При желании, можно погуглить, что это за штуки такие, но в данном случае это неважно. Важно то, что по умолчанию выбирается первый клиент, который оказывается "рабочим". В данном случае, это клиент поверх usock, т.к. он идёт первым по порядку в коде библиотеки.

Внутри этого клиента используется функция select. В документации по этой функции прямым текстом написано, что в ней есть баг. Дело в том, что внутри реализации glibc существует константа FD_SETSIZE, которая равна 1024 и ограничивает набор файловых дескрипторов, которые может отслеживать эта функция. Как только открытых дескрипторов становится 1024, вызов этой функции неизбежно обречён завершиться ошибкой.

Итого, ситуация такая: при количестве контейнеров в ~256 штук, на сервере скапливалось 1024 открытых файловых дескриптора, после чего попытка открыть новые, т.е. запустить ещё контейнеры, приводила к краху функции select в механизме сбора сетевых метрик и всего процесса управляющего приложения в целом.

Вот она, магия чисел 256 и 1024. А фикс проблемы в итоге достаточно простой: при вызове функции teamdctl_connect явно передавать параметр cli_type = dbus, чтобы использовался клиент поверх dbus, где уже нет описанных недостатков.

Забавный факт. После этой истории нагуглилось что-то очень похожее на переписку по почте, где как раз обсуждается данный баг и даже предлагается патч на него, но в итоге патч не был принят.

2⁹ = 512

Следующий барьер поджидал на отметке ~450-500 контейнеров. Точная степень двойки, опять же, возникнет попозже :)

Выглядело это так: когда набиралось указанное число контейнеров, на сервере начинались очень жёсткие проблемы с DNS и сетью. Все контейнеры резко переставали резолвить любые DNS-имена, исходящие запросы не работали, даже локальные TCP-соединения между процессами внутри сервера ломались. При этом, по системным ресурсам (CPU, RAM, Network) сервер выглядел нагруженным примерно на 10-20%. И как к такому подступаться?

Для начала, накину немного контекста. В рамках управляющего процесса, который запускает контейнеры, есть периодическая проверка сервера на работоспособность DNS. Это, как многим известно, называется healthcheck. Суть этого хелсчека в том, что, периодически, из DNS кэша чистятся записи о некоторых именах, а затем идёт попытка их снова разрезолвить. Если получается, значит DNS и сеть на сервере действительно работает. В данном случае, для этого, в том числе, используется unbound — это DNS кэш для Linux. В Linux не во всех дистрибутивах есть встроенный DNS кэш, в отличие от Windows. Тут была CentOS 7.9. Кэш на таких активных хостах, где куча произвольных контейнеров ходят в кучу произвольных DNS имён, конечно же, нужен.

Так вот, первое, что бросалось в глаза, это неуспешные хелсчеки на DNS. Они падали из-за того, что операция сброса кэша не успевала завершиться за таймаут. Подозрения сразу же упали на unbound, ведь это ненативная штука. К тому же, именно unbound отвечает за DNS, который вроде как сломан. А вдруг unbound не может выдержать такую нагрузку? Или вдруг его неправильно настроили? Будем проверять и экспериментировать. Довольно быстро начали находиться подкрепления этим гипотезам. Например, на одном из серверов, unbound просто напрочь завис и не отвечал ни на какие запросы, даже когда нагрузки уже было ноль, а все контейнеры выключены.

Посмотрим с помощью gdb в процесс unbound. Увидим, что там всего 1 поток, который завис на методе socket_read:

(gdb) thread apply all bt

Thread 1 (Thread 0x7fd68d2a2840 (LWP 14937)):
#0  0x00007fd68c19b740 in __read_nocancel () from /lib64/libpthread.so.0
#1  0x00007fd68c4c666b in sock_read () from /lib64/libcrypto.so.10
#2  0x00007fd68c4c46ab in BIO_read () from /lib64/libcrypto.so.10
#3  0x00007fd68ce4a3c4 in ssl3_read_n () from /lib64/libssl.so.10
#4  0x00007fd68ce4bcbd in ssl3_read_bytes () from /lib64/libssl.so.10
#5  0x00007fd68ce486d4 in ssl3_read_internal () from /lib64/libssl.so.10
#6  0x000055aa405f0905 in handle_req.isra.18.9925.4909 ()
#7  0x000055aa405f0b41 in remote_control_callback ()
#8  0x00007fd68cbe8a14 in event_base_loop () from /lib64/libevent-2.0.so.5
#9  0x000055aa40619a0c in comm_base_dispatch ()
#10 0x000055aa40621441 in daemon_fork ()
#11 0x000055aa405b6d08 in main ()

т.е. пытается вычитать какие-то данные из сокета. Понятно, что раз он там завис, это значит, что никто уже данные в этот сокет писать не собирается, т.е. клиент, видимо, отпал.

Стектрейс указывал, что это был запрос из unbound-control, а хелсчек как раз пытается выполнить такую команду: unbound-control flush www.google.com. При этом, если хелсчек за таймаут не смог этого сделать, то логика прибивает процесс unbound-control, чтобы не плодить зомби-процессы.

Нетрудными логическими усилиями можно понять, что происходит следующая гонка: пытаемся сделать unbound-control flush www.google.com, тем самым открываем сокет соединение к unbound; из-за проблем с сетью на сервере это не получается сделать за таймаут; терминируем процесс unbound-control; тем временем сам unbound наконец доходит до обработки этого запроса, пытается вычитать данные из сокета, но уже всё, поздно, клиента прибили и данные в сокет никто не напишет. Итого - всё зависло, ведь по дефолту unbound однопоточный, а единственный поток встал на ожидании того, что никогда не произойдёт.

Так стало понятно, что unbound в данном случае плохо настроен, быстро нашлось как нужно его настраивать для высоконагруженных серверов, в том числе, конечно, делать его многопоточным.

Хорошо, применили новый, правильный конфиг, unbound перестал намертво зависать. Но исходную проблему это никак не полечило, она осталась. Параллельно, сделали нагрузочный тест unbound и увидели, что он переживает около 85 000 RPS, что было сильно выше нагрузки в данной ситуации, т.е. имеется огромный запас прочности. Таким образом, стало понятно, что unbound работает хорошо и надо искать проблему дальше, в другом месте.

Между делом, было подмечено, что версия docker на разных серверах была разная, и как будто более новая версия работала лучше. Но, обновив docker везде, стало понятно, что это тоже неверная гипотеза, т.к. проблема осталась.

На этом моменте был небольшой тупик. Явных гипотез по симптомам уже не удавалось найти. Но, как всегда, на помощь пришёл поиск информации в интернете. Удалось нагуглить темы про похожие проблемы, а там мелькали советы про тюнинг настроек ARP кэша на сервере.

В Linux есть настройки семейства net.ipv{4,6}.neigh.default.gc_thresh{1,2,3}, которые настраивают поведение очистки ARP записей. Настройка с 1 на конце — до какого кол-ва записей GC вообще не будет ничего чистить; с 2 на конце — после этого числа GC будет агрессивным и начнёт чистить записи каждые 5 сек; с 3 на конце — после этого кол-ва GC будет чистить всё немедленно.

Угадайте, какие дефолты у этих настроек? Конечно же, GC становится агрессивным по умолчанию на числе 512 (и совсем сходит с ума на 1024), именно примерно на таком количестве контейнеров всё переставало работать, но главное тут, это количество ARP записей, потому что GC ARP кэша начинал вредить — постоянно вычищать то, что на самом деле нужно здесь и сейчас. Контейнеры добавляли ARP записи, а GC их чистил. И так по кругу. Из-за этого всё и деградировало.

Вот она, магия числа 512. После тюнинга этих настроек на серверах, всё заработало.

2¹⁰ = 1024

Следующий барьер случился на отметке 1024 контейнера. И это уже точное число.

Выглядело это так: запуск ровно 1024 контейнера заканчивался ошибкой failed to create endpoint <some endpoint name> on network bridge: adding interface <some interface> to bridge docker0 failed: exchange full.

Тут уже не будет длинной истории про раскопку ошибки, т.к. она понятная и легко гуглится. Дело в том, что docker предлагает несколько вариантов того, как устроить сеть для контейнеров на сервере. Например, это может быть bridge, overlay, host. Конкретно тут была bridge сеть по ряду причин. Но ядро Linux имеет фундаментальное ограничение — максимум 1023 сетевых интерфейса для bridge сети. Об этом, кстати, упомянуто в документации docker. Это ограничение можно обходить, например, компилировать ядро Linux с другой константой, или шардировать контейнеры на несколько bridge сетей внутри одного сервера. Это решение и было выбрано.

Вот она, магия числа 1024. Этот кейс примечателен тем, что тут раскопка проблемы лёгкая, а решение относительно сложное. В двух предыдущих ситуациях было наоборот — трудно раскопать, но легко починить.

2ª = x

Ждут ли ещё какие-то сюрпризы дальше? Неизвестно. 6000 контейнеров на одном сервере запустить возможно, но, кажется, что такие большие числа на данный момент просто не нужны в реальной жизни.

Было увлекательно находить подобные закономерности в разных проблемах. На самом деле, после первой проблемы контекст остался в голове, и уже в следующие разы, гипотезы про «магическое число» мелькали сразу же, и направляли в верное русло.

Поэтому, продолжайте творить и не теряйте интерес раскапывать даже самые запутанные, на первый взгляд, проблемы. Всех с праздником!