Pinterest поддерживает формирование отчётов по метрикам рекламных объявлений внешних рекламодателей и расчёт рекламных бюджетов в реальном времени. Всё это основано на потоковых конвейерах обработки данных, созданных с помощью на Apache Flink. Доступность заданий (job) Flink для пользователей находится на уровне 99-го перцентиля. Но время от времени некоторые задачи (task) «валятся» под ударами неприятных ошибок, вызванных утечками прямой памяти (Out-Of-Memory, OOM), возникающими сразу в нескольких операторах. Выглядит это примерно так:
Как и в случае с большинством проблем, происходящих в распределённой системе, подобное часто ведёт к целому каскаду сбоев в самых разных местах. Одна такая ошибка оставляет после себя множество ложных следов. Flink‑платформа, используемая в Pinterest, поддерживает автоматический перезапуск задания в том случае, когда объём сбоев превысит настраиваемое пороговое значение. Но, из‑за того, что такое происходит нечасто, мы, для обеспечения отказоустойчивости системы, обычно позволяем произвести автоматический перезапуск с самой свежей контрольной точки. К концу прошлого года мы начали консолидацию кластеров и подкорректировали выделение памяти во всех заданиях ради повышения эффективности использования ресурсов. Неожиданным следствием этого шага стало то, что мы, в начале текущего года, стали получать целые страницы сообщений об утечках прямой памяти. Это повлекло за собой сбои и повлияло на службы, зависящие от нашей системы. Всё более очевидным становилось то, что с этой проблемой надо что‑то делать. В этом материале мы расскажем об используемом нами процессе поиска ошибок и поделимся идеями, которые могут пригодиться при отладке любой крупномасштабной распределённой системы. Такой системы, где одних лишь разумно размещённых инструкций print для борьбы с ошибками недостаточно.
Первая часть головоломки заключалась в том, чтобы отделить симптомы проблемы от её первопричины. В ходе инцидента мы обратили внимание на высокий уровень обратного давления (back pressure) у нескольких операторов, а так же — на сбои задачи, отражённые на вышеприведённом стрек‑трейсе. Сначала нам показалось, что возможной причиной проблемы могут быть и неполадки уровня контейнера. А именно, у контейнера могла закончиться память в ходе выделения прямой памяти для сетевых буферов, используемых для организации работы каналов ввода/вывода. Это привело к первому набору действий — к искусственному вызову отказов задач и к созданию высокого обратного давления на экземпляре задания, используемого в ходе разработки. При этом мы наблюдали за тем, как всё это воздействует на потребление прямой памяти. Делалось это для того, чтобы установить причинно‑следственную связь между этими двумя событиями.
Но сначала нам надо было найти временное решение, позволяющее предотвратить частое обращение к дежурным инженерам в то время, пока мы устраняем глубинную причину проблемы. Для того чтобы это сделать, полезно было вспомнить о том, как устроена модель памяти Flink.
Как видно на предыдущем рисунке — конфигурацию прямой памяти Flink можно разделить на три части. Это — память фреймворка вне кучи (framework off‑heap memory), память задания вне кучи (task off‑heap memory) и сетевая память (network memory). Память фреймворка вне кучи зарезервирована для внутренних операций Flink и для структур данных. Не зная точно о том, вызвана ли OOM утечкой памяти уровня приложения, мы увеличили и память задания вне кучи и сетевую память с 2 до 5 Гб. Мы сознательно сделали столь щедрый жест, надеясь на то, что «купим» себе таким образом достаточно времени для решения проблемы.
Искусственное создание обратного давления
Так как в нашем задании Flink имеется лишь один выходной Sink‑оператор — создание обратного давления сложностей не вызвала. А именно — для этого достаточно было добавить в главный поток длинную паузу, воспользовавшись конструкцией Thread.sleep(). Так как такой оператор на обрабатывает какие‑либо входные записи, входные буферы всех операторов, находящихся перед ним, быстро переполнятся, что создаст значительное обратное давление.
На рисунке показана ситуация с обратным давлением в различных операторах, возникшая после некоторого времени работы приложения. Это неизменно ведёт к нехватке прямой памяти на узлах, подверженных обратному давлению. А это, в свою очередь, вызывает отказы заданий.
Искусственный перезапуск заданий
В Pinterest Flink-приложения отправляют менеджеру ресурсов, входящему в состав YARN. Он распределяет задачи заданий по контейнерам, расположенным на машинах, которыми управляют сущности YARN NodeManager. Для того чтобы сымитировать перезапуск задач, мы останавливали случайным образом выбранные экземпляры контейнеров, используя команду yarn container -signal [container-id] GRACEFUL_SHUTDOWN, наблюдая при этом за тем, как приложение потребляет прямую память.
График на предыдущем рисунке иллюстрирует воздействие искусственно вызванных сбоев на потребление прямой памяти. Он показывает заметное увеличение потребления памяти, возникающее в точности тогда, когда мы останавливаем контейнер. Это, в итоге, вело к OOM‑ошибкам, а когда останавливался кворум контейнеров одного и того же оператора, вызывало возникновение обратного давления на узлах, предшествовавших этому оператору. «Лестничный» паттерн на графике выглядит особенно интригующим, так как это — красноречивое свидетельство утечки памяти. Значит — где‑то в коде была выделена прямая память, которую не освободили должным образом.
Для того чтобы сузить сферу поиска, мы решили выяснить — является ли причиной происходящего ошибка платформы, или проблема, связанная с логикой приложения. Чтобы это сделать — мы повторили ручной перезапуск задачи на отдельном приложении, в котором не выполнялась логика нашего задания. Мы хотели понаблюдать за тем, появится ли при этом уже знакомый нам паттерн потребления прямой памяти. Это указало бы на то, что, возможно, во всём виновата ошибка уровня платформы.
Как видно на предыдущем рисунке — в другом Flink‑приложении никаких заметных пиков в потреблении прямой памяти нам заметить не удалось. Это послужило убедительным доказательством того, что источник утечки памяти связан с ошибкой в коде нашего приложения.
Отладка кода приложения
Наше Flink‑приложение состоит из нескольких тысяч строк кода. При отладке столь масштабной кодовой базы полезно использовать подход, который можно сравнить с чисткой лука. А именно — речь идёт о том, что код разбивают на небольшие компоненты, исследуемые с целью воспроизведения проблемы. Очень упрощённая схема нашего приложения выглядит так.
Первый слой (Layer 1 на рисунке) выполняет чтение из различных топиков Kafka, десериализует данные, формируя внутренние объекты, и передаёт их на второй слой (Layer 2), который объединяет выходные данные и производит некоторые трансформации. Этот слой, кроме того, выполняет кое‑какие RPC‑вызовы к внешнему KVStore, обращаясь к downstream‑службам, после чего передаёт данные третьему слою (Layer 3), который трансформирует данные и передаёт событие в Druid. Эти три слоя заключают в себе группу операторов, использующих прямую память. Вооружённые знаниями об архитектуре приложения, мы можем, в индивидуальном порядке, убирать некоторые из операторов и пытаться воспроизвести проблему, вручную перезапуская задачи. При таком подходе мы можем изолировать оператор, являющийся источником проблемы, и исправить код.
Убираем операторы 2 и 3 слоёв
На прерыдущем рисунке некоторые операторы из второго слоя выполняют RPC‑вызовы к внешнему KVStore с очень большими объёмами передаваемых данных. Мы подозревали, что именно эти большие объекты вызывали OOM‑ошибки в том случае, если объект DirectByteBuffer из Thrift не мог зарезервировать достаточно прямой памяти для выполнения сетевых операций ввода/вывода.
В слое 3 тоже используется память вне кучи. В ней хранятся курсы обмена валют для различных стран. Эти сведения загружаются из внешнего хранилища данных. Раньше эти вычисления выполнялись с использованием памяти кучи, на которую они создавали очень серьёзную нагрузку. Файл, хранящий обменные курсы, периодически загружался из хранилища, подвергался парсингу для извлечения из него полезной информации, трансформировался в хеш‑карту, которая потом заменяла старую (иммутабельную) хеш‑карту. Старая хеш‑карта затем перемещалась в область памяти, предназначенную для хранения сущностей старого поколения (Old Generation). Это значит, что соответствующая память не освобождалась до следующего вызова полной процедуры сборки мусора. Из‑за большого размера данных онлайн‑приложения, и из‑за того, что полная сборка мусора выполняется нечасто, мы перешли на решение, использующее память вне кучи, применив ChronicleMap. При этом проблема, связанная с освобождением этой памяти, вполне может, со временем, привести к OOM‑ошибке. В результате мы начали с того, что убрали эти блоки кода. Далее — мы перезапускали задачи, выбираемые произвольно и связанные с оставшимися операторами, наблюдая при этом за воздействием происходящего на потребление прямой памяти.
Как и ожидалось — мы не заметили каких‑либо аномалий в потреблении прямой памяти. Это позволило нам сузить область поиска причины утечки памяти до оставшихся операторов.
Убираем операторы слоя 3
Теперь мы удалили операторы слоя 3, использующие ChronicleMap для реализации логики приложения и повторили уже знакомый эксперимент по искусственному перезапуску задач.
Предыдущий рисунок иллюстрирует обнаруженное нами небольшое отклонение, но на нём не наблюдается «лестницы», которая позволила бы сделать вывод об утечке памяти в оставшихся операторах. Это показалось нам интересным, так как, в противовес исходному предположению, мы не смогли найти свидетельств утечки памяти в операторах, которые взаимодействуют с KVStore посредством RPC‑вызовов.
Убираем операторы слоя 2
Далее — изолируем операторы третьего слоя, убрав операторы слоя 2, которые тоже используют прямую память.
Вот оно! Мы смогли воспроизвести проблему в урезанном варианте кода приложения. На схеме эта проблема устрашающе похожа на ту, которую мы наблюдали в самом начале, анализируя поведение полной версии кода. Мы нашли убедительные доказательства того, что утечка прямой памяти коренится в коде, относящемся к третьему слою приложения, в котором используется такая память.
Исправление ошибки
После исследования проблемного оператора, мы обнаружили, что ссылка на ChronicleMap удалялась, но при этом связанная с ней память не освобождалась, что и приводило к утечке. Эта память не освобождалась до выполнения следующей полной процедуры сборки мусора, что особенно проблематично в онлайн‑службах наподобие нашей, при проектировании которых стремятся к тому, чтобы сборка мусора выполнялась бы не слишком часто.
Для того чтобы лучше с этим разобраться, разумнее всего будет поговорить о жизненном цикле задач Flink и о внутреннем механизме их перезапуска. Он используется при остановке задач из‑за сбоев. В такой ситуации JVM продолжает работу, а при выполнении Flink‑кода осуществляется переход на метод close() оператора, затронутого сбоем. После перезапуска Flink вызовет метод open(), определённый в коде оператора. Если логика ссылается на объект (вроде ChronicleMap), находящийся за пределами жизненного цикла оператора, код может непроизвольно вызвать утечку памяти.
После исправления утечки мы снова организовали перезапуск задачи и понаблюдали за воздействием этого на потребление прямой памяти.
Как видно на предыдущем рисунке, мы наблюдаем ровную линию, описывающую характер потребления памяти. Она сильно отличается от той «лестницы», которую мы видели в самом начале.
Итоги
Код, устраняющий утечку памяти, тесно связан с логикой нашего приложения. Но главным, универсальным результатом нашей работы стала сама процедура нахождения первопричины проблемы. На примере истории борьбы с нашим сбоем мы прошли через девять принципов отладки, которые описал Дэвид Дж. Аганс в книге «Отладка: девять незаменимых правил для обнаружения самых неуловимых ошибок в ПО и „железе“»:
Изучите свою систему.
Воспроизведите ошибку (надёжно воспроизведите).
Не предполагайте, а смотрите.
Разделяйте и властвуйте.
Вносите по одному изменению за раз.
Записывайте всё, что происходит.
Проверьте кабель.
Воспользуйтесь чьим‑то свежим взглядом.
Если вы не исправили ошибку — она не исчезла.
О, а приходите к нам работать? ? ?
Мы в wunderfund.io занимаемся высокочастотной алготорговлей с 2014 года. Высокочастотная торговля — это непрерывное соревнование лучших программистов и математиков всего мира. Присоединившись к нам, вы станете частью этой увлекательной схватки.
Мы предлагаем интересные и сложные задачи по анализу данных и low latency разработке для увлеченных исследователей и программистов. Гибкий график и никакой бюрократии, решения быстро принимаются и воплощаются в жизнь.
Сейчас мы ищем плюсовиков, питонистов, дата-инженеров и мл-рисерчеров.
Antgor
Хороший пример.
Но в вашем случае явно виден источник утечки в меткиках DirectBuffer Pool (количество аллокаций и суммарный размер). И включив NMT вы увидите прогрессирующую статистику. Дальше можно снять хипдамп и увидеть ненормальное количество инстансов класса.
Но у DirectBuffer есть очень нехороший паттерн поведения, когда RSS процесса растет, а все метрики по Native Memory в норме, что может привести к системному OOMKiller.
Это связано с тем, что под капотом DirectBuffer pool никакого пула на самом деле нет. Есть только Atomic каунтеры количества и размера. А механизм это тривиальные malloc() - free(), ну и плюс к объекту, использующему этот "пул" прикручивается java.lang.ref.Cleaner (c 11 версии). Поэтому и зачистка только во время GC. В итоге получается, что в нативной памяти процесса создаются и удаляются "кусочки памяти" которые ведут к её фрагментации и распуханию RSS, который невозможно диагностировать стандартными метриками. Обычно утечка проявляется на хорошо нагруженных сервисах обрабатывающих http/grpc.
Раньше с проблемой бороться было невозможно, кроме перезапуска приложения, но в glibc с версии 2.8 завезли malloc_trim() который умеет во всем адресном пространстве процесса релизить "залипшую память".
В JVM в DiagnosticCommand сделали метод trimNativeMemory() который можно дернуть через JMX MBean (в контейнере) или через jcmd в обычной инсталляции. А в JVM 17.0.9 сделали ключ -XX:TrimNativeInterval (пока экспериментальный) который взводит таймер регулярных malloc_trim()
С точки зрения GC, проблему, описанную в статье на небольших сервисах "лечил" паллиативно путем использования ZGC (утечки были в зависимостях, не в нашем коде). У G1 да, были проблемы с утечками буферов, но вроде бы они её вылечили и они чистятся сейчас в mixed фазе, но это не точно.